USB devices dis/reconnected by cron.daily
Hi
I'm running Lenny (2.6.26-1-orion5x) on a QNAP TS-209. I have one USB HP printer
and one of the infamous FreeAgent USB drives connected to it but it behaves ok
after shutting off autostandby according to:
http://alienghic.livejournal.com/382903.html
...at least most of the time. When the drive is in use *and* cron.daily starts,
it (always) disconnects the USB devices and then reconnects them. But since the
drive is in use, it reports an IO error and is remounted in read-only mode.
It seems to have something to do with kmsg being restarted, but I thought that
process shouldn't be restarted unless during reboot?
The system (udev?) seems to lose connection to all USB devices when the syslog
is restarted, and then rescans it to reconnect them, but sometimes the device
name changes (like /dev/sdc->/dev/sdd) for the USB drive, which in that case
will also make the remount in read-only fail.
I can't really tell exactly which daily cron job that causes the restart of the
log. Often, it's php5/maxlifetime that is the last entry from the daily cron
jobs, but today it took over 11 minutes before:
Jan 25 07:50:13 Qnap kernel: Kernel logging (proc) stopped.
and in the mean time, 3 getmail runs were completed. But they are running every
5 minutes so I wouldn't blame them.
On the other hand, today (in the syslog before the log process restart) I got
lots of lines like:
Jan 25 07:35:52 Qnap NetworkManager: <debug> [1232865352.068146]
nm_hal_device_removed(): Device removed (hal udi is
'/org/freedesktop/Hal/devices/usb_device_3f0_d12_CN48162039_if0').
and then a similar bunch of:
Jan 25 07:35:57 Qnap NetworkManager: <debug> [1232865357.203377]
nm_hal_device_added(): New device added (hal udi is
'/org/freedesktop/Hal/devices/usb_device_3f0_d12_CN48162039_if0').
But I haven't seen those before, perhaps I simply haven't looked carefully.
The next syslog file starts with:
Jan 25 07:50:13 Qnap kernel: imklog 3.18.6, log source = /proc/kmsg started.
Jan 25 07:50:13 Qnap kernel: ] Result: hostbyte=DID_NO_CONNECT
driverbyte=DRIVER_OK,SUGGEST_OK
Jan 25 07:50:13 Qnap kernel: [44625430.780000] end_request: I/O error, dev sdd,
sector 1310728736
[...]
Jan 25 07:50:13 Qnap rsyslogd: [origin software="rsyslogd" swVersion="3.18.6"
x-pid="1643" x-info="http://www.rsyslog.com";] restart
Jan 25 07:50:13 Qnap kernel: [44625430.930000] Remounting filesystem read-only
Jan 25 07:50:13 Qnap kernel: [44625430.940000] usb 2-1.4: USB disconnect, address 14
Jan 25 07:50:13 Qnap kernel: [44625431.220000] usb 2-1: new high speed USB
device using orion-ehci and address 15
Jan 25 07:50:13 Qnap kernel: [44625431.370000] usb 2-1: configuration #1 chosen
from 1 choice
Jan 25 07:50:13 Qnap kernel: [44625431.370000] hub 2-1:1.0: USB hub found
Jan 25 07:50:13 Qnap kernel: [44625431.380000] hub 2-1:1.0: 4 ports detected
Jan 25 07:50:13 Qnap kernel: [44625431.500000] usb 2-1: New USB device found,
idVendor=05e3, idProduct=0607
[...]
Jan 25 07:50:15 Qnap kernel: imklog 3.18.6, log source = /proc/kmsg started.
Jan 25 07:50:15 Qnap rsyslogd: [origin software="rsyslogd" swVersion="3.18.6"
x-pid="1643" x-info="http://www.rsyslog.com";] restart
Jan 25 07:50:22 Qnap anacron[3402]: Job `cron.daily' terminated (exit status: 1)
(mailing output)
Note that the lines about /proc/kmsg and rsyslog being restarted appear twice in
the log. Haven't seen that before either.
Anyone knows what's going on?
Magnus
Reply to: