logging messages to error_log with "INFO:" does not work

Kurt Pfeifle kpfeifle at danka.de
Tue Jul 4 08:26:35 PDT 2006


Kurt Pfeifle <kpfeifle at danka.de> wrote (Tuesday 04 July 2006 15:45):

> Helge Blischke <h.blischke at srz.de> wrote (Tuesday 04 July 2006 14:31):
> 
>> At least in CUPS 1.1.x, the INFO messages are written to the error_log only if
>> the log level is at least warning or notice (don't know exactly). With log level
>> info, the latest info message is saved as the state message in the internal printer's
>> structure (and dumped inot printers.conf, shown in the web interface, or with the
>> lpstat command).
>> 
>> I currently don't know if things have changed with 1.2.x.
> 
> Thanks for this info, Helge.
> 
> If I understand correctly, that would mean: if I repeat that same
> "info level" log message one more time (or if I write another one)
> on the next line, it should appear in the error_log.
> 
> I tried it. However, it does neither appear in the error log, nor
> as a state messsage in printers.conf/web interface/lpstat output...
> (this one only tested with trunk/r5706 so far, not yet with 1.1.23)

OK, I tested now with 1.1.23 (SUSE-10.0 packages, "RunAsUser No"). I 
modified the dummy backend to emit the following messages to stderr 
each time it is run:

  echo "EMERG:  This is a \"emergency\" level log message" 1>&2
  echo "ALERT:  This is a \"alert\" level log message"     1>&2
  echo "CRIT:   This is a \"critical\" level log message"  1>&2
  echo "ERROR:  This is a \"error\" level log message"     1>&2
  echo "WARN:   This is a \"warn\" level log message"      1>&2
  echo "NOTICE: This is a \"notice\" level log message"    1>&2
  echo "INFO:   This is a \"info\" level log message"      1>&2
  echo "INFO:   This is a 2nd \"info\" level log message"  1>&2
  echo "INFO:   This is a 3rd \"info\" level log message"  1>&2
  echo "DEBUG:  This is a \"debug\" level log message"     1>&2
  echo "DEBUG2: This is a \"debug2\" level log message"    1>&2


This results in the following lines in the error_log and in the web 
interface, depending on the LogLevel setting:


"LogLevel info":
----------------

X [04/Jul/2006:17:09:34 +0200] [Job 578] This is a "emergency" level log message
A [04/Jul/2006:17:09:34 +0200] [Job 578] This is a "alert" level log message
C [04/Jul/2006:17:09:34 +0200] [Job 578] This is a "critical" level log message
E [04/Jul/2006:17:09:34 +0200] [Job 578] This is a "error" level log message
N [04/Jul/2006:17:09:34 +0200] [Job 578] : This is a "notice" level log message
 
 soprano:~ # links -dump http://localhost:631/printers/dummy | grep "log message"
             "This is a 3rd "info" level log message"


"LogLevel debug":
-----------------

 soprano:~ # grep "log message" /var/log/cups/error_log
 X [04/Jul/2006:17:10:29 +0200] [Job 579] This is a "emergency" level log message
 A [04/Jul/2006:17:10:29 +0200] [Job 579] This is a "alert" level log message
 C [04/Jul/2006:17:10:29 +0200] [Job 579] This is a "critical" level log message
 E [04/Jul/2006:17:10:29 +0200] [Job 579] This is a "error" level log message
 D [04/Jul/2006:17:10:29 +0200] [Job 579] WARN:   This is a "warn" level log message
 N [04/Jul/2006:17:10:29 +0200] [Job 579] : This is a "notice" level log message
 D [04/Jul/2006:17:10:29 +0200] [Job 579] This is a "debug" level log message
 
 soprano:~ # links -dump http://localhost:631/printers/dummy | grep "log message"
             "This is a 3rd "info" level log message"


"LogLevel debug2":
------------------

 soprano:~ # grep "log message" /var/log/cups/error_log
 X [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "emergency" level log message
 A [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "alert" level log message
 C [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "critical" level log message
 E [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "error" level log message
 D [04/Jul/2006:17:12:55 +0200] [Job 580] WARN:   This is a "warn" level log message
 N [04/Jul/2006:17:12:55 +0200] [Job 580] : This is a "notice" level log message
 I [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "info" level log message
 I [04/Jul/2006:17:12:55 +0200] [Job 580] This is a 2nd "info" level log message
 I [04/Jul/2006:17:12:55 +0200] [Job 580] This is a 3rd "info" level log message
 D [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "debug" level log message
 d [04/Jul/2006:17:12:55 +0200] [Job 580] This is a "debug2" level log message
 
 soprano:~ # links -dump http://localhost:631/printers/dummy | grep "log message"
             "This is a 3rd "info" level log message"


Note,...
 ...how the "NOTICE:" line appears with the leading ": "
 ...how the "INFO:" line only appears in log level debug2
 ...how the "WARN:" line appears with the "D" marker, and including the "WARN:   "
 ...how the web interface always keeps the last info level log message

Cheers,
Kurt




More information about the cups mailing list