Unhandled exception in `relay_slave.py`: OSError: Received empty chunk!

[XenoKovah]

I was testing the relay code against a free fitness tracker that I got, which has no screen and therefore is required to interact with an Android app. I got the following errors in 3/3 tests. (2 with --fastslave --fastmaster and 1 without.)

Also, I'm testing with Sonoffs, and the first 3 tests I hadn't updated the firmware to the 1.11.0 release, but then I did 2 more tests after updating them (both with --fastslave --fastmaster), and I still got the same basic error.

Launched relay_master.py with:

user@BTVM:~/class/Sniffle/python_cli$ python3 ./relay_master.py -m d7:0e:a3:14:18:79 -P -q --fastslave --fastmaster -o test_relay_on_MOVE.pcap
Waiting for relay slave to connect...
Got connection from 127.0.0.1
Round trip latency: 0.1 ms
Found advertisement.
Found scan response.
Target Advertisement:
Timestamp: 1.186744  Length: 38  RSSI: -49  Channel: 37  PHY: 1M  CRC: 0x40EA78
Ad Type: ADV_IND
ChSel: 1 TxAdd: 0 RxAdd: 0 Ad Length: 36
AdvA: d7:0e:a3:14:18:79 (Public)
0x0000:  20 24 79 18 14 a3 0e d7  1d ff f8 f7 22 08 03 02   $.........."...
0x0010:  02 07 cb 13 00 00 00 00  00 00 00 61 01 3f 00 00  ...........a.?..
0x0020:  00 00 00 00 00 00                                 ......

Target Scan Response:
Timestamp: 1.187589  Length: 32  RSSI: -49  Channel: 37  PHY: 1M  CRC: 0x0C27C2
Ad Type: SCAN_RSP
ChSel: 0 TxAdd: 0 RxAdd: 0 Ad Length: 30
AdvA: d7:0e:a3:14:18:79 (Public)
0x0000:  04 1e 79 18 14 a3 0e d7  10 09 4d 4f 56 45 42 32  ..........MOVEB2
0x0010:  41 41 41 41 41 41 41 41  41 02 01 05 03 03 0d 18  AAAAAAAAA.......

Waiting for relay slave to notify us of connection...
Relay slave notified us of connection request. Connecting to real target...
Timestamp: 0.000000  Length: 36  RSSI:   0  Channel: 37  PHY: 1M  CRC: 0xFDCA31
Ad Type: CONNECT_IND
ChSel: 1 TxAdd: 1 RxAdd: 0 Ad Length: 34
InitA: 72:33:9D:76:64:21 (RPA) AdvA: d7:0e:a3:14:18:79 (Public) AA: 0x3A27491C CRCInit: 0x1374C8
WinSize: 2 WinOffset: 23 Interval: 36 Latency: 0 Timeout: 500 Hop: 9 SCA: 0
Channel Map: FF FF FF FF 1F (all channels)
0x0000:  65 22 21 64 76 9d 33 72  79 18 14 a3 0e d7 1c 49  e"!dv.3r.......I
0x0010:  27 3a c8 74 13 02 17 00  24 00 00 00 f4 01 ff ff  ':.t....$.......
0x0020:  ff ff 1f 09                                       ....
Traceback (most recent call last):
  File "/home/user/class/Sniffle/python_cli/./relay_master.py", line 415, in <module>
    main()
  File "/home/user/class/Sniffle/python_cli/./relay_master.py", line 212, in main
    connect_target(mac_bytes, args.advchan, not args.public, connector_addr,
  File "/home/user/class/Sniffle/python_cli/./relay_master.py", line 394, in connect_target
    hw.mark_and_flush()
  File "/home/user/class/Sniffle/python_cli/sniffle/sniffle_hw.py", line 422, in mark_and_flush
    msg = self.recv_and_decode(True)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/class/Sniffle/python_cli/sniffle/sniffle_hw.py", line 383, in recv_and_decode
    mtype, mbody, msg = self._recv_msg(desync)
                        ^^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/class/Sniffle/python_cli/sniffle/sniffle_hw.py", line 322, in _recv_msg
    pkt = self.ser.readline()
          ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/serial/serialposix.py", line 595, in read
    raise SerialException(
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

Launched relay_slave.py with:

user@BTVM:~/class/Sniffle/python_cli$ python3 ./relay_slave.py --help
Connected to master.
Waiting for advertisement and scan response...
Received advertisement and scan response.

<snip SCAN_REQs>

Timestamp: 26.985154  Length: 36  RSSI: -53  Channel: 38  PHY: 1M  CRC: 0xFDCA31
Ad Type: CONNECT_IND
ChSel: 1 TxAdd: 1 RxAdd: 0 Ad Length: 34
InitA: 72:33:9D:76:64:21 (RPA) AdvA: d7:0e:a3:14:18:79 (Public) AA: 0x3A27491C CRCInit: 0x1374C8
WinSize: 2 WinOffset: 23 Interval: 36 Latency: 0 Timeout: 500 Hop: 9 SCA: 0
Channel Map: FF FF FF FF 1F (all channels)
0x0000:  65 22 21 64 76 9d 33 72  79 18 14 a3 0e d7 1c 49  e"!dv.3r.......I
0x0010:  27 3a c8 74 13 02 17 00  24 00 00 00 f4 01 ff ff  ':.t....$.......
0x0020:  ff ff 1f 09                                       ....

Ignoring message due to missing CRLF
Message: b'BBLcnT989EPg==\r\nRA'
Timestamp: 28.143765  Length: 38  RSSI: -48  Channel: 37  PHY: 1M  CRC: 0x40EA78
Ad Type: ADV_IND
ChSel: 1 TxAdd: 0 RxAdd: 0 Ad Length: 36
AdvA: d7:0e:a3:14:18:79 (Public)
0x0000:  20 24 79 18 14 a3 0e d7  1d ff f8 f7 22 08 03 02   $.........."...
0x0010:  02 07 cb 13 00 00 00 00  00 00 00 61 01 3f 00 00  ...........a.?..
0x0020:  00 00 00 00 00 00                                 ......

Traceback (most recent call last):
  File "/home/user/class/Sniffle/python_cli/./relay_slave.py", line 164, in <module>
    main()
  File "/home/user/class/Sniffle/python_cli/./relay_slave.py", line 113, in main
    sock_recv_print_forward(conn)
  File "/home/user/class/Sniffle/python_cli/./relay_slave.py", line 118, in sock_recv_print_forward
    mtype, body = conn.recv_msg()
                  ^^^^^^^^^^^^^^^
  File "/home/user/class/Sniffle/python_cli/sniffle/relay_protocol.py", line 63, in recv_msg
    hdr = recvall(self.sock, 4)
          ^^^^^^^^^^^^^^^^^^^^^
  File "/home/user/class/Sniffle/python_cli/sniffle/relay_protocol.py", line 31, in recvall
    raise IOError("Received empty chunk!")
OSError: Received empty chunk!

[sultanqasim]

The relaying functionality should still work with the 1.10.0 firmware (as the relevant functionality used by the relay scripts has been in the firmware for years), so that shouldn't be the issue. The relay_slave.py script crashed because the relay_master.py script crashed and closed the connection unexpectedly.

Were you running both sides of the relay on the same computer? I don't see you specifying an IP address for the other side, and I didn't see you specifying a serial port in either command. The relay_master and relay_slave scripts need to connect to two separate Sniffle devices, so if there are two connected to the same computer, you need to explicitly specify the serial ports for the two scripts and point them to two different Sniffle devices. I should better document this, and maybe implement something to detect attempts to open a serial port that is already opened and in use by another script.

[XenoKovah]

OK yes you're right, I wasn't using -s and a specific serial port in those tests on the fitness tracker. I just assumed that the relay_master would use the 0th one in the list and the relay_slave the 1th one. I think this also explains why I saw different behavior when testing with my class teaching tool UltraVulnerablCentral/Peripheral combo, where I was using -s, which then I didn't submit yet since I was at a loss to explain why they were behaving so differently. When I start using -s then I no longer see this error. But I'll submit a different issue for what I see when I use -s.

So I'm going to leave this open to track documenting that -s is required on a single-host setup, if you want to. Otherwise you can feel free to close this and chalk it up to user error.