Transaction timing out on 586 embedded CPU

[Kai Scharwies]

2012/12/4 Bjørn Mork <bjorn at mork.no>:
> Kai Scharwies <kai at scharwies.de> writes:
>
>> Neither the patch from Aleksander, nor increasing the timeout is successful.
>> This is before increasing the timeout:
>>
>> root at MeshUnit13:~# time qmicli -d /dev/cdc-wdm0 --dms-get-ids
>> error: operation failed: Transaction timed out
>>
>> real  0m10.692s
>> user  0m0.020s
>> sys   0m0.020s
>>
>> And this is after changing it to 25 seconds:
>>
>> root at MeshUnit13:~# time qmicli -d /dev/cdc-wdm0 --dms-get-ids
>> error: operation failed: Transaction timed out
>>
>> real  0m25.771s
>> user  0m0.020s
>> sys   0m0.020s
>
> Yes, 10 seconds should be more than enough for those commands.
>
>> It doesn't seem another process is accessing /dev/cdc-acm0:
>>
>> root at MeshUnit13:~/lte/libqmi-1.0.0# lsof | grep cdc
>> qmicli    25861             root    4u      CHR    180,176      0t0
>>   16228 /dev/cdc-wdm0
>> pool      25861 25862       root    4u      CHR    180,176      0t0
>>   16228 /dev/cdc-wdm0
>
> So much for that theory.
>
>> Very strange...
>
> Yes.  Could you use usbmon to try to see if there are anything data
> received from the device after the last write, or if it just stops
> responding?
>
> What libqmi does looks fine to me, so I guess the problem must be
> somewhere between the character device and the modem. But I really don't
> know where to start looking.
>
>
> Bjørn

Here is the usbmon output:

cf5e7000 482609333 S Ii:1:007:5 -115:16 64 <
cf5e7d00 482611025 S Co:1:007:0 s 21 00 0000 0003 0010 16 = 010f0000
00000001 22000400 01010002
cf5e7d00 482612264 C Co:1:007:0 0 16 >
cf5e7000 482613132 C Ii:1:007:5 0:16 8 = a1010000 03000000
cf5e7a80 482613144 S Ci:1:007:0 s a1 01 0000 0003 0100 256 <
cf5e7000 482613161 S Ii:1:007:5 -115:16 64 <
cf5e7a80 482613625 C Ci:1:007:0 0 24 = 01170080 00000101 22000c00
02040000 00000001 02000202
cf5e7d00 482615009 S Co:1:007:0 s 21 00 0000 0003 000d 13 = 010c0000
02020001 00250000 00
cf5e7d00 482616007 C Co:1:007:0 0 13 >
(timeout "hangs" here)
cf5e7d00 508030782 S Co:1:007:0 s 21 00 0000 0003 0011 17 = 01100000
00000002 23000500 01020002 02
cf5e7d00 508032849 C Co:1:007:0 0 17 >
cf5e7000 508034093 C Ii:1:007:5 0:16 8 = a1010000 03000000
cf5e7a80 508034106 S Ci:1:007:0 s a1 01 0000 0003 0100 256 <
cf5e7000 508034124 S Ii:1:007:5 -115:16 64 <
cf5e7a80 508034713 C Ci:1:007:0 0 42 = 01290080 02020201 0025001d
00020400 00000000 10010030 110f0033 35373134
cf5e7000 508036092 C Ii:1:007:5 0:16 8 = a1010000 03000000
cf5e7a80 508036104 S Ci:1:007:0 s a1 01 0000 0003 0100 256 <
cf5e7000 508036120 S Ii:1:007:5 -115:16 64 <
cf5e7a80 508036587 C Ci:1:007:0 0 12 = 010b0080 00000200 27000000
cf5e7000 508038089 C Ii:1:007:5 0:16 8 = a1010000 03000000
cf5e7a80 508038102 S Ci:1:007:0 s a1 01 0000 0003 0100 256 <
cf5e7000 508038117 S Ii:1:007:5 -115:16 64 <
cf5e7a80 508038587 C Ci:1:007:0 0 24 = 01170080 00000102 23000c00
02040000 00000001 02000202
cf5e7000 508039422 C Ii:1:007:5 -2:16 0

Could this really be a problem of processor/architecture? I tried the
same software (compiled for i586) on an Core2Duo Laptop and it works
fine, just as the i686 image usually ran on it.

I am out of ideas at the moment.