12 Jul
2023
12 Jul
'23
4:45 p.m.
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!