On 05/01/2012 08:15 PM, Jeremy C. Reed wrote:
> The BIND 10 suite uses log4cplus. We have multiple processes running
> that use a centralized logging configuration. Our use of log4cplus is
> wide-spread through our code. But mostly abstracted as our own library
> with code at
> http://git.bind10.isc.org/~jreed/gitweb/gitweb.cgi?p=bind10/.git;a=tree;f=src/lib/log
>
> (By the way, we have a nice feature where we have a unique log message
> for every use that has a corresponding longer description that is
> available in our documentation.)
>
> A few problems we have include:
>
> 1) stderr output sometimes has Ctrl-@ characters included in the output.
> I have only seen this on our MacOS system and can't reproduce it, but it
> happens frequently.
>
> An example:
>
> 2012-01-25 03:58:52.408 DEBUG [b10-cmdctl.cmdctl] CMDCTL_STARTED cmdctl
> is listening for connections on 127.0.0.1:8080
> 2012-01-25 03:58:52.429 012-01-25 03:58:52.428^@IINFO ^@^@^@ ^@
> [^@^@b10-xfrout.xfrouttats-httpd^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@]
> ^@^@XFROUT_NEW_CONFIG Update xfrout
> configuration^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@
> ^@2012-01-25 03:58:52.429 INFO [b10-xfrout.xfrout]
> XFROUT_NEW_CONFIG_DONE Update xfrout configuration done
> 2012-01-25 03:59:07.946 INFO [b10-xfrin.xfrin]
> XFRIN_XFR_TRANSFER_STARTED IXFR transfer of zone example/IN started
>
> Anyone see CTRL-@? (Note that you probably can't see it unless you
> convert it to something visible. I piped the saved output through cat
> -v.) (The rest of the corruption in that output is probably due to poit
> #2 below.)
>
> Our BIND 10 specific ticket about this is at
> http://bind10.isc.org/ticket/1629
I have never seen such behaviour. You are the first one reporting this.
I have no idea why it could be happening.
>
> 2) Often we have log output that is mixed when sent to console (stdout
> or stderr). For example, the following line:
>
> 2012-02-22 11:20:33.287 DEBUG2012-02-22 11:20:33.287 DEBUG [b10-auth.auth] AUTH_DNS_SERVICES_CREATED DNS services created
>
> was logged as different entries but ended up interspersed. We have seen
> this on multiple different operating systems.
>
> I see the new fileappender UseLockFile. Is there any similar feature so
> different processes (using same log4cplus setup) won't write their log
> output to console at the same time?
>
> Our BIND 10 specific ticket about this is at
> http://bind10.isc.org/ticket/1704
There is no inter-process synchronization for console output. In theory,
it should be possible to implement it using lock file.
>
> 3) Old rotated logs continue to be open and written to. fstat shows it
> clearly. The problem is mostly understood. Multiple processes (all using
> log4cplus) are writing to the same rotated log file. One process noticed
> file needs to be rotated, so files are renamed. Other processes continue
> to have the file handle open (now with an old name with number at
> end) and start logging to it (starting from an empty file?). Later it
> may reach our max file size configuration and be rotated too.
>
> I haven't tried the fileappender's UseLockFile, but maybe it handles
> this rotation problem also. Any suggestions on this?
>
> Our BIND 10 specific ticket about this is at
> http://bind10.isc.org/ticket/1896
Yes, this has been reported and it should be fixed on trunk and upcoming
1.1.0 for FileAppender and RollingFileAppender. DailyRollingFileAppender
still has issues with synchronization between multiple processes.
>[...]
--
VZ
|
