USB Serial input buffer contains junk shortly after boot.
-
Apologies in advance; this is a strange error and at first I thought I was imagining it. So I want to post it here before raising a GitHub issue since I'm curious to see if anyone else can reproduce. Especially other Duet2 owners.
I've got a Duet 2 WiFi/Ethernet board that I upgraded to 3.4.x recently, it is connected to a Raspberry Pi via USB, the Pi runs a fully updated Bullseye release.
The board's input buffer appears to be initialised improperly following a reboot, and can contain junk.
- If the first USB serial input is sent after the WiFi connects then a fragment of the WiFi connection message is pre-pended to the input, causing an error in response to the first command sent (see example below)
My initial reaction was that it must be some super-quirky effect from my PrintEye, but this persists even once I had the PrintEye physically unplugged and all it's config commented out.
Currently my config initialises the USB serial port with the default:
M575 P0 S2Here is a log to show what I mean, sorry it is a bit long but I wanted to put the
m122outputs in full here.I connect via miniterm from the attached Pi to the Duet2 immediately after rebooting it and before WiFi has been established:
(env) owen@transmog:~/miniterm $ pyserial-miniterm --echo --eol CR /dev/ttyACM0 --- Miniterm on /dev/ttyACM0 9600,8,N,1 --- --- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H --- <pause while wifi completes connecting> WiFi module is connected to access point TINKERBEL, IP address 10.0.0.30I then send 'm122', and get back debug info as expected:
m122 === Diagnostics === RepRapFirmware for Duet 2 WiFi/Ethernet version 3.4.2rc1 (2022-07-06 16:21:02) running on Duet WiFi 1.02 or later Board ID: <snip> Used output buffers: 1 of 26 (2 max) === RTOS === Static ram: 23860 Dynamic ram: 74592 of which 0 recycled Never used RAM 13628, free system stack 193 words Tasks: NETWORK(ready,8.9%,267) HEAT(notifyWait,0.0%,339) Move(notifyWait,0.0%,363) MAIN(running,84.3%,454) IDLE(ready,6.8%,30), total 100.0% Owned mutexes: WiFi(NETWORK) USB(MAIN) === Platform === Last reset 00:00:13 ago, cause: software Last software reset at 2022-08-13 13:21, reason: User, GCodes spinning, available RAM 13628, slot 1 Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a Error status: 0x00 Aux0 errors 0,0,0 Step timer max interval 0 MCU temperature: min 36.0, current 37.4, max 37.6 Supply voltage: min 2.1, current 2.6, max 2.6, under voltage events: 0, over voltage events: 0, power good: no Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0 Events: 0 queued, 0 completed Driver 0: ok, SG min n/a Driver 1: ok, SG min n/a Driver 2: ok, SG min n/a Driver 3: ok, SG min n/a Driver 4: ok, SG min n/a Driver 5: Driver 6: Driver 7: Driver 8: Driver 9: Driver 10: Driver 11: Date/time: 1970-01-01 00:00:00 Cache data hit count 597476626 Slowest loop: 10.05ms; fastest: 0.13ms I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0 === Storage === Free file entries: 9 SD card 0 detected, interface speed: 20.0MBytes/sec SD card longest read time 0.9ms, write time 3.9ms, max retries 0 === Move === DMs created 83, segments created 0, maxWait 0ms, bed compensation in use: none, comp offset 0.000 === MainDDARing === Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1 === AuxDDARing === Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1 === Heat === Bed heaters 0 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0 === GCodes === Segments left: 0 Movement lock held by null HTTP is idle in state(s) 0 Telnet is idle in state(s) 0 File is idle in state(s) 0 USB is ready with "m122" in state(s) 0 Aux is idle in state(s) 0 Trigger is idle in state(s) 0 Queue is idle in state(s) 0 LCD is idle in state(s) 0 Daemon is idle in state(s) 0 Autopause is idle in state(s) 0 Code queue is empty === Network === Slowest loop: 16.40ms; fastest: 0.00ms Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0), 0 sessions HTTP sessions: 0 of 8 - WiFi - Network state is active WiFi module is connected to access point Failed messages: pending 0, notready 0, noresp 0 WiFi firmware version 1.26 WiFi MAC address 60:01:94:33:8b:8c WiFi Vcc 3.40, reset reason Power up WiFi flash size 4194304, free heap 26240 WiFi IP address 10.0.0.30 WiFi signal strength -47dBm, mode 802.11n, reconnections 0, sleep mode modem Clock register 00002002 Socket states: 0 0 0 0 0 0 0 0 okI now send
m199to reset/reboot the board (causing miniterm to exit as the USB is dropped):m999 T0:32.3 /0.0 B:27.5 /0.0 (miniterm) Exception in thread rx: (miniterm) --- exit ---I now wait for the led's to show me the Wifi has reconnected (eg I wait till after the 'WiFi Module is Connected..' message has been sent).
Then I restart miniterm, send
m122and get an error.(env) owen@transmog:~/miniterm $ pyserial-miniterm --echo --eol CR /dev/ttyACM0 --- Miniterm on /dev/ttyACM0 9600,8,N,1 --- --- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H --- m122 Error: Bad command: WiFi module is com122 okNote the error message: '
Error: Bad command: WiFi module is com122'- So the input the firmware received is
'WiFi module is co'(the first 17 characters of the WiFi Connected message) concatenated with the command I sent:'m122'. - I looks to me as if the input buffer initialisation is incorrect or incomplete; and the default input buffer gets allocated somewhere that already has a fragment of another buffer in it.
This is a one-off error that follows the reset; subsequent commands are processed as expected.
m115 FIRMWARE_NAME: RepRapFirmware for Duet 2 WiFi/Ethernet FIRMWARE_VERSION: 3.4.2rc1 ELECTRONICS: Duet WiFi 1.02 or later FIRMWARE_DATE: 2022-07-06 16:21:12 okThe Pi is a Model3 B+ running Bullseye and fully updated:
(env) owen@transmog:~/miniterm $ python -m pip list pyserial pyserial 3.5 (env) owen@transmog:~/miniterm $ uname -a Linux transmog 5.15.56-v7+ #1575 SMP Fri Jul 22 20:28:11 BST 2022 armv7l GNU/LinuxCan anybody reproduce this? It's pretty minor but has caused me some issues due to my setup.
- I realise that this could also be something Pi specific, so I am curious to see if it also happens to people using other connection solutions.
tl;dr
I noticed this when I connected the board to a default-configured octoprint installation; by default octoprint sends am122to detect firmware, but also always responds to any error with am199. This resuts in a sort of 'connect loop' where you attempt to connect from OctoPrint, it sendsm122, sees the error and reboots the board, then waits for the user to re-try the connection. Putting you in a loop as the error repeats with a reboot on every connect attempt.I have re-configured Octoprint to not be so aggressive with the
m199when it encounters errors to work-around this. I use DWC for most operations anyway, but find OctoPrint handy for actual printing (especially it's time-lapse abilities).
