RFC2217 is too slow for ESP32 auto-reset circuits to work correctly

[ghost]

• Operating system: Windows 10 Pro 64bit for rfc2217 server
• Python version: 2.7.11
• ESP hardware in use: Recent version of Bangood Geekcreit ESP32 with the 'capacitor' fix as per: ESP32 Reset To Bootloader Issues on Windows (ESPTOOL-386) #136

Full esptool.py command line as run:

Any that use rfc2217://hostname:2217 as port

What is the expected behaviour?

Flashing works, including putting the module in Flash mode automatically

Do you have any other information from investigating this?

There's probably several ways to approach this, and I would also understand if this is too far out of scope for esptool. I'm happy to help with testing at least :)

Currently I'm using esptool 2.4.1 because of this issue: #373
Solving that issue would be a prerequisite for this issue being solved. Mayby have an option to prevent setting the timeout? Could be an rfc2218 option that also tweaks other things where needed.

I'm using rfc2217_server.py as rfc2218 server, on Windows 10.
This seems to be the recommended server as per: https://github.com/espressif/esptool/wiki/Remote-Serial-Ports

With 2.4.1 and rfc2217_server.py flashing does in fact work!
What does not work for me is putting the module in auto flashing mode.
I think there might be several reasons for this, first let me show you a log of what happens on the server with doing this, including timing. I've included what I think are the matching bits of esptool python:

>2018-12-01 17:48:28,210 INFO:rfc2217.server:set baud rate: 115200
>2018-12-01 17:48:28,219 INFO:rfc2217.server:set data size: 8
>2018-12-01 17:48:28,226 INFO:rfc2217.server:set parity: N
>2018-12-01 17:48:28,233 INFO:rfc2217.server:set stop bits: 1
>2018-12-01 17:48:28,267 INFO:rfc2217.server:changed flow control to None

            self._setDTR(False)  # IO0=HIGH
2018-12-01 17:48:28,305 INFO:rfc2217.server:changed DTR to inactive

            self._setRTS(True)   # EN=LOW, chip in reset
2018-12-01 17:48:28,355 INFO:rfc2217.server:changed RTS to active
2018-12-01 17:48:28,407 INFO:rfc2217.server:changed DTR to inactive (Z)

            time.sleep(0.1)
            self._setDTR(True)   # IO0=LOW
2018-12-01 17:48:28,556 INFO:rfc2217.server:changed DTR to active

            self._setRTS(False)  # EN=HIGH, chip out of reset
2018-12-01 17:48:28,607 INFO:rfc2217.server:changed RTS to inactive
2018-12-01 17:48:28,657 INFO:rfc2217.server:changed DTR to active (Z)

            time.sleep(0.05)
            self._setDTR(False)  # IO0=HIGH, done
2018-12-01 17:48:28,756 INFO:rfc2217.server:changed DTR to inactive

Things to notice:

• There seems to be at least 50ms between any DTR and/or RTS change
• I guess that's because of the way the protocol is set up, possibly with an ACK for each change. Haven't looked deeply enough in the client and server to say yet.
• This includes the additional 'change' to DTR which is intended to trigger the RTS change on Windows with usbser.sys. I marked these (Z)

To be honest I'm not sure what the best way would be to make this work, I think the main things needing adressing are:

• Those 50 ms delays, I guess one would want the same workaround that esptool has for adding a non-changing DTR change to each RTS change in the server, and disabling the workaround in esptool. That would remove one 50ms delay after each RTS change, and hopefull make the RTS change quicker.
• What's harder is where a DTR and RTS change should follow each other very quickly, you kinda want to send those together, instead of sending one, waiting for an ack(?), then sending the other. But that would involve messing a lot with the rfc2217 libraries I guess, and not sure it even fits in the rfc spec (though it might, I think you're allowed to send the options together, without waiting for an ack).

I can see how this all would be combined in some esptool changes that are activated when the com port uses the rfc protocol/url, and mayby a dedicated esptool version of the rfc2217_server.py server.
To complicate things, that server would still have to work with the IDF monitor preferably, though as long as it sticks with rfc2217 that should be the case.

I know it's all a bit much to ask, for me the use case is allowing me to build on docker containers without serial port access (the case on windows for example), which really makes using the IDF a lot more pleasant. The module is then connected to a system which does have serial port access, and I only need to install the rfc2217 server there.

Cheers!

Some usefull links:
Pyserial rfc2217 client/server lib: https://github.com/pyserial/pyserial/blob/master/serial/rfc2217.py
Pyserial rfc2217 server: https://github.com/pyserial/pyserial/blob/master/examples/rfc2217_server.py
Fix for issue on windows that adds extra 'noop' DTR change: 8b80fac
About ESP32 boto mode selection: https://github.com/espressif/esptool/wiki/ESP32-Boot-Mode-Selection
Issue with the 'capacitor fix' which I also use on my boards: #136
Old thread on rfc2217 support: https://esp32.com/viewtopic.php?f=2&t=3040
The actual rfc: https://tools.ietf.org/html/rfc2217

[projectgus]

Thanks for posintg all this detail. I see the problem and the (reasonable) desire for a solution. Unfortunately I don't believe there's any clean way to fix this.

It is possible, I think, to comply to the RFC2217 spec by sending multiple "Set DTR Signal State" or "Set RTS Signal State" commands in a sequence without waiting for RFC2217 layer ACKs for each one (or at least, deferring the ACK check until after a sequence of requests have been sent). But this isn't how the pyserial library does this now, and it's not an easy modification to make.

Even batching commands like this still doesn't guarantee they are processed on the server in a short enough time window for auto-reset to work. There's potential latency is introduced by the TCP layer, which could fragment the request - although it probably won't. Plus the RFC server will introduce latency (processing each command in sequence, sending an ACK, any logging, etc.)

I don't see an RFC2217 command which can set DTR & RTS in a single command, which is what would be best.

There's also no way in the pyserial API to set DTR & RTS in a single function call, they have to be set independently in two calls. This is already a limitation on some Windows systems and VMs where the latency between the two function calls can be too high for correct auto-reset timing, that's on a fully local system with no network processing overhead.

Forking pyserial into esptool to add these kind of features is not really viable.

The one method which is guaranteed to work, even with the current latency-rich processing setup, is to remove the auto-reset circuit from the target board and wire RTS & DTR directly to EN & GPIO0. (Normal serial programs will then hold the board in reset unless RTS is disabled, but auto-flashing will work.)

[ghost]

Hi! Thanks for the speedy and considerate answer :)
I understand all the points you make, and agree. Trying to do the time sensitive stuff over TCP and RFC2217 is just not a really viable option. At least we can leave this issue for other people so they'll know why :)

I am still thinking about alternatives.
The only thing that doesn't work over RFC2217 is getting the module in flash mode, moving the full dtr/rts juggle into the server would work, it could be triggered by a custom telnet option. But to do that you'd have to call RFC2217 client code directly, instead of wrapped by the pyserial serial interface, and again it would likely need changing of the pyserial parts, unless the RFC2217 parts can be extended somehow (I don't code python, so dunno :) ).
And the other obvious alternative is to just install (only) esptool on the machine with serial port access, and use scp+ssh or such, but downsides are that in my case (Windows) there's no ssh server, and this won't integrate with the esp-idf, you'd have to copy paste the esptool commandline, and monitor won't work :)

[ghost]

Has, success! I created a monster! :D
Adding a custom telopt on both sides, that triggers flash mode, works! :)
And it is doable with overriding classes (Just make sure pyserial is at least 3.1.0, since there's a 'private' method that got renamed, lots a couple of hours on that.. :) )

Short.ish story of what I did:
New package in a folder named rfc2217esp

init.py:

import serial
from .portmanager import PortManager
serial.protocol_handler_packages.append("rfc2217esp.urlhandler")

portmanager.py:

import serial.rfc2217
import time

PURGE_FLASH = b'\x07' # Set the ESP in flash mode

class PortManager(serial.rfc2217.PortManager):

    def __init__(self, serial_port, connection, logger=None):
        super(PortManager, self).__init__(serial_port, connection, logger)

    def _setDTR(self, state):
        self.serial.setDTR(state)

    def _setRTS(self, state):
        self.serial.setRTS(state)
        # Work-around for adapters on Windows using the usbser.sys driver:
        # generate a dummy change to DTR so that the set-control-line-state
        # request is sent with the updated RTS state and the same DTR state
        self.serial.setDTR(self.serial.dtr)

    def _telnet_process_subnegotiation(self, suboption):
        if suboption[0:1] == serial.rfc2217.COM_PORT_OPTION and suboption[1:2] == serial.rfc2217.PURGE_DATA and suboption[2:3] == PURGE_FLASH:
            if self.logger:
                self.logger.info("Set ESP to flash mode")

            self._setDTR(False)  # IO0=HIGH
            self._setRTS(True)   # EN=LOW, chip in reset
            time.sleep(0.1)
            self._setDTR(True)   # IO0=LOW
            self._setRTS(False)  # EN=HIGH, chip out of reset
            time.sleep(0.05)
            self._setDTR(False)  # IO0=HIGH, done

            self.rfc2217_send_subnegotiation(serial.rfc2217.SERVER_PURGE_DATA, PURGE_FLASH)
                
        else:
            super(PortManager, self)._telnet_process_subnegotiation(suboption)

And then a subfolder called 'urlhandler' with:
An empty init.py

protocol_rfc2217esp.py:

import serial.rfc2217

PURGE_FLASH = b'\x07' # Set the ESP in flash mode

class Serial(serial.rfc2217.Serial):

    def __init__(self, *args, **kwargs):
        super(Serial, self).__init__(*args, **kwargs)

    def from_url(self, url):
       return super(Serial, self).from_url(url.replace("esp", ""))

    def flash_esp(self):
        if not self.is_open:
            raise portNotOpenError
        self.rfc2217_send_purge(PURGE_FLASH)

The server needs patching ofcourse:
https://github.com/pyserial/pyserial/blob/master/examples/rfc2217_server.py is patched with:

--- rfc2217_server.py   2018-12-03 21:59:18.797049200 +0100
+++ rfc2217_server_esp.py       2018-12-03 22:03:02.349956200 +0100
@@ -13,7 +13,7 @@
 import time
 import threading
 import serial
-import serial.rfc2217
+import rfc2217esp


 class Redirector(object):
@@ -21,7 +21,7 @@
         self.serial = serial_instance
         self.socket = socket
         self._write_lock = threading.Lock()
-        self.rfc2217 = serial.rfc2217.PortManager(
+        self.rfc2217 = rfc2217esp.PortManager(
             self.serial,
             self,
             logger=logging.getLogger('rfc2217.server') if debug else None)

And finally esptool.py, based on 2.4.1 because of the timeout issue.
This is the hard coded variety :)

--- esptool.py  2018-12-03 22:05:53.240032500 +0100
+++ esptool_esp.py      2018-12-03 20:13:13.535194700 +0100
@@ -33,6 +33,7 @@
 import zlib
 import string
 import serial.tools.list_ports as list_ports
+import rfc2217esp

 import serial

@@ -396,23 +397,24 @@
         # DTR & RTS are active low signals,
         # ie True = pin @ 0V, False = pin @ VCC.
         if mode != 'no_reset':
-            self._setDTR(False)  # IO0=HIGH
-            self._setRTS(True)   # EN=LOW, chip in reset
-            time.sleep(0.1)
-            if esp32r0_delay:
-                # Some chips are more likely to trigger the esp32r0
-                # watchdog reset silicon bug if they're held with EN=LOW
-                # for a longer period
-                time.sleep(1.2)
-            self._setDTR(True)   # IO0=LOW
-            self._setRTS(False)  # EN=HIGH, chip out of reset
-            if esp32r0_delay:
-                # Sleep longer after reset.
-                # This workaround only works on revision 0 ESP32 chips,
-                # it exploits a silicon bug spurious watchdog reset.
-                time.sleep(0.4)  # allow watchdog reset to occur
-            time.sleep(0.05)
-            self._setDTR(False)  # IO0=HIGH, done
+            self._port.flash_esp()
+#            self._setDTR(False)  # IO0=HIGH
+#            self._setRTS(True)   # EN=LOW, chip in reset
+#            time.sleep(0.1)
+#            if esp32r0_delay:
+#                # Some chips are more likely to trigger the esp32r0
+#                # watchdog reset silicon bug if they're held with EN=LOW
+#                # for a longer period
+#                time.sleep(1.2)
+#            self._setDTR(True)   # IO0=LOW
+#            self._setRTS(False)  # EN=HIGH, chip out of reset
+#            if esp32r0_delay:
+#                # Sleep longer after reset.
+#                # This workaround only works on revision 0 ESP32 chips,
+#                # it exploits a silicon bug spurious watchdog reset.
+#                time.sleep(0.4)  # allow watchdog reset to occur
+#            time.sleep(0.05)
+#            self._setDTR(False)  # IO0=HIGH, done

         for _ in range(5):
             try:

And the last ingredient is to use something like the following as URL, in sdkconfig if the idf is used:
rfc2217esp://host.docker.internal:2217

It's only slightly hacky.. :D
Still, proof of concept, not sure I'd recommend making anything official out of it..
But it's a workaround for anyone looking for one I guess :)

[ghost]

Oh, and putting that url (rfc2217esp://host.docker.internal:2217) in sdkconfig does break idf monitor, cause it doesn't recognize it..
Hmm, I guess unregistering the existing protocol handlers, and then renaming ours to just rfc2217 would work, you lose the other url/protocols, but we probably don't need those for ESP stuff :)

[ghost]

Yep, that worked, you can find it all together with some cmd scripts to run it here: https://github.com/cranphin/Colourful/tree/048781c6354ebbd3b93d1fe18631a1fd642b1fd6

[projectgus]

Nice, I'm glad you got this to work!

Probably this is a not a solution we can adopt in esptool.py, but having it out there may come in very useful for others.

[wwcwang]

To resolve the problem, just change the time.sleep(0.1) to 0.01 or less in following code of rfc2217.py and specify ign_set_control in port url , eg : rfc2217://127.0.0.1:4000?ign_set_control
good luck!

    if self._ignore_set_control_answer:
        # answers are ignored when option is set. compatibility mode for
        # servers that answer, but not the expected one... (or no answer
        # at all) i.e. sredird
        time.sleep(0.1)  # this helps getting the unit tests passed
    else:
        item.wait(self._network_timeout)  # wait for acknowledge from the server