`relay_slave.py` fails to start advertisement 9/10 times

[XenoKovah]

I'm testing with both relay master & slave on the same box, and explicitly passing /dev/ttyUSB0 to master & ttyUSB1 to slave, with 1.11.0 firmware on both Sonoff dongles.

python3 ./relay_master.py -m d7:0e:a3:14:18:79 -P -q -o test_relay_on_MOVE_new_fw.pcap -s /dev/ttyUSB0
and
python3 ./relay_slave.py -s /dev/ttyUSB1
in a separate tab

At least 9/10 times for me when I start relay_slave.py it doesn't begin advertising (as evidenced by not printing out anything after "Received advertisement and scan response." in the original code, or by the fact it's not printing out packets.)

When I put the following print debugging in, it looks like it's getting to "Got here2" but not "Got here3".

    # advertise to impersonate our target
    print("Got here1")
    hw.cmd_setaddr(advert.AdvA, bool(advert.TxAdd))
    hw.cmd_adv_interval(200) # approx 200ms advertising interval
    adv_data = advert.body[8:]
    scan_rsp_data = scan_rsp.body[8:]
    print("Got here2")
    hw.cmd_follow(True) # accept connections
    hw.mark_and_flush()
    print("Got here3")
    hw.cmd_advertise(adv_data, scan_rsp_data)
    print("Got here4")

user@BTVM:~/class/Sniffle/python_cli$ python3 ./relay_slave.py -s /dev/ttyUSB1
Connected to master.
Waiting for advertisement and scan response...
Received advertisement and scan response.
Got here1
Got here2

And then in the rare case where I do get it to start advertising (after just retrying a bunch of time), when the legitimate Central (an Android phone) connects to the relay slave (as evidenced by the relay_slave.py starting to print out empty packets, and also a 3rd Sonoff dongle catching the same connection), the only thing I see are empty packets until it times out. The Central seems to send an LL_FEATURE_REQ as its first packet (according to the 3rd dongle pcap, it's not actually captured in the pcap from the relay_master.py -o option!), and then it never gets a reply and never attempts to retransmit it, so the connection just times out after 30s or so.

Also I should note that I physically power off and power on the Sonoffs (in case the firmware's stuck or something) but it didn't seem to affect the success rate of starting advertisements.

Is it possible the Sonoffs are less reliable for the beginning of advertisement than the TI dev boards which you presumably used during testing?

[Haicaji]

I have the same problem, but I use TI dev.
However, I found that commenting out "mark_and_flush()" does not affect the send/receive functionality, and this applies to both relay_master.py and relay_slave.py.
I'm not sure, but I think it could be a potential cause. The same TI device seems to not have this issue on the Raspberry Pi, but it often occurs in the VMware virtual machine on Windows (by the way, Windows doesn't support Bluetooth relay functionality).

[sultanqasim]

I'm not sure why it's failing for you so often, though I think I've encountered this failure mode myself once or twice. My guess is that mark_and_flush fails due to UART receive buffers being full of stale junk, causing the fresh marker message to be lost. I'll see what I can do to avoid this.

[sultanqasim]

Ah, I think I know what's happening. The scripts set up the hardware to sniff advertising when we don't need them, and UART receive buffers fill up with advertisements while waiting for the other side of the relay. The busier the BLE advertising environment, the more likely the buffers are to fill up. The commit 49acf5f should fix this, though I'll wait for you let me know it works before I close this.