Bugzilla – Bug 15567
Log messages truncated in /var/log/messages
Last modified: 2010-04-08 17:26:05 UTC
...pretty often rendering them useless. Can't we have the full log messages in the log file?
Vahid, somehow it seems like we have a bunch of logfile-related bugs. I hope you don't mind taking a look.
I believe the /var directory is mounted as ramfs as follows: ramfs on /var type ramfs (rw) This means that all the information under /var/log will be lost as soon as the system is rebooted.
Vahid - this bug isn't about the log file being wiped, but all messages being truncated before they're logged. Somebody mentioned it was a limitation/configuration of syslog. I don't know nothing about it.
The syslogd gets started in the rcS script(/etc/inid.d/rcS) during the start-up. The version of the syslogd that is run on our systems does not use the syslog.conf. As a matter of fact there is no syslog.conf in the system. At the moment the syslogd is run by the -S option, which in its manual says "Smaller Logging Output". I am looking more into this.
Vahid - it's most obvious with SBS log messages, in particular if the contain a backtrace: Feb 2 22:35:30 slimserver.pl: [10-02-02 22:35:30.0575] main::init (341) Error: Starting Squeezebox Server (v7.5.0, r29973, Tue Feb 2 07:38:41 MST 2010) perl 5.010000 Feb 2 22:35:30 slimserver.pl: [10-02-02 22:35:30.0758] main::init (341) Backtrace: frame 0: Slim::Utils::Log::logBacktrace (/usr/squeezecenter/slimserver.pl line 341) frame 1: main::init (/usr/squeezecenter/slimserver.pl line 630) frame 2: The rest of the backtrace is missing. You can easily modify slimserver.pl in order to get a quick demo of the issue. On the fab4: - open /usr/squeezecenter/slimserver.pl - go to line 341 (about), which should be: $log->error("Starting Squeezebox Server (v$VERSION, r$REVISION, $BUILDDATE) perl $]"); - modify this line to be: logBacktrace("Starting Squeezebox Server (v$VERSION, r$REVISION, $BUILDDATE) perl $]"); - restart Squeezebox Server using Settings/Advanced/Squeezebox Server on the touch - see the above log be added to syslog
I traced the logs to usr/lib/perl/5.10.0/Sys/Syslog.pm and the message is delivered properly to _syslog_send_native. _syslog_send_native calls the syslog_xs to write the data to the syslog file. I noticed that if the size of the buffer in the call to syslog_xs function is more than 220 characters then the character after the 220th position will be lost.
Ugh... means it's a limitation in Sys::Syslog? I thought it was in syslog itself... Maybe we could treat multiline messages as independant messages, logging every line of a stack trace separately. Andy/Alan - is there an important reason we're sending SBS logs to syslog? imho it's a huge step back when it comes to diagnosing issues in embedded SBS.
The busybox includes an implementation of the syslogd. I am looking into the implementation to find out if there are potential problems there or not. I am able to make changes in busybox and test the changes. I will get into the end of this problem very soon. I should have a fix for it hopefully by Tuesday next week.
under busybox-1.15.2 the syslogd is implemented at /sysklogd/syslogd.c. It seems to me that the data between the Syslog implementation of the perl and the syslogd implementation of the busybox is transferred through /dev/log. To run an experiment I made the following change in the file(/sysklogd/syslogd.c): enum { MAX_READ = 512, DNS_WAIT_SEC = 2 * 60, }; which means I increased the MAX_READ from 256 to 512. After I run the test I can see the complete back trace in the logs. I have to understand this better to have a final solution.
> The busybox includes an implementation of the syslogd. I am looking into > the implementation to find out if there are potential problems there or > not. If the perl module is truncating the logs, then there's little need to investigate syslogd, is there?
> which means I increased the MAX_READ from 256 to 512. After I run the > test I can see the complete back trace in the logs. Hehe... I'll shut up then :-). Thanks for your work!
The problem of truncating the log files in /var/log/message is in the implementation of the syslogd in busybox. If I increase the buffer size from 256 to 2K, it will resolve the issue.
Sounds like a good solution. FWIW, I am in favour of using syslog.
I checked in my changes to increase the buffer size for the maximum line that can be sent to syslog. I tested the change and the logs are not truncated anymore. The maximum line size is set to be 2048. I do not expect the lines to be more than this, otherwise I have to spend more time and fix this problem.
This bug has been marked fixed in a released version of Squeezebox Server or the accompanying firmware or mysqueezebox.com release. If you are still seeing this issue, please let us know!