27 Mar
2024
27 Mar
'24
5 p.m.
Hello,
I am having difficulty with a particular SIM card over osmo-remsim. On the bank daemon
side, PCSC is timing out after 1 second on the same transaction (modemToCard: 81f2400202)
after every reset. This behavior is very reliable and happens on every
reset/initialization sequence from the modem. When I enable PCSC debugging, I see it is
getting back the error CCID error 0xFE “Card absent or mute” from the CCID reader. When I
use this card directly attached to the modem, everything is fine and the modem can go
online (but I have no insight as to whether the modem is encountering an issue with the
same APDU, or not).f
When this transaction error occurs, osmo-remsim-bankd closes the connection, leading to a
removal/insertion and card reset event. So, the system is in infinite loop of resetting
the card, making a bunch of successful APDU transactions, timing out on the offending
transaction, and then resetting again all over again...
As an experiment, I changed osmo-remsim-bankd behavior to ignore the PCSC error, leave the
connection open, and return a general error (0x6F 0x00) to the modem. When I do that, the
modem periodically re-sends the offending APDU every few seconds, but, despite that,
everything else is fine and the modem can now go online with this card over osmo-remsim.
I’m thinking either card needs more time to answer this query, or perhaps it does not
support this query at all.
Based on some earlier troubleshooting it appears to be related to eSIM (eUICC)
functionality. This particular card reports as an eSIM (side note: curiously, its EID is
blank). When I use old modem firmware that does not support eSIM capabilities, the card
works just fine over osmo-remsim. It is only when I upgrade the modem firmware to a
version that supports eSIM that this problem appears.
Other things I tried:
- Upgrading to latest libccid and pcsc-lite — no change
- Using a different card reader with different chip set — no change, and both are listed
as “should be supported” by pcsc-lite.
A couple questions:
- Is there a way to change the timeout? I tried modifying libccid to set bBWI to 0xFF for
this transaction (it was 0x00), but that had to effect. Internal timeouts within pcscd
seem to be set to 3 seconds, and so I do not think they are coming into play, here.
- What are your feelings on having osmo-remsim-bankd ignore this error and return a 0x6f
0x00?
- Any other ideas?
Here is the truncated log of traffic leading up to the offending APDU:
local4.info: 2024-03-26 03:10:31.221037 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO tpduCardToModem(621982054221001c0383026f408a01058b036f06058002005488009000)
local4.info: 2024-03-26 03:10:31.228286 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00b208bc3e)
local4.info: 2024-03-26 03:10:31.242339 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO
tpduCardToModem(800101a40683010195010880015aa40683010a9501088401d4a40683010a950108ffffffffffffffffffffffffffffffffffffffffffffffffffffffffff9000)
local4.info: 2024-03-26 03:10:31.250619 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00b205043e)
local4.info: 2024-03-26 03:10:31.255170 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO
tpduCardToModem(800103a406830101950108800158a40683010a9501088401d4a40683010a950108ffffffffffffffffffffffffffffffffffffffffffffffffffffffffff9000)
local4.info: 2024-03-26 03:10:31.263534 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00b209043e)
local4.info: 2024-03-26 03:10:31.267873 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO
tpduCardToModem(800101a406830101950108800102a406830181950108800158a40683010a9501088401d4a40683010a950108ffffffffffffffffffffffffffffffffffff9000)
local4.info: 2024-03-26 03:10:31.276622 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00b206043e)
local4.info: 2024-03-26 03:10:31.280369 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO
tpduCardToModem(8001019000800102a406830101950108800158a40683010a9501088401d4a40683010a950108ffffffffffffffffffffffffffffffffffffffffffffffff9000)
local4.info: 2024-03-26 03:10:31.288355 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00b201043e)
local4.info: 2024-03-26 03:10:31.293560 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO
tpduCardToModem(800101900080015aa40683010a9501088401d4a40683010a950108ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff9000)
local4.info: 2024-03-26 03:10:31.304765 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00a40804047fff6fc6)
local4.info: 2024-03-26 03:10:31.312115 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO tpduCardToModem(611c)
local4.info: 2024-03-26 03:10:31.316190 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00c000001c)
local4.info: 2024-03-26 03:10:31.319163 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO tpduCardToModem(621a8205422100080183026fc68a01058b036f0601800200088801d09000)
local4.info: 2024-03-26 03:10:31.328212 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(00a2010408ffffffffffffffff)
local4.info: 2024-03-26 03:10:31.330957 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:793 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Tx
RSPRO tpduCardToModem(6282)
local4.info: 2024-03-26 03:10:31.335619 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:766 [000 B1:0 CONN_CLIENT_MAPPED_CARD] Rx
RSPRO tpduModemToCard(81f2400202)
local4.info: 2024-03-26 03:10:32.363083 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_pcsc.c:319 [000 B1:0 CONN_CLIENT_MAPPED_CARD]
SCardTransmit: Transaction failed. (0x80100016)
local4.info: 2024-03-26 03:10:32.363239 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:970 [000 B1:0 CONN_CLIENT_MAPPED_CARD]
Error handling RSPRO
local4.info: 2024-03-26 03:10:32.363364 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:1051 [000 B1:0 CONN_CLIENT_MAPPED_CARD]
Error -2146435050 occurred: Cleaning up state
local4.info: 2024-03-26 03:10:32.375002 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1763
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:492 [000 B1:0 CONN_CLIENT_MAPPED_CARD]
Changing state to ACCEPTING
local4.info: 2024-03-26 03:10:32.378255 bdu-arm-ce-imx8mp bankd-wrapper[1762]: 1764
DBANKDW INFO ../../../git/src/bankd/bankd_main.c:1036 [001 B65535:65535 ACCEPTING]
Accepted connection from 100.64.33.10:35063
And here is the experimental patch to osmo-remsim-bankd:
diff --git a/src/bankd/bankd.h b/src/bankd/bankd.h
index 8a48a21..3c0f18f 100644
--- a/src/bankd/bankd.h
+++ b/src/bankd/bankd.h
@@ -17,6 +17,8 @@
#include "rspro_client_fsm.h"
#include "debug.h"
+#define MAX_CONSECUTIVE_TRANSCEIVE_ERRORS 5
+
extern struct value_string worker_state_names[];
#define LOGW(w, fmt, args...) \
@@ -102,6 +104,9 @@ struct bankd_worker {
/* last known state of the SIM card reset indication */
bool last_resetActive;
+
+ /* number of consecutive transceive errors */
+ int consecutive_transceive_errors;
};
/* bankd card reader driver operations */
diff --git a/src/bankd/bankd_main.c b/src/bankd/bankd_main.c
index 90b05d8..c6cafe0 100644
--- a/src/bankd/bankd_main.c
+++ b/src/bankd/bankd_main.c
@@ -120,6 +120,7 @@ static struct bankd_worker *bankd_create_worker(struct bankd *bankd,
unsigned in
worker->ops = &pcsc_driver_ops;
worker->last_vccPresent = true; /* allow cold reset should first indication be false
*/
worker->last_resetActive = false; /* allow warm reset should first indication be true
*/
+ worker->consecutive_transceive_errors = 0;
/* in the initial state, the worker has no client.fd, bank_slot or pcsc handle yet */
@@ -787,8 +788,21 @@ static int worker_handle_tpduModemToCard(struct bankd_worker *worker,
const Rspr
rc = worker->ops->transceive(worker, mdm2sim->data.buf, mdm2sim->data.size,
rx_buf, &rx_buf_len);
- if (rc < 0)
- return rc;
+
+ if (rc < 0) {
+ LOGW(worker, "Transceieve error %d (count %d/%d)\n", rc,
+ worker->consecutive_transceive_errors, MAX_CONSECUTIVE_TRANSCEIVE_ERRORS);
+
+ if (++worker->consecutive_transceive_errors == MAX_CONSECUTIVE_TRANSCEIVE_ERRORS) {
+ return rc;
+ }
+
+ rx_buf[0] = 0x6f;
+ rx_buf[1] = 0x00;
+ rx_buf_len = 2;
+ }
+
+ worker->consecutive_transceive_errors = 0;
LOGW(worker, "Tx RSPRO tpduCardToModem(%s)\n", osmo_hexdump_nospc(rx_buf,
rx_buf_len));
/* encode response PDU and send it */
Regards,
James