Make USB ACM firmware upload actually work

Move the handling of USB ACM receive into a separate thread, and do
some hacking around in the driving Perl script. Take out a bunch of
the debugging output. Now it actually seems to work...

esp32/flashesp.pl

@@ -380,23 +380,26 @@ if ($found < 3) {
 }
 
 $start_enq = $tt;
+my $last_req;
 my $winspc;
 while (!defined($winspc)) {
     $tt = time();
     if ($tt - $start_enq >= 10) {
 	die "$0: $port: failed to start FPGA firmware upload\n";
     }
-    tty_write($tty, "\034\001: /// MAX80 FW UPLOAD \~\@\~ \$\r\n\035");
+    if ($tt != $last_req) {
+	tty_write($tty, "\034\001: /// MAX80 FW UPLOAD \~\@\~ \$\r\n\035");
+	$last_req = $tt;
+    }
     my $d;
     while (1) {
-	$d = tty_read($tty, \$ttybuf, 1000);
+	$d = tty_read($tty, \$ttybuf, 100);
 	last if ($d eq '');
 	my $dc = unpack('C', $d);
+	print STDERR $a[$dc];
 	if ($dc == 036) {
 	    $winspc = 0;
 	    last;
-	} else {
-	    print STDERR $a[$dc];
 	}
     }
 }
@@ -408,11 +411,13 @@ my $maxahead = 256;
 my $last_ack = 0;
 my @pktends  = ();
 my $last_enq = 0;
+my $last_ack_time = 0;
 
 print STDERR "\nStarting packet transmit...\n";
 
 while ($last_ack < $bytes) {
     my $chunk;
+    my $now;
 
     while (1) {
 	$chunk = $bytes - $offset;
@@ -424,24 +429,26 @@ while ($last_ack < $bytes) {
 	$chunk = $maxchunk if ($chunk > $maxchunk);
 
 	my $d = tty_read($tty, \$ttybuf, $chunk ? 0 : $maxchunk/10);
+	$now = time();
 	last if ($d eq '');
 
 	my $dc = unpack('C', $d);
 	if ($dc == 022) {
 	    $winspc = 0;
-	    print STDERR "WRST, window: $winspc\n";
 	} elsif ($dc == 024) {
 	    if (defined($winspc)) {
 		$winspc += 256;
-		print STDERR "WGO, window: $winspc\n";
 	    }
 	} elsif ($dc == 006) {
 	    $last_ack = shift(@pktends) || $last_ack;
-	    print STDERR "ACK to $last_ack\n";
+	    if ($now != $last_ack_time) {
+		printf STDERR "%s: %s: %d/%d (%d%%) uploaded\n",
+		    $0, $port, $last_ack, $bytes, $last_ack*100/$bytes;
+		$last_ack_time = $now;
+	    }
 	} else {
 	    print STDERR $a[$dc];
 	    if ($dc == 025 || $dc == 031 || $dc == 037) {
-		print STDERR "\n$0: $port: resetting upload to $last_ack\n";
 		$offset = $last_ack;
 		@pktends = ();
 		undef $winspc;	# Wait for WRST before resuming
@@ -452,13 +459,10 @@ while ($last_ack < $bytes) {
 	}
     }
 
-    print STDERR "Send offset: $offset, last ack: $last_ack, window: $winspc, chunk: $chunk\n";
     if (!$chunk) {
 	if ($bytes > $offset) {
-	    my $now = time();
 	    if ($now != $last_enq) {
 		tty_write($tty, "\026"); # SYN: request window resync
-		print STDERR "Trying to resynchronize window\n";
 		$last_enq = $now;
 	    }
 	}

esp32/max80/tty.cpp

@@ -1,3 +1,6 @@
+#define MODULE "tty"
+#define DEBUG 0
+
 #define BAUD_RATE 115200
 
 #include "tty.h"
@@ -64,8 +67,6 @@ TTY::~TTY()
 
 int TTY::rxdata(void *buf, size_t len)
 {
-    printf("[TTY]  rxdata(%zu) ", len);
-
     if (!rx_sbuf)
 	return 0;
 
@@ -83,16 +84,16 @@ int TTY::rxdata(void *buf, size_t len)
 
 	if (tx_credits_reset) {
 	    // Drain input before WRST
-	    flush();
+	    //flush();
 	    if (port().write(WRST)) {
-		printf("[UPLD] Resetting window, last_ack = %u\n", rx.last_ack);
+		MSG("Resetting window, last_ack = %u\n", rx.last_ack);
 		tx_credits_reset = false;
 		tx_credits = STREAMBUF_SIZE - BUF_SLACK;
 	    } else {
 		// Uhm... wait a tiny bit and then try again to sent WRST?
 		static bool failed_once = false;
 		if (!failed_once) {
-		    printf("[UPLD] Failed to reset window?!\n");
+		    MSG("Failed to reset window?!\n");
 		    failed_once = true;
 		}
 		rcv = xStreamBufferReceive(rx_sbuf, buf, len, 1);
@@ -106,7 +107,7 @@ int TTY::rxdata(void *buf, size_t len)
 	}
     }
 
-    printf("got %d\n", rcv);
+    CMSG("got %d\n", rcv);
     return rcv;
 }
 
@@ -118,26 +119,27 @@ int TTY::rxdata(token_t me, void *buf, size_t len)
 
 void TTY::_upload_begin()
 {
-    printf("[TTY]  _upload_begin\n");
+    MSG("_upload_begin\n");
 
     if (rx_sbuf)
 	xStreamBufferReset(rx_sbuf);
     else
 	rx_sbuf = xStreamBufferCreate(STREAMBUF_SIZE, 1);
 
-    printf("[TTY]  rx_sbuf = %p\n", rx_sbuf);
+    MSG("rx_sbuf = %p\n", rx_sbuf);
 
     if (!rx_sbuf)
 	goto can;
 
+    tx_credits_reset = false;
+    tx_credits = STREAMBUF_SIZE - BUF_SLACK;
     port().write(RS);
-    tx_credits_reset = true;
     rx.state = rx_state::stxwait;
     rx.last_ack = 0;
     rx.rlen  = 0;
     rx.b64_bits = 0;
 
-    printf("[TTY]  firmware_update_start()\n");
+    MSG("firmware_update_start()\n");
     if (firmware_update_start(TTY::rxdata, (token_t)this, true))
 	goto can;
 
@@ -236,7 +238,7 @@ void TTY::_onrx()
 		break;
 	    case ETX:
 	    case CAN:
-		printf("[UPLD] Received <%02X> waiting for STX\n", byte);
+		MSG("Received <%02X> waiting for STX\n", byte);
 		reset();
 		byte = CAN;
 		break;
@@ -271,14 +273,14 @@ void TTY::_onrx()
 		// Nothing to do
 	    } else if (rx.rlen >= sizeof rx.hdr_raw) {
 		// ERROR THIS SHOULD NEVER HAPPEN
-		printf("[UPLD] Header buffer overrun!!!\n");
+		MSG("Header buffer overrun!!!\n");
 		reset();
 		byte = CAN;
 	    } else {
 		rx.hdr_raw[rx.rlen++] = data;
 		if (rx.rlen == sizeof rx.hdr) {
 		    // Start of data packet
-		    printf("[UPLD] Start packet hdr %d length %d offset %d last_ack %d\n",
+		    MSG("Start packet hdr %d length %d offset %d last_ack %d\n",
 			   rx.rlen, rx.hdr.len+1, rx.hdr.offs, rx.last_ack);
 		    rx.state = rx_state::data;
 		    rx.rlen = 0;
@@ -298,7 +300,7 @@ void TTY::_onrx()
 		// Nothing to do
 	    } else if (rx.rlen >= sizeof rx_data) {
 		// ERROR THIS SHOULD NEVER HAPPEN
-		printf("[UPLD] Packet data buffer overrun!!!\n");
+		MSG("Packet data buffer overrun!!!\n");
 		reset();
 		byte = CAN;
 	    } else {
@@ -309,18 +311,14 @@ void TTY::_onrx()
 		    uint32_t crc;
 
 		    if (have != rx.hdr.len + 1) {
-			printf("[UPLD] Invalid packet length (should not happen...)\n");
+			MSG("Invalid packet length (should not happen...)\n");
 			byte = NAK;
 		    } else if ((crc = crc32_le(0, rx_data, have))
 			       != rx.hdr.crc) {
-			printf("[UPLD] Packet CRC error hdr %08x data %08x\n", rx.hdr.crc, crc);
-			printf("\"");
-			for (int i = 0; i < have; i++)
-			    printf("\\x%02x", rx_data[i]);
-			printf("\"\n");
+			MSG("Packet CRC error hdr %08x data %08x\n", rx.hdr.crc, crc);
 			byte = NAK;
 		    } else if (rx.hdr.offs > rx.last_ack) {
-			printf("[UPLD] Invalid packet offsets [%d..%d) at %d\n",
+			MSG("Invalid packet offsets [%d..%d) at %d\n",
 			       rx.hdr.offs, rx.hdr.offs + have, rx.last_ack);
 			byte = EM;
 		    } else if (rx.hdr.offs + have <= rx.last_ack) {
@@ -335,10 +333,10 @@ void TTY::_onrx()
 			rx.last_ack += sent;
 
 			if (sent != have) {
-			    printf("[UPLD] Packet underrun, got %d, expected %d\n", sent, have);
+			    MSG("Packet underrun, got %d, expected %d\n", sent, have);
 			    byte = NAK;
 			} else {
-			    printf("[UPLD] %d bytes received OK\n", sent);
+			    MSG("%d bytes received OK\n", sent);
 			    byte = ACK;
 			}
 		    }
@@ -372,31 +370,58 @@ void TTY::_ondisconnect()
     reset();
 }
 
-static TTY *uart_tty, *usb_tty;
+static TTY *usb_tty;
+static TaskHandle_t usb_tty_task;
+
+#define USB_NOTIFY_INDEX     0   /* Seems to be the only available... */
+#define USB_TASK_STACK	  4096
+#define USB_TASK_PRIORITY    5
+
+void TTY::usb_task_handler(void *pvt)
+{
+    (void)pvt;
+
+    while (1) {
+	uint32_t notify_value;
+
+	xTaskNotifyWaitIndexed(USB_NOTIFY_INDEX, 0, 1,
+			       &notify_value, portMAX_DELAY);
+	usb_tty->_onrx();
+    }
+}
 
 void TTY::usb_onevent(void *arg, esp_event_base_t event_base,
 		      int32_t event_id, void *event_data)
 {
-    switch (event_id) {
-    case ARDUINO_USB_CDC_CONNECTED_EVENT:
-    case ARDUINO_USB_CDC_LINE_STATE_EVENT:
-	usb_tty->_onconnect();
-	break;
-    case ARDUINO_USB_CDC_DISCONNECTED_EVENT:
-	usb_tty->_ondisconnect();
-	break;
-    case ARDUINO_USB_CDC_RX_EVENT:
-	usb_tty->_onrx();
-	break;
-    case ARDUINO_USB_CDC_RX_OVERFLOW_EVENT:
-	usb_tty->_onerr();
-	break;
-    default:
-	// Do nothing
-	break;
+    if (event_base == ARDUINO_USB_CDC_EVENTS) {
+	switch (event_id) {
+	case ARDUINO_USB_CDC_CONNECTED_EVENT:
+	case ARDUINO_USB_CDC_LINE_STATE_EVENT:
+	    usb_tty->_onconnect();
+	    break;
+	case ARDUINO_USB_CDC_DISCONNECTED_EVENT:
+	    usb_tty->_ondisconnect();
+	    break;
+	case ARDUINO_USB_CDC_RX_EVENT:
+	    xTaskNotifyIndexed(usb_tty_task, USB_NOTIFY_INDEX, 1, eSetBits);
+	    break;
+	case ARDUINO_USB_CDC_RX_OVERFLOW_EVENT:
+	    usb_tty->_onerr();
+	    break;
+	default:
+	    // Do nothing
+	    break;
+	}
     }
 }
 
+static void usb_flush()
+{
+    Serial.flush();
+}
+
+static TTY *uart_tty;
+
 void TTY::uart_onrx(void)
 {
     uart_tty->_onrx();
@@ -419,11 +444,6 @@ static void uart_flush()
     Serial0.flush(true);
 }
 
-static void usb_flush()
-{
-    Serial.flush();
-}
-
 void TTY::init()
 {
     enq_str[sizeof(enq_str)-5] += max80_board_version;
@@ -436,7 +456,12 @@ void TTY::init()
 
     usb_tty  = new TTY(Serial);
     usb_tty->_flush = usb_flush;
-    Serial.onEvent(usb_onevent);
+    if (xTaskCreate(usb_task_handler, "usbttyd",
+		    USB_TASK_STACK, usb_tty,
+		    USB_TASK_PRIORITY, &usb_tty_task) == pdPASS) {
+	Serial.onEvent(usb_onevent);
+	xTaskNotifyIndexed(usb_tty_task, USB_NOTIFY_INDEX, 1, eSetBits);
+    }
     Serial.enableReboot(true);
 }
 

esp32/max80/tty.h

@@ -53,6 +53,7 @@ public:
 
 private:
     // Event handler dispatchers
+    static void usb_task_handler(void *);
     static void usb_onevent(void *arg, esp_event_base_t event_base,
 			    int32_t event_id, void *event_data);
     static void uart_onrx();