-
Notifications
You must be signed in to change notification settings - Fork 22
SMPBadSequence with expected > actual should trigger a transport "flush" #104
Description
So I'm playing with timeouts while implementing a tailored subset of smpmgr with retries (got bored of restarting an upload 3-4 times because a UDP packet is dropped). The timeout I set on upload is 1s, and on the last chunk of the firmware image it takes more than that to get a reply (I'm guessing a flash operation, or a checksum is computed). This leads to a timeout in upload, and yet the UDP socket gets the response. When I go to retry the upload I'm now stuck because the sequence number will always be 1 behind (we're reading the previous request's response from the UDP socket).
I was thinking about adding _transport.receive() calls in SMPClient::request when the expected sequence number is higher than the actual. Any thoughts about this?
2026-04-04 16:13:48,696 DEBUG smpclient.transport.udp Sending 464 B
2026-04-04 16:13:48,696 DEBUG smpclient.transport.udp Sent 464 B
2026-04-04 16:13:48,696 DEBUG smpclient.transport.udp Awaiting data
2026-04-04 16:13:48,937 DEBUG smpclient.transport._udp_client 18 B datagram received from ('fd76:4e9:11e1:1:e09a:296c:3689:821c', 1337, 0, 0)
2026-04-04 16:13:48,937 DEBUG smpclient.transport.udp Received 18 B
2026-04-04 16:13:48,937 DEBUG smpclient.transport.udp Received header=Header(op=<OP.WRITE_RSP: 3>, version=<Version.V2: 1>, flags=<Flag.UNUSED: 0>, length=10, group_id=1, sequence=192, command_id=1)
2026-04-04 16:13:48,937 DEBUG smpclient.transport.udp Finished receiving message of length 18 B
2026-04-04 16:13:48,938 INFO __main__ Upload progress: 587597/587872 bytes
2026-04-04 16:13:48,938 DEBUG smpclient.transport.udp Sending 301 B
2026-04-04 16:13:48,938 DEBUG smpclient.transport.udp Sent 301 B
2026-04-04 16:13:48,938 DEBUG smpclient.transport.udp Awaiting data
2026-04-04 16:13:49,939 ERROR smpclient Timeout (1.0s) waiting for request header=Header(op=<OP.WRITE: 2>, version=<Version.V2: 1>, flags=<Flag.UNUSED: 0>, length=293, group_id=<GroupId.IMAGE_MANAGEMENT: 1>, sequence=193, command_id=<ImageManagement.UPLOAD: 1>) version=<Version.V2: 1> sequence=193 smp_data=b'\n\x00\x01%\x00\x01\xc1\x01\xa2coff\x1a\x00\x08\xf7MddataY\x01\x13\xe5\x83;#\xc2\x9f\x93Y=\x00\x01\x8c\xfa\x99\x94 \x00\x00\x01E\x07\x9c\x063\xa0b\xb4\xa8!\xa1\x10\xf5?\x85\xb5X\xce\xd2\xcd\x9cy\x8e\xaa\xf9\x16\xe5\xdb\xaa\xea\xccp\xb4\xf7\xed~\n\x98\x83pT\xca>\xf3|E\xc1d\xbf\xbe6)\x05\xd5\x1bf\xe9~+w\xd0\xd5]\xc0*\xe8W\xb1\xaf\xbd\x1c\x80\x18\xbfZn\xaf\x93a^\x9aV\xc5\xe1\x98\x85\xe86~@\xdc\xc6\xe0\xb6\x02\xec\xd2^E\xdb\xbc\x8a/\x04o\x14\xc6k\xb8\xc5\x05\xcb\xb9\xfc\xef"\x8b\x81"\xf4\xc4\xd2Px\xd3\xbc\x92\x9b\xc0\xa6\xfb\xf6\xeb)\xed\x86\xd1\xd4\xd7\x16\xa4?\xe5j\x843k\x94\xbb\x00/\xb6Q\xaa>\xce\xd6+\rM\x11=y\x19\xcb\xf1\xc99s\x9e\xafE\xe0\xf0\x14\xb6D\x08\xe0Z*\xee\r\xaa\x06\xc9K\xbe\xf1r\xd5\x05\x08\xbbh\x00.\xce\xce\x99\xcd\xcc\xaa\x8e\xf4-\x19@v\xcd\x98\xc0\xec(\xacr\xbd\xe0\x13m\xb0x\xad\xf3K;!{i\xcd\xae\xe5\xb3\x147\xe5\xcb\x96\xbcZ\x99\xec\xd0f\xfd!\xc8U\xa2\xfa\xe8\x032\xd2\xae\x07' off=587597 data=b'\xe5\x83;#\xc2\x9f\x93Y=\x00\x01\x8c\xfa\x99\x94 \x00\x00\x01E\x07\x9c\x063\xa0b\xb4\xa8!\xa1\x10\xf5?\x85\xb5X\xce\xd2\xcd\x9cy\x8e\xaa\xf9\x16\xe5\xdb\xaa\xea\xccp\xb4\xf7\xed~\n\x98\x83pT\xca>\xf3|E\xc1d\xbf\xbe6)\x05\xd5\x1bf\xe9~+w\xd0\xd5]\xc0*\xe8W\xb1\xaf\xbd\x1c\x80\x18\xbfZn\xaf\x93a^\x9aV\xc5\xe1\x98\x85\xe86~@\xdc\xc6\xe0\xb6\x02\xec\xd2^E\xdb\xbc\x8a/\x04o\x14\xc6k\xb8\xc5\x05\xcb\xb9\xfc\xef"\x8b\x81"\xf4\xc4\xd2Px\xd3\xbc\x92\x9b\xc0\xa6\xfb\xf6\xeb)\xed\x86\xd1\xd4\xd7\x16\xa4?\xe5j\x843k\x94\xbb\x00/\xb6Q\xaa>\xce\xd6+\rM\x11=y\x19\xcb\xf1\xc99s\x9e\xafE\xe0\xf0\x14\xb6D\x08\xe0Z*\xee\r\xaa\x06\xc9K\xbe\xf1r\xd5\x05\x08\xbbh\x00.\xce\xce\x99\xcd\xcc\xaa\x8e\xf4-\x19@v\xcd\x98\xc0\xec(\xacr\xbd\xe0\x13m\xb0x\xad\xf3K;!{i\xcd\xae\xe5\xb3\x147\xe5\xcb\x96\xbcZ\x99\xec\xd0f\xfd!\xc8U\xa2\xfa\xe8\x032\xd2\xae\x07' image=None len=None sha=None upgrade=None
2026-04-04 16:13:49,939 WARNING __main__ Attempt 8/16 – timeout at offset 587597/587872, retrying
2026-04-04 16:13:49,940 DEBUG smpclient.transport.udp Sending 464 B
2026-04-04 16:13:49,940 DEBUG smpclient.transport.udp Sent 464 B
2026-04-04 16:13:49,940 DEBUG smpclient.transport.udp Awaiting data
2026-04-04 16:13:50,849 DEBUG smpclient.transport._udp_client 25 B datagram received from ('fd76:4e9:11e1:1:e09a:296c:3689:821c', 1337, 0, 0)
2026-04-04 16:13:50,850 DEBUG smpclient.transport.udp Received 25 B
2026-04-04 16:13:50,850 DEBUG smpclient.transport.udp Received header=Header(op=<OP.WRITE_RSP: 3>, version=<Version.V2: 1>, flags=<Flag.UNUSED: 0>, length=17, group_id=1, sequence=193, command_id=1)
2026-04-04 16:13:50,850 DEBUG smpclient.transport.udp Finished receiving message of length 25 B
2026-04-04 16:13:50,850 WARNING smpclient Bad sequence 193, expected 194