Logging problem

[Lew]

Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

I'm a little surprised by that. I would have thought actual errors would
get acted on fairly quickly, particulary anything categorized as SEVERE.

"Acted on quickly" means that it happened.

And he said "routine errors", not "SEVERE".

Have you looked at any real system's logs?

You should.

(I'll use the java.util.logging levels for these remarks.) I could see
that something that is categorized as WARNING may take longer to fix,
especially if WARNING is used for messages that indicate the program is
able to continue using some kind of alternate strategy; if the alternate

Not necessarily.

strategy is perfectly reasonable and doesn't skew the result, there's no
great harm in leaving the problem unsolved. But if we assume that a

Way wrong. There's always harm in leaving a WARNING unresolved. Otherwise it'd be reported at a lower level.

SEVERE error is a show-stopper, wouldn't that get dealt with right away?

It has to happen first, then it can be dealt with. Otherwise there's nothing with which to deal.

I haven't worked on Unix/Linux in a while but I have used 'tail' ;-)
Frankly, I don't recall if it works on open files but from you've said,
apparently it does.

"man tail"

GIYF.

If it didn't work on open files, "tail -f" would be pretty useless, now wouldn't it?

That "console output" one should already be way familiar to you.

Perfect. Existing tools that will read the file while still being written
are what I was hoping for ;-)

Basic OS knowledge here. Nothing outré about reading a file while it's being written.

Programmers need to know more than the basics of OSes, let alone have gaps in the basics.

 

[Novice]

Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

"Acted on quickly" means that it happened.

And he said "routine errors", not "SEVERE".

Okay, but any severity of error could be routine.

Have you looked at any real system's logs?
No.
You should.

I agree. Can you point me to any? I don't have any.

Not necessarily.



Way wrong. There's always harm in leaving a WARNING unresolved.
Otherwise it'd be reported at a lower level.

I'm not encouraging such errors to be ignored. I'm just saying that I can
imagine some shops might not get to them right away. For instance, maybe
there is a long standing issue with a date routine that always raises a
warning but the Tomcat software has a known bug that is causing it and we
know that Apache will be fixing it eventually so we just tolerate the
warning pending Apache's fix of Tomcat. I can picture something like that
happening.

It has to happen first, then it can be dealt with. Otherwise there's
nothing with which to deal.

Of course.

"man tail"

GIYF.

If it didn't work on open files, "tail -f" would be pretty useless,
now wouldn't it?

I'm on a Windows system, not a *nix system, and I simply don't remember
the details of 'tail'. Yes, I could have and would have looked it up if I
really needed to know. I was just making a passing comment that I didn't
remember if 'tail' could read an open file.

That "console output" one should already be way familiar to you.

Absolutely, I've seen that. But elsewhere in one of the threads I
started, I think there was a general concensus that we couldn't
necessarily count on consoles being accessible to everyone who would
ideally want access to one so I've been trying to think through things
without taking for granted that there was was a console available. So I
asked myself what someone without a console might experience....

 

[Arved Sandstrom]

On 12-03-09 01:36 AM, Novice wrote:
[ SNIP ]

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.

In a real-world production situation odds are you're getting errors
logged all the time. There are a whole bunch of errors that will
happen, sometimes frequently, sometimes a few times a day, sometimes
once a month, but you know they _will_ happen. So routine errors get
logged all the time.

I'm a little surprised by that. I would have thought actual errors would
get acted on fairly quickly, particulary anything categorized as SEVERE.
(I'll use the java.util.logging levels for these remarks.) I could see
that something that is categorized as WARNING may take longer to fix,
especially if WARNING is used for messages that indicate the program is
able to continue using some kind of alternate strategy; if the alternate
strategy is perfectly reasonable and doesn't skew the result, there's no
great harm in leaving the problem unsolved. But if we assume that a
SEVERE error is a show-stopper, wouldn't that get dealt with right away?

[ SNIP ]

When I use the term "error" here, I mean conditions that correspond to
severity levels 3 (Error) and 4 (Warning) of Syslog (RFC 5424,
http://tools.ietf.org/html/rfc5424, also see
http://en.wikipedia.org/wiki/Syslog#Severity_levels). These levels
translate to ERROR and WARN of log4j. java.util.logging has WARNING that
maps to syslog 4, but doesn't have enough granularity with SEVERE to
capture the necessary distinction between syslog 0-2 (Emergency, Alert,
Critical) and 3 (Error); log4j does that reasonably well with ERROR and
FATAL.

Syslog describes Error (level 3) means a non-urgent failure. Admins or
developers have some time frame (other than "yesterday") to resolve the
problem. This is the kind of error that happens a lot, overall, and
99.99% of them have to do with network printing.

Just kidding (about the printing). But you get the idea, a syslog Error
is an operational error. Your app identified a problem through good
error-handling and basically decided it couldn't proceed, but the app
itself is not at risk. Maybe a file provided by an external system is
malformed, and input processing for a scheduled import job aborts.
That's a syslog 3 Error - depending on the nature of the import and when
it happened you might have hours or days to fix the problem.

Your impressions of what the levels mean aren't exactly wrong. If we
take j.u.l SEVERE as syslog 0-2 and j.u.l WARNING as syslog 4 then they
map OK, and your descriptions are pretty good. But java.util.logging is
missing that important syslog 3 mapping, and in order to make j.u.l
levels useable you need to add it. IMHO. But that's one of the reasons I
prefer log4j. I don't even know what the Sun developers were thinking
when they left that one out...maybe they don't use logs.

AHS

 

[Novice]

On 12-03-09 01:36 AM, Novice wrote:
[ SNIP ]

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.

In a real-world production situation odds are you're getting errors
logged all the time. There are a whole bunch of errors that will
happen, sometimes frequently, sometimes a few times a day, sometimes
once a month, but you know they _will_ happen. So routine errors get
logged all the time.

I'm a little surprised by that. I would have thought actual errors
would get acted on fairly quickly, particulary anything categorized
as SEVERE. (I'll use the java.util.logging levels for these remarks.)
I could see that something that is categorized as WARNING may take
longer to fix, especially if WARNING is used for messages that
indicate the program is able to continue using some kind of alternate
strategy; if the alternate strategy is perfectly reasonable and
doesn't skew the result, there's no great harm in leaving the problem
unsolved. But if we assume that a SEVERE error is a show-stopper,
wouldn't that get dealt with right away?

[ SNIP ]

When I use the term "error" here, I mean conditions that correspond to
severity levels 3 (Error) and 4 (Warning) of Syslog (RFC 5424,
http://tools.ietf.org/html/rfc5424, also see
http://en.wikipedia.org/wiki/Syslog#Severity_levels). These levels
translate to ERROR and WARN of log4j. java.util.logging has WARNING
that maps to syslog 4, but doesn't have enough granularity with SEVERE
to capture the necessary distinction between syslog 0-2 (Emergency,
Alert, Critical) and 3 (Error); log4j does that reasonably well with
ERROR and FATAL.

Syslog describes Error (level 3) means a non-urgent failure. Admins or
developers have some time frame (other than "yesterday") to resolve
the problem. This is the kind of error that happens a lot, overall,
and 99.99% of them have to do with network printing.

Just kidding (about the printing). But you get the idea, a syslog
Error is an operational error. Your app identified a problem through
good error-handling and basically decided it couldn't proceed, but the
app itself is not at risk. Maybe a file provided by an external system
is malformed, and input processing for a scheduled import job aborts.
That's a syslog 3 Error - depending on the nature of the import and
when it happened you might have hours or days to fix the problem.

Your impressions of what the levels mean aren't exactly wrong. If we
take j.u.l SEVERE as syslog 0-2 and j.u.l WARNING as syslog 4 then
they map OK, and your descriptions are pretty good. But
java.util.logging is missing that important syslog 3 mapping, and in
order to make j.u.l levels useable you need to add it. IMHO. But
that's one of the reasons I prefer log4j. I don't even know what the
Sun developers were thinking when they left that one out...maybe they
don't use logs.

Thanks for the clarification Arved. It all makes perfectly good sense the
way you explain it - just as I expected it would ;-)

 

[Martin Gregorie]

I agree. Can you point me to any? I don't have any.

That is a disadvantage of using desktop Windows, which doesn't believe in
logs. I don't know whether Windows Server uses them, so the best I can do
is suggest that, if you have a suitable box [1], you put one of the Linux
flavours[2] on it, have a play with it and then take a look at the files
in /var/log/ with "less".

[1] since Linux will run well on less hardware than Windows needs, in
general this means anything you have lying around that's now too small
and/or slow to run current Windows releases. If you can leave it running
and networked with your other computers you may well find it generally
useful: a slow Linux box with big disk(s) that is running Samba makes a
good networked print and filing system for Windows boxes and can be
managed OK without needing an attached screen or keyboard.

[2] try Ubuntu or Fedora 14 as general purpose distributions or consider
PuppyLinux if the box is very small and slow, e.g. a 386/486 with under
400 MB RAM.

 

[Lew]

Arved Sandstrom wrote:
Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

Wha...?

These programs run on Windows, too.

This is about OSes. Windows is like Linux in this regard.

I agree. Can you point me to any? I don't have any.

Go to your nearest real system and ask to see the logs.

A lot of Apache projects use log4j. Run one of those.

I'm on a Windows system, not a *nix system, and I simply don't remember
the details of 'tail'. Yes, I could have and would have looked it up if I
really needed to know. I was just making a passing comment that I didn't
remember if 'tail' could read an open file.

"
Windows is no different in this regard. This is about reading files as they're
written, not Linux. You need to know the basics of OSes.

Windows the same thing happens. Substitute "Notepad" for "vi", why don't you?

And "tail" runs on Windows, too. Many programs are available for both Windows
and Linux. It's the operating system that determines the behavior, not whether
it's "tail" or some other program.

So stop throwing those red herrings at us, please. Take the coaching and don't
make the excuses.

Absolutely, I've seen that. But elsewhere in one of the threads I
started, I think there was a general concensus that we couldn't
necessarily count on consoles being accessible to everyone who would
ideally want access to one so I've been trying to think through things
without taking for granted that there was was a console available. So I
asked myself what someone without a console might experience....

You're mixing topics. I pointed out the console scenario in the context of
being able to read a file while it's being written. In no wise does that carry
over to an inference that I'm recommending its use for logging.

The point you ducked is that this is basic, fundamental, elementary, beginner
OS knowledge that applies to Windows, too. It's stuff you should already know.
You must understand the basics of the OS.

If you did, you'd've known that the ability of "tail" to read files as they're
written is neither a feature of "tail" nor unique to Linux.

 

[Arved Sandstrom]

That is a disadvantage of using desktop Windows, which doesn't believe in
logs.

Come, come, Martin, desktop Windows isn't quite so bad. Windows
events go into the Application log, the Security log or the System log
and are what we see through the Event Viewer.

It's quite decent logging actually, although the utility of the
Application log is determined entirely by what applications choose to
write to Windows events.

As a sidenote, log4j and log4net, among other frameworks, can write to
Windows events.

I don't know whether Windows Server uses them, so the best I can do

is suggest that, if you have a suitable box [1], you put one of the Linux
flavours[2] on it, have a play with it and then take a look at the files
in /var/log/ with "less".

[ SNIP ]

AHS

 

[Arne Vajhøj]

Novice wrote:
Arved Sandstrom wrote:
Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

Wha...?

These programs run on Windows, too.

This is about OSes. Windows is like Linux in this regard.

You can get them for Windows.

But they are not that common on Windows.

Arne

 

[Lew]

Come, come, Martin, desktop Windows isn't quite so bad. Windows
events go into the Application log, the Security log or the System log
and are what we see through the Event Viewer.

Arved's answering your question: these are examples you can see, Novice.

It's quite decent logging actually, although the utility of the
Application log is determined entirely by what applications choose to
write to Windows events.

This is rather the point of understanding logs from the reader's standpoint.

It's an exercise in projective empathy. You have to project yourself into a
future and identify with some poor shnook who has to suss out what's going on,
and why, with a shrieking customer and nothing to go on but log output and too
much coffee, and you have to care.

As a sidenote, log4j and log4net, among other frameworks, can write to
Windows events.

I don't know whether Windows Server uses them, so the best I can do

is suggest that, if you have a suitable box [1], you put one of the Linux
flavours[2] on it, have a play with it and then take a look at the files
in /var/log/ with "less".

[SNIP/REARRANGE]

I wonder what a Google search might reveal. Hmm, let me see, I wonder ...
(imagination running wild)
Could it be ...
<http://lmgtfy.com/?q=example+log+output>
?

From that:
[09/03/2004 21:59:18.060 GMT]
fadef4b T:
com.ibm.mm.beans.CMBConnection
CMBConnection.connect() entered.
[09/03/2004 21:59:18.070 GMT] fadef4b T:
com.ibm.mm.beans.CMBConnection
CMBConnection._createNewDS() entered.
[09/03/2004 21:59:18.070 GMT] fadef4b
T: com.ibm.mm.beans.CMBConnection
CMBConnection._createNewDS()
=>datastore className=
com.ibm.mm.sdk.server.DKDatastoreICM
[09/03/2004 21:59:18.310 GMT] fadef4b
T: com.ibm.mm.beans.CMBConnection Args[0]
is null, no arg constructor called for
com.ibm.mm.sdk.server.DKDatastoreICM
[09/03/2004 21:59:18.430 GMT] fadef4b
T: com.ibm.mm.beans.CMBConnection
CMBConnection._createNewDS()=>
datastore created with args=null
[09/03/2004 21:59:18.430 GMT] fadef4b
T: com.ibm.mm.beans.CMBConnection
CMBConnection.connect()=>
com.ibm.mm.CMBConnection[connection
type=0,clientURLObj=null,csURLObj=null,
serviceConnectionType=0,serviceClientURLObj=null,
serviceCsURLObj=null,dataManagementEnabled=true,
schemaManagementEnabled=
true,workflowDataManagementEnabled=true,dsType=
ICM,serverName=icmnlsdb,portNo=0,
servicePortNo=0,RMIHostname=,
serviceRMIHostname=,
userid=icmadmin,isConnected=false]
[09/03/2004 21:59:18.430 GMT] fadef4b
T: com.ibm.mm.beans.CMBConnection
Connecting to server.
Please wait...
[09/03/2004 21:59:22.486 GMT]
fadef4b
T:com.ibm.mm.beans.workflow.CMBWorkFlowDataManagement
<http://publib.boulder.ibm.com/infoc...c=/com.ibm.troubleshooting.doc/frnm2mst21.htm>

 

[Lew]

Lew wrote:
Novice wrote:
Arved Sandstrom wrote:
Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

Wha...?

These programs run on Windows, too.

This is about OSes. Windows is like Linux in this regard.

You can get them for Windows.

But they are not that common on Windows.

True, but irrelevant. The point is that they are just programs, and that the
issue at hand is operating system behavior, not program behavior. What program
is involved has no bearing - the ability to read from a file as it's being
written is a function of the OS and file system, inherently so. It doesn't
matter what program we cite. I mentioned that they run on Windows, too, to
point out that the behavior is not inherent to the program. That point is
unaffected by how common the program is. There are plenty of programs on
Windows, too. If you don't like my example, please extend the reasoning on
your own to apply to whatever program you do like as an example.

 

[Novice]

Novice wrote:
Arved Sandstrom wrote:
Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

Wha...?

These programs run on Windows, too.

This is about OSes. Windows is like Linux in this regard.

I agree. Can you point me to any? I don't have any.

Go to your nearest real system and ask to see the logs.

A lot of Apache projects use log4j. Run one of those.

I'm on a Windows system, not a *nix system, and I simply don't
remember the details of 'tail'. Yes, I could have and would have
looked it up if I really needed to know. I was just making a passing
comment that I didn't remember if 'tail' could read an open file.

"
Windows is no different in this regard. This is about reading files as
they're written, not Linux. You need to know the basics of OSes.

Windows the same thing happens. Substitute "Notepad" for "vi", why
don't you?

I've had Notepad refuse to open files because they were in use. (Or was
that Wordpad? I may be muddling the two....) Therefore, it was not
intuitively obvious to me that Notepad would always read a file that was
in use.

And "tail" runs on Windows, too. Many programs are available for both
Windows and Linux. It's the operating system that determines the
behavior, not whether it's "tail" or some other program.

So stop throwing those red herrings at us, please. Take the coaching
and don't make the excuses.

Coaching or bludgeoing? Sometimes it seems like you seize on even
slightest misstep to emphasize how I am utterly wrong about something.
This is one such case.

The topic at hand was how an operator would access a log file that was
still open. Someone suggested 'tail' as a tool for reading such a file. I
mentioned in passing that I didn't know it could read an open file. I
didn't demand that someone tell me whether it could. If I had, you could
rightly say that I should look it up. I didn't feel any particular need
then - nor do I now - to go out and determine all the programs on all the
popular operating systems, including Windows, that can read an open file.
I didn't know that tail, vi, or emacs were available in Windows versions.
I'm not actually surprised but I didn't know it. Notepad may or may not
be able to read an open file - I'm sure I had trouble reading at least
one open file with either Notepad or Wordpad yesterday but I don't recall
which - but it's not a big concern to me at this moment. I'm much more
interested in the big picture so that I can improve my use of logs. When
I need to read an open file in Windows, I'll figure out how to do that.

You're mixing topics. I pointed out the console scenario in the
context of being able to read a file while it's being written. In no
wise does that carry over to an inference that I'm recommending its
use for logging.

I was only trying to find out how operators would read an open file in
the absence of consoles. I didn't want to blithely assume that a console
was always going to be at hand. That's all I was trying to say.

The point you ducked is that this is basic, fundamental, elementary,
beginner OS knowledge that applies to Windows, too. It's stuff you
should already know. You must understand the basics of the OS.

If you did, you'd've known that the ability of "tail" to read files as
they're written is neither a feature of "tail" nor unique to Linux.

You're obviously better at remembering large numbers of things for a long
time than I am. I tend not to remember a lot of details due to my less
reliable memory. Therefore, I don't have a list in my head of exactly
which programs on each of the major OSes will read open files. I just
assume that such tools exist and that I might have some of them on my
computer. If I need to read an open file, I use the tools I have. If they
don't work, I look for others or maybe even build one of my own.

I don't memorize the fact that there are Windows version of vi, emacs,
tail, less, and so forth nor which of them can read a file that is open
nor whether Notepad or Wordpad or the various other Windows editors can
handle them. I've never found that I remember things like that
particularly well. I wish I could. I muddle along as best I can within my
limitations.

 

[Martin Gregorie]

Come, come, Martin, desktop Windows isn't quite so bad.

I wasn't saying it was - just that The Microsoft Way tends not to use
logs to the extent that *NIXen do.

I admit its been quite a while since I've used Windows in developer mode,
but about the only place I can remember seeing good logging was from ODBC,
and only then if it was configured on. The ODBC log entries weren't
timestamped, but were pretty good in all other respects.[*]

OTOH every *NIX system I've used produces timestamped logs and has a
mechanism for changing logfiles and keeping the number kept under
control. IOW I've never see a log under Windows that let me see what had
happened at about 02:30:15 last Wednesday but all Unices support that
sort of thing.

Hey, Novice - this example below is a good example of the unexpected
places where a decent log can come in useful.

[*] I was using the ODBC logs to help me tune one of the more
incompetently written databases I've seen. No adequate application
documentation of course! So, I was reduced to exercising every function
of the application with ODBC logging turned on and then working through
the log to work out what indexes and table storage strategies were needed
to make the database perform: AKA doing a traditional access path
frequency analysis after the app had gone live and promptly slowed to a
crawl. You really can't expect a join on 25,000 accounts to be fast if
there are no indexes to support it, though somebody had done exactly
that. And, of course the problem didn't show up during development, which
had populated the test database with the traditional handful of accounts:
when each table occupies no more than one or two disk blocks all queries
are quick.

 

[Arne Vajhøj]

Novice wrote:
Lew wrote:
Novice wrote:
Arved Sandstrom wrote:
Novice wrote:
[ SNIP ]

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.

As mentioned, "tail" or "tail -f".

Or vi or emacs.

Or "less".

Or just about anything.

Okay. As I said, my Unix/Linux is pretty rusty.

Wha...?

These programs run on Windows, too.

This is about OSes. Windows is like Linux in this regard.

You can get them for Windows.

But they are not that common on Windows.

True, but irrelevant. The point is that they are just programs, and that
the issue at hand is operating system behavior, not program behavior.
What program is involved has no bearing - the ability to read from a
file as it's being written is a function of the OS and file system,
inherently so. It doesn't matter what program we cite. I mentioned that
they run on Windows, too, to point out that the behavior is not inherent
to the program. That point is unaffected by how common the program is.
There are plenty of programs on Windows, too. If you don't like my
example, please extend the reasoning on your own to apply to whatever
program you do like as an example.

All very true.

But I think novice was just trying to say that he was rusty in *nix
including those tools.

And that is not particular surprising if he is a Windows user.

Arne