Hi, I'm on FC6 machine that gets updated at least once a week. I notice today {monday}, that messages has been rotated and is empty so far. -rw------- 1 root root 0 Apr 8 09:07 /var/log/messages -rw------- 1 root root 326802 Apr 5 07:03 /var/log/messages.1 -rw------- 1 root root 632374 Apr 1 04:05 /var/log/messages.2 -rw------- 1 root root 273450 Mar 25 11:06 /var/log/messages.3 -rw------- 1 root root 89829 Mar 20 18:53 /var/log/messages.4
Since the machine has been shutdown and rebooted 3/4 times since Apr5, it seems that no data is getting to this log. The machine has been on for many hours almost every day since (now Apr9). Normally yum log items are also logged to messages, but there have been none of these in this time frame.
Is this just my PC, or are others seeing this ?
DaveT. ==== messages.1: last few entries. Apr 5 05:43:29 davidtdesktop ntpd[2986]: synchronized to 192.135.48.21, stratum 2 Apr 5 06:12:58 davidtdesktop ntpd[2986]: synchronized to 193.138.193.113, stratum 2 Apr 5 06:59:31 davidtdesktop kernel: device eth0 left promiscuous mode Apr 5 06:59:31 davidtdesktop kernel: audit(1175720371.077:22): dev=eth0 prom=0 old_prom=256 auid=4294967295 Apr 5 06:59:31 davidtdesktop kernel: bridge-eth0: disabled promiscuous mode Apr 5 07:03:23 davidtdesktop gconfd (root-9821): GConf server is not in use, shutting down. Apr 5 07:03:23 davidtdesktop gconfd (root-9821): Exiting Apr 5 07:03:30 davidtdesktop shutdown[16032]: shutting down for system halt Apr 5 07:03:33 davidtdesktop restorecond: Will not restore a file with more than one hard link (/etc/resolv.conf) No such file or directory Apr 5 07:03:33 davidtdesktop smartd[3442]: smartd received signal 15: Terminated Apr 5 07:03:33 davidtdesktop smartd[3442]: smartd is exiting (exit status 0) Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Got SIGTERM, quitting. Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::20c:6eff:fe1c:654b. Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Leaving mDNS multicast group o n interface eth0.IPv4 with address 192.168.2.210. Apr 5 07:03:41 davidtdesktop dhcpd: dhcpd shutdown succeeded Apr 5 07:03:46 davidtdesktop xinetd[10792]: Exiting... Apr 5 07:03:50 davidtdesktop ntpd[2986]: ntpd exiting on signal 15 Apr 5 07:03:51 davidtdesktop rpc.statd[2740]: Caught signal 15, un-registering and exiting. Apr 5 07:03:52 davidtdesktop pcscd: pcscdaemon.c:529:signal_trap() Preparing for suicide Apr 5 07:03:52 davidtdesktop pcscd: hotplug_libusb.c:361:HPEstablishUSBNotifications() Hotplug stopped Apr 5 07:03:53 davidtdesktop pcscd: readerfactory.c:1350:RFCleanupReaders() entering cleaning function Apr 5 07:03:53 davidtdesktop pcscd: pcscdaemon.c:489:at_exit() cleaning /var/run Apr 5 07:03:53 davidtdesktop kernel: Kernel logging (proc) stopped. Apr 5 07:03:53 davidtdesktop kernel: Kernel log daemon terminating. Apr 5 07:03:54 davidtdesktop exiting on signal 15 ===== yum.log: Apr 03 07:35:00 Updated: japa.i386 0.2.0-2.fc6.ccrma Apr 04 22:00:58 Updated: audit-libs.i386 1.4.2-5.fc6 Apr 04 22:01:07 Updated: ruby-libs.i386 1.8.5.35-2.fc6 Apr 04 22:01:11 Updated: ruby.i386 1.8.5.35-2.fc6 Apr 04 22:01:20 Updated: samba-common.i386 3.0.24-3.fc6 Apr 04 22:01:21 Updated: ruby-irb.i386 1.8.5.35-2.fc6 Apr 04 22:01:23 Updated: ruby-rdoc.i386 1.8.5.35-2.fc6 Apr 04 22:01:25 Updated: file.i386 4.19-2.fc6 Apr 04 22:01:29 Updated: yum.noarch 3.0.5-1.fc6 Apr 04 22:01:32 Updated: parted.i386 1.8.2-2.fc6 Apr 04 22:01:38 Updated: dvdrip.i386 0.98.4-2.fc6 Apr 04 22:01:40 Updated: gpm.i386 1.20.1-82.fc6 Apr 04 22:01:43 Updated: samba-client.i386 3.0.24-3.fc6 Apr 04 22:01:45 Updated: yum-updatesd.noarch 3.0.5-1.fc6 Apr 04 22:01:47 Updated: psmisc.i386 22.2-5.1 Apr 04 22:01:47 Updated: audit-libs-python.i386 1.4.2-5.fc6 Apr 04 22:02:09 Updated: rhythmbox.i386 0.9.8-1.fc6 Apr 04 22:03:18 Updated: ruby-ri.i386 1.8.5.35-2.fc6 Apr 04 22:03:35 Updated: azureus.i386 2.5.0.4-2.fc6 Apr 04 22:03:37 Updated: redhat-rpm-config.noarch 8.0.45-9.fc6 Apr 04 22:21:30 Updated: VMware-server.i386 1.0.2-39867 Apr 04 22:34:16 Updated: VMware-server-console.i386 1.0.2-39867 Apr 06 10:31:51 Installed: screen.i386 4.0.3-2.fc6 Apr 06 20:15:26 Installed: eclipse-rcp-sdk.i386 1:3.2.2-1.fc6 Apr 06 20:15:40 Installed: eclipse-platform-sdk.i386 1:3.2.2-1.fc6 Apr 06 20:16:49 Installed: java-1.4.2-gcj-compat-javadoc.i386 1.4.2.0-40jpp.110 Apr 06 20:17:10 Installed: eclipse-jdt.i386 1:3.2.2-1.fc6 Apr 06 20:17:11 Installed: eclipse-pde-runtime.i386 1:3.2.2-1.fc6 Apr 06 20:17:17 Installed: eclipse-pde.i386 1:3.2.2-1.fc6 Apr 08 09:14:02 Updated: krb5-libs.i386 1.5-21 Apr 08 09:14:06 Updated: openssh.i386 4.3p2-19.fc6 Apr 08 09:14:07 Updated: cups-libs.i386 1:1.2.10-3.fc6 Apr 08 09:14:13 Updated: selinux-policy.noarch 2.4.6-49.fc6
On Mon, 09 Apr 2007 09:03:48 +1000 David Timms dtimms@iinet.net.au wrote:
Hi, I'm on FC6 machine that gets updated at least once a week. I notice today {monday}, that messages has been rotated and is empty so far.
Is syslogd running?
David Timms wrote:
Hi, I'm on FC6 machine that gets updated at least once a week. I notice today {monday}, that messages has been rotated and is empty so far. -rw------- 1 root root 0 Apr 8 09:07 /var/log/messages -rw------- 1 root root 326802 Apr 5 07:03 /var/log/messages.1 -rw------- 1 root root 632374 Apr 1 04:05 /var/log/messages.2 -rw------- 1 root root 273450 Mar 25 11:06 /var/log/messages.3 -rw------- 1 root root 89829 Mar 20 18:53 /var/log/messages.4
Since the machine has been shutdown and rebooted 3/4 times since Apr5, it seems that no data is getting to this log. The machine has been on for many hours almost every day since (now Apr9). Normally yum log items are also logged to messages, but there have been none of these in this time frame.
Is this just my PC, or are others seeing this ?
DaveT.
messages.1: last few entries. Apr 5 05:43:29 davidtdesktop ntpd[2986]: synchronized to 192.135.48.21, stratum 2 Apr 5 06:12:58 davidtdesktop ntpd[2986]: synchronized to 193.138.193.113, stratum 2 Apr 5 06:59:31 davidtdesktop kernel: device eth0 left promiscuous mode Apr 5 06:59:31 davidtdesktop kernel: audit(1175720371.077:22): dev=eth0 prom=0 old_prom=256 auid=4294967295 Apr 5 06:59:31 davidtdesktop kernel: bridge-eth0: disabled promiscuous mode Apr 5 07:03:23 davidtdesktop gconfd (root-9821): GConf server is not in use, shutting down. Apr 5 07:03:23 davidtdesktop gconfd (root-9821): Exiting Apr 5 07:03:30 davidtdesktop shutdown[16032]: shutting down for system halt Apr 5 07:03:33 davidtdesktop restorecond: Will not restore a file with more than one hard link (/etc/resolv.conf) No such file or directory Apr 5 07:03:33 davidtdesktop smartd[3442]: smartd received signal 15: Terminated Apr 5 07:03:33 davidtdesktop smartd[3442]: smartd is exiting (exit status 0) Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Got SIGTERM, quitting. Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::20c:6eff:fe1c:654b. Apr 5 07:03:34 davidtdesktop avahi-daemon[3291]: Leaving mDNS multicast group o n interface eth0.IPv4 with address 192.168.2.210. Apr 5 07:03:41 davidtdesktop dhcpd: dhcpd shutdown succeeded Apr 5 07:03:46 davidtdesktop xinetd[10792]: Exiting... Apr 5 07:03:50 davidtdesktop ntpd[2986]: ntpd exiting on signal 15 Apr 5 07:03:51 davidtdesktop rpc.statd[2740]: Caught signal 15, un-registering and exiting. Apr 5 07:03:52 davidtdesktop pcscd: pcscdaemon.c:529:signal_trap() Preparing for suicide Apr 5 07:03:52 davidtdesktop pcscd: hotplug_libusb.c:361:HPEstablishUSBNotifications() Hotplug stopped Apr 5 07:03:53 davidtdesktop pcscd: readerfactory.c:1350:RFCleanupReaders() entering cleaning function Apr 5 07:03:53 davidtdesktop pcscd: pcscdaemon.c:489:at_exit() cleaning /var/run Apr 5 07:03:53 davidtdesktop kernel: Kernel logging (proc) stopped. Apr 5 07:03:53 davidtdesktop kernel: Kernel log daemon terminating. Apr 5 07:03:54 davidtdesktop exiting on signal 15 ===== yum.log: Apr 03 07:35:00 Updated: japa.i386 0.2.0-2.fc6.ccrma Apr 04 22:00:58 Updated: audit-libs.i386 1.4.2-5.fc6 Apr 04 22:01:07 Updated: ruby-libs.i386 1.8.5.35-2.fc6 Apr 04 22:01:11 Updated: ruby.i386 1.8.5.35-2.fc6 Apr 04 22:01:20 Updated: samba-common.i386 3.0.24-3.fc6 Apr 04 22:01:21 Updated: ruby-irb.i386 1.8.5.35-2.fc6 Apr 04 22:01:23 Updated: ruby-rdoc.i386 1.8.5.35-2.fc6 Apr 04 22:01:25 Updated: file.i386 4.19-2.fc6 Apr 04 22:01:29 Updated: yum.noarch 3.0.5-1.fc6 Apr 04 22:01:32 Updated: parted.i386 1.8.2-2.fc6 Apr 04 22:01:38 Updated: dvdrip.i386 0.98.4-2.fc6 Apr 04 22:01:40 Updated: gpm.i386 1.20.1-82.fc6 Apr 04 22:01:43 Updated: samba-client.i386 3.0.24-3.fc6 Apr 04 22:01:45 Updated: yum-updatesd.noarch 3.0.5-1.fc6 Apr 04 22:01:47 Updated: psmisc.i386 22.2-5.1 Apr 04 22:01:47 Updated: audit-libs-python.i386 1.4.2-5.fc6 Apr 04 22:02:09 Updated: rhythmbox.i386 0.9.8-1.fc6 Apr 04 22:03:18 Updated: ruby-ri.i386 1.8.5.35-2.fc6 Apr 04 22:03:35 Updated: azureus.i386 2.5.0.4-2.fc6 Apr 04 22:03:37 Updated: redhat-rpm-config.noarch 8.0.45-9.fc6 Apr 04 22:21:30 Updated: VMware-server.i386 1.0.2-39867 Apr 04 22:34:16 Updated: VMware-server-console.i386 1.0.2-39867 Apr 06 10:31:51 Installed: screen.i386 4.0.3-2.fc6 Apr 06 20:15:26 Installed: eclipse-rcp-sdk.i386 1:3.2.2-1.fc6 Apr 06 20:15:40 Installed: eclipse-platform-sdk.i386 1:3.2.2-1.fc6 Apr 06 20:16:49 Installed: java-1.4.2-gcj-compat-javadoc.i386 1.4.2.0-40jpp.110 Apr 06 20:17:10 Installed: eclipse-jdt.i386 1:3.2.2-1.fc6 Apr 06 20:17:11 Installed: eclipse-pde-runtime.i386 1:3.2.2-1.fc6 Apr 06 20:17:17 Installed: eclipse-pde.i386 1:3.2.2-1.fc6 Apr 08 09:14:02 Updated: krb5-libs.i386 1.5-21 Apr 08 09:14:06 Updated: openssh.i386 4.3p2-19.fc6 Apr 08 09:14:07 Updated: cups-libs.i386 1:1.2.10-3.fc6 Apr 08 09:14:13 Updated: selinux-policy.noarch 2.4.6-49.fc6
I saw this on my machine on the update to kernel-2.6.20-1.2933.fc6. I backed off to the previous kernel kernel-2.6.20-1.2925.fc6 which does log properly and sent out a query to this list on March 26. https://www.redhat.com/archives/fedora-list/2007-March/msg03318.html However, I had no reply, so I was thinking that it was perhaps something particular to my machine. However, if you have seen this as well, perhaps one of us should file a Bugzilla report. (I just did another search of Bugzilla and didn't see this problem reported, but that doesn't mean it isn't there.)
John DeDourek wrote:
David Timms wrote:
Hi, I'm on FC6 machine that gets updated at least once a week. I notice today {monday}, that messages has been rotated and is empty so far. -rw------- 1 root root 0 Apr 8 09:07 /var/log/messages -rw------- 1 root root 326802 Apr 5 07:03 /var/log/messages.1 -rw------- 1 root root 632374 Apr 1 04:05 /var/log/messages.2 -rw------- 1 root root 273450 Mar 25 11:06 /var/log/messages.3 -rw------- 1 root root 89829 Mar 20 18:53 /var/log/messages.4
Since the machine has been shutdown and rebooted 3/4 times since Apr5, it seems that no data is getting to this log. The machine has been on for many hours almost every day since (now Apr9). Normally yum log items are also logged to messages, but there have been none of these in this time frame.
Apr 04 22:21:30 Updated: VMware-server.i386 1.0.2-39867 Apr 04 22:34:16 Updated: VMware-server-console.i386 1.0.2-39867
VMware server updates have the nasty habit of modifying /etc/services and changing its SeLinux context. Running restorecon /etc/services as root should fix the problem.
Joel Gomberg wrote:
John DeDourek wrote:
David Timms wrote:
Hi, I'm on FC6 machine that gets updated at least once a week. I notice today {monday}, that messages has been rotated and is empty so far. -rw------- 1 root root 0 Apr 8 09:07 /var/log/messages -rw------- 1 root root 326802 Apr 5 07:03 /var/log/messages.1 -rw------- 1 root root 632374 Apr 1 04:05 /var/log/messages.2 -rw------- 1 root root 273450 Mar 25 11:06 /var/log/messages.3 -rw------- 1 root root 89829 Mar 20 18:53 /var/log/messages.4
Since the machine has been shutdown and rebooted 3/4 times since Apr5, it seems that no data is getting to this log. The machine has been on for many hours almost every day since (now Apr9). Normally yum log items are also logged to messages, but there have been none of these in this time frame.
Apr 04 22:21:30 Updated: VMware-server.i386 1.0.2-39867 Apr 04 22:34:16 Updated: VMware-server-console.i386 1.0.2-39867
Frank: # service syslog status syslogd (pid 2814) is running... klogd (pid 2818) is running...
VMware server updates have the nasty habit of modifying /etc/services and changing its SeLinux context. Running restorecon /etc/services as root should fix the problem.
# ls -lZ /etc/serv* -rw-r--r-- root root user_u:object_r:rpm_script_tmp_t /etc/services # restorecon -v /etc/services restorecon reset /etc/services context user_u:object_r:rpm_script_tmp_t:s0->system_u:object_r:etc_t:s0 # ls -lZ /etc/ser* -rw-r--r-- root root system_u:object_r:etc_t /etc/services
So the se context was incorrect. It didn't seem to start logging immediately {ie on an ssh login}.
# service syslog restart
And now /var/log/messages is being updated like normal.
Thanks Joel :)
John: Do you have vmware {of some flavour} installed ? (I guess Joel's hunch would apply to any of their apps that use an .pl install script).
Since the vmware-server install is from their rpm package, I am going to post there: http://www.vmware.com/community/thread.jspa?messageID=617291
DaveT.
David Timms wrote:
Joel Gomberg wrote: # ls -lZ /etc/serv* -rw-r--r-- root root user_u:object_r:rpm_script_tmp_t /etc/services # restorecon -v /etc/services restorecon reset /etc/services context user_u:object_r:rpm_script_tmp_t:s0->system_u:object_r:etc_t:s0 # ls -lZ /etc/ser* -rw-r--r-- root root system_u:object_r:etc_t /etc/services
/usr/sbin/getenforce replies: Permissive
That is, I run with selinux in "Permissive" so it should not be blocking access even if a context is messed up. I should see some log entries, which I don't. Currently running under kernel 2.6.20-1.2925.fc6 which didn't show the syslog problem on bootup. I will try again under 2.6.20-1.2933.fc6 later this week.
So the se context was incorrect. It didn't seem to start logging immediately {ie on an ssh login}.
# service syslog restart
And now /var/log/messages is being updated like normal.
My actual hunch about this problem after thinking about the above is that it is really a udev problem. My suspicion would be that udev is not making a "dev node" required for syslog to start "soon enough" in the boot. This would mean that a "service syslog restart" AFTER booting is completed would always restore syslogging, but after another reboot, syslog MIGHT (depending on some race condition) again cause syslog to fail, requiring another "service syslog restart" to restore logging.
Please observe whether that is an issue after your next reboot.
The udev people have created a lot of various kinds of race conditions in their effort to speed up rebooting by allowing udev to run multiple threads to do things in parallel. I am actually considering investigating where the "knob" is to turn that off. I don't reboot the machine in question often enough that I worry about booting time very much. (Besides, having learned to be a coffee drinker when dealing with booting the computers of the 60's and 70's, I usually have a cup of coffee nearby during boots. :0) A laptop or some such that gets booted often is where booting time is an issue.
Thanks Joel :)
John: Do you have vmware {of some flavour} installed ? (I guess Joel's hunch would apply to any of their apps that use an .pl install script).
No VMWare on this machine. Besides, as noted above, selinux is running "Permissive" so selinux access denials should not be a problem.
Since the vmware-server install is from their rpm package, I am going to post there: http://www.vmware.com/community/thread.jspa?messageID=617291
See my comment above about udev race conditions. I would be interested in an observation of whether "service syslog restart" is required after the next boot. You would have to watch /var/log/messages a little closer since it would no longer be "0 bytes" at that point and you might miss that logging went away again.
If it is a udev race, note that it may affect some machines, not others (mine is a dual core) and might affect some boots, not others, if the race condition is "close".
DaveT.
John DeDourek http://www.cs.unb.ca/~dedourek/
-
Development discussions related to Fedora -
Frank Cox -
Joel Gomberg -
John DeDourek