simtrace August 2023

simtrace@lists.osmocom.org

1 participants
1 discussions

Phone locks up on boot with simtrace cable attached
by Adrian Popa 01 Aug '23

01 Aug '23

Again, with my client-server remsim setup. The client starts correctly: DRSPRO INFO ../rspro_client_fsm.c:307 RSPRO_CLIENT(bankd){REESTABLISH}: Creating TCP connection to server at 192.168.1.111:9999 DLINP NOTICE input/ipa.c:141 192.168.1.111:9999 connection done DRSPRO NOTICE ../rspro_client_fsm.c:127 RSPRO_CLIENT(bankd){REESTABLISH}: RSPRO link to 192.168.1.111:9999 UP DLINP NOTICE simtrace2_api.c:172 [0] <= osmo_st2_cardem_request_card_insert(inserted=1) DLINP NOTICE simtrace2_api.c:321 [0] <= _modem_sim_select(remote_sim=1) DLINP NOTICE simtrace2_api.c:254 [0] <= osmo_st2_cardem_request_set_atr(3b 00 ) DLINP NOTICE simtrace2_api.c:288 [0] <= _modem_reset(asserted=2, pulse_ms=300) DLINP NOTICE simtrace2_api.c:254 [0] <= osmo_st2_cardem_request_set_atr(3b 9f 96 80 1f c7 80 31 e0 73 fe 21 13 67 98 07 02 10 01 01 01 54 ) The bankd sees the card correctly: Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:955 [000 ACCEPTING] Accepted connection from 192.168.1.9:45513 Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:442 [000 ACCEPTING] Changing state to CONN_WAIT_ID Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:655 [000 CONN_WAIT_ID] Rx RSPRO connectClientReq(T=0, N='rpi-cardem-2', SW='remsim-client', VER='1.0.0') Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:442 [000 CONN_WAIT_ID] Changing state to CONN_CLIENT Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:625 [000 CONN_CLIENT] slotmap found: C(1:1) -> B(1:1) Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:450 [000 CONN_CLIENT] Changing state to CONN_CLIENT_MAPPED (timeout=10) Jul 12 14:54:43 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:261 [000 CONN_CLIENT_MAPPED] Attempting to open PC/SC context Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:264 [000 CONN_CLIENT_MAPPED] SCardEstablishContext: OK Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:215 [000 CONN_CLIENT_MAPPED] Attempting to find card/slot using regex 'SCM Microsystems Inc. SCR 3310' Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:234 [000 CONN_CLIENT_MAPPED] Attempting to open card/slot 'SCM Microsystems Inc. SCR 3310 [CCID Interface] (53312144266274) 00 00' Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED] SCardStatus: OK Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:442 [000 CONN_CLIENT_MAPPED] Changing state to CONN_CLIENT_MAPPED_CARD Jul 12 14:54:44 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:780 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO setAtrRes Once the phone powers on, the client starts showing such messages: DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x12, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 00 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x0, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 01 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x1, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 03 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x3, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 13 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x13, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 03 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x3, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 13 00 00 00 00 00 01 01 0a 80 25 00 00 DST2 INFO user_simtrace2.c:180 SIMtrace IRQ STATUS: flags=0x13, fi=1, di=1, wi=10 wtime=9600 DST2 INFO user_simtrace2.c:193 SIMtrace IRQ 01 04 00 00 00 00 15 00 12 00 00 00 00 00 01 01 0a 80 25 00 00 But the phone never completes the boot (shows just the splash screen). The bankd daemon shows in an infinite loop: Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:288 [000 CONN_CLIENT_MAPPED_CARD] SCardReconnect: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED_CARD] SCardStatus: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED_CARD] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=INACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=ABSENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:284 [000 CONN_CLIENT_MAPPED_CARD] Resetting card in 'SCM Microsystems Inc. SCR 3310' (cold reset) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:288 [000 CONN_CLIENT_MAPPED_CARD] SCardReconnect: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED_CARD] SCardStatus: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED_CARD] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=ABSENT, CLK=INACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:284 [000 CONN_CLIENT_MAPPED_CARD] Resetting card in 'SCM Microsystems Inc. SCR 3310' (cold reset) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:288 [000 CONN_CLIENT_MAPPED_CARD] SCardReconnect: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED_CARD] SCardStatus: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED_CARD] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=INACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=ABSENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:284 [000 CONN_CLIENT_MAPPED_CARD] Resetting card in 'SCM Microsystems Inc. SCR 3310' (cold reset) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:288 [000 CONN_CLIENT_MAPPED_CARD] SCardReconnect: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED_CARD] SCardStatus: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED_CARD] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=ABSENT, CLK=INACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:284 [000 CONN_CLIENT_MAPPED_CARD] Resetting card in 'SCM Microsystems Inc. SCR 3310' (cold reset) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:288 [000 CONN_CLIENT_MAPPED_CARD] SCardReconnect: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:198 [000 CONN_CLIENT_MAPPED_CARD] SCardStatus: OK Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:200 [000 CONN_CLIENT_MAPPED_CARD] Card ATR: 3b9f96801fc78031e073fe2113679807021001010154 Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=INACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=PRESENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_main.c:749 [000 CONN_CLIENT_MAPPED_CARD] Rx RSPRO clientSlotStatusInd(RST=INACTIVE, VCC=ABSENT, CLK=ACTIVE) Jul 12 15:38:29 rpi-cardem-1 osmo-remsim-bankd[19847]: 19848 DBANKDW INFO bankd_pcsc.c:284 [000 CONN_CLIENT_MAPPED_CARD] Resetting card in 'SCM Microsystems Inc. SCR 3310' (cold reset) So, something seems to cause the card reader to reset and it looks like the phone is waiting for the sim card to initialize. How should I try to troubleshoot further? Does it look like a card reader problem? A misplaced/poor contact SIM FPC cable? A problem with the SIM in the reader? Should I try with a different phone (hard to get phones with fullsized SIM), or a different reader? How should I proceed further? Perhaps try a trace (but that doesn't use an external reader)? Thanks for any suggestions. Cheers!

5 14

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

simtrace August 2023