[Looking for Charlie's main web site?]

The ColdFusion 'metrics log', an oft-missed or misunderstood feature, 'new' since CF10 (Part 1)

I'd like to take a diversion from my recent posts focused on CF2016 and talk about something that applies (and should interest) anyone using CF 10, 11, or 2016.

Have you heard of the new "metrics log" option that was enabled in CF10? If you have not, it's worth knowing about (there's precious little documentation, and I'll point to it, and give you still more info to help you use it). It's a useful, low-impact mechanism to get some high-level metrics logged by CF every 60 seconds (by default), and stored along with other CF logs.

If you did know about it, you've probably had some problems with it. Why does it show "nulls"? What do reported metrics really mean? Why do they not jive with what I'd expect to be the numbers reported?

In this post, and a Part 2 to come, I will introduce the metrics log, pointing out some key things you need to know to have it setup to work at all, and then I'll share my observations of things I've come to understand about the reported metrics.

I will be dividing this post into two parts (two posts). This first one will offer some overview about the metrics log, enabling it, some common problems with it (like the "null" values), and a quick overview of some key things to know. Then in part 2, I'll discuss each field in the log in more detail, offering with my take (from experience observing them, and given the lack of docs) on what the fields are about and how to use them for problem-solving.

Let's proceed with the topics I'll cover in this first part, which we might title, "Overview of the Metrics log: enabling it, common problems ("null values"), and some points to ponder".

1) Enabling it, and finding the docs for it

First up, what is the metrics log, and how do you enable it? For that, I will point you to the one resources about it that I have found offered on the Adobe site:

Enable Metric logging

It's a technote from the CF10 timeframe, and it does an adequate job of pointing out how to enable it, via the CF Admin. It explains where the logs are stored, how you can change the logging frequency, etc.

It doesn't mention it, but you also don't need to worry about the metrics log (or any CF log) taking up lots of space. There is a built-in archival mechanism, which lets any CF log grow at most to 20m, at which point it rotates and keeps up to 10 rotations (which can be controlled in the CF Admin Logging Settings page.)

There's an even more important key facet that it does NOT touch on, which I address next.

2) You almost certainly will need to change the "Connector port" on that page

Sadly, that technote does NOT tell you that you very likely will need to change the "Connector port" field on the bottom of that CF admin change where you enable the metrics logging. If you don't, you will either find that most of the metrics in the log are "null" (literally that word), or they appear "wrong". More on that in a moment.

It will default to either the value used for the internal web server, if you chose to use that at installation of CF (which may be 8500, 8501, 8502, or other values, depending on whether 8500 was already in use at the time you installed CF.). Or if you did NOT choose to enable the built-in web server at installation, or did so later, then the default value in this "Connector port" field on the Admin page will be 8500.

(For more on the internal, or "built-in" web server for CF, see a post I did in the CF10 timeframe, as it's not changed: The built-in web server in ColdFusion 10: enabling it, configuring it, reconsidering it.)

Either way, unless you use that internal web server for all your inbound requests to CF, then you do NOT want THAT port to be the listed "Connector port".

Assuming your "real traffic" into CF comes by way of an external web server (IIS, Apache, etc.), you will want to change that "Connector port" field to the value of the "ajp port" port, which is the port over which the web server and CF talk to each other. (It is NOT the port that your users type in to visit your site, whether that's 80, 81, 82, or so on.)

The "ajp port" is something a user would NEVER type in, so you need to find it in the CF configuration files. There are two places to find it.

One is the server.xml file of your [coldfusion]\cfusion\runtime\conf folder (or replace "cfusion" with your instance name if running CF Enterprise and multiple instances). That line may look like this, for instance:

<Connector port="8014" protocol="AJP/1.3" redirectPort="8447" tomcatAuthentication="false" />

Just do be careful when viewing lines in that file. There are many different "Connector" lines pointing to different ports, and some are in comments. You're looking for one that is UNCOMMENTED and referring to protocol="AJP/1.3", by default.

You can also find the AJP port in the workers.properties file of your [coldfusion]\config\wsconfig\[n] folder, where "n" will be a number for each "connector" you may have. (If you have multiple instances, just beware that different connectors will likely point to different ports. That's why I pointed you to the server.xml as the better file to get the port. That WILL tell you the incoming "ajp port" for your instance.)

Put that port value in the "Connector port" field, and restart CF, and you should now see "real" values in the metrics logs.

And let me note that blogger Chris Tierney had done a post on this in 2014, and you can get more details from him (including showing examples of the log lines with "null" values, as well as a screenshot of the CF admin page, and more): ColdFusion 11 Metrics Log NULL values.

And as he notes, this "Connector port" setting ALSO controls the command-line CFSTAT tool, also enabled on the same page. (That tool, and some configurability as well as warts with it, is another topic for another time.)

3) So why do most of the fields in the log report "null" values for some folks?

Despite the title of Chris' aforementioned blog post, he doesn't really explain is why you get "null" values until you make this change. (But he does an admirable job of explaining the need to make the port change discussed above, so it's worth a look.)

So why do some see nulls? Well, if the port that's pointed to in the "Connector port" field is NOT a port that CF uses for ANY incoming web connections, then it will report "nulls", because there's nothing CF can look at to get the metric data. That's why it's critical to get the "Connector port" right.

Again, though, if you DO change the "Connector port" field in the CF admin, you will need to restart CF for that change to take effect, whereas you do not need to restart CF to just "enable" the metrics log. (That's one other point Chris's otherwise helpful post failed to point out. And I'll note that CF11 and above does now warn you of this if you change the port.)

4) So what's in the log?

OK, finally, we can start to discuss the log lines themselves. While I'll get into more detail about each field in Part 2, let's start here with just an example line, from a lightly loaded development workstation:

"Information","scheduler-0","03/01/16","23:30:28",,"Max threads: 200 Current thread count: 10 Current thread busy: 0 Max processing time: 52752 Request count: 315 Error count: 6 Bytes received: 866 Bytes sent: 4633883 Free memory: 249674752 Total memory: 381681664 Active Sessions: 3"

That Adobe technote above gives longer names to the fields, but it offers only a very brief explanation for each. Still, it's at least a start if you're anxious to know more (and which everyone should read if you have not yet done so, as it's quite brief).

I'll try to fill in the gaps and expand on each field considerable in part 2.

5) Why might the log line values STILL not look "right" perhaps?

I've already explained in the second section above about the importance of getting the "connector port" specified correctly in the CF admin when enabling the metrics log.

Even if you do that, some aspects of the reported metrics may still not look "right" to you.

Along those lines, and before detailing each field in part 2, here are some general observations I've come to understand about the metrics in general (which may help some who find even just this Part 1 first, while trying to resolve possible confusion in understanding the values):

  • Consider that you may have requests that you DO make via your external web server as WELL as the internal web server. (Many use the latter for accessing the CF Admin, for instance. And that's the default behavior in CF 2016.) But note that the metrics log can only track requests made against ONE port, so beware that it cannot track ALL requests made against CF. It ONLY tracks those made against the given, specified "connector port" (see the second section, above). So be careful you don't expect to see a summation of values representing requests against both the internal AND external web server. You will not see that.
  • While it may make ready sense that some of the fields are specific to requests that come in on a given connector port (like those referring to "threads"), my testing shows that ALL but the last 3 fields in the log are tracked ONLY with respect to requests made via that connector port. That could be a big surprise and another source of confusion if you did not expect it. More on that in part 2.

I also have some gripes I'd like to share about the feature (I'm sure some of you readers have them in mind already), but while could share them now I think it makes more sense to hold them to the conclusion of Part 2, and I'd ask you to so also, please.

And I certainly welcome feedback from others on this part, or that when it's done. This is one of those topics where (because of the lack of docs) we need to help each other out to better understand the ins and outs.

In the meantime, I hope that some of these introductory remarks here may help get some of you on the right track to using and making the most of these metrics. Look for Part 2 in the next day or two.

Comments
Waiting with bated breath for part 2! Seriously, thanks Charlie. Looking forward to it.
# Posted By Chris | 3/2/16 7:25 AM
Thanks Charlie - it's particularly tricky if you have more than one instance on a physical server. You have to be very careful to get the right server.xml or worker.properties value into the right server. Looking forward to part 2 to understand what the error count represents.
# Posted By Brian G | 3/2/16 10:32 AM
Hi Charlie,

Thanks *very* much for clarifying what to do about the connector port. I wanted to quickly note that I've filed 4115249 (Metrics Frequency reverts to 60 after CF restart) which affects both CF11 and CF2016 - so just something to watch out for.

Thanks!,
-Aaron
# Posted By Aaron Neff | 3/3/16 12:29 PM
@Chris, Brian, and Aaron, thanks for the kind regards. Part 2 is indeed in the works.

@Aaron, I'd not noticed that bug. Thanks for sharing it here.

@Brian, you raise two points.

First, sure about possible confusion with multiple instances. You seem to be posing that as a warning for people to note, but I hope you noticed I had indeed anticipated that issue with the following two points:

First regarding the location of the "right" server.xml, I listed the location and added "(or replace "cfusion" with your instance name if running CF Enterprise and multiple instances)".

And about the workers.properties, I'd said:

"(If you have multiple instances, just beware that different connectors will likely point to different ports. That's why I pointed you to the server.xml as the better file to get the port. That WILL tell you the incoming "ajp port" for your instance.)"

So I was indeed trying to anticipate that very challenge you raise. But thanks for calling it out, in case anyone else may have missed it--whether you did or not. :-)

Finally, as for meaning the error count field, well, it shouldn't be any real surprise--if you have configured the port right, that is. It's the count of errors that have happened in CFML.

But note my second bullet point in the last section of the post, it is among those first several fields which is ONLY counted regarding requests coming in on that named connector port.

Could that be why you have found it to be other than you expect, perhaps?
# Posted By Charlie Arehart | 3/3/16 1:05 PM
Charlie, I don't think error count is quite as simple as you propose. I'm battling with some issues now where almost immediately on start the server has an error count of 5 or 6. But there are no errors in exception.log or anywhere else that I can find. Where would these errors be occurring and why wouldn't they be logged?
# Posted By Brian G | 3/17/16 1:54 PM
Brian, that is indeed interesting. I'll do some more research as I prepare the part 2, to see if I may be able to help you. I have some ideas in mind but want to confirm them if I can first (or if you find an answer, please do let us know.)
# Posted By Charlie Arehart | 3/19/16 8:44 PM
Hi Charlie,

I was wondering if you ever posted the Part 2 to this article? I really appreciate your knowledge regarding this issue and am looking forward to working through to a solution to my connector tuning problem!
# Posted By Will Zablocki | 6/30/16 10:30 AM
Hi there,

thank you for your post and explanation about the metrics setup in CF10 and above.

Where can I find the Part 2?

Thanks in advance!

Kind regards from Germany,

Patrick
# Posted By Patrick Sch├╝tz | 2/8/17 9:00 AM
Thanks. Never did it. May eventually. Can't promise for now. sorry.
# Posted By Charlie Arehart | 2/8/17 11:16 AM
BlogCFC was created by Raymond Camden. This blog is running version 5.005. (Want to validate the html in this page?)

Managed Hosting Services provided by
Managed Dedicated Hosting