Sticking system log?

[skyewright]

Two days in a row now the system log on my ALIX 1D seems to have 'stopped' (i.e. no more entries) at
00:18:02

The sample at the bottom of this message shows how the log still ends at 09:57

Both yesterday and today the last in the log before additions stopped was the same, i.e. "ncftpput /data/uploads/fallback.html: server said: Could not open: Input/output error"

N.B. Although the log is not updating, eveything else seems to be working fine - including the fact that fallback.html continues to be uploaded to my server every 15 minutes as per schedule.


If I reboot, normal operation of the system log resumes.

Strange...

PS. I'm using 3.2d, could this have been one of the "minor bugs" fixed by 3.2e?

Code: Select all

Dec 19 00:18:02 localhost /USR/SBIN/CRON[5233]: (root) CMD (/bin/pidof wswinimport || /usr/bin/nice /home/meteohub/wswinimport 2>>/data/log/messages)
Dec 19 00:18:02 localhost CRON[5231]: (pam_unix) session closed for user root
Dec 19 00:18:02 localhost CRON[5225]: (pam_unix) session closed for user root
ncftpput /data/uploads/fallback.html: server said: Could not open: Input/output error

[skyewright]

Two days in a row now the system log on my ALIX 1D seems to have 'stopped' (i.e. no more entries) at 00:18:02

And again!

Just the same!

On reboot the system log was functioning normally - and contained entries from before the reboot, that were previously not visible in Meteohub! Here's the shutdown/restart section of the system log, to illustrate that:

Code: Select all

Dec 20 11:36:03 localhost rpc.statd[2042]: Caught signal 15, un-registering and exiting.
Dec 20 11:36:03 localhost kernel: Kernel logging (proc) stopped.
Dec 20 11:36:03 localhost kernel: Kernel log daemon terminating.
Dec 20 11:36:04 localhost exiting on signal 15
Dec 20 11:41:07 localhost syslogd 1.4.1#18: restart.
Dec 20 11:41:07 localhost kernel: klogd 1.4.1#18, log source = /proc/kmsg started.
Dec 20 11:41:07 localhost kernel: Linux version 2.6.24-etchnhalf.1-486 (Debian 

Any ideas?

PS. the gap between 11:36 and 11:41 was where I discovered that the ALIX 1D "hang if no monitor" bug also applies if a monitor is attached, but not switched on! :(
But fine with a bent paperclip! :)

[skyewright]

And again!

I've now discovered that it's not just midnight that this can happen.

I rebooted at 11:45. Now at 14:33 system log shows:

Code: Select all

Dec 20 12:18:02 localhost CRON[4038]: (pam_unix) session closed for user root
Dec 20 12:18:02 localhost CRON[4043]: (pam_unix) session opened for user root by (uid=0)
Dec 20 12:18:02 localhost CRON[4045]: (pam_unix) session opened for user root by (uid=0)
Dec 20 12:18:02 localhost /USR/SBIN/CRON[4044]: (root) CMD (/usr/bin/tail -n 1000 /var/log/messages >/var/log/messages.new; /bin/mv -f /var/log/messages.new /var/log/messages)
Dec 20 12:18:02 localhost /USR/SBIN/CRON[4046]: (root) CMD (/bin/pidof wswinimport || /usr/bin/nice /home/meteohub/wswinimport 2>>/data/log/messages)
Dec 20 12:18:02 localhost CRON[4045]: (pam_unix) session closed for user root
Dec 20 12:18:02 localhost CRON[4040]: (pam_unix) session closed for user root

Could it be that there is some sort of problem with the CRON job

Code: Select all

18 */4 * * * /usr/bin/tail -n 1000 /var/log/messages >/var/log/messages.new; /bin/mv -f /var/log/messages.new /var/log/messages

I think that runs at 18 minutes past the hour, every 4 hours?

The last couple of nights I've rebooted within 4 hours of midnight...

[admin]

I will try to reproduce this. What weather station is connected? Any other special services running?

[skyewright]

I will try to reproduce this. What weather station is connected? Any other special services running?

ALIX 1D
RFXCOM USB
Meteohub 3.2d

Nothing special running, except that WD is calling the logging protocol every 3 secobds for the most recent sensor reading, and on the minute for the last minute's worth of readings.

PS. I'm not sure if it may be relevant, but in addition I have now had 2 unexplained halts of the ALIX 1D in the last week.
On the second one I observed the restart and it was definitely a matter of recovery from an sudden halt rather than restart after a controlled shutdown.

After start up Meteohub automatically (I assume) performed a recompute.
I caught the system log for the change over. Here's a snippet. I have more if it might be helpful.

Code: Select all

Dec 19 21:00:47 localhost CRON[23586]: (pam_unix) session closed for user root
Dec 19 21:00:49 localhost thttpd[1986]: spawned CGI process 23644 for file 'meteolog.cgi'
Dec 19 21:00:53 localhost thttpd[1986]: spawned CGI process 23646 for file 'meteolog.cgi'
Dec 19 21:00:57 localhost thttpd[1986]: spawned CGI process 23648 for file 'meteolog.cgi'
Dec 19 21:19:19 localhost syslogd 1.4.1#18: restart.
Dec 19 21:19:19 localhost kernel: klogd 1.4.1#18, log source = /proc/kmsg started.
Dec 19 21:19:19 localhost kernel: Linux version 2.6.24-etchnhalf.1-486 (Debian 2.6.24-6~etchnhalf.6) (dannf@debian.org) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)) #1 Mon Oct 13 06:47:02 UTC 2008
Dec 19 21:19:19 localhost kernel: BIOS-provided physical RAM map:
Dec 19 21:19:19 localhost kernel:  BIOS-e820: 0000000000000000 - 000000000009e800 (usable)

[skyewright]

...and if it might help I'm happy to let you SSH in if you wish. If you want to do that, let me know and I'll e-mail you the IP and password (I think you've done that before, but the password is not the same now).

[admin]

yes, that is a great idea. I can implement some more logging to your system to find out what the reason is.

[skyewright]

I can implement some more logging to your system to find out what the reason is.

Details sent by e-mail.

[skyewright]

Just to note that the issues I was having with the ALIX 1D have now been resolved.
The log is not 'sticking' and the ALIX 1D seems to be running nice and stable. :cheer:

Many thanks to Boris for his efforts.