Re: Re: MA111 problem at boot on Fedora FC3
"Peter Ison" <[email protected]>
| Newsgroups | gmane.linux.linux-wlan.user |
|---|---|
| Message-ID | <004301c56d5d$41e91e70$0200a8c0@station1xp> |
I enclose an unsorted file for some of the log entries posted previously from /var/log/messages. This shows that the stream of kernel messages can be up to a minute or more out of sync with the other messages. I have looked at the log quite carefully and I think that the timestamps are correct, and it was correct to sort the file to get the true sequence of events. I do not think that the time differences are caused by time synchronisation (ntpd) because that would affect all messages equally after that service was started. This out-of-sequence effect is most notable at boot and while there are many debug messages going to the logs (I left out many of the messages which were not relevant). It may be something to do with the fact that there is a separate mechanism for kernel messages (klogd) and that syslog does not start until S12 which is after kudzu, iptables and network etc. and so could there be a backlog of messages to be written to the log? Perhaps someone can throw more light on this. I agree that it is difficult to understand what is happening with hotplug and the loading of the prism2_usb module, but I think that the log I posted was valid. Peter ----- Original Message ----- From: <[email protected]> To: "Peter Ison" <[email protected]>; "Dave Jenkins" <[email protected]>; <[email protected]> Sent: Thursday, June 09, 2005 10:26 AM Subject: Re: Re: [lwlan-user] MA111 problem at boot on Fedora FC3 > Hmmmm - there is alot in this log that makes no sense to me. > > > You have > > 23:50:40 myntech default.hotplug[2567] > > which is the add net event for wlan0 coming from driver > prism2_usb, and yet the 'prism2_usb' loaded message > doesn't appear until much later: > > 23:51:42 myntech kernel: prism2usb_init: dev_info is: prism2_usb > > > Karl > > >> From: "Peter Ison" <[email protected]> >> Dave, >> >> I uncommented the debug lines in hotplug.functions, usb.agent and >> wlan.agent >> and rebooted. I attach the log for the relevant hotplug, usb.agent, >> wlan.agent, Prism2 events. I sorted the file because I noticed that the >> kernel events were out of sequence in /var/log/messages. >> >> All activity seems to be initiated through hotplug (or coldplug as part >> of >> the boot process). However, in reply to your question, there are no >> significant events after the linkstatus DISCONNECTED/CONNECTED sequence. >> >> Hope this helps. >> >> Peter > > > ----------------------------------------- > Email provided by http://www.ntlhome.com/ > _______________________________________________ Linux-wlan-user mailing list [email protected] http://lists.linux-wlan.com/mailman/listinfo/linux-wlan-user
unsortedbootlog.txt
(text/plain, 7 KB)
Jun 8 23:50:35 myntech wlan.agent[1749]: WLAN startup on null (null) Jun 8 23:50:36 myntech default.hotplug[1765]: arguments (drivers) env (SUBSYSTEM=drivers OLDPWD=/ DEVPATH=/bus/usb/drivers/prism2_usb PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 DEBUG=yes SEQNUM=469 _=/bin/env) Jun 8 23:50:36 myntech default.hotplug[1758]: arguments (module) env (SUBSYSTEM=module OLDPWD=/ DEVPATH=/module/prism2_usb PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 DEBUG=yes SEQNUM=468 _=/bin/env) Jun 8 23:50:36 myntech wlan.agent[1749]: WLAN p80211 starting! Jun 8 23:50:36 myntech wland[1787]: wland daemon init successful <14>Jun 8 23:50:36 wland[1787]: netlink socket opened and bound successfully Jun 8 23:51:17 myntech kernel: usbcore: registered new driver usbfs Jun 8 23:51:17 myntech kernel: usbcore: registered new driver hub Jun 8 23:51:30 myntech kernel: usbcore: registered new driver hiddev Jun 8 23:51:31 myntech kernel: usbcore: registered new driver usbhid Jun 8 23:51:31 myntech kernel: drivers/usb/input/hid-core.c: v2.0:USB HID core driver Jun 8 23:50:39 myntech default.hotplug[2421]: arguments (usb_host) env (PHYSDEVPATH=/devices/pci0000:00/0000:00:07.2 SUBSYSTEM=usb_host OLDPWD=/ DEVPATH=/class/usb_host/usb1 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=uhci_hcd DEBUG=yes PHYSDEVBUS=pci SEQNUM=518 _=/bin/env) Jun 8 23:50:39 myntech default.hotplug[2421]: no runnable /etc/hotplug/usb_host.agent is installed Wed Jun 8 23:50:39 BST 2005 Jun 8 23:50:39 myntech default.hotplug[2432]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.2/usb1 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=usb DEBUG=yes PHYSDEVBUS=usb SEQNUM=519 _=/bin/env) Jun 8 23:51:34 myntech kernel: SLPB PCI0 USB0 USB1 MODM UAR1 UAR2 Jun 8 23:50:39 myntech default.hotplug[2440]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.2/usb1/1-0:1.0 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 DEVICE=/proc/bus/usb/001/001 PRODUCT=0/0/206 TYPE=9/0/0 DEBUG=yes PHYSDEVBUS=usb SEQNUM=520 _=/bin/env) Jun 8 23:50:39 myntech default.hotplug[2432]: invoke /etc/hotplug/usb.agent () Jun 8 23:50:39 myntech default.hotplug[2440]: invoke /etc/hotplug/usb.agent () Jun 8 23:50:39 myntech default.hotplug[2465]: arguments (usb_host) env (PHYSDEVPATH=/devices/pci0000:00/0000:00:07.3 SUBSYSTEM=usb_host OLDPWD=/ DEVPATH=/class/usb_host/usb2 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=uhci_hcd DEBUG=yes PHYSDEVBUS=pci SEQNUM=521 _=/bin/env) Jun 8 23:50:39 myntech default.hotplug[2465]: no runnable /etc/hotplug/usb_host.agent is installed Wed Jun 8 23:50:39 BST 2005 Jun 8 23:50:39 myntech default.hotplug[2476]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.3/usb2 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=usb DEBUG=yes PHYSDEVBUS=usb SEQNUM=522 _=/bin/env) Jun 8 23:50:39 myntech default.hotplug[2486]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.3/usb2/2-0:1.0 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 DEVICE=/proc/bus/usb/002/001 PRODUCT=0/0/206 TYPE=9/0/0 DEBUG=yes PHYSDEVBUS=usb SEQNUM=523 _=/bin/env) Jun 8 23:50:39 myntech default.hotplug[2486]: invoke /etc/hotplug/usb.agent () Jun 8 23:50:39 myntech default.hotplug[2476]: invoke /etc/hotplug/usb.agent () Jun 8 23:50:40 myntech wlan.agent[2546]: WLAN register on wlan0 (prism2_usb) Jun 8 23:50:40 myntech wlan.agent[2546]: WLAN wlan0 registered. Jun 8 23:50:40 myntech default.hotplug[2567]: arguments (net) env (PHYSDEVPATH=/devices/pci0000:00/0000:00:07.3/usb2/2-1/2-1:1.0 SUBSYSTEM=net OLDPWD=/ DEVPATH=/class/net/wlan0 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=prism2_usb INTERFACE=wlan0 DEBUG=yes PHYSDEVBUS=usb SEQNUM=527 _=/bin/env) Jun 8 23:51:38 myntech ntpd[4888]: Listening on interface wlan0, 192.168.0.1#123 Jun 8 23:50:40 myntech default.hotplug[2565]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.3/usb2/2-1/2-1:1.0 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 DEVICE=/proc/bus/usb/002/002 INTERFACE=255/255/255 PRODUCT=846/4110/132 TYPE=0/0/0 DEBUG=yes PHYSDEVBUS=usb SEQNUM=526 _=/bin/env) Jun 8 23:50:40 myntech default.hotplug[2565]: invoke /etc/hotplug/usb.agent () Jun 8 23:50:41 myntech usb.agent[2565]: Setup prism2_usb for USB product 846/4110/132 Jun 8 23:51:41 myntech kernel: SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts Jun 8 23:50:42 myntech default.hotplug[2557]: arguments (usb) env (SUBSYSTEM=usb OLDPWD=/ DEVPATH=/devices/pci0000:00/0000:00:07.3/usb2/2-1 PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug HOME=/ SHLVL=2 PHYSDEVDRIVER=usb DEBUG=yes PHYSDEVBUS=usb SEQNUM=525 _=/bin/env) Jun 8 23:50:42 myntech default.hotplug[2557]: invoke /etc/hotplug/usb.agent () Jun 8 23:51:42 myntech kernel: prism2usb_init: prism2_usb.o: 0.2.1-pre26 Loaded Jun 8 23:51:42 myntech kernel: prism2usb_init: dev_info is: prism2_usb Jun 8 23:50:42 myntech usb.agent[2486]: Setup 0x00 0x00 for USB product 0/0/206 Jun 8 23:51:43 myntech kernel: usbcore: registered new driver prism2_usb Jun 8 23:50:42 myntech usb.agent[2565]: Setup 0x00 0x00 for USB product 846/4110/132 Jun 8 23:50:39 myntech usb.agent[2440]: Setup 0x00 0x00 for USB product 0/0/206 Jun 8 23:51:46 myntech kernel: USB Universal Host Controller Interface driver v2.2 Jun 8 23:51:46 myntech kernel: uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 Jun 8 23:51:47 myntech kernel: hub 1-0:1.0: USB hub found Jun 8 23:51:47 myntech kernel: uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 Jun 8 23:51:47 myntech kernel: hub 2-0:1.0: USB hub found Jun 8 23:50:44 myntech wlan.agent[2546]: WLAN wlan0 brought up successfully. Jun 8 23:50:44 myntech wlan.agent[2546]: WLAN bringing up layer 3+ with /sbin/ifup Jun 8 23:51:49 myntech kernel: usb 2-1: new full speed USB device using uhci_hcd and address 2 Jun 8 23:51:57 myntech kernel: Prism2 card SN: \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00 Jun 8 23:51:58 myntech kernel: linkstatus=DISCONNECTED (unhandled) Jun 8 23:52:00 myntech kernel: linkstatus=CONNECTED Jun 8 23:51:08 myntech ifup: SET failed on device wlan0 ; Operation not supported. Jun 8 23:51:08 myntech ifup: SET failed on device wlan0 ; Operation not supported. Jun 8 23:51:08 myntech ifup: SET failed on device wlan0 ; Function not implemented. Jun 8 23:52:18 myntech haldaemon: haldaemon startup succeeded Jun 8 23:51:08 myntech ifup: SET failed on device wlan0 ; Operation not supported. Jun 8 23:51:08 myntech ifup: SET failed on device wlan0 ; Operation not supported. Jun 8 23:51:11 myntech network: Bringing up interface wlan0: succeeded