modem_shell with softsim enabled: but APDUs are never sent in less than a second

[Pascal TROUVIN]

Hi,

I've integrated the softsim feature to the modem_shell application, which is working fine.

But I have a performance issue: I'm receiving the APDU from the modem after 1 second when milli-seconds are expected.

Any idea about this 1 second delay?

Example:

10.868 VG- [00:10:39.188,568] <inf> cloudsim: CS>80f20000000168
(0)
10.868 VG- Receive STATUS(FCP) APDU: 80f20000000168
10.868 VG- Server response: #1(0 ms) STATUS (0) 782183023f008a01058b032f060fc60c90012083010183018183010a9000
10.876 VG- mosh:~$ cloudsim apdu 621e8202782183023f008a01058b032f060fc60c900120830101830181
10.877 VG- 83010a9000
11.892 VG- [00:10:40.212,066] <inf> cloudsim: CS>00a408040000022fe20168
11.892 VG- Extended SELECT-FILE TO normal. 00a40804022fe2

80f20000000168 Received at 10.868s, answered at 10.876

But the next APDU is received only at 11.892 !!!

Any idea are welcome.

[Øyvind]

Hello, 

Could you please elaborate more on your setup? What modem FW are you running on your device, and what version of the nRF Connect SDK are working with?

Please provide more information for me to reproduce. 

Thanks.

Kind regards,
Øyvind

[Pascal TROUVIN]

Thanks for your time.

Here some informations:

*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***

Reset reason: PIN reset

MOSH version:       v2.6.1
MOSH build id:      custom
MOSH build variant: dev

The nrf softsim is enabled at startup with the AT commands:

\r\rat at+cfun=0\rat at+%CSUS=0\rat at+%CSUS=2\rat at+cfun=1\r

And the softsim software part is derived from the nRF documentation: docs.nordicsemi.com/.../softsim_interface.html

And from build, which files could help you?

Kind regards

[Pascal TROUVIN]

Ok I made another test

I answer to the ATR and few first APDU directly

void nrf_modem_softsim_req_handler(enum nrf_modem_softsim_cmd cmd, uint16_t req_id, void *data, uint16_t data_len)

{

apdu.req_id=req_id;

switch (cmd)

{

case NRF_MODEM_SOFTSIM_INIT:

/* Process INIT. */

apdu.out[0]=0;

apdu.out_len=0;

LOG_INF("CS>ATR?");

k_sem_give(&ss_enabled);

if(cloudsim_debug){

LOG_DBG("softsim_handler.NRF_MODEM_SOFTSIM_INIT softsim_enabled(%d) ss_enabled(%d)", softsim_enabled, k_sem_count_get(&ss_enabled));

}

replyToModem(cmd, req_id, "3B9F14801FC78031E073FE21136749250C2900000112");

break;

case NRF_MODEM_SOFTSIM_APDU:

/* Process APDU. */

if (data)

{

bin2hex(data, data_len, apdu.apdu_hexa, sizeof(apdu.apdu_hexa));

if(cloudsim_debug){

LOG_DBG("softsim_handler.NRF_MODEM_SOFTSIM_APDU (%d)%s\n", data_len, apdu.apdu_hexa);

}

LOG_INF("CS>%s", apdu.apdu_hexa);

if(strcmp(apdu.apdu_hexa, "80f20000000168") == 0)

{

// STATUS

replyToModem(cmd, req_id, "621e8202782183023f008a01058b032f060fc60c90012083010183018183010a9000");

}

else if(strcmp(apdu.apdu_hexa, "00a408040000022fe20168") == 0)

{

// STATUS

replyToModem(cmd, req_id, "62318202412183022fe2a506c00100ca01008a0105ab1580010190008001029700800118a40683010a9501088002000a8801109000");

}

else if(strcmp(apdu.apdu_hexa, "00b000000a") == 0)

{

// STATUS

replyToModem(cmd, req_id, "981370104200204203f49000");

}

}

break;

case NRF_MODEM_SOFTSIM_DEINIT:

/* Process DEINIT. */

LOG_ERR("softsim_handler.NRF_MODEM_SOFTSIM_DEINIT");

k_sem_reset(&ss_enabled);

/* Defer DEINIT request to `softsim_deinit_async()` and return immediately. */

#if NRFSOFTSIM_AS_KWORK

queue_req(req_id, cmd, data, data_len);

#else

nrf_modem_softsim_res(cmd, req_id, NULL, 0);

#endif

break;

case NRF_MODEM_SOFTSIM_RESET:

/* Process RESET. */

LOG_ERR("softsim_handler.NRF_MODEM_SOFTSIM_RESET");

k_sem_reset(&ss_enabled);

/* Defer RESET request to `softsim_reset_async()` and return immediately. */

#if NRFSOFTSIM_AS_KWORK

queue_req(req_id, cmd, data, data_len);

#else

nrf_modem_softsim_res(cmd, req_id, NULL, 0);

#endif

break;

default:

LOG_ERR("softsim_handler.UNKNOWN-CODE(%d)\n", cmd);

break;

}

if(data)

{

nrf_modem_softsim_data_free(data);

}

}

Results:

[00:02:18.712,799] <inf> cloudsim: CS>ATR?                                      
[00:02:18.712,890] <dbg> cloudsim: replyToModem: replyToModem: (44)3B9F14801FC7)
                                                                                
[00:02:18.713,195] <inf> cloudsim: CS>80f20000000168                            
[00:02:18.713,317] <dbg> cloudsim: replyToModem: replyToModem: (68)621e82027821)
                                                                                
[00:02:18.713,592] <inf> cloudsim: CS>00a408040000022fe20168                    
[00:02:18.713,714] <dbg> cloudsim: replyToModem: replyToModem: (106)62318202412)
                                                                                
[00:02:18.719,940] <inf> cloudsim: CS>00b000000a                                
[00:02:18.720,031] <dbg> cloudsim: replyToModem: replyToModem: (24)981370104200)
                                                                                
[00:02:18.720,581] <inf> cloudsim: CS>00a408040000022f000168                    
[00:02:20.720,703] <err> cloudsim: softsim_handler.NRF_MODEM_SOFTSIM_RESET      
[00:02:20.720,977] <err> cloudsim: softsim_handler.NRF_MODEM_SOFTSIM_DEINIT     
[00:02:20.721,496] <err> cloudsim: softsim_handler.NRF_MODEM_SOFTSIM_DEINIT

The softsim is answering as expected: within milli-seconds.

So my performance issue is located inside the modem_shell itself. I need to explain a bit more on how is implemented the architecture:

nRF9160-softsim+modem_shell <- ttyACM2-console -> control-program
                                                    <- ttyACM0-ppp -> linux pppd

And the control-program is monitoring the console:

CS>ATR? -> mosh~$ cloudsim atr 3B..........

^

1 second delay !!!!

v

CS>80f20000000168 -> mosh~$ cloudsim apdu ....reply-to-APDU.hexastring....

^

1 second delay !!!!

v

CS>00a408040000022fe20168

Is it understandable?

Regards

[Pascal TROUVIN]

Hi,

I fixed my performance issue by removing SHELL and switching to CONSOLE

The case can be closed.

Thanks for your help.