Hello list,
I've been playing with the sysmoQMOD board and I find that more often than not the remsim-client justs sits there waiting for something [1] when I list the modem using ofono/test/list-modem [2] it shows that there is no SIM present. I've tried a Telit modem and a Sierra Wireless modem and both do the same thing. Sometimes it works but more often than not it justs sits there. I've tried using the 'uhubctl' tool to power cycle the modem but this has no effect on the st2 client. It deletes the modem instance and cretes a new one in ofono.
Anyone have any suggestion of what I can try to trigger the modem to do something?
Or how I can get some debug info from the card?
Thanks
Alan
---------------------------------
[1]
sudo ./osmo-remsim-client-st2 -V 0x1d50 -P 0x4004 -c 0 -C 1 -I 0 -H 1-6.1
simtrace2-remsim-client - Remote SIM card client for SIMtrace (C) 2010-2017, Harald Welte laforge@gnumonks.org (C) 2018, sysmocom -s.f.m.c. GmbH, Author: Kevin Redon kredon@sysmocom.de
<0000> fsm.c:299 RSPRO_CLIENT(server)[0x564613030760]{INIT}: Allocated <0000> fsm.c:299 BANKD_CONN(bankd)[0x5646130317c0]{INIT}: Allocated SIMtrace <- 01 05 00 00 00 00 09 00 01 SIMtrace <- 02 02 00 00 00 00 09 00 01 SIMtrace <= cardem_request_set_atr(3b 00 ) SIMtrace <- 01 02 00 00 00 00 0b 00 02 3b 00 SIMtrace <- 02 01 00 00 00 00 0b 00 02 2c 01 Entering main loop <0003> input/ipa.c:128 127.0.0.1:9998 connection done <0000> rspro_client_fsm.c:105 RSPRO_CLIENT(server)[0x564613030760]{INIT}: RSPRO link to 127.0.0.1:9998 UP <0000> rspro_client_fsm.c:107 RSPRO_CLIENT(server)[0x564613030760]{INIT}: Received Event SRVC_E_TCP_UP <0000> rspro_client_fsm.c:210 RSPRO_CLIENT(server)[0x564613030760]{INIT}: state_chg to ESTABLISHED <0000> rspro_client_fsm.c:78 RSPRO_CLIENT(server)[0x564613030760]{ESTABLISHED}: Tx RSPRO connectClientReq <0000> rspro_client_fsm.c:141 RSPRO_CLIENT(server)[0x564613030760]{ESTABLISHED}: Received RSPRO [L1]> 00 40 ee 07 [L2]> 30 3d 80 01 02 81 02 09 26 a2 34 a3 32 30 2d 0a 01 01 16 0a 66 69 78 6d 65 2d 6e 61 6d 65 80 0d 72 65 6d 73 69 6d 2d 73 65 72 76 65 72 81 0d 30 2e 31 2e 30 2e 31 32 2d 66 30 31 38 0a 01 00 <0000> simtrace2-remsim_client.c:669 RSPRO_CLIENT(server)[0x564613030760]{ESTABLISHED}: Received Event SRVC_E_CLIENT_CONN_RES <0000> rspro_client_fsm.c:254 RSPRO_CLIENT(server)[0x564613030760]{ESTABLISHED}: state_chg to CONNECTED <0000> rspro_client_fsm.c:141 RSPRO_CLIENT(server)[0x564613030760]{CONNECTED}: Received RSPRO [L1]> 00 21 ee 07 [L2]> 30 1e 80 01 02 81 01 00 a2 16 b1 14 30 06 02 01 01 02 01 00 30 0a 80 04 7f 00 00 01 02 02 27 0f <0000> simtrace2-remsim_client.c:687 BANKD_CONN(bankd)[0x5646130317c0]{INIT}: Received Event BDC_E_ESTABLISH <0000> bankd_client_fsm.c:195 BANKD_CONN(bankd)[0x5646130317c0]{INIT}: state_chg to REESTABLISH <0000> bankd_client_fsm.c:159 BANKD_CONN(bankd)[0x5646130317c0]{REESTABLISH}: Creating TCP connection to bankd at 127.0.0.1:9999 <0000> rspro_client_fsm.c:78 RSPRO_CLIENT(server)[0x564613030760]{CONNECTED}: Tx RSPRO configClientBankRes <0003> input/ipa.c:128 127.0.0.1:9999 connection done RSPRO link to 127.0.0.1:9999 UP <0000> bankd_client_fsm.c:47 BANKD_CONN(bankd)[0x5646130317c0]{REESTABLISH}: Received Event BDC_E_TCP_UP <0000> bankd_client_fsm.c:181 BANKD_CONN(bankd)[0x5646130317c0]{REESTABLISH}: state_chg to ESTABLISHED <0000> simtrace2-remsim_client.c:649 BANKD_CONN(bankd)[0x5646130317c0]{ESTABLISHED}: Received RSPRO [L1]> 00 45 ee 07 [L2]> 30 42 80 01 02 81 02 09 26 a2 39 a3 37 30 32 0a 01 02 16 0a 66 69 78 6d 65 2d 6e 61 6d 65 80 0c 72 65 6d 73 69 6d 2d 62 61 6e 6b 64 81 13 30 2e 31 2e 30 2e 31 32 2d 66 30 31 38 2d 64 69 72 74 79 0a 01 00 <0000> simtrace2-remsim_client.c:613 BANKD_CONN(bankd)[0x5646130317c0]{ESTABLISHED}: Received Event BDC_E_CLIENT_CONN_RES <0000> bankd_client_fsm.c:122 BANKD_CONN(bankd)[0x5646130317c0]{ESTABLISHED}: state_chg to CONNECTED <0000> simtrace2-remsim_client.c:649 BANKD_CONN(bankd)[0x5646130317c0]{CONNECTED}: Received RSPRO [L1]> 00 2c ee 07 [L2]> 30 29 80 01 02 81 01 00 a2 21 aa 1f 30 06 02 01 00 02 01 00 04 15 3b 9e 96 80 1f c7 80 31 e0 73 fe 21 1b 66 d0 02 17 8d 11 00 89 SIMtrace <= cardem_request_set_atr(3b 9e 96 80 1f c7 80 31 e0 73 fe 21 1b 66 d0 02 17 8d 11 00 89 ) SIMtrace <- 01 02 00 00 00 00 1e 00 15 3b 9e 96 80 1f c7 80 31 e0 73 fe 21 1b 66 d0 02 17 8d 11 00 89 <0000> bankd_client_fsm.c:58 BANKD_CONN(bankd)[0x5646130317c0]{CONNECTED}: Received Event BDC_E_RSPRO_TX
--------------------------
[2]
~/ofono/test/list-modems [ /sierra_15 ] Powered = 1 Interfaces = org.ofono.SimManager org.ofono.LocationReporting org.ofono.VoiceCallManager Model = MC7304 Revision = SWI9X15C_05.05.58.00 r27038 carmd-fwbuild1 2015/03/04 21:30:23 Manufacturer = Sierra Wireless, Incorporated Serial = 356853054058773 Online = 0 SystemPath = /sys/devices/pci0000:00/0000:00:14.0/usb1/1-6/1-6.2 Features = sim gps Type = hardware Emergency = 0 Lockdown = 0 [ org.ofono.SimManager ] Present = 0 [ org.ofono.LocationReporting ] Enabled = 0 Type = nmea [ org.ofono.VoiceCallManager ] EmergencyNumbers = 08 000 999 110 112 911 118 119
--------------------------------
Hi Alan,
sorry to hear about your troubles.
My first question would be to do a 'strace' on the remsim-client when this problem happens.
From the log file it seems that remsim-client is fully set up,
i.e. it has connected to the server, received instruction to connect to the bankd and it has established that bankd connection. It appears that the client "simply" doesn't receive any APDU from the SAM3S microcontroller.
The strace would give us certainty about what the remsim-client is doing, i.e. whether or not it receives something over USB or whether it's in some endless loop or whatever else.
If remsim-client appears to be fine, we have to look one level deeper: the simtrace2 cardem firmware running on the SAM3S microcontrollers.
Debugging the microcontroller itself is unfortunately not possible without a 3.3V UART cable attached to the 3-pin headers of the SAM3S processors (X601, X701). I can ship you the required cabling tomorrow, hoping this helps us further to see what's going on.
Do you have any particular method to reproduce this? Does it appear related to a specific sim card? Does it fail from the beginning or only appear after some time? I'm basically looking for any way to gaing more information.
If you'd like to provide remote (SSH) access to a machine where the board is connected, we could also try to debug that remotely.
Another thing to try would be to use the 'simtrace2-remsim' program from simtrace2.git (see the sysmoQMOD user manual towards the end) with a local PC/SC reader. If it works there, then the bug must be in the osmo-remsim software.
Thanks for your patience.
Regards, Harald
Hi Harald,
Thanks for responding.
Debugging the microcontroller itself is unfortunately not possible without a 3.3V UART cable attached to the 3-pin headers of the SAM3S processors (X601, X701). I can ship you the required cabling tomorrow, hoping this helps us further to see what's going on.
I will dig out a Raspberry PI and connect it to the debug port.
Do you have any particular method to reproduce this? Does it appear related to a specific sim card? Does it fail from the beginning or only appear after some time? I'm basically looking for any way to gaing more information.
I've managed to narrow the problem down a little bit:
i) The card reader and sysmoQMOD are on the same server : works great ii) Move the card reader and bankkd onto a remote server which adds a delay : soon get this stuck state iii) Move the card reader back to the same server : still in this stuck state iv) Power cycle the sysmoQMOD card : works again
It seems that when I intoduce a delay between bankd and st2 it can get into this state and then stays there.
I've tried several methods to restart the modem rather than powercycle the card but nothing seems to work:
atz at#reboot uhubctl -a cycle -p 2
Regards
Alan
Hi Alan, On Fri, May 31, 2019 at 11:02:50AM +0100, KageDS wrote:
FYI The pins are missing on X601 and X701. Looks like I need to dig up some header pins as well.
yes, this is intentional. The pin headers were impacting some enclosure ingtegration of a customer, and we decided to not place them by default. After all, they're not for use in production.
I guess we could place them for the 1-off evaluation board purchases, thanks for pointing that out.
Hi Harald,
Well it looks like my attempt to solder header pins onto the board has ended in a disaster:
I'm now seeing this when I connect the USB.
Jun 3 09:23:23 kageds kernel: [1094465.891611] usb 1-1: new low-speed USB device number 71 using xhci_hcd Jun 3 09:23:23 kageds kernel: [1094466.011674] usb 1-1: device descriptor read/64, error -71 Jun 3 09:23:23 kageds kernel: [1094466.239641] usb 1-1: device descriptor read/64, error -71 Jun 3 09:23:23 kageds kernel: [1094466.467689] usb 1-1: new low-speed USB device number 72 using xhci_hcd Jun 3 09:23:23 kageds kernel: [1094466.587703] usb 1-1: device descriptor read/64, error -71 Jun 3 09:23:23 kageds kernel: [1094466.815730] usb 1-1: device descriptor read/64, error -71 Jun 3 09:23:24 kageds kernel: [1094466.923737] usb usb1-port1: attempt power cycle Jun 3 09:23:24 kageds kernel: [1094467.567751] usb 1-1: new low-speed USB device number 73 using xhci_hcd Jun 3 09:23:24 kageds kernel: [1094467.568257] usb 1-1: Device not responding to setup address. Jun 3 09:23:24 kageds kernel: [1094467.776277] usb 1-1: Device not responding to setup address. Jun 3 09:23:25 kageds kernel: [1094467.983753] usb 1-1: device not accepting address 73, error -71 Jun 3 09:23:25 kageds kernel: [1094468.103767] usb 1-1: new low-speed USB device number 74 using xhci_hcd Jun 3 09:23:25 kageds kernel: [1094468.104244] usb 1-1: Device not responding to setup address. Jun 3 09:23:25 kageds kernel: [1094468.312219] usb 1-1: Device not responding to setup address. Jun 3 09:23:25 kageds kernel: [1094468.519831] usb 1-1: device not accepting address 74, error -71 Jun 3 09:23:25 kageds kernel: [1094468.520812] usb usb1-port1: unable to enumerate USB device
I also just see garbage on both debug ports. Though I'm not sure which is pin1 on the headers or what baud rate I should be using.
I'm guessing I should send the board back for repair?
Any thoughts
Thanks
Alan
On 31/05/2019 15:08, Harald Welte wrote:
Hi Alan, On Fri, May 31, 2019 at 11:02:50AM +0100, KageDS wrote:
FYI The pins are missing on X601 and X701. Looks like I need to dig up some header pins as well.
yes, this is intentional. The pin headers were impacting some enclosure ingtegration of a customer, and we decided to not place them by default. After all, they're not for use in production.
I guess we could place them for the 1-off evaluation board purchases, thanks for pointing that out.
Hi Alan,
On Mon, Jun 03, 2019 at 10:49:34AM +0100, KageDS wrote:
Well it looks like my attempt to solder header pins onto the board has ended in a disaster:
Sorry to hear that :/
I also just see garbage on both debug ports. Though I'm not sure which is pin1 on the headers or what baud rate I should be using.
The pin-out should be in the manual, but isn't. Typically one of the pin has a square copper layer and the others are round, then the square one is GND. I don't have a board with me right now so I cannot verify, but we'll investigate.
The baud rate depends on the firmware version. Older versions use 115200 while current master uses 921600 bps.
We'll make sure to update the manual to include related information.
I'm guessing I should send the board back for repair?
That's probably the best idea. Sorry for the troubles. Please return to sysmocom, we'll make sure to repair, test and return it together with cables for the serial console to get back to the analyzing the actual problems you've been experiencing.
Thanks, Harald
Hi Harald,
many thanks for the quick turnaround fixing the board.
I've managed to catch the problem on the debug port but not sure how much help it is going to be:
============================================================================= SIMtrace2 firmware 0.4.186-6349 (C) 2010-2016 by Harald Welte ============================================================================= -I- Chip ID: 0x28900960 (Ext 0x00000000) -I- Serial Nr. 51203120-39513450-32303031-32333037 -I- Reset Cause: general reset (first power-up reset) -I- Detected Quad-Modem ST12 -I- VERSION_DET ADC=3731 => 3003455 uVund -I- USB init... USBD_Init Std gDesc Dev Std sAddr SetAddr(11) Std gDesc Dev Std gDesc Qua -W- Sta 0x888A8. -I- calling init of config 1... -I- 536881924: CLK activateda work-around -I- Modem 0: physical SIM -I- 0: Use local/physical SIM -I- Modem 1: physical SIM -I- 1: Use local/physical SIM -I- entering main loop... -I- 0: Card Detect Status -1 -> 0 -I- 1: Card Detect Status -1 -> 0 -I- USB is now configured Std sInterface -W- Sta 0x88828 [0] -W- _ Std cFeat Hlt Std cFeat Hlt Std cFeat D -I- Modem 0: virtual SIM -I- 0: Use remote/emulated SIM -I- 0: ATR set: 3b 00 -I- 0: Asserting modem reset -I- 0: De-asserting modem reset -I- 0: ATR set: 3b 9e 96 80 1f c7 80 31 e0 73 fe 21 1b 66 d0 02 17 8d 11 00 89
Regards
Alan
On 03/06/2019 14:57, Harald Welte wrote:
Hi Alan,
On Mon, Jun 03, 2019 at 10:49:34AM +0100, KageDS wrote:
Well it looks like my attempt to solder header pins onto the board has ended in a disaster:
Sorry to hear that :/
I also just see garbage on both debug ports. Though I'm not sure which is pin1 on the headers or what baud rate I should be using.
The pin-out should be in the manual, but isn't. Typically one of the pin has a square copper layer and the others are round, then the square one is GND. I don't have a board with me right now so I cannot verify, but we'll investigate.
The baud rate depends on the firmware version. Older versions use 115200 while current master uses 921600 bps.
We'll make sure to update the manual to include related information.
I'm guessing I should send the board back for repair?
That's probably the best idea. Sorry for the troubles. Please return to sysmocom, we'll make sure to repair, test and return it together with cables for the serial console to get back to the analyzing the actual problems you've been experiencing.
Thanks, Harald
On 30/05/2019 22:56, Harald Welte wrote:
The strace would give us certainty about what the remsim-client is doing, i.e. whether or not it receives something over USB or whether it's in some endless loop or whatever else.
Hi Harald,
Of course when I run 'strace remsim-client' I don't see the problem, at least not yet. To me that suggests its some sort of timing issue.
Alan
Hi Harald,
Here is the strace after it gets stuck.
Let me know if you spot anything interesting.
The only way I've found to get it working again is to power cycle the card.
Regards
Alan
Hi Alan,
we are be building a setup with the 'tc netem' scheduler between remsim-client and remsim-bankd, so we can introduce any amount of delay to further investigate.
Regards, Harald
-
Harald Welte -
KageDS