Hi,
We have integrated the Onomondo SoftSIMs in our devices (custom PCB). The integration is looking good. We can provision it, works in multiple countries etc.
However, sometimes the SIM fails when booting. We get a CEREG: 90 from the modem and after turning on logging, I see Softsim RESET/DEINIT/INIT requests while searching.
The device does not recover from this until full reboot. The SIM profile is not permanently damaged, because the SIM will work again after 1 or multiple reboots.
Logs (we use a custom format seconds|thread|module|level|message):
13.994|main|CIOT|I|TX: AT+COPS=0␊ 14.004|main|CIOT|I|RX: OK␊ 14.008|main|CIOT|I|TX: AT+CFUN=41␊ 14.018||softsim|D|SoftSIM INIT REQ␊ 14.018|main|CIOT|I|RX: OK␊ 14.025|main|CIOT|I|TX: AT+CFUN?␊ 14.026||fs_nvs|D|Recovering last ate from sector 2␊ 14.029||fs_nvs|I|8 Sectors of 4096 bytes␊ 14.029||fs_nvs|I|alloc wra: 2, d78␊ 14.029||fs_nvs|I|data wra: 2, ae4␊ 14.035|main|CIOT|I|RX: +CFUN: 41␊ 14.035|main|CIOT|I|RX: OK␊ 14.045|main|CIOT|I|TX: AT+CRSM=214,28539,0,0,12,"FFFFFFFFFFFFFFFFFFFFFFFF"␊ 14.048||softsim|D|SoftSIM ATR3b9311008071fe8d␊ 14.055||softsim|D|SoftSIM APDU request80f20000000168␊ 14.062||softsim|D|SoftSIM APDU response6700␊ 14.076||softsim|D|SoftSIM INIT REQ␊ 14.106||softsim|D|Allocating buffer of size 18␊ 14.144||softsim|D|Allocating buffer of size 28␊ 14.177||softsim|D|Allocating buffer of size 640␊ 14.204||softsim|D|SoftSIM ATR3b9311008071fe8d␊ 14.211||softsim|D|SoftSIM APDU request80f20000000168␊ 14.235||softsim|D|Allocating buffer of size 27␊ 14.268||softsim|D|Allocating buffer of size 66␊ 14.385||softsim|D|SoftSIM APDU response621e8202782183023f008a01058b032f060fc60c90012083010183018183010a9000␊ 14.395||softsim|D|SoftSIM APDU request00a408040000022fe20168␊ 14.424||softsim|D|Allocating buffer of size 25␊ 14.519||softsim|D|SoftSIM APDU response62258202412183022fe28a01058b032f06038002000a880110c60c90012083010183018183010a9000␊ 14.530||softsim|D|SoftSIM APDU request00b000000a␊ 14.540||softsim|D|Allocating buffer of size 10␊ 14.550||softsim|D|SoftSIM APDU response985437000000625295409000␊ 14.556||softsim|D|SoftSIM APDU request00a408040000022f000168␊ 14.586||softsim|D|Allocating buffer of size 28␊ 14.685||softsim|D|SoftSIM APDU response62288205422100260283022f008a01058b032f06028002004c8801f0c60c90012083010183018183010a9000␊ 14.697||softsim|D|SoftSIM APDU request00b2010426␊ 14.715||softsim|D|Allocating buffer of size 76␊ 14.732||softsim|D|SoftSIM APDU response61194f10a0000000871002ffffffff890709000050055553696d31ffffffffffffffffffffff9000␊ 14.743||softsim|D|SoftSIM APDU request00a408040000022f050168␊ 14.773||softsim|D|Allocating buffer of size 25␊ 14.870||softsim|D|SoftSIM APDU response62258202412183022f058a01058b032f06018002000a880128c60c90012083010183018183010a9000␊ 14.881||softsim|D|SoftSIM APDU request00b000000a␊ 14.913||softsim|D|SoftSIM APDU responseffffffffffffffffffff9000␊ 14.920||softsim|D|SoftSIM APDU request00a408040000022f080168␊ 15.041||softsim|D|SoftSIM APDU response62258202412183022f088a01058b032f060280020005880140c60c90012083010183018183010a9000␊ 15.053||softsim|D|SoftSIM APDU request00b0000005␊ 15.084||softsim|D|SoftSIM APDU response3c050200009000␊ 15.090||softsim|D|SoftSIM APDU request80100000233301e842119c00078000001f2060000043c0000000004000400000000008008017700c␊ 15.103||softsim|D|SoftSIM APDU response9000␊ ... 17.712||softsim|D|SoftSIM APDU request00b000000c␊ 17.760||softsim|D|SoftSIM APDU responseffffffffffffffffffffffff9000␊ 17.766||softsim|D|SoftSIM APDU request00a408040000047fff6f420168␊ 17.907||softsim|D|SoftSIM APDU response62278205422100340283026f428a01058b036f0602800200688800c60c90012083010183018183010a9000␊ 17.919||softsim|D|SoftSIM APDU request00b2010434␊ 17.947||softsim|D|SoftSIM APDU responseffffffffffffffffffffffffffffffffffffffffffffffffe5ffffffffffffffffffffffff0791447779078484ffffffffff00a89000␊ 17.962||softsim|D|SoftSIM APDU request00b2020434␊ 17.971||softsim|D|SoftSIM APDU responseffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff9000␊ 17.985||softsim|D|SoftSIM APDU request00a408040000087fff7f665f404f400168␊ 18.069||softsim|D|SoftSIM APDU response6a82␊ 18.076||softsim|D|SoftSIM APDU request00a408040000087fff7f665f404f410168␊ 18.147||softsim|D|SoftSIM APDU response6a82␊ 18.153||softsim|D|SoftSIM APDU request00a408040000087fff7f665f404f420168␊ 18.225||softsim|D|SoftSIM APDU response6a82␊ 18.232||softsim|D|SoftSIM APDU request00a408040000087fff7f665f404f430168␊ 18.303||softsim|D|SoftSIM APDU response6a82␊ 18.310||softsim|D|SoftSIM APDU request00a408040000087fff7f665f304f340168␊ 18.381||softsim|D|SoftSIM APDU response6a82␊ 18.389||softsim|D|SoftSIM APDU request80f2010c␊ 18.396||softsim|D|SoftSIM APDU response9000␊ 18.403||softsim|D|SoftSIM APDU request00a408040000047fff6f7b0168␊ 18.532||softsim|D|SoftSIM APDU response62258202412183026f7b8a01058b036f06048002000c880168c60c90012083010183018183010a9000␊ 18.543||softsim|D|SoftSIM APDU request00d600000cffffffffffffffffffffffff␊ 18.583||softsim|D|SoftSIM APDU response9000␊ 18.590||softsim|D|SoftSIM APDU request00a408040000047fff6f7b0168␊ 18.720||softsim|D|SoftSIM APDU response62258202412183026f7b8a01058b036f06048002000c880168c60c90012083010183018183010a9000␊ 18.731||softsim|D|SoftSIM APDU request00b000000c␊ 18.760||softsim|D|SoftSIM APDU responseffffffffffffffffffffffff9000␊ 18.768|main|CIOT|I|RX: +CRSM: 144,0,""␊ 18.768|main|CIOT|I|RX: OK␊ 18.775|main|CIOT|I|TX: AT+CRSM=176,28539,0,0,12␊ 18.785||softsim|D|SoftSIM APDU request00a408040000047fff6f7b0168␊ 18.909||softsim|D|SoftSIM APDU response62258202412183026f7b8a01058b036f06048002000c880168c60c90012083010183018183010a9000␊ 18.921||softsim|D|SoftSIM APDU request00b000000c␊ 18.950||softsim|D|SoftSIM APDU responseffffffffffffffffffffffff9000␊ 18.957|main|CIOT|I|RX: +CRSM: 144,0,"FFFFFFFFFFFFFFFFFFFFFFFF"␊ 18.957|main|CIOT|I|RX: OK␊ 18.966|main|CIOT|I|TX: AT+CFUN=1␊ 18.999|sysworkq|lte_lc|D|%XMODEMSLEEP notification␊ 18.999|sysworkq|lte_lc|D|Dispatching event: type=9␊ 18.999|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 18.999|sysworkq|lte_lc|D|Done␊ 19.000|main|CIOT|I|RX: OK␊ 19.010|main|CIOT|I|TX: AT+CFUN?␊ 19.015|main|CIOT|I|RX: +CFUN: 1␊ 19.015|main|CIOT|I|RX: OK␊ 19.023|main|CIOT|I|TX: AT null: tmr restart␊ 20.751||softsim|D|SoftSIM APDU request00a408040000047fff6fe40168␊ 20.751|sysworkq|lte_lc|D|+CEREG notification: +CEREG: 2,"3AA4","00147CC9",9␊ 20.752|sysworkq|lte_lc|D|Network registration status: 2␊ 20.752|sysworkq|lte_lc|D|LTE mode: 9␊ 20.752|sysworkq|lte_lc|D|Dispatching event: type=0␊ 20.752|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 20.752|sysworkq|lte_lc|D|Done␊ 20.752|sysworkq|lte_lc|D|Dispatching event: type=4␊ 20.752|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 20.752|sysworkq|lte_lc|D|Done␊ 20.752|sysworkq|lte_lc|D|Dispatching event: type=5␊ 20.752|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 20.752|sysworkq|lte_lc|D|Done␊ 20.830|main|LOG|I|Log processing time: count:101 avg:5ms max:14ms␊ 20.955||softsim|D|SoftSIM APDU response62288205422100360183026fe48a01058b036f0604800200368801c0c60c90012083010183018183010a9000␊ 20.966||softsim|D|SoftSIM APDU request00dc010436a0348001078120e10a147ed48d3d8eac28bfb40db482fa13d12802cb3482db5fa3fbda25a2db76820400000022830400000022840132␊ 21.003||softsim|D|SoftSIM APDU response9000␊ 21.177|sysworkq|lte_lc|D|%MDMEV notification␊ 21.177|sysworkq|lte_lc|D|Occurrence found: PRACH CE-LEVEL 0␍␊ 21.177|sysworkq|lte_lc|D|Dispatching event: type=11␊ 21.177|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 21.177|sysworkq|lte_lc|D|Done␊ 23.241|sysworkq|lte_lc|D|%MDMEV notification␊ 23.241|sysworkq|lte_lc|D|Occurrence found: PRACH CE-LEVEL 1␍␊ 23.241|sysworkq|lte_lc|D|Dispatching event: type=11␊ 23.241|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 23.241|sysworkq|lte_lc|D|Done␊ 24.174|sysworkq|lte_lc|D|+CSCON notification␊ 24.174|sysworkq|lte_lc|D|Dispatching event: type=3␊ 24.174|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 24.174|sysworkq|lte_lc|D|Done␊ 28.010||softsim|D|SoftSIM APDU request0088008122100561d96ad8eea678bd041a84b49088e610f58f07fb0caa80000676e7d51b391e0f00␊ 29.226||softsim_crypto|D|AES encrypt to key id: 10␊ 29.239||softsim_crypto|D|AES encrypt to key id: 10␊ 29.253||softsim_crypto|D|AES encrypt to key id: 10␊ 29.266||softsim_crypto|D|AES encrypt to key id: 10␊ 29.280||softsim_crypto|D|AES encrypt to key id: 10␊ 29.293||softsim_crypto|D|AES encrypt to key id: 10␊ 29.307||softsim_crypto|D|AES encrypt to key id: 10␊ 29.320||softsim_crypto|D|AES encrypt to key id: 10␊ 29.333||softsim_crypto|D|AES encrypt to key id: 10␊ 29.347||softsim_crypto|D|AES encrypt to key id: 10␊ 30.057||softsim|D|SoftSIM APDU responsedb08dccfd48611da4ad11016fe9a34d27b92155eb5102cbaef4cea10206f85d5a60ac7be64a4504a6f2c0789080c805f87a1b21ec89000␊ 30.071||softsim|D|SoftSIM RESET␊ 30.117||softsim|D|Allocating buffer of size 640␊ 30.145||softsim|D|SoftSIM DEINIT REQ␊ 30.176||softsim|I|Softsim stop - committing /3f00/7ff0/6fe4 to NVS␊ 30.191||softsim|D|SoftSIM INIT REQ␊ 30.203||fs_nvs|D|Recovering last ate from sector 2␊ 30.226||fs_nvs|I|8 Sectors of 4096 bytes␊ 30.226||fs_nvs|I|alloc wra: 2, d68␊ 30.231||fs_nvs|I|data wra: 2, b24␊ 30.287||softsim|D|SoftSIM ATR3b9311008071fe8d␊ 30.287||softsim|D|SoftSIM DEINIT REQ␊ 30.288|sysworkq|lte_lc|D|+CEREG notification: +CEREG: 90␊ 30.288|sysworkq|lte_lc|D|Network registration status: 90␊ 30.288|sysworkq|lte_lc|D|LTE mode not found, error code: -22␊ 30.288|sysworkq|lte_lc|D|Dispatching event: type=0␊ 30.288|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 30.288|sysworkq|lte_lc|D|Done␊ 30.288|sysworkq|lte_lc|D|Dispatching event: type=4␊ 30.288|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 30.288|sysworkq|lte_lc|D|Done␊ 30.288|sysworkq|lte_lc|D|Dispatching event: type=5␊ 30.288|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 30.289|sysworkq|lte_lc|D|Done␊ 30.388|sysworkq|lte_lc|D|%MDMEV notification␊ 30.388|sysworkq|lte_lc|D|Occurrence found: SEARCH STATUS 2␍␊ 30.388|sysworkq|lte_lc|D|Dispatching event: type=11␊ 30.388|sysworkq|lte_lc|D| - handler=0x0002E42D␊ 30.388|sysworkq|lte_lc|D|Done␊
Do you have any idea on what would be causing this failure? It happens on or after the AES key thing (second 30 in the log).
