Project

General

Profile

Bug #4742

TPDU failure in 00a20104020000

Added by laforge 18 days ago. Updated 9 days ago.

Status:
New
Priority:
High
Assignee:
Target version:
-
Start date:
09/02/2020
Due date:
% Done:

20%

Spec Reference:

Description

[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:761 Rx RSPRO tpduModemToCard
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:701 tpduModemToCard(00a40004024f09)
[001 CONN_CLIENT_MAPPED_CARD] bankd_pcsc.c:221 : OK
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:727 tpduModemToCard response from card: 6124
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:761 Rx RSPRO tpduModemToCard
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:701 tpduModemToCard(00c0000024)
[001 CONN_CLIENT_MAPPED_CARD] bankd_pcsc.c:221 : OK
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:727 tpduModemToCard response from card: 6222820542210002fa83024f09a506c00100ca01808a01058b036f0605800201f48801209000
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:761 Rx RSPRO tpduModemToCard
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:701 tpduModemToCard(00a20104020000)
[001 CONN_CLIENT_MAPPED_CARD] bankd_pcsc.c:221 SCardTransmit: Transaction failed. (0x80100016)
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:882 Error handling RSPRO
[001 CONN_CLIENT_MAPPED_CARD] bankd_main.c:960 Error -2146435050 occurred: Cleaning up state

this happens reproducibly when using an EC20 via osmo-remsim with a sysmoUSIM-SJS1 in a sysmoOCTSIM.

Yet to be determined why.

History

#1 Updated by laforge 18 days ago

INS=A2 is a "SEEK" command.

File 4f09 is EF_PBC in DF_PHONEBOOK (5F3A) beneath DF_TELECOM (7F10).

I can confirm the problem when manually executing the followng sequence:

(ISO 7816-4) > 00a40004023f00
--------------------------------------------------------------------------------
Beginning transaction 4
>> 0000:  00 a4 00 04 02 3f 00                              .....?.         
<< 0000:  61 56                                             aV              
>> 0000:  00 c0 00 00 56                                    ....V           
<< 0000:  62 54 82 02 78 21 83 02 3f 00 a5 19 80 01 71 83   bT..x!..?.....q.
   0010:  02 7f ff cb 0d 00 00 00 00 00 00 00 00 00 00 00   ................
   0020:  00 00 ca 01 82 8a 01 05 ab 1b 84 01 2e 90 00 84   ................
   0030:  01 88 a4 06 83 01 01 95 01 08 84 01 fc a4 06 83   ................
   0040:  01 0a 95 01 08 c6 0f 90 01 70 83 01 01 83 01 0a   .........p......
   0050:  83 01 0b 83 01 81 90 00                           ........        
Ending transaction 4
--------------------------------------------------------------------------------

0000:  62 54 82 02 78 21 83 02 3f 00 a5 19 80 01 71 83   bT..x!..?.....q.
0010:  02 7f ff cb 0d 00 00 00 00 00 00 00 00 00 00 00   ................
0020:  00 00 ca 01 82 8a 01 05 ab 1b 84 01 2e 90 00 84   ................
0030:  01 88 a4 06 83 01 01 95 01 08 84 01 fc a4 06 83   ................
0040:  01 0a 95 01 08 c6 0f 90 01 70 83 01 01 83 01 0a   .........p......
0050:  83 01 0b 83 01 81                                 ......          
Normal execution (SW 9000), 0.0431s
(ISO 7816-4) > 00a40004027f10
--------------------------------------------------------------------------------
Beginning transaction 5
>> 0000:  00 a4 00 04 02 7f 10                              .......         
<< 0000:  61 32                                             a2              
>> 0000:  00 c0 00 00 32                                    ....2           
<< 0000:  62 30 82 02 78 21 83 02 7f 10 a5 16 83 02 7f ff   b0..x!..........
   0010:  cb 0d 00 00 00 00 00 00 00 00 00 00 00 00 00 ca   ................
   0020:  01 82 8a 01 05 8b 03 2f 06 01 c6 06 90 01 00 83   ......./........
   0030:  01 01 90 00                                       ....            
Ending transaction 5
--------------------------------------------------------------------------------

0000:  62 30 82 02 78 21 83 02 7f 10 a5 16 83 02 7f ff   b0..x!..........
0010:  cb 0d 00 00 00 00 00 00 00 00 00 00 00 00 00 ca   ................
0020:  01 82 8a 01 05 8b 03 2f 06 01 c6 06 90 01 00 83   ......./........
0030:  01 01                                             ..              
Normal execution (SW 9000), 0.0359s
(ISO 7816-4) > 00a40004025F3A
--------------------------------------------------------------------------------
Beginning transaction 7
>> 0000:  00 a4 00 04 02 5f 3a                              ....._:         
<< 0000:  61 32                                             a2              
>> 0000:  00 c0 00 00 32                                    ....2           
<< 0000:  62 30 82 02 78 21 83 02 5f 3a a5 16 83 02 7f ff   b0..x!.._:......
   0010:  cb 0d 00 00 00 00 00 00 00 00 00 00 00 00 00 ca   ................
   0020:  01 80 8a 01 05 8b 03 6f 06 02 c6 06 90 01 00 83   .......o........
   0030:  01 01 90 00                                       ....            
Ending transaction 7
--------------------------------------------------------------------------------

0000:  62 30 82 02 78 21 83 02 5f 3a a5 16 83 02 7f ff   b0..x!.._:......
0010:  cb 0d 00 00 00 00 00 00 00 00 00 00 00 00 00 ca   ................
0020:  01 80 8a 01 05 8b 03 6f 06 02 c6 06 90 01 00 83   .......o........
0030:  01 01                                             ..              
Normal execution (SW 9000), 0.0345s
(ISO 7816-4) > 00a40004024f09
--------------------------------------------------------------------------------
Beginning transaction 9
>> 0000:  00 a4 00 04 02 4f 09                              .....O.         
<< 0000:  61 24                                             a$              
>> 0000:  00 c0 00 00 24                                    ....$           
<< 0000:  62 22 82 05 42 21 00 02 fa 83 02 4f 09 a5 06 c0   b"..B!.....O....
   0010:  01 00 ca 01 80 8a 01 05 8b 03 6f 06 05 80 02 01   ..........o.....
   0020:  f4 88 01 20 90 00                                 ... ..          
Ending transaction 9
--------------------------------------------------------------------------------

0000:  62 22 82 05 42 21 00 02 fa 83 02 4f 09 a5 06 c0   b"..B!.....O....
0010:  01 00 ca 01 80 8a 01 05 8b 03 6f 06 05 80 02 01   ..........o.....
0020:  f4 88 01 20                                       ...             
Normal execution (SW 9000), 0.0338s
(ISO 7816-4) > 00a20104020000
--------------------------------------------------------------------------------
Beginning transaction 10
>> 0000:  00 a2 01 04 02 00 00                              .......         
<class 'smartcard.Exceptions.CardConnectionException'>: Failed to transmit with protocol T0. Transaction failed.
  File "/space/home/laforge/projects/git/cyberflex-shell/shell.py", line 126, in _run

#2 Updated by laforge 18 days ago

the ISO7816-3 FSM goes into the RESET state and gets stuck there:

ISO7816 ERROR <0002> ../ccid_common/iso7816_fsm.c:214 ISO7816-3(SIM2)[0x200140a0]{RESET}: Event UART_RX_SINGLE not permitted
ISO7816 ERROR <0002> ../ccid_common/iso7816_fsm.c:214 ISO7816-3(SIM2)[0x200140a0]{RESET}: Event UART_RX_SINGLE not permitted

even re-starting the client program doesn't help:

ISO7816 ERROR <0002> ../ccid_common/ccid_slot_fsm.c:286 ISO7816-3(SIM2)[0x200140a0]{RESET}: Event XCEIVE_TPDU_CMD not permitted
</pr>

#3 Updated by laforge 18 days ago

  • % Done changed from 0 to 10

It turns out the waiting time expires, i.e. CUART_E_RX_TIMEOUT is received and delivered as ISO7816_E_WTIME_EXP to the ISO7816-3 FSM which then transitions to RESET state.

The ISO7816-3 FSM is in IN_TPDU state, and the TPDU FSM is in SW1 state, i.e. waiting for the status word. As we receive two RX_SINGLE events after going into RESET, I think the timeout expires prematurely in this case? Either our timeout is too short regarding the spec, or the card is slower than specified?

#4 Updated by laforge 18 days ago

  • % Done changed from 10 to 20

Extending the waiting time by 1s (as a hack) seems to work:

(ISO 7816-4) > 00a20104020000
--------------------------------------------------------------------------------
Beginning transaction 4
>> 0000:  00 a2 01 04 02 00 00                              .......         
<< 0000:  61 fa                                             a.              
>> 0000:  00 c0 00 00 fa                                    .....           
<< 0000:  01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10   ................
   0010:  11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20   ............... 
   0020:  21 22 23 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f 30   !"#$%&'()*+,-./0
   0030:  31 32 33 34 35 36 37 38 39 3a 3b 3c 3d 3e 3f 40   123456789:;<=>?@
   0040:  41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f 50   ABCDEFGHIJKLMNOP
   0050:  51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60   QRSTUVWXYZ[\]^_`
   0060:  61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70   abcdefghijklmnop
   0070:  71 72 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f 80   qrstuvwxyz{|}~..
   0080:  81 82 83 84 85 86 87 88 89 8a 8b 8c 8d 8e 8f 90   ................
   0090:  91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f a0   ................
   00a0:  a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0   ................
   00b0:  b1 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0   ................
   00c0:  c1 c2 c3 c4 c5 c6 c7 c8 c9 ca cb cc cd ce cf d0   ................
   00d0:  d1 d2 d3 d4 d5 d6 d7 d8 d9 da db dc dd de df e0   ................
   00e0:  e1 e2 e3 e4 e5 e6 e7 e8 e9 ea eb ec ed ee ef f0   ................
   00f0:  f1 f2 f3 f4 f5 f6 f7 f8 f9 fa 90 00               ............    
Ending transaction 4
--------------------------------------------------------------------------------

0000:  01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10   ................
0010:  11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20   ............... 
0020:  21 22 23 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f 30   !"#$%&'()*+,-./0
0030:  31 32 33 34 35 36 37 38 39 3a 3b 3c 3d 3e 3f 40   123456789:;<=>?@
0040:  41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f 50   ABCDEFGHIJKLMNOP
0050:  51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60   QRSTUVWXYZ[\]^_`
0060:  61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70   abcdefghijklmnop
0070:  71 72 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f 80   qrstuvwxyz{|}~..
0080:  81 82 83 84 85 86 87 88 89 8a 8b 8c 8d 8e 8f 90   ................
0090:  91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f a0   ................
00a0:  a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0   ................
00b0:  b1 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0   ................
00c0:  c1 c2 c3 c4 c5 c6 c7 c8 c9 ca cb cc cd ce cf d0   ................
00d0:  d1 d2 d3 d4 d5 d6 d7 d8 d9 da db dc dd de df e0   ................
00e0:  e1 e2 e3 e4 e5 e6 e7 e8 e9 ea eb ec ed ee ef f0   ................
00f0:  f1 f2 f3 f4 f5 f6 f7 f8 f9 fa                     ..........      
Normal execution (SW 9000), 0.336s

#5 Updated by laforge 18 days ago

with that artificial 1s WTIME extension, I am getting the EC20 + sysmoUSIM fully bootstrapped:


+CPIN: READY

+QUSIM: 1

+QIND: SMS DONE

+QIND: PB DONE

#6 Updated by Hoernchen 10 days ago

I've just tried to reproduce this, but I can't - it just works for me...

#7 Updated by Hoernchen 10 days ago

That is with the cyberflex shell and the octsim itself, no modem involved - and at least after looking at the fsms I can't see why it would fail either. That being said the minimum timeout value can safely be increased to any kind of value, since expected timeouts are only going to happen during powerup with wrong voltages for old 5v cards and during ATR reading with arcane tail bytes.

#8 Updated by laforge 10 days ago

for the record, there's a patch available at https://gerrit.osmocom.org/c/osmo-ccid-firmware/+/19952/3

If it only happens on my system, I don't think it's worth to merge it. I guess we'd need more samples from people with other computers/kernels/distributions/...

#9 Updated by Hoernchen 10 days ago

There was maybe a slight miscalculation involved, so probably fixed by https://gerrit.osmocom.org/c/osmo-ccid-firmware/+/20071 even though I never ran into any issues.

#10 Updated by laforge 9 days ago

On Thu, Sep 10, 2020 at 11:05:11PM +0000, Hoernchen [REDMINE] wrote:

There was maybe a slight miscalculation involved, so probably fixed by https://gerrit.osmocom.org/c/osmo-ccid-firmware/+/20071 even though I never ran into any issues.

thanks, I'll try to reproduce the problem on the old firmware first and then try your patch.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)