Skip navigation
cf_ron
cf_ron
Currently Being Moderated

Help with CF8 CFLOG oddity?

Jun 14, 2011 12:40 PM

I have encountered an oddity with calls to CFLOG on one of our CF8-based production servers that is repeatable on that system but not repeatable on a CF8 dev server, a CF9 dev server, or a CF9 production server: we have code that periodically invokes CFLOG with LOG="application" and TYPE="information" attributes (e.g., in the application.cfc's onApplicationStart and onApplicationEnd methods). This is going to sound crazy, but any such log entries are eliminated by the next CFLOG invocation with a FILE="application" attribute.

 

I stumbled on to this as we were trying to troubleshoot some issues associated with application initialization on this particular server: we added the CFLOG LOG="application"... calls and I started watching the logs to see what was going on. Eventually, we had enough diagnostic information that I had figured out what was going on. When I checked the application.log file the next day, those entries were no longer present... I could see entries before and after those entries, but they were gone. I downloaded the log file and verified that they were in fact not present and weren't just being omitted by the log file viewer within the CFAdmin interface. Definitely not present. I reinitialized the application and verified that our informational log entries were there; checked again this morning... gone. Apparently overwritten by the next error being thrown, caught, and logged. Interestingly, our error logging uses CFLOG FILE="application".

 

I have verified this behavior with some test code on this particular server: if I call CFLOG log="application" and then check the log file, that new entry is present. As soon as I turn around and call CFLOG FILE="application", that first entry (and anything after it, regardless of how it got there!) is clobbered and the message from that CFLOG FILE="application" is the last entry in the log (both via the CFAdmin interface and in the downloaded application.log file).

 

I have another CF8 box (both running at CHF 4) that does not exhibit this behavior, nor can I get this to happen on any of our other various CF servers. Based on a note from Charlie Arehart on CFLOG reference page, I checked the coldfusion-out.log... and those entries that end up being clobbered from application.log ARE present in the coldfusion-out.log file on the server exhibiting this behavior.

 

Anyone have any sort of a clue as to what is going on here and how to solve it? It's particularly troubling to have stuff be logged only to disappear from the log files, and for whatever reason it appears that there is some sort of odd interaction between the LOG="application" and FILE="application" attributes on different invocations of the CFLOG tag.

 

Thanks. (And really, I'm neither crazy -- at least not REALLY crazy -- nor making this up!)

 

--

/ron

550 Views   9 Replies   Latest reply: cf_ron, Jun 17, 2011 9:07 AM
 
Replies
  • BKBK
    Currently Being Moderated
    1. BKBK,
    Jun 16, 2011 6:55 AM   in reply to cf_ron
    Report

    It is an oddity indeed. But so too is your code.

     

    If you wish to log to the file Application.log, then the code to use is

     

    <CFLOG FILE="application" TYPE="information"> or <CFLOG TYPE="information">

     

    That is, you're meant to use the file attribute to specify which standard log ColdFusion should write to. The log attribute is meant for you to use to specify your own custom file name. In other words, you shouldn't be using LOG="application" in any case.

     
    |
    Mark as:
  • Adam Cameron.
    Currently Being Moderated
    2. Adam Cameron.,
    Jun 16, 2011 7:09 AM   in reply to BKBK
    Report

    It's the other way round, mate.

     

    Use FILE to specify a custom log or LOG to specify a standard one, eg:

     

    <cflog log="application" text="Goes to CF's standard application.log">

     

    or:

     

    <cflog file="adam" text="Goes to adam.log">

     

    --

    Adam

     
    |
    Mark as:
  • BKBK
    Currently Being Moderated
    3. BKBK,
    Jun 16, 2011 7:30 AM   in reply to Adam Cameron.
    Report
    function(){return A.apply(null,[this].concat($A(arguments)))}

    Adam Cameron. wrote:

     

    It's the other way round, mate.

     

    Indeed. Thanks, Adam. I mistakenly wrote 'log' and 'file' the other way round! My post should have read:

     

    It is an oddity indeed. But so too is your code.

     

    If you wish to log to the file Application.log, then the code to use is

     

    <CFLOG LOG="application" TYPE="information"> or <CFLOG TYPE="information">

     

    That is, you're meant to use the log attribute to specify which standard log ColdFusion should write to. The file attribute is meant for you to use to specify your own custom file name. In other words, you shouldn't be using FILE="application" in any case.

     
    |
    Mark as:
  • cf_ron
    Currently Being Moderated
    4. cf_ron,
    Jun 16, 2011 7:31 AM   in reply to Adam Cameron.
    Report

    @Adam: thanks for the follow up.

     

    The Adobe tag reference documents are silent on the exclusive use of the FILE vs LOG attributes to write to the standard (application or scheduler) logs, and having looked at them there is nothing there that I would read as indicating that one approach is required or even recommended for getting content into the stardard log files. On all of our servers except the one I mentioned, the use of the two different attributes exhibits no difference in behavior: content goes into the appropriate logs without any problems. The oddity to me is the behavior of the one CF8-based server where entries going in via  one mechanism (and all subsequent content, regardless of the mechanism by which that content went in) get truncated by content added via the other...

     

    We can certainly change the logic to ensure consistency (FILE for non-standard logs, LOG for standard) but that involves changing code in hundreds of files in several different applications to work around behavior on just one of the servers... something we're trying stay away from.

     
    |
    Mark as:
  • Adam Cameron.
    Currently Being Moderated
    5. Adam Cameron.,
    Jun 16, 2011 8:33 AM   in reply to cf_ron
    Report

    Oh, I wasn't suggesting there was anything wrong with you code, I was replying to BKBK and just putting them straight on CFLOG usage.

     

    As for your own problem, I have no idea what might be going on, so have nothing to add in that regard.

     

     

    --

    Adam

     
    |
    Mark as:
  • BKBK
    Currently Being Moderated
    6. BKBK,
    Jun 17, 2011 6:25 AM   in reply to cf_ron
    Report

    Although you shouldn't have used file="application", I still find it rather strange that ColdFusion would eject stuff from your application.log file. Are you sure it's the same file?

     

    In other words, are you sure ColdFusion is deleting archived log messages before writing a new message to the same file? Or, could it be that, with file="application", ColdFusion creates a new application.log file, as it is instructed to, and simply replaces the existing application.log file with it?

     
    |
    Mark as:
  • BKBK
    Currently Being Moderated
    7. BKBK,
    Jun 17, 2011 6:37 AM   in reply to cf_ron
    Report
    function(){return A.apply(null,[this].concat($A(arguments)))}

    cf_ron wrote:


    We can certainly change the logic to ensure consistency (FILE for non-standard logs, LOG for standard) but that involves changing code in hundreds of files in several different applications to work around behavior on just one of the servers... something we're trying stay away from.

    I think it's worth the effort to correct it. You cannot afford going without application log messages.

     

    Don't underestimate your own human ingenuity. I thought like you when faced with several dozen changes in hundreds of files. However, unlike you, I had a deadline and no choice.

     

    I can tell you that, once you get going, solutions come quicker and quicker. Start with the obvious: the extended search/replace mechanism in Eclipse. You could be through in an hour or two!

     
    |
    Mark as:
  • cf_ron
    Currently Being Moderated
    8. cf_ron,
    Jun 17, 2011 8:54 AM   in reply to BKBK
    Report

    Yes, we are quite sure that the application.log file is not being replaced. We see log entries created with the FILE="application" attribute prior to these still present and log entries created with the FILE="application" following them are present in the application.log file both when viewed through the CFAdmin interface and in the downloaded version of the log file. It is only the entries created with the LOG="application" attribute that get clobbered.

     
    |
    Mark as:
  • cf_ron
    Currently Being Moderated
    9. cf_ron,
    Jun 17, 2011 9:07 AM   in reply to BKBK
    Report

    Unfortunately this is not as simple as a search and replace because much of the code creating log entries is used in other forms of exception handling that log to other "non-standard" logs (e.g., not application or scheduler) based on the types of exceptions and thus has to use the FILE= attribute, so there's conditional logic that will need to be added based on where the log entries should be added. And all of the changes also then kick in customer's change control process...

     

    Having said that, and given the apparent absence of any other sort of solution, that's likely what we're faced with.

     

    The part of this that seems really odd to us is that this behavior seems to be unique to one server: our staging server and the one dev server we have that's still running CF8 -- both running CF8 patched to the same level and the same version of the Java VM, etc. -- are not exhibiting this behavior, nor are any of our CF9 boxes.

     
    |
    Mark as:
Actions

More Like This

  • Retrieving data ...

Bookmarked By (0)

Answers + Points = Status

  • 10 points awarded for Correct Answers
  • 5 points awarded for Helpful Answers
  • 10,000+ points
  • 1,001-10,000 points
  • 501-1,000 points
  • 5-500 points