Hi Jim
hfa384x_usbctlx_complete_sync errors is where I may be able to help,
since I've spent alot of time debugging these blighters myself!
The errors likely do not mean your particular usb card(s) are bad - it
seems to be a generic problem with prism2_usb hardware.
I thought I had all but eradicated these in 0.2.9 - but as your logs
show, obviously not!
I'll have to leave the skb_p80211_to_ether errors for someone else to
explain.
I think you get the p80211knetdev_hard_start_xmit errors because your
system thinks the wireless card is up, whereas in reality it hasn't
actually associated with the access point.
prism2usb_init: prism2_usb.o: 0.2.9 Loaded
prism2usb_init: dev_info is: prism2_usb
Configuring network interfaces...usb 1-2: reset full speed USB device using isp116x-hcd and address 2
SIOCSIFFLAGS: No such device <------------------is this important?
SIOCSIFFLAGS: No such device
route: SIOC[ADD|DEL]RT: Network is unreachable
Are you specifying the prism2_doreset flag for the prism2_usb module
(quering the 'reset full speek USB device' entry in your log)? If so,
then turn that off - the prism2_usb cards really don't like a usb reset
in my experience.
Your user-space scripts are trying to configure wlan0 before it is set
up and ready. Hence the SIOCSIFFLAGS errors. It should be benign, but
will serve to confue matters. Are you using hotplug/udev? If so, better
to use that to trigger setting up wlan0 (via the ADD NET event).
state(Request failed)
By this point, the card has already started up (successfully) and is now
going through the user-space sequence to load firmware and get ready for
associating. Normally it should be okay at this point and come up
cleanly. What you could try is inserting a sleep 2 statement in the
userspace scripts, which has helped many others in the past.
hfa384x_usbctlx_complete_sync: CTLX[1] error: state(Request failed)
hfa384x_drvr_start: First cmd_initialize() succeeded, but second
attempt failed (result=-5)
hfa384x_drvr_start: Most likely the card will be functional
prism2sta_ifstate: hfa384x_drvr_start() failed,result=-5
Failed to enable the device, resultcode= implementation_failure .
This all means your card has decided not to play ball.
Things for you to try:
- ensure you are not doing prism2_doreset
- add a sleep statement before the ifstate=disable in the userspace
scripts
It may not be much fun, but usually we can get these issues sorted.
Karl
Hello again,
Many thanks to those whom have helped me get to this point.
Cross-compile to the arm environment works and the scripts run.
Now I'm getting errors on boot. The most important one puts this on the
hfa384x_usbctlx_complete_sync: CTLX[3] error: state(Request failed)
It happens intermittently whenever wlan accesses the USB device during
setup. These errors seem to be sometimes benign, while other times they
cause whatever process is in effect to fail.
Sometimes a boot will complete successfully, perhaps one in three.
I don't have complete confidence in the hardware either. The error has
something to do with missing an interrupt. While this is a commercial
single board computer (an Arcom Viper), it is V1 and they now ship V2.
This board is powered by a pxa255.
I've attached a commented boot log. All suggestions are welcome. As I
can't do anything about the hardware, this may be a show stopper for
using the USB for wireless. I can always use an external wireless bridge
as the network port seems rock solid.
If all goes well on boot and the radio associates with the access point,
then I get another error on the console. This one seems to be benign,
skb_p80211_to_ether: DIXII frame too large (2936 > 1500)
or
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
The "2936" number changes from one boot to the next, although it is
always right around 2900. These errors occur intermittently, with a
period of perhaps 2 seconds to 2 minutes.
There is one more error that I see sometimes. On boot, after the USB
stuff has associated the driver with the radio, but before wlan sets it
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame
dropped.
If this error occurs, I may see 40 or more of these error messages. It
slows down the boot considerably. It doesn't seem to be fatal however,
as the radio can set up correctly after a boot where these errors occurred.
Regards,
Jim Ham
plain text document attachment (arm_boot.log)
**********************************
comment here
**********************************
message in log <---------------my comment here
Failure of the radio seems to be associated with the following error messages,
which shows up irregularly when something is accessing the radio.
hfa384x_usbctlx_complete_sync: CTLX[3] error: state(Request failed)
Does this mean I have flakey hardware?
-----Start Log--------
+Ethernet eth0: MAC address 00:80:66:10:10:39
No IP info for device!
RedBoot(tm) bootstrap and debug environment [ROM]
Non-certified release, version W468 V3I6 - built 11:20:00, Jun 7 2005
Platform: VIPER (XScale PXA255)
Copyright (C) 2000, 2001, 2002, 2003, 2004 Red Hat, Inc.
RAM: 0x00000000-0x04000000, [0x00400000-0x03fd1000] available
FLASH: base 0x60000000, size 0x02000000, 256 blocks of 0x00020000 bytes each.
== Executing boot script in 1.000 seconds - enter ^C to abort
RedBoot> clock -l 27 -m 4 -n 10
mem:99.532MHz run:398.131MHz turbo:398.131MHz. cccr 0x161 (L=27 M=1 N=1.0)
RedBoot> mount -t jffs2 -f filesystem
RedBoot> load -r -b 0x600000 /boot/initrd.gz
Using default protocol (file)
Open failed, error 2
Can't load '/boot/initrd.gz': error 0
RedBoot> load -r -b 0x400000 /boot/zImage.1
Using default protocol (file)
Raw file loaded 0x00400000-0x004c4aaf, assumed entry at 0x00400000
RedBoot> exec -r 0x600000
Using base address 0x00400000 and length 0x000c4ab0
Uncompressing Linux...................................................... done, booting the kernel.
CPU: XScale-PXA255 [69052d06] revision 6 (ARMv5TE)
CPU0: D VIVT undefined 5 cache
CPU0: I cache: 32768 bytes, associativity 32, 32 byte lines, 32 sets
CPU0: D cache: 32768 bytes, associativity 32, 32 byte lines, 32 sets
Machine: Arcom VIPER SBC
Memory policy: ECC disabled, Data cache writeback
Memory clock: 99.53MHz (*27)
Run Mode clock: 398.13MHz (*4)
Turbo Mode clock: 398.13MHz (*1.0, active)
Built 1 zonelists
Kernel command line: root=31:02 rootfstype=jffs2 ro console=ttyS0,115200
Map ISA IRQ 3 to IRQ 104
Map ISA IRQ 4 to IRQ 105
Map ISA IRQ 5 to IRQ 106
Map ISA IRQ 6 to IRQ 107
Map ISA IRQ 7 to IRQ 108
Map ISA IRQ 10 to IRQ 109
Map ISA IRQ 11 to IRQ 110
Map ISA IRQ 12 to IRQ 111
Map ISA IRQ 9 to IRQ 112
Map ISA IRQ 14 to IRQ 113
Map ISA IRQ 15 to IRQ 114
PID hash table entries: 512 (order: 9, 8192 bytes)
Console: colour dummy device 80x30
Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
Memory: 64MB = 64MB total
Memory: 63104KB available (1341K code, 273K data, 60K init)
Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
CPU: Testing write buffer coherency: ok
NET: Registered protocol family 16
viper: setting CPU core voltage to 1.3V at 398.131MHz
viper: this hardware version has no version register.
PXA CPU frequency change support initialized
NetWinder Floating Point Emulator V0.97 (double precision)
JFFS2 version 2.2. (C) 2001-2003 Red Hat, Inc.
Serial: 8250/16550 driver $Revision: 1.90 $ 59 ports, IRQ sharing enabled
ttyS3 at MMIO 0x14300010 (irq = 27) is a 16550A
ttyS4 at MMIO 0x14300000 (irq = 26) is a 16550A
ttyS0 at MMIO 0x40100000 (irq = 15) is a FFUART
ttyS1 at MMIO 0x40200000 (irq = 14) is a BTUART
ttyS2 at MMIO 0x40700000 (irq = 13) is a STUART
io scheduler noop registered
eth0: SMC91C11xFD (rev 1) at 0xc4856300 IRQ 1 [nowait]
eth0: Ethernet addr: 00:80:66:10:10:39
Probing VIPER flash device at physical address 0x04000000
Probing flash at physical address 0x04000000
flash: Found 1 x16 devices at 0x0 in 16-bit bank
Intel/Sharp Extended Query Table at 0x0031
Using buffer write method
cfi_cmdset_0001: Erase suspend on write enabled
Unlocking VIPER flash device
VIPER flash unlocked
cmdlinepart partition parsing not available
Searching for RedBoot partition table in flash at offset 0x0
3 RedBoot partitions found on MTD device flash
0x00000000-0x0001f000 : "FIS directory"
0x0001f000-0x00020000 : "RedBoot config"
0x00020000-0x02000000 : "filesystem"
i2c /dev entries driver
NET: Registered protocol family 2
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP established hash table entries: 4096 (order: 3, 32768 bytes)
TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
TCP: Hash tables configured (established 4096 bind 4096)
NET: Registered protocol family 1
VFS: Mounted root (jffs2 filesystem) readonly.
Freeing init memory: 60K
INIT: version 2.85 booting
Activating swap.
Calculating module dependencies... done.
Loading modules...
All modules loaded.
Setting clock (utc): Sat Jun 21 15:41:45 PDT 2008.
Checking all file systems...
fsck 1.35 (28-Feb-2004)
Loading the saved-state of the serial devices... .
Mounting local filesystems...
tmpfs on /var/tmp type tmpfs (rw,size=4M)
Creating boot directories...
***********************************************************
starts to get interesting here
*************************************************************
usb
usbcore: registered new driver usbfs
usbcore: registered new driver hub
116x: driver isp116x-hcd, Mar 15 2006
116x: Found ISP116x Host Controller
116x: ISP116x Host Controller, irq 25
isp116x-hcd isp116x-hcd: new USB bus registered, assigned bus number 1
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
usb 1-2: new full speed USB device using isp116x-hcd and address 2
done
Setting up IP spoofing protection: rp_filter.
prism2usb_init: prism2_usb.o: 0.2.9 Loaded
prism2usb_init: dev_info is: prism2_usb
Configuring network interfaces...usb 1-2: reset full speed USB device using isp116x-hcd and address 2
SIOCSIFFLAGS: No such device <------------------is this important?
SIOCSIFFLAGS: No such device
route: SIOC[ADD|DEL]RT: Network is unreachable
done.
Starting portmap daemon: portmap.
Initializing random number generator...done.
INIT: Entering runlevel: 3ident: nic h/w: id=0x8026 1.0.0
ident: pri f/w: id=0x15 1.1.2
ident: sta f/w: id=0x1f 1.5.6
MFI:SUP:role=0x00:id=0x01:var=0x01:b/t=1/1
CFI:SUP:role=0x00:id=0x02:var=0x02:b/t=1/1
PRI:SUP:role=0x00:id=0x03:var=0x01:b/t=1/4
STA:SUP:role=0x00:id=0x04:var=0x01:b/t=1/10
PRI-CFI:ACT:role=0x01:id=0x02:var=0x02:b/t=1/1
STA-CFI:ACT:role=0x01:id=0x02:var=0x02:b/t=1/1
STA-MFI:ACT:role=0x01:id=0x01:var=0x01:b/t=1/1
Prism2 card SN: 000000000000
usbcore: registered new driver prism2_usb
Starting system log daemon: syslogd.
Starting kernel log daemon: klogd.
Starting NFS common utilities: statd.
Loading /etc/console/keymap.gz
Starting PCMCIA services: cardmgr[747]: watching 1 socket
done.
**********************************************************************
Note the following error message "hfa384...failed)"
*********************************************************************
Starting WLAN Devices: hfa384x_usbctlx_complete_sync: CTLX[1] error: state(Request failed)
message=lnxreq_ifstate
ifstate=disable
resultcode=success
message=lnxreq_ifstate
ifstate=fwload
resultcode=success
Reading S-record file /etc/wlan//prism2_ru.hex...
NIC ID: 0x8026 v1.0.0
MFI ID: 0x1 v1 1->1
CFI ID: 0x2 v2 1->1
PRI ID: 0x3 v1 1->4
Version: ID 0x1f 1.8.3
Compat: Role 0 Id 0x4 v3 1->15
Compat: Role 0x1 Id 0x1 v1 1->1
Compat: Role 0x1 Id 0x2 v2 1->1
Compat: Role 0x1 Id 0x3 v1 4->4
Seq: 0
Platform: ID 0x800a 1.0.0
Platform: ID 0x800f 1.0.0
Platform: ID 0x8010 1.0.0
Platform: ID 0x8011 1.0.0
Platform: ID 0x801e 1.0.0
Platform: ID 0x801f 1.0.0
Platform: ID 0x8020 1.0.0
Platform: ID 0x8025 1.0.0
Platform: ID 0x8026 1.0.0
Platform: ID 0x8027 1.0.0
prism2dl: warning: Failed to find PDR for plugrec 0x0406.
prism2dl: warning: Failed to find PDR for plugrec 0x0302.
prism2dl: warning: Failed to find PDR for plugrec 0x0412.
prism2dl: warning: Failed to find PDR for plugrec 0x0414.
prism2dl: finished.
hfa384x_usbctlx_complete_sync: CTLX[1] error: state(Request failed)
hfa384x_drvr_start: First cmd_initialize() succeeded, but second attempt failed (result=-5)
hfa384x_drvr_start: Most likely the card will be functional
prism2sta_ifstate: hfa384x_drvr_start() failed,result=-5
Failed to enable the device, resultcode= implementation_failure .
Starting internet superserver: inetd.
Starting http server: thttpd.
Starting OpenBSD Secure Shell Server: sshd.
Starting touchscreen controller daemon.
Starting periodic command scheduler: cron.
Starting X
Starting X...--done
.
Starting weather
Starting Weather...Starting /root/weather.arm...
Detatching to start /root/weather.arm...done.
--done
.
***************************************************************
the boot is finished here, the rest is my commands and the
responses.
**************************************************************
Arcom Embedded Linux v4i1d (ttyS0)
viper login: root
lo no wireless extensions.
eth0 no wireless extensions.
wlan0 no wireless extensions.
******************************************
At this point I unplugged and replugged the USB radio
******************************************
Starting WLAN Devices: message=lnxreq_ifstate
ifstate=disable
resultcode=success
message=lnxreq_ifstate
ifstate=fwload
resultcode=success
Reading S-record file /etc/wlan//prism2_ru.hex...
NIC ID: 0x8026 v1.0.0
MFI ID: 0x1 v1 1->1
CFI ID: 0x2 v2 1->1
PRI ID: 0x3 v1 1->4
Version: ID 0x1f 1.8.3
Compat: Role 0 Id 0x4 v3 1->15
Compat: Role 0x1 Id 0x1 v1 1->1
Compat: Role 0x1 Id 0x2 v2 1->1
Compat: Role 0x1 Id 0x3 v1 4->4
Seq: 0
Platform: ID 0x800a 1.0.0
Platform: ID 0x800f 1.0.0
Platform: ID 0x8010 1.0.0
Platform: ID 0x8011 1.0.0
Platform: ID 0x801e 1.0.0
Platform: ID 0x801f 1.0.0
Platform: ID 0x8020 1.0.0
Platform: ID 0x8025 1.0.0
Platform: ID 0x8026 1.0.0
Platform: ID 0x8027 1.0.0
prism2dl: warning: Failed to find PDR for plugrec 0x0406.
prism2dl: warning: Failed to find PDR for plugrec 0x0302.
prism2dl: warning: Failed to find PDR for plugrec 0x0412.
prism2dl: warning: Failed to find PDR for plugrec 0x0414.
prism2dl: finished.
hfa384x_usbctlx_complete_sync: CTLX[2] error: state(Request failed) <-------This message signals failure, depending when it arrives
**************************************************************
The radio seems to be working, but hasn't associated...
**************************************************************
lo no wireless extensions.
eth0 no wireless extensions.
wlan0 IEEE 802.11-DS ESSID:"PorcineAssociates" Nickname:"PorcineAssociates"
Mode:Auto Frequency:2.422 GHz Access Point: 00:00:00:00:00:00
Bit Rate:2 Mb/s Tx-Power:18 dBm
Retry min limit:8 RTS thr:off Fragment thr:off
Encryption key:ABCD-EF01-2345-6789-ABCD-EF01-23 Security mode:restricted
Link Quality:0 Signal level:0 Noise level:0
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0
route: SIOC[ADD|DEL]RT: File exists
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
UP LOOPBACK RUNNING MTU:16436 Metric:1
RX packets:87 errors:0 dropped:0 overruns:0 frame:0
TX packets:87 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:27888 (27.2 KiB) TX bytes:27888 (27.2 KiB)
wlan0 Link encap:Ethernet HWaddr 00:0F:66:4D:95:C0
inet addr:192.168.0.96 Bcast:192.168.0.255 Mask:255.255.255.0
UP BROADCAST MULTICAST MTU:1500 Metric:1
RX packets:3 errors:14 dropped:0 overruns:0 frame:1
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:64 (64.0 B) TX bytes:0 (0.0 B)
PING GrapeSoda (192.168.0.1): 56 data bytes
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
--- GrapeSoda ping statistics ---
4 packets transmitted, 0 packets received, 100% packet loss
PING GrapeSoda (192.168.0.1): 56 data bytes
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
p80211knetdev_hard_start_xmit: Tx attempt prior to association, frame dropped.
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
--- GrapeSoda ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
lo no wireless extensions.
eth0 no wireless extensions.
wlan0 IEEE 802.11-b ESSID:"PorcineAssociates" Nickname:"PorcineAssociates"
Mode:Auto Frequency:2.462 GHz Access Point: 00:00:00:00:00:00
Bit Rate:11 Mb/s Tx-Power:18 dBm
Retry min limit:8 RTS thr:off Fragment thr:off
Encryption key:ABCD-EF01-2345-6789-ABCD-EF01-23 Security mode:restricted
Link Quality:0 Signal level:0 Noise level:0
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
UP LOOPBACK RUNNING MTU:16436 Metric:1
RX packets:93 errors:0 dropped:0 overruns:0 frame:0
TX packets:93 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:28560 (27.8 KiB) TX bytes:28560 (27.8 KiB)
lo no wireless extensions.
eth0 no wireless extensions.
hfa384x_usbctlx_complete_sync: CTLX[3] error: state(Request failed)
wlan0 no wireless extensions.
********************************************************************************
still not associated
*******************************************************************************
lo no wireless extensions.
eth0 no wireless extensions.
wlan0 IEEE 802.11-b ESSID:"PorcineAssociates" Nickname:"PorcineAssociates"
Mode:Auto Frequency:2.462 GHz Access Point: 00:00:00:00:00:00
Bit Rate:11 Mb/s Tx-Power:18 dBm
Retry min limit:8 RTS thr:off Fragment thr:off
Encryption key:ABCD-EF01-2345-6789-ABCD-EF01-23 Security mode:restricted
Link Quality:0 Signal level:0 Noise level:0
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0
***************************************************************************
At the point I unplugged and replugged again
***************************************************************************
hfa384x_drvr_start: First cmd_initialize() succeeded, but second attempt failed (result=-5)
hfa384x_drvr_start: Most likely the card will be functional
prism2sta_ifstate: hfa384x_drvr_start() failed,result=-5
Starting WLAN Devices: message=lnxreq_ifstate
ifstate=disable
resultcode=success
message=lnxreq_ifstate
ifstate=fwload
resultcode=success
Reading S-record file /etc/wlan//prism2_ru.hex...
NIC ID: 0x8026 v1.0.0
MFI ID: 0x1 v1 1->1
CFI ID: 0x2 v2 1->1
PRI ID: 0x3 v1 1->4
Version: ID 0x1f 1.8.3
Compat: Role 0 Id 0x4 v3 1->15
Compat: Role 0x1 Id 0x1 v1 1->1
Compat: Role 0x1 Id 0x2 v2 1->1
Compat: Role 0x1 Id 0x3 v1 4->4
Seq: 0
Platform: ID 0x800a 1.0.0
Platform: ID 0x800f 1.0.0
Platform: ID 0x8010 1.0.0
Platform: ID 0x8011 1.0.0
Platform: ID 0x801e 1.0.0
Platform: ID 0x801f 1.0.0
Platform: ID 0x8020 1.0.0
Platform: ID 0x8025 1.0.0
Platform: ID 0x8026 1.0.0
Platform: ID 0x8027 1.0.0
prism2dl: warning: Failed to find PDR for plugrec 0x0406.
prism2dl: warning: Failed to find PDR for plugrec 0x0302.
prism2dl: warning: Failed to find PDR for plugrec 0x0412.
prism2dl: warning: Failed to find PDR for plugrec 0x0414.
prism2dl: finished.
prism2sta_commsqual_defer: error fetching commsqual
wlan0
PING GrapeSoda (192.168.0.1): 56 data bytes
64 bytes from 192.168.0.1: icmp_seq=0 ttl=64 time=21.6 ms
64 bytes from 192.168.0.1: icmp_seq=1 ttl=64 time=23.2 ms
64 bytes from 192.168.0.1: icmp_seq=2 ttl=64 time=6.8 ms
--- GrapeSoda ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 6.8/17.2/23.2 ms
*********************************************************************************
so now it's working
********************************************************************************
lo no wireless extensions.
eth0 no wireless extensions.
hfa384x_usbctlx_complete_sync: CTLX[3] error: state(Request failed)
wlan0 no wireless extensions. <--------failed
lo no wireless extensions.
eth0 no wireless extensions.
wlan0 IEEE 802.11-DS ESSID:"PorcineAssociates" Nickname:"PorcineAssociates"
Mode:Managed Frequency:2.462 GHz Access Point: 00:16:01:4A:C8:A3
Bit Rate:2 Mb/s Tx-Power:18 dBm
Retry min limit:8 RTS thr:off Fragment thr:off
Encryption key:ABCD-EF01-2345-6789-ABCD-EF01-23 Security mode:restricted
Link Quality=82/100 Signal level=-59 dBm Noise level=-93 dBm
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:0 Missed beacon:0
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
skb_p80211_to_ether: OTHER frame too large (2920 > 1500)
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
skb_p80211_to_ether: OTHER frame too large (2944 > 1500)
skb_p80211_to_ether: OTHER frame too large (2920 > 1500)
skb_p80211_to_ether: OTHER frame too large (2920 > 1500)
*******************************************************************
Note that I got some of these "skb...frame too large..." messages even when the radio was
not associated with a access point. They come irregularly, but maybe once a
minute on average.
*******************************************************************