Author Message

<  Everything Coding  ~  Nokia 0421:0637 won't switch

PostPosted: Wed Sep 07, 2016 8:29 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
The device uses the StandardEject sequence. Nevertheless, it seems like it generally won't respond to the first message sent to it:

Code:
[root@gsm-r5s9-01 ~# echo 3-6:1.0 >/sys/bus/usb/devices/3-6/3-6:1.0/driver/unbind; sleep 10
[root@gsm-r5s9-01 ~]# "/usr/sbin/usb_modeswitch" "-D" "-u -1" "-b 3" "-g 2" "-v" "0421" "-p" "0637" "-f" "$(echo -e "# Nokia CS-21M-02\nTargetVendor=0x0421\nTargetProduct=0x0638\nStandardEject=1\n")"
Use given bus/device number: 003/002 ...
Look for default devices ...
 bus/device number matched
   product ID matched
 Found devices in default mode (1)
Get the current device configuration ...
Use interface number 0
Use endpoints 0x01 (out) and 0x81 (in)

USB description data (for identification)
-------------------------
Manufacturer: Nokia
     Product: Nokia USB Modem
  Serial No.: 0.0.1
-------------------------
Sending standard EJECT sequence
Looking for active driver ...
 No active driver found. Detached before or never attached
Set up interface 0
Use endpoint 0x01 for message sending ...
Trying to send message 1 to endpoint 0x01 ...
 OK, message successfully sent
Read the response to message 1 (CSW) ...
 Response reading failed (error -7)
 Device is gone, skip any further commands
ok:busdev
[root@gsm-r5s9-01 ~]#


The second attempt proceeds just fine:

Code:
[root@gsm-r5s9-01 ~]# "/usr/sbin/usb_modeswitch" "-D" "-u -1" "-b 3" "-g 2" "-v" "0421" "-p" "0637" "-f" "$(echo -e "# Nokia CS-21M-02\nTargetVendor=0x0421\nTargetProduct=0x0638\nStandardEject=1\n")"
Use given bus/device number: 003/002 ...
Look for default devices ...
 bus/device number matched
   product ID matched
 Found devices in default mode (1)
Get the current device configuration ...
Use interface number 0
Use endpoints 0x01 (out) and 0x81 (in)

USB description data (for identification)
-------------------------
Manufacturer: Nokia
     Product: Nokia USB Modem
  Serial No.: 0.0.1
-------------------------
Sending standard EJECT sequence
Looking for active driver ...
 No active driver found. Detached before or never attached
Set up interface 0
Use endpoint 0x01 for message sending ...
Trying to send message 1 to endpoint 0x01 ...
 OK, message successfully sent
Read the response to message 1 (CSW) ...
 Response successfully read (13 bytes), status 0
Trying to send message 2 to endpoint 0x01 ...
 OK, message successfully sent
Read the response to message 2 (CSW) ...
 Response successfully read (13 bytes), status 0
Trying to send message 3 to endpoint 0x01 ...
 OK, message successfully sent
Read the response to message 3 (CSW) ...
 Response successfully read (13 bytes), status 0
Trying to send message 4 to endpoint 0x01 ...
 OK, message successfully sent
Read the response to message 4 (CSW) ...
 Response successfully read (13 bytes), status 0
Reset response endpoint 0x81
Reset message endpoint 0x01
 Device is gone, skip any further commands
ok:busdev
[root@gsm-r5s9-01 ~]#


This sounds a lot like what's described here: viewtopic.php?f=3&t=1955

The attached patch fixes the issue for me. Nevertheless, it's not exactly elegant.
Ideas about how to do this better appreciated.
Attachments:
Offline Profile
PostPosted: Thu Sep 08, 2016 7:53 am Reply with quote
Posts: 1102Location: Koh Samui, THJoined: Wed Jul 11, 2012 3:14 pm
Your problem is likely related to the modem not being stable on the usb bus.

The 4 messages behind StandardEject are:

to SCSI LUN 0
1. Unlock media (allow media removal)
2. Stop unit (eject media)

to SCSI LUN 1
3. Unlock media (allow media removal)
4. Stop unit (eject media)

The unlock cmd is only a preparation for eject (in case the cd-rom driver has issued a media lock) but it should not be able to cause the modem to fall off the bus as in your first log.
Your patch is not a fix, only a work-around, and I think we better find the reason why you get this kind of behaviour. CS21M has been supported for many years now and this is the first problem report I've seen for it..
What does your dmesg show from the usb activity?
Can you test if another distro behaves the same?
(Note that the similar problem you linked to was also using a Fedora distro).


Offline Profile
PostPosted: Thu Sep 08, 2016 8:03 am Reply with quote
Site AdminPosts: 6269Joined: Sat Nov 03, 2007 12:30 am
lkundrak wrote:
[code][root@gsm-r5s9-01 ~# echo 3-6:1.0 >/sys/bus/usb/devices/3-6/3-6:1.0/driver/unbind; sleep 10

What happens if you leave out the "sleep" period? What happens if you leave out the unbind line altogether?


Offline Profile
PostPosted: Thu Sep 08, 2016 12:09 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
LOM wrote:
Your problem is likely related to the modem not being stable on the usb bus.
The unlock cmd is only a preparation for eject (in case the cd-rom driver has issued a media lock) but it should not be able to cause the modem to fall off the bus as in your first log.


Note the modem didn't fall off a bus -- that's merely imperfect wording in the error message. The real error there is "-7" which is a timeout.

LOM wrote:
CS21M has been supported for many years now and this is the first problem report I've seen for it..


I think some older versions of usb_modeswitch & the data did things differently? Looking at usb-modeswitch-data-20130807, arguably quite ancient, shipped with RHEL 7.2 does this instead of aj eject:

MessageContent="5553424312345678000000000000061b000000020000000000000000000000"

LOM wrote:
What does your dmesg show from the usb activity?


Nothing at all. (I guess you expected something here because you assumed the device actually dropped off the bus?)

LOM wrote:
Can you test if another distro behaves the same?
(Note that the similar problem you linked to was also using a Fedora distro).


Unfortunately not. I don't have a physical access to the machine nor an access to the firmware console.

Josh wrote:
lkundrak wrote:
[code][root@gsm-r5s9-01 ~# echo 3-6:1.0 >/sys/bus/usb/devices/3-6/3-6:1.0/driver/unbind; sleep 10

What happens if you leave out the "sleep" period? What happens if you leave out the unbind line altogether?


No effect, the same symptoms.

I just left that in place to ensure the unbinding didn't interfere with the switch.


Offline Profile
PostPosted: Thu Sep 08, 2016 12:11 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
LOM wrote:
What does your dmesg show from the usb activity?


Oh, sorry, there actually is something.

When the kernel driver binds:

Code:
[    3.902716] sr 0:0:0:0: [sr1] scsi3-mmc drive: 0x/0x caddy
[    3.908377] sr 0:0:0:0: Attached scsi CD-ROM sr1
[    3.909234] sd 0:0:0:1: [sdb] Attached SCSI removable disk
[    3.969474] sr 0:0:0:0: [sr1] CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
[    3.979911] sr 0:0:0:0: [sr1] Sense Key : Hardware Error [current]
[    3.986284] sr 0:0:0:0: [sr1] Add. Sense: No additional sense information


And when the kernel driver is unbound:

Code:
[   66.749050] sr 0:0:0:0: [sr1] CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
[   66.873062] sr 0:0:0:0: [sr1] Sense Key : Hardware Error [current]
[   66.949329] sr 0:0:0:0: [sr1] Add. Sense: No additional sense information


Offline Profile
PostPosted: Thu Sep 08, 2016 2:52 pm Reply with quote
Posts: 1102Location: Koh Samui, THJoined: Wed Jul 11, 2012 3:14 pm
What kind of hardware is the host, a very fast computer?
Hopefully not a Raspberry Pi..


Offline Profile
PostPosted: Thu Sep 08, 2016 4:04 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
LOM wrote:
What kind of hardware is the host, a very fast computer?
Hopefully not a Raspberry Pi..


According to the DMI it's a ThinkCentre M73 with BIOS dated 12/2015. Doesn't seem like an old machine.
Has a 4th i3-4150 CPU and the phone is plugged into an USB 2.0 port of "Intel Corporation 8 Series/C220 Series Chipset".


Offline Profile
PostPosted: Fri Sep 09, 2016 11:44 am Reply with quote
Posts: 1102Location: Koh Samui, THJoined: Wed Jul 11, 2012 3:14 pm
lkundrak wrote:
LOM wrote:
Your problem is likely related to the modem not being stable on the usb bus.
The unlock cmd is only a preparation for eject (in case the cd-rom driver has issued a media lock) but it should not be able to cause the modem to fall off the bus as in your first log.


Note the modem didn't fall off a bus -- that's merely imperfect wording in the error message. The real error there is "-7" which is a timeout.


Right.


lkundrak wrote:
LOM wrote:
CS21M has been supported for many years now and this is the first problem report I've seen for it..


I think some older versions of usb_modeswitch & the data did things differently? Looking at usb-modeswitch-data-20130807, arguably quite ancient, shipped with RHEL 7.2 does this instead of aj eject:

MessageContent="5553424312345678000000000000061b000000020000000000000000000000"




It might be that the urb which we don't get the status reply for is accepted by the modem.
The previous switch method was a single eject msg which would switch the dongle while the new dual msg will only get the first prepare msg through.


lkundrak wrote:
LOM wrote:
What does your dmesg show from the usb activity?


Oh, sorry, there actually is something.

When the kernel driver binds:

Code:
[    3.902716] sr 0:0:0:0: [sr1] scsi3-mmc drive: 0x/0x caddy
[    3.908377] sr 0:0:0:0: Attached scsi CD-ROM sr1
[    3.909234] sd 0:0:0:1: [sdb] Attached SCSI removable disk
[    3.969474] sr 0:0:0:0: [sr1] CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
[    3.979911] sr 0:0:0:0: [sr1] Sense Key : Hardware Error [current]
[    3.986284] sr 0:0:0:0: [sr1] Add. Sense: No additional sense information


And when the kernel driver is unbound:

Code:
[   66.749050] sr 0:0:0:0: [sr1] CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
[   66.873062] sr 0:0:0:0: [sr1] Sense Key : Hardware Error [current]
[   66.949329] sr 0:0:0:0: [sr1] Add. Sense: No additional sense information



Is indicative of something wrong with the virtual cd-rom, it is either partially destroyed or very slow, it is probably also the reason why we don't get a status reply for our first cmd within time.

I think we may get that reply if we only wait long enough for it, can you try to add a delay instead of doing a retry? 100mS could be a reasonable value.


Offline Profile
PostPosted: Fri Sep 09, 2016 4:49 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
LOM wrote:
I think we may get that reply if we only wait long enough for it, can you try to add a delay instead of doing a retry? 100mS could be a reasonable value.


The current timeout is 3 seconds. I've previously tried to raise it to 30 seconds, but that didn't change anything.


Offline Profile
PostPosted: Fri Sep 09, 2016 5:34 pm Reply with quote
Posts: 1102Location: Koh Samui, THJoined: Wed Jul 11, 2012 3:14 pm
lkundrak wrote:
LOM wrote:
I think we may get that reply if we only wait long enough for it, can you try to add a delay instead of doing a retry? 100mS could be a reasonable value.


The current timeout is 3 seconds. I've previously tried to raise it to 30 seconds, but that didn't change anything.


I don't think we are talking about the same thing, I'd like to have a delay between sending a message and checking the status reply for that message.

usb in a nutshell wrote:
A USB compliant Host expects all requests to be processed within a maximum period of 5 seconds. It also specifies stricter timing for specific requests :

Standard Device requests without a data stage must be completed in 50ms.

Standard Device requests with a data stage must start to return data 500ms after the request.
Each data packet must be sent within 500ms of the successful transmission of the previous packet.
The status stage must complete within 50ms after the transmission of the last data packet.

The SetAddress command (which contains a data phase) must process the command and return status within 50ms. The device then has 2ms to change address before the next request is sent.


"unlock media" is not in the list over Standard Device requests and I don't find it unreasonable that it could take longer than 50mS to grant an unlock if the cd-rom is busy.

If it really is so that we never get that status reply, that we need an extra dummy message in order to wake up the device then it is surely a device firmware bug which shouldn't be fixed by usb_modeswitch.
It would also explain the inability for the cd-rom driver to "read disk info"....


Offline Profile
PostPosted: Mon Sep 12, 2016 2:22 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
LOM wrote:
lkundrak wrote:
LOM wrote:
I think we may get that reply if we only wait long enough for it, can you try to add a delay instead of doing a retry? 100mS could be a reasonable value.


The current timeout is 3 seconds. I've previously tried to raise it to 30 seconds, but that didn't change anything.


I don't think we are talking about the same thing, I'd like to have a delay between sending a message and checking the status reply for that message.


Ah, ok. Tried that as well now, nothing changed :(

LOM wrote:
usb in a nutshell wrote:
A USB compliant Host expects all requests to be processed within a maximum period of 5 seconds. It also specifies stricter timing for specific requests :

Standard Device requests without a data stage must be completed in 50ms.

Standard Device requests with a data stage must start to return data 500ms after the request.
Each data packet must be sent within 500ms of the successful transmission of the previous packet.
The status stage must complete within 50ms after the transmission of the last data packet.

The SetAddress command (which contains a data phase) must process the command and return status within 50ms. The device then has 2ms to change address before the next request is sent.


"unlock media" is not in the list over Standard Device requests and I don't find it unreasonable that it could take longer than 50mS to grant an unlock if the cd-rom is busy.

If it really is so that we never get that status reply, that we need an extra dummy message in order to wake up the device then it is surely a device firmware bug which shouldn't be fixed by usb_modeswitch.
It would also explain the inability for the cd-rom driver to "read disk info"....


Dan Williams reported that his phone switches correctly with Fedora 23. I've tried the latest kernel tip on the machine where I can reproduce the problem -- the error messages from the CD-ROM driver is gone, but the problem is still there.


Offline Profile
PostPosted: Mon Sep 12, 2016 2:29 pm Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
Hmm, blacklisting sr_mod and cdrom modules fixes the issue.
Need to look into what do they do.


Offline Profile
PostPosted: Fri Aug 18, 2017 10:43 am Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
Looked a bit further into the issue.

The phone misbehaves (ignores one message) in most cases when the endpoint is reset prior to issuing the allow remove (0x1e) command.
It doesn't seem to happen when the one of the few commands preceding the reset is test unit ready (0x00) which explains why it worked sometimes.

It is obvious now that this is a hardware/firmware (we can't fix) issue and there's perhaps not too much a kernel could do either.
I guess the best idea would be to only issue the endpoint reset when we're positive that the endpoint is in a stall condition? (patch attached)
Attachments:
Offline Profile
PostPosted: Fri Aug 18, 2017 10:53 am Reply with quote
Posts: 22Joined: Wed Jun 22, 2016 2:17 pm
Sorry for the bump.
Seems like this one has been silently applied and thus the issue is resolved.


Offline Profile
PostPosted: Fri Aug 18, 2017 2:06 pm Reply with quote
Site AdminPosts: 6269Joined: Sat Nov 03, 2007 12:30 am
Well, don't know about "silently" ... :)

viewtopic.php?p=17382

(Also in the official ChangeLog)


Offline Profile

Display posts from previous:  Sort by:

All times are UTC + 1 hour [ DST ]
Page 1 of 1
15 posts
Users browsing this forum: No registered users and 1 guest
Search for:
Post new topic  Reply to topic
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum