[Looking for Charlie's main web site?]

CF911: Lies, damned lies, and when memory problems not be at all what they seem, Part 1

Following on my earlier entry, CF911: Lies, Damned Lies, and CF Request Timeouts...What You May Not Realize, another common source of confusion and misunderstanding for people is when they think their server is "running out of memory", when in fact the problem is often not at all what they think. In this entry, I want to apply the same "cranky" tone :-) and extended explanation to this equally controversial/confusing topic.

I hear people raise concerns with memory problems quite often, whether in my CF Server Troubleshooting practice, or just in my participating in many mailing lists. Indeed, addressing this issue more than a few times the past couple of weeks has motivated me to create this, which will be a series of blog entries.

The series parts are expected to be:

  • Step 1: Determine if indeed you are getting "outofmemory" errors (this entry)
  • Step 2: Realize that OutOfMemory does not necessarily mean "out of heap" (entry to come)
  • Step 3: Diagnose why you really are running out of heap (if you are) (entry to come)
  • Step 4: Realize that having high memory usage is not necessarily a problem (entry to come)

Common refrains about memory issues

The common complaints about memory issues (and my quick responses, to give you a sense of where I'll be going in this series) are:

  • "CF has a memory leak" (to which I'd retort, no, generally, it does not. There's nearly always some other explanation)
  • "CF's use of memory is high" (which may not be a problem. If you're looking at memory from the OS perspective, it may not matter as much as heap use within CF)
  • "CF's use of heap memory is high" (to which you'd think, "ah, well that's got to be a problem, right?", but no, not necessarily, as I'll explain in part 4)
  • "CF is crashing all the time" (well, is it really crashing, or just hanging up and not responding? That's not a good thing, but it's very different from it crashing on its own)
  • "CF is running at 100% CPU before it crashes" (this could be related to memory problems, and more a consequence rather than a cause, or it could be entirely unrelated to memory issues)

So what if we really are suffering a problem?

I'm not saying there's never a real problem of really "running out of memory". It's just that often things are not at all what they seem (or what most presume them to be, from my experience helping people), and that's going to be the bulk of what I'll talk about in this series.

But what if your server is really crashing (or simply not responding), and you think/swear/know that it's a memory problem....

What should you do? Increase the heap size? Increase the permspace? Change the GC algorithm?

Sacrifice a chicken?

I'd say, none of them (though if you're in a rural setting, then perhaps cooking and eating the chicken might help settle your blood sugar so you can stay calm). Really, I know that goes against conventional wisdom, which seems always to suggest diving into the JVM settings. I'd say "hold on there, pardner."

Step 1: Determine if indeed you are getting "outofmemory" errors

This is one that surprisingly few people consider when faced with their server crashing or not responding. They go with whatever conveys to them a sense of there being a memory problem, perhaps adding their own experience or what they read, and they start chasing solutions.

I can't tell you how often I hear people lament that they've googled and found all manner of conflicting and confusing recommendations. And it doesn't help at all that they may be running on CF 8 or 9 (with Java 1.6) while reading about a "solution" written in the time of CF 6 or 7, when it ran on Java 1.4. Of course, the writer often won't have thought ahead to clarify that.

Instead, I'm saying, "stop, drop, and roll".

"Stop" the tail-chasing, "drop" into the pertinent logs directory in CF, and "roll" through them looking for an occurrence of "outofmemory".

Look first in the Runtime/JRun logs

Let me be more explicit: the logs you want to look at for these outofmemory errors are NOT the ones you see in the CF Admin Log Files page. Those are the [cf]\logs directory (or are buried deep within an instance on Multiserver).

Instead, look in the [cf]\runtime\logs directory (or [jrun]\logs on Multiserver), especially at the -out logs. If you're on Multiserver, there will be a prefix for each instance name in the log file names, and there are also -event logs there that you might be able to ignore. (If you're on *nix, you do want to also look at the cfserver.log in the main CF logs directory.)

Some refer to these as the runtime logs, or the jrun logs, or perhaps the jvm logs. Whatever you may call them, their location is above and the explanation of their value follows.

Bonus topic: you can increase the max log size

(I will note that the way these -out.log files work, by default, is that they fill at 200k increments. Yep, not 200mb, but 200kb!, and you may blow through dozens of them in a few minutes if things are going nuts. That size is configurable, but not through means you'd normally expect. See the blog entry I recently published, CF911: How to control the size of CF's -out.logs.)

Look next in the hotspot/pid/jvm abort logs

Separately, there are some other potentially important logs that may relate info concerning memory problems: what some call the "pid", "hotspot", or jvm abort logs. The filename is in a form like hs_err_pidnnnn.log, with some number in place of the n's.

These logs are found in a very unexpected place (for logs): in the directory where CF stores the jvm.config. So on Standard/Server deployments, that's [cf]\runtime\bin. For Multiserver, that's [jrun]\bin. Look in there for any .log files. There is one log for each time that the jvm crashes due to certain kinds of problems. It could be a crash in the hotspot compiler, in hotspot compiled code, or in native code.

What matters most, for this post, is that again you look in them for any reference to the phrase "outofmemory". (Of course, you'll want to look at them in the event of a crash for any other message or info, but explaining the parts and value of these "pid" log files is beyond the scope of this entry.)

So, when you have a crash and you suspect it's a memory issue (or if you don't know the cause and want to learn more about what it may have been), you want to look in these two log directories mentioned above. Many never do, and this is part of why they end up chasing their tails, going instead on gut feelings or trying out various alternatives. I say: find the diagnostic info, and act on it.

Searching through the log files, the easy way

But rather than "look" at all these logs in these directories, one at a time, I suggest instead that you search them (I was tempted to say "stop, drop, and mole" above, since you're "ferreting" through the logs, but it just seemed a stretch.)

If you're on *nix, I don't need to give you any more info on how to search the files. Just grep it and rip it. :-)

If you're on Windows, though, you'll perhaps be tempted to use the good ol' built-in Windows Search tool to search the directory. Let me plead, for the sake of all things decent, please use something better. It's just not a completely reliable (nor fast) tool.

I have blogged about a wonderful free alternative, called File Locator Lite. Use that instead. (If you have another tool or editor you favor, that's fine. No need to bring that up here. I recognize those other options in the other blog entry.)

The beauty of FLL is that having installed it (which is fast, itself), if you right-click on the log directory (or any directory) and choose "File Locator Lite" from the menu, you can then just put the string outofmemory in the search box, and it will in a few moments show any files found in the lower left pane. Then, here's the real beauty over other tools, you don't need to double-click the files to open them. You just single-click each file, and in the right pane, it shows any lines that had the string that was searched. Brilliant, and again, a really fast way to find things.

Don't stop at the last outofmemory error before a crash

This feature of the File Locator Lite tool (to see all the lines in the file with that string) is especially useful in this case, because when searching for outofmemory errors, you also want to be able to quickly see the time for *all* the error messages you may find.

And you *do not* want to focus solely on the last error prior to the crash (or the slowdown, that made you want to restart CF).

Once you find one (or more) preceding the time of the crash, you want to look for any occurring prior to it. It may be that the problem started several minutes before the crash (or your restarting CF). Further, it may be that the outofmemory error just prior to the crash is different from the one that started things out.

Step 1 down, 3 more to go

OK, that's step 1 in determining whether memory problems are really at all what they seem. As I mentioned at the outset, the planned parts in the series are:

  • Step 1: Determine if indeed you are getting "outofmemory" errors (this entry)
  • Step 2: Realize that OutOfMemory does not necessarily mean "out of heap" (entry to come)
  • Step 3: Diagnose why you really are running out of heap (if you are) (entry to come)
  • Step 4: Realize that having high memory usage is not necessarily a problem (entry to come)

After I publish them, I'll update the lists here to link to them.

As always, I look forward to your feedback (pro, con, or indifferent).

CF911: How to control the size of CF's -out.logs

As a CF user or Administrator running on Windows, have you ever wondered how to increase the size of the -out log file in the [cf]\runtime\logs directory (or [jrun]\logs in Multiserver)? This entry will tell you how. It's quite easy to do, but it's not done using usual log file size control settings in CF's Admin or XML files.

The quick answer is to use either of two approaches: either the jrunsvc.exe in CF's runtime\bin (or [jrun]\bin), or do a manual registry tweak, both of which I show below. If that's enough to get you going, there you have it. If you want (or need) more details, follow along.

BTW, if you don't know what CF's -out*.log files are about (they're important!), they're technically holding the console output for CF, when it's started as a Windows service. This can be vital information that is NOT logged in the normal [cf]\logs directory or Admin Log Files display. (If you're on *nix, the same info appears instead in the [cf]/logs/cfserver.log. I know some people have wondered about controlling the size of that file. I don't think what I discuss here does apply.) Finally, if you start CF from the command line, then the same info is written to the command line instead and not to the log file.

I'm about to post an entry discussing the value of looking in these logs for certain key error messages. That's what prompted me to write this entry, so I can refer back to it about how to change the size and rotation.

Background on the sizing of the -out*.log files

You may have noticed that the default (since about CF 7) has been for them to grow no larger than 200k (not 200mb, but 200kb!), and up to 200 occurrences of them per instance.

Certain kinds of problems can lead to a lot of information being written to those files, such that in some instances, a given -out log file will contain only a few minutes of data (if that). And if too many of those happen, old log files will rotate off and you may soon not be able to see much than hours or days ago. It would be helpful, then, to let these files grow larger, both to make it easier to look at anyone and see a longer period of time in it, or to allow the sum of rotations to cover a longer period of time.

At the default of 200kb * 200 rotations, that's 40mb at the most that the files can use. I think most servers these days have a good bit more disk space they can afford to use! :-)

Even at 2000kb (a 10-fold increase), that would be only a max of 400mb, or less than half a gig. How large you want to make them is your call.

Just beware of the temptation to perhaps lower the rotations and increase the size (like 100mb * 4 rotations). The larger the files get, the less likely you'll be able to easily open them with simple editors like NotePad (which starts to get slower to open, the larger the file is). That said, I can point out a great alternative tool for looking at larger files, though. I just blogged about it, Universal Viewer.

(Actually, prior to CF7, there was a bug where the -out.log file would grow unchecked and could itself grow to a GB, which is one the first reasons I learned about Universal Viewer. More on that issue and the fix for it in a moment.)

As for the filenames and rotations, if you've not noticed it, they use the instance name and a sequence number, such as coldfusion-out.log for the latest out.log (for a standalone CF instance), or myinstance-out199.log for the 199th rotation of a given instance's out log. The rotations starts with 1 until (the default of) 200 is reached, when it starts reusing the numbers starting at 1 for the newest logs. As such, at least until that rotation max is reached, the lower the number, the older the log.

Changing it may not work as you'd expect

Unfortunately, setting the size and rotation for these files isn't as simple as making a change in the CF Admin. You may notice that there is a setting on the Debugging&Logging>Logging Settings page for "Maximum file size" and "Maximum Number of Archives", but that setting controls the traditional CF logs (those shown in the Admin's Log Files page, or found in [cf]\logs, or deep within the directories for an instance in Multiserver mode.)

Also, some may know that there is an available jrun.xml file that has a jrunx.logger.FileLogEventHandler entry with available rotationSize and rotationFiles attributes, but those only control the -event*.log files (even if you tweak them as suggested by an old Macromedia technote). BTW, if you're interested, that file was in the [cf]\runtime\bin directory in CF 6.1, but since 7 it's been in [cf]\runtime\servers\coldfusion\SERVER-INF (or [jrun]\servers\[instancename]\SERVER-INF on Multiserver).

So how, then do you increase the size of the -out*.log files? Yes, we're finally ready for the "big reveal".

Supported approach: Using the jrunsvc to change the logfilesize and rotation

Again, I gave away the secret at the top when I said that you use the jrunsvc command. But how did I find that? And what are the details? (Again, before you follow this more challenging solution, consider the far simpler registry tweak I show below.)

Well, the solution to this challenge (and the reference on using this command for it) is actually buried at the bottom of an old Adobe Hotfix note for CF7, which you might otherwise assume did not apply if you were on CF 8 or 9. But the information it offers (again, at the bottom) does apply (after you apply the hotfix at the top, if indeed you are on CF 7.01 or 7.02. This is the solution to the problem where the -out*.log files would instead grow unchecked in size), even on CF 8 or 9.

The key info at the bottom says:

To configure the log file size, run the following from a command line, either from [jrun-home]\bin or [cf_root]\runtime\bin, depending on the product you have installed:

jrunsvc.exe -logfilesize <filesize> <service_name>

For example:

jrunsvc.exe -logfilesize 260 "ColdFusion MX 7 Application Server"

will set the log file size to 260KB for the ColdFusion server and a new file will be created every time the coldfusion-err.log and coldfusion-out.log files reach 260KB in size.

jrunsvc.exe -logfilesize 260 "JRun default Server"

will set the log file size to 260KB for the default server and a new file will be created every time the default-err.log and default-out.log files reach 260KB in size.

For our purposes, let's not worry about the reference to the -err.log.

As for the name of the service, you can of course look that up on your own in your Windows Services panel. I will note that for CF9 Standard or Server, it's "ColdFusion 9 Application Server".

And I did increase mine to 1000 (kb).

How will you know that the change takes effect?

Well, of course you can watch the files to see if they grow larger than the default size. But you may prefer to check without waiting so long. :-) That leads to the next point.

Unsupported approach: Use the registry to confirm or indeed make the change

It turns out that this jrunsvc command simply updates the Windows Registry, with respect to information about the Windows service, so you can also confirm the change by looking in the registry. The standard disclaimer about registry tweaks does apply: if you don't know how to use the registry, skip to the next section. Here be dragons. :-) But really, it's quite simple and safe if you're comfortable with registry tweaking. You're just dealing with one entry. I can't imagine any real problem even if you made a mistake (it just wouldn't change the log size.)

There's a key where Windows Service settings for the CF service are stored, such as (on my machine, for the CF9 Server Instance) HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\services\ColdFusion 9 Application Server\.

There, you will see (only if you successfully did the jrunsvc above) that the jrunsvc command places a new REG_SZ value in this key, such as for LogFileSize. Before executing the command, there is no value for the key.

So for those who want to live dangerously, you can in fact skip the jrunsvc command and just drop this new (string) value into the registry. CF will start leveraging the change immediately, even without a restart. As always, beware changing the registry.

And of course, when confirming if it's working, make sure you're looking in the right key for the service name that you're interested in (and/or provided on the jrunsvc command line).

What about changing the rotation count?

I'll note as well that, though not mentioned in the technote, if you run the jrunsvc command with a /? argument (or any invalid argument), it shows that there is also an option said to control the log file rotation: -logfileRotationLimit. But when I try to use that, even just to set it to the default of 200, it curiously replies with the error:

Error: log file rotaion limit must be at least 1000

What? (BTW, that misspelling of "rotation" is indeed in the error message.)

It makes no sense that that should be required to be "at least 1000". Am I misunderstanding its purpose?

Oh well, I'm not interested in changing the rotation limit anyway, just the size, so I can move on. Perhaps someone from Adobe may want to look into this (or help me out with my misunderstanding).

FWIW, if somehow that is resolved, I'll note that you do need to provide the two arguments each in their own jrunsvc command, it seems.

I will note that you can also change the rotation limit through the registry hack I offer above. The string key is LogFileRotationLimit.

Summary

I've confirmed from my own servers and others that making this change (either way) does indeed let the -out*.log files grow larger, which is a great help when solving certain kinds of troubleshooting problems. I'll discuss one of them in the next entry.

In conclusion, I'm surprised to find that if you search google for the phrase:

"jrunsvc" "LogFileSize"

the only hit found (prior to me writing this) was that one Adobe technote (and one with the technote in Japanese). I'm stunned that no one else may have ever mentioned this. I know I've seen other blog entries where people have mentioned that they, too, had noticed that the traditional solutions (and even some other hotfixes) did not solve the problem of how to change the size and rotation of the -out*.log files.

While I do hope that many people will benefit from this entry, I will admit that there's a real sense of discovery and some awe when one gets to "walk" where seemingly few have gone before. :-)

Let me know what you think, whether you read this within days or years of this being published. Cheers.

Better understanding the IIS HTTPERR logs

If you run IIS, are you familiar with its HTTPERR logs? If not, you may be missing out on some useful diagnostic information. Sadly, many (sometimes most) of the entries in the logs are innocuous (you don't need to worry about them), but sometimes they're useful. And if have noticed the logs, perhaps you'd like to know more about them.

There's a useful MS document, Error logging in HTTP API, with more about the HTTPERR logs, including their location, format, and info on the kinds of errors reported within them. Hope that's helpful to my readers.

Here's another (more brief) introduction to the files: in the technical reference section of the IIS 6 docs.

BlogCFC was created by Raymond Camden. This blog is running version 5.005.

Managed Hosting Services provided by
Managed Dedicated Hosting