Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > comp.lang.java.programmer > #12797

Re: Logging problem

From Novice <novice@example..com>
Newsgroups comp.lang.java.programmer
Subject Re: Logging problem
Date 2012-03-09 05:36 +0000
Organization Your Company
Message-ID <XnsA0116442B9A2jpnasty@94.75.214.39> (permalink)
References <XnsA01094E18E46Ejpnasty@94.75.214.39> <jjbb75$dgo$1@dont-email.me> <XnsA010D48F8E7BFjpnasty@94.75.214.39>

Show all headers | View raw


Novice <novice@example..com> wrote in
news:XnsA010D48F8E7BFjpnasty@94.75.214.39: 

> markspace <-@.> wrote in news:jjbb75$dgo$1@dont-email.me:
> 
>> On 3/8/2012 11:38 AM, Novice wrote:
>>> I've suddenly started having an odd problem with respect to my
>>> logging and would appreciate a hint or tip to help me sort it out.
>>>
>>> For some reason I can't figure out, the last line of the log, which
>>> simply says:
>>>
>>> </log>
>>>
>>> is not being written.
>> 
>> 
>> Did you close the Handlers in use?
>> 
>> 
>> Can you produce an SSCCE that duplicates the problem?  Try to use a 
>> MemoryHandler if possible, so your SSCCE doesn't write files to a 
>> tester's hard drive.
>> 
>> 
>> 
> 
> I could try to create an SSCCE but before I do, I think I need to take
> a step back and sort out some conceptual stuff with your help.
> 
> As I started composing a reply to one one of the responders in the 
> thread, it occurred to me that I really wasn't clear on what was
> SUPPOSED to happen with a normal log file. I had gotten as far as
> determining that getTail() in XMLFormatter would write the missing
> </log> tag but I hadn't really thought through what SHOULD be
> happening. It occurred to me that maybe the aberrant behavior was what
> I _had_ been getting and maybe what I'm seeing now actually makes
> sense. 
> 
> Now that I've read and googled a bit more, I'm thinking I was right
> about that theory, although I'm definitely not certain. But in case
> I'm going down the wrong path, let me think out loud for a minute and
> you folks can tell me if I'm out in left field or if I'm making sense.
> 
> After some poking around, I found close() and flush() methods in
> Handler, which is abstract, and in its children and grandchildren. The
> one that concerns me is FileHandler, which is the one that writes
> physical logs. Also, java.util.logging.Formatter, which is abstract,
> and its descendants have a getTail() method, which is what writes that
> missing </log> record. 
> 
> It seems to me that a real log, one you'd see in a production system, 
> would want to execute flush() and close() and getTail() when it was
> about to be closed. But what events would cause that? I went back to
> the logging.properties file and rediscovered 
> java.util.logging.FileHandler.limit, which has a default value of
> 50,000. I'll assume that's lines but it may be the number of log
> records too; it doesn't much matter. I'm assuming that's how big a
> physical log file can get before it needs to be closed and a new file
> created. In the meantime, Java keeps writing log records to that log.
> The mere fact that I start or stop a given program shouldn't have any
> effect on whether the log is locked or not; the log will be available
> when it's needed and will get written until it is full. 
> 
> Now, what happens when it gets full? Well, if it is a continuous log,
> we just keep creating new physical law files, typically with a
> sequential number to distinguish it from earlier logs, e.g. log0,
> log1, log2, etc. The integer just keeps going up. If it is a circular
> log, we keep incrementing the integer until we hit a threshhold like 5
> or 10, then start back at 0, overwriting the old log0. If I remember
> correctly, Java can do both continuous or circular logs. 
> 
> Have I got this more-or-less right so far? Because that would make
> sense to me based on my (somewhat vague) memories of logging in
> relational databases. 
> 
> If I do have that right, then the aberrant behavior was when the log
> was nicely closed as soon as my program ended. (Which raises the
> question why did THAT happen? But if I'm right about the log not
> normally getting the </log> tag added until the log is closed because
> it's full, then I'm not going to worry about the aberrant behavior. I
> just want to know how to work with a log that is functioning
> normally.) 
> 
> So, if a log normally only gets that </log> tag written when it is
> ready to be closed because it's full, what happens in the real world
> if you want to read a log BEFORE it's full? If there is some kind of
> system crash long before the log is full, you're not going to want to
> wait until the log is full; you want to read it NOW. So how what do
> you do? That has to be a routine situation and there must be a routine
> answer. And that's as far as I've gotten with my reasoning. 
> 
> If I'm right, nothing is really broken after all and I was just
> finding those log files closed and finished by sheer good luck (or
> having done some stupid things that worked in my favor). In that case,
> I just need to know how the rest of you arrange to read an incomplete
> log. Maybe there's a standard utility that you use to read an
> incomplete log?? 
> 
> 
> I'll stop there and wait for your feedback before I go off the rails 
> completely ;-)
> 


Just to follow up on my own post, I've found a simple way to cause that 
closing tag to be written to the log file. My program is launched for a 
very simple JFrame that has two buttons, one for each of the two 
principal classes. I've added code so that when I click on the close 
button on the JFrame, I simply use the Logger object to determine all the 
handlers for that Logger. Then, I do a for each loop to go through the 
handlers and simply close each one. Upon completion, my physical log file 
has no lock file associated with it and I can open it without difficulty. 
When I edit the log file, I see that the </log> tag is right where it 
should be. 

It's a bit of a sledgehammer approach to the problem but I can fine-tune 
it to close only the FileHandler. But it doesn't answer the question of 
how the situation would be handled in the real world. Are real production 
programs closing physical log files when they stop running? It seems 
unlikely that a 24x7 (or nearly 24x7) application would stop running at 
all except for a maintenance period yet if it starts writing error 
messages to its log, I can't see people waiting until the log is full 
before they get their hands on it and find out what's going on.  

It would be very helpful if someone could explain what would happen in a 
real-world production situation where a long-running batch program or a 
constantly-running online program started writing error messages to the 
log. What will operators do to be able to read the log? I'm guessing they 
force it to close early and then start a new file or they have a tool 
that will read the log file correctly even without the final </log> tag. 

-- 
Novice

Back to comp.lang.java.programmer | Previous | NextPrevious in thread | Next in thread | Find similar


Thread

Logging problem Novice <novice@example..com> - 2012-03-08 19:38 +0000
  Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 14:48 -0500
    Re: Logging problem Novice <novice@example..com> - 2012-03-08 20:06 +0000
      Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 15:38 -0500
        Re: Logging problem Martin Gregorie <martin@address-in-sig.invalid> - 2012-03-08 22:02 +0000
      Re: Logging problem Patricia Shanahan <pats@acm.org> - 2012-03-08 14:53 -0800
        Re: Logging problem markspace <-@.> - 2012-03-08 15:20 -0800
          Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 19:48 -0500
            Re: Logging problem Patricia Shanahan <pats@acm.org> - 2012-03-08 17:17 -0800
              Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 20:55 -0500
                Re: Logging problem markspace <-@.> - 2012-03-08 18:01 -0800
                Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 21:19 -0500
      Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 20:56 -0500
  Re: Logging problem markspace <-@.> - 2012-03-08 14:18 -0800
    Re: Logging problem Novice <novice@example..com> - 2012-03-09 01:53 +0000
      Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-08 20:59 -0500
      Re: Logging problem Novice <novice@example..com> - 2012-03-09 05:36 +0000
        Re: Logging problem Patricia Shanahan <pats@acm.org> - 2012-03-09 06:27 -0800
        Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-09 12:31 -0500
          Re: Logging problem Novice <novice@example..com> - 2012-03-09 18:57 +0000
            Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-09 14:26 -0500
        Re: Logging problem Arved Sandstrom <asandstrom3minus1@eastlink.ca> - 2012-03-09 15:59 -0400
          Re: Logging problem Novice <novice@example..com> - 2012-03-09 21:32 +0000
            Re: Logging problem Lew <lewbloch@gmail.com> - 2012-03-09 13:56 -0800
              Re: Logging problem Novice <novice@example..com> - 2012-03-09 22:57 +0000
                Re: Logging problem Martin Gregorie <martin@address-in-sig.invalid> - 2012-03-10 14:51 +0000
                Re: Logging problem Arved Sandstrom <asandstrom3minus1@eastlink.ca> - 2012-03-10 13:00 -0400
                Re: Logging problem Lew <noone@lewscanon.com> - 2012-03-10 10:04 -0800
                Re: Logging problem Martin Gregorie <martin@address-in-sig.invalid> - 2012-03-10 20:23 +0000
                Re: Logging problem Lew <noone@lewscanon.com> - 2012-03-10 07:56 -0800
                Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-10 12:05 -0500
                Re: Logging problem Lew <noone@lewscanon.com> - 2012-03-10 10:10 -0800
                Re: Logging problem Arne Vajhøj <arne@vajhoej.dk> - 2012-03-12 16:13 -0400
                Re: Logging problem Novice <novice@example..com> - 2012-03-10 20:10 +0000
            Re: Logging problem Arved Sandstrom <asandstrom3minus1@eastlink.ca> - 2012-03-09 19:15 -0400
              Re: Logging problem Novice <novice@example..com> - 2012-03-10 01:59 +0000

csiph-web