Bug #4335: Unexpected/malformed data from SIM applet causes simtrace2-sniff to stop until simtrace2 board is reset - SIMtrace 2 - Open Source Mobile Communications

Actions

Copy link

#1

Updated by laforge over 4 years ago

Related to Bug #4331: simtrace2 firmware fails to zend zero-length packet on IN endpoint if transfer size == wMaxPacketSize added

Actions

Copy link

#2

Updated by laforge over 4 years ago

Related to Bug #4329: IN endpoint gets stuck during USB suspend added

Actions

Copy link

#3

Updated by laforge over 4 years ago

Assignee set to laforge

many problems in the simtrace2 firmware have been fixed in recent days. As of today, we've reached 7.0.36, including fixes for bugs #4331 and #4329. Maybe you can re-try with a more recent firmware?

If that doesn't help, I think it's going to be very hard to debug for anyone who doesn't have the specific setup in which this can be reproduced.

Do you happen to have a serial console cable for the SIMtrace2 to get serial debug/uart output? It's an osmocom-style serial cable with 2.54mm plug, see https://osmocom.org/projects/baseband/wiki/Serial_Cable

Actions

Copy link

#4

Updated by rbeiter over 4 years ago

Thank you, laforge - I'm going to try the updated firmware now.

I don't have one of the cables, but I do have a serial/usb interface handy. I can solder a header onto the board and attach to that easily. Anything special to be done to get additional debug output there or just capture what I see with the latest firmware build?

Do you have access to a u-blox SARA-R410M by chance? I can get you a SIM exhibiting this behavior if the fw update and/or serial capture don't help us.

Actions

Copy link

#5

Updated by rbeiter over 4 years ago

Same result with `0.7.0.36-56360`. Working on finding some headers here to solder on, otherwise will be able to get that debug output later in the evening my time.

Actions

Copy link

#6

Updated by laforge over 4 years ago

On Tue, Dec 17, 2019 at 04:00:31PM +0000, rbeiter [REDMINE] wrote:

Thank you, laforge - I'm going to try the updated firmware now.

let me know how things go.

I don't have one of the cables, but I do have a serial/usb interface handy. I can solder a header onto the board and attach to that easily.

please note that it's a UART at 3.3V. You cannot attach 9-12V RS232 signal levels to it.

Anything special to be done to get additional debug output there or just capture what I see with the latest firmware build?

The existing output might already be useful, but we also could possibly add additional debug output in custom builds of the firmware.

Do you have access to a u-blox SARA-R410M by chance?

We have no u-blox modems here, sorry. Only Fibocom, Gemalto, Quectel, SIMcom, Huawei, and various old Ericsson, Siemens, ....

I can get you a SIM exhibiting this behavior if the fw update and/or serial capture don't help us.

Thanks for the offer, but I'm sorry but I currently don't have the time to work on this anyway :/

Actions

Copy link

#7

Updated by rbeiter over 4 years ago

Hi laforge,

I completely understand, just wanted to extend the offer. Thank you for all of your hard work on this great tool!

I was able to get serial console output and it might be useful:


=============================================================================
SIMtrace2 firmware 0.7.0.36-56360 (C) 2010-2016 by Harald Welte
=============================================================================
-I- Chip ID: 0x28900960 (Ext 0x00000000)
-I- Serial Nr. <redacted>
-I- Reset Cause: 0x4
-I- USB configuration used: 1
-I- USB init...
USBD_Init

=============================================================================
SIMtrace2 firmware 0.7.0.36-56360 (C) 2010-2016 by Harald Welte
=============================================================================
-I- Chip ID: 0x28900960 (Ext 0x00000000)
-I- Serial Nr. <redacted>
-I- Reset Cause: 0x4
-I- USB configuration used: 1
-I- USB init...
USBD_Init
SetAddr(16) -W- Sta 0x888A8 [0] -W- _ -W- Sta 0x888A8 [0] -W- _ -W- Sta 0x888A8 [0] -W- _ SetCfg(1) cfgChanged1 -I- calling configur
e of all configurations...
-I- Sniffer config
-I- calling init of config 1...
-I- Sniffer Init
-I- entering main loop...
-I- USB is now configured
-I- Changed to ISO 7816-3 state 1
reset de-asserted
'nknown command '
-W- Sta 0x88828 [0] -W- _ -I- WT updated to 9600 ETU
-I- Changed to ISO 7816-3 state 0
reset asserted
-I- Changed to ISO 7816-3 state 1
reset de-asserted
-I- Changed to ISO 7816-3 state 2
ATR: 3b 9e 96 80 1f c7 80 31 e0 73 fe 21 1b 66 d0 02 2a e8 13 00 d3 
-I- Changed to ISO 7816-3 state 3
-I- Changed to ISO 7816-3 state 5

< .... >

TPDU: 00 b0 00 00 ff 13 00 14 c0 80 62 f2 30 c0 81 64 f0 00 c0 82 27 f2 70 c0 83 63 f3 10 c0 84 05 f5 20 c0 85 32 f2 50 c0 86 32 f2 01 c0 87 63 f4 94 c0 88 37 f6 10 c0 89 27 f4 60 c0 90 27 f4 01 c0 91 27 f4 11 c0 92 27 34 27 c0 93 03 02 23 c0 94 37 f0 20 c0 95 37 f0 70 c0 96 17 f2 40 c0 97 12 f9 01 c0 98 32 f0 30 c0 99 32 f8 02 c1 00 32 f8 66 c1 01 07 f6 40 c1 02 42 f8 10 c1 03 42 f8 20 c1 04 42 f4 19 c1 05 42 f4 63 c1 06 02 f8 20 c1 07 02 f8 10 c1 08 62 f2 30 c1 09 02 f2 41 c1 10 07 f4 30 c1 11 54 f4 30 c1 12 54 f4 60 c1 13 12 f6 07 c1 14 04 f4 29 c1 15 15 f0 80 c1 16 22 f2 01 c1 17 42 f6 10 c1 18 72 f0 10 c1 19 72 f0 77 c1 20 54 f5 10 c1 21 54 f5 30 c1 22 33 04 30 c1 23 33 f4 30 c1 24 02 f4 40 c1 25 35 f0 10 c1 26 17 00 03 c1 27 42 f2 20 c1 28 17 04 20 c1 29 17 f6 60 c1 30 90 00 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

TPDU: 00 b0 00 ff ff 62 f0 60 c1 31 62 f8 10 c1 32 22 f6 10 c1 33 22 f6 01 c1 34 52 f0 10 c1 35 56 f5 10 c1 36 12 f4 40 c1 37 14 f3 20 c1 38 42 f0 10 c1 39 22 f8 10 c1 40 22 f8 20 c1 41 64 f6 29 c1 42 64 f6 98 c1 43 25 f0 00 c1 44 24 f4 30 c1 45 24 f4 20 c1 46 32 f4 02 c1 47 13 00 62 c1 48 47 f8 70 c1 49 34 f4 40 c1 50 72 f6 20 c1 51 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 90 00 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

TPDU: 00 b0 01 fe ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff -E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-E- USART buffer full

ff ff ff ff -E- USART buffer full

-W- USART overrun error

-E- USART buffer full

ff ff ff ff ff ff ff ff ff ff ff-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USART overrun error

-E- USART buffer full

-W- USAR------------------------------------------ ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f-E- USART bu-f ff ff ff ff ff ff -E- Uff ff ff ff ff ff ff f-E- -f ff ff ff ff ff ff ff ff ff ff ff ff 90 00 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

TPDU: 00 b0 02 fd ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 90 00 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-W- invalid SW1 0x21

TPDU (malformed): 00 b0 03 fc ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 61 1e 00 c0 00 00 1e c0 62 1c 82 02 41 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-W- invalid SW1 0x03

TPDU (malformed): 83 02 6f 7b a5 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-W- invalid SW1 0x05

TPDU (malformed): 80 01 71 8a 01 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-W- invalid SW1 0x80

TPDU (malformed): 8b 03 6f 06 08 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

TPDU: 02 00 0c 88 01 68 90 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-W- invalid SW1 0x0c

TPDU (malformed): 00 00 b0 00 00 

-I- Changed to ISO 7816-3 state 3

-I- Changed to ISO 7816-3 state 4

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

-E- TPDU data overflow

<... repeats many times, often oddly in the terminal - device doesn't log any more packets until reset >

Actions

Copy link

#8

Updated by rbeiter over 4 years ago

This is likely not the ideal fix, but this gets us past the buffer overflow and keeps the trace happening:

diff --git a/firmware/libcommon/include/ringbuffer.h b/firmware/libcommon/include/ringbuffer.h
index a6eddc9..23aaa59 100644
--- a/firmware/libcommon/include/ringbuffer.h
+++ b/firmware/libcommon/include/ringbuffer.h
@@ -21,7 +21,7 @@
 #include <stdbool.h>
 #include <sys/types.h>

-#define RING_BUFLEN 512
+#define RING_BUFLEN 1024

 typedef struct ringbuf {
        uint8_t buf[RING_BUFLEN];

The debug uart is excellent, thank you for suggesting checking it!

Actions

Copy link

#9

Updated by laforge over 4 years ago

Assignee changed from laforge to tsaitgaist
% Done changed from 0 to 30

Thanks for reporting back. I'm assigning this to Kevin for further investigation.

The ring buffer overflow IMHO can only happen in one situation: UART characters are received so fast that in beteen the receive interrupts there is not sufficient CPU cycles to actually pull them out of the ring buffer and transfer them over USB.

Once the ring buffer is full, we print an error message [whcih costs time] and we are getting into UART overrun situations.

As there's sufficient RAM, there's nothing wrong by increasing its size. I am very puzzled though, as with T=0 the maximum TPDU size is a few bytes more than 256 bytes, so how can we ever get to overflowing a 512 byte sized ringbuffer? Is the second TPDU following-up so closely back-to-back?

Actions

Copy link

#10

Updated by laforge over 4 years ago

Category set to firmware

Actions

Copy link

#11

Updated by laforge over 4 years ago

I've submitted this change as https://gerrit.osmocom.org/c/simtrace2/+/16919

I'm not very happy about not being able to reproduce this (and hence not understanding why we need such a large buffer in your specific scenario), but as it's unlikely to hurt, let's get this merged.

Actions

Copy link

#12