Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Programming speed is terribly slow sometimes #44

Closed
pfalcon opened this issue May 30, 2015 · 16 comments
Closed

Programming speed is terribly slow sometimes #44

pfalcon opened this issue May 30, 2015 · 16 comments

Comments

@pfalcon
Copy link
Contributor

pfalcon commented May 30, 2015

I've been bitten by this ever since 1st module I tried. For some modules, programming speed is very slow. Example below (using a patch to be submitted) shows that actual UART speed used by bootloader is likely 9600. The issues definitely depends on USB-serial adapter used. But what's most annoying is "persistent sticky" nature of the problem. For example, today I just unpacked a new board with CH341 adapter builtin, and first programming went fast, but all subsequent show speed as below. Google is pretty silent on this specific issue, so posting this, as this is more or less appropriate place for it hopefully. Please don't close this prematurely, let's collect stats and maybe find some pattern.

Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 60.84 seconds (7270.84 bit/s)...
Erasing flash...
Writing at 0x0004f000... (100 %) 
Written 259072 bytes in 287.08 seconds (7219.56 bit/s)...

Leaving...
0.12user 0.04system 5:50.45elapsed 0%CPU (0avgtext+0avgdata 9224maxresident)k
@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

My overall stats is that 2 out of 3 modules I used have this issue.

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

I'm on ubuntu and I already turned off all the serial port plug&play crap - at least there're no syslog messages that something pokes into newly connected /dev/ttyUSB* device.

@atx
Copy link

atx commented May 30, 2015

But what's most annoying is "persistent sticky" nature of the problem.

Does reflashing esp_init_data_default.bin (or as a next step, flashing an entire flash image from a correcly working board) at least temporarily reset this?

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

Ok, test 1:

esptool.py --port /dev/ttyUSB0 erase_flash
[power cycle board]
esptool.py --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 60.85 seconds (7.27 kbit/s)...

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

Test 2:

# Known good, ~complete firmware dump
$ ls -l wi07c.rom 
-rw-rw-r-- 1 pfalcon pfalcon 524288 Sep  6  2014 wi07c.rom

time esptool.py --port /dev/ttyUSB0 write_flash 0 wi07c.rom
...
real    9m35.625s

[power cycle board]

time esptool.py --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 60.85 seconds (7.27 kbit/s)...

So, no, erasing flash or flashing in its entirety with a known good firmware doesn't help.

@dpgeorge
Copy link

I have a board with an FTDI USB-UART converter. Running under Arch Linux. I get:

Connecting...
Erasing flash...
Writing at 0x0000d000... (100 %) 
Written 54272 bytes in 5.26 seconds (82.61 kbit/s)...
Erasing flash...
Writing at 0x0004e800... (100 %) 
Written 257024 bytes in 24.97 seconds (82.35 kbit/s)...

Leaving...

That seems about right for 115200 baud with overhead.

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

Thanks.

So, I diconnect builtin CH341 adapter via jumpers, and connect "known good" (used with a 1 of 3 modules with which I didn't have problems) PL2303 adapter:

time esptool.py --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 5.35 seconds (82.61 kbit/s)...
Erasing flash...
Writing at 0x0004f000... (100 %) 
Written 259072 bytes in 25.21 seconds (82.20 kbit/s)...

Leaving...
0.25user 0.06system 0:33.16elapsed 0%CPU (0avgtext+0avgdata 9220maxresident)k

So, some USB-UART chips don't play well with esp8266 auto-bauding. I invited @projectgus to comment on this issues, as he contributed some patches to esptool to workaround ch340 issues.

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

For completeness, going higher-baud (with the same PL2303 adapter):

time esptool.py -b230400 --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 2.84 seconds (155.95 kbit/s)...
Erasing flash...
Writing at 0x0004f000... (100 %) 
Written 259072 bytes in 13.34 seconds (155.37 kbit/s)...

Leaving...
0.26user 0.04system 0:19.35elapsed 1%CPU (0avgtext+0avgdata 9224maxresident)k
time esptool.py -b460800 --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 1.53 seconds (288.97 kbit/s)...
Erasing flash...
Writing at 0x0004f000... (100 %) 
Written 259072 bytes in 7.23 seconds (286.70 kbit/s)...

Leaving...
0.18user 0.06system 0:11.88elapsed 2%CPU (0avgtext+0avgdata 9224maxresident)k
time esptool.py -b921600 --port /dev/ttyUSB0 write_flash 0 build/firmware.elf-0x00000.bin 0x10000 build/firmware.elf-0x10000.bin
Connecting...
Erasing flash...
Writing at 0x0000d400... (100 %) 
Written 55296 bytes in 0.91 seconds (486.47 kbit/s)...
Erasing flash...
Writing at 0x0004f000... (100 %) 
Written 259072 bytes in 4.29 seconds (483.37 kbit/s)...

Leaving...
0.20user 0.04system 0:08.33elapsed 2%CPU (0avgtext+0avgdata 9224maxresident)k

Btw, I surely tested 921600 before, possibly with another adapter and certainly with another module and it simply didn't work at all (wires are longer than minimal).

@atx
Copy link

atx commented May 30, 2015

@pfalcon which kernel version do you use?

See http://lxr.free-electrons.com/source/drivers/usb/serial/ch341.c?v=3.18#L312
This line has been removed in 4.0

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

Oh right, https://github.com/IIJ-NetBSD/netbsd-src/blob/8e3b562e96a8d7cde901515dda64c1a2d7d68cdb/sys/dev/usb/uchcom.c#L36

Will try to get that module built separately, otherwise running stock 3.13 of ubuntu 14.04. Thanks for the hint!

@dpgeorge
Copy link

Wow, it really can go up to large speeds (eg using 921600 baud):

Connecting...
Erasing flash...
Writing at 0x0000d000... (100 %) 
Written 54272 bytes in 0.91 seconds (479.13 kbit/s)...
Erasing flash...
Writing at 0x0004e800... (100 %) 
Written 257024 bytes in 4.29 seconds (479.36 kbit/s)...

Leaving...

So I guess the bootloader autodetects the baud rate, and it's slow with the CH341 because that chipset for some reason decides to do 9600 baud.

@projectgus
Copy link
Contributor

Had an "a-ha" moment when I saw @atalax's comment! Can you see if the commit 1a9b16f fixes the problem?

I think the kernel doesn't send a new baud rate in set_termios if it thinks the baud rate hasn't changed from what was last set. Combined with the "default to 9600 on open()" bug means that the device can be set to 9600 but the kernel thinks it's still set at the higher speed, so doesn't change it.

(I think when I "fixed" it before what I was doing was changing the baud rate a lot when testing, so it kept re-setting it correctly!)

On my NodeMCU board (the rev 1 one) I seem to be able to reliably upload repeatedly at 230400, 460800 and mostly-reliably at similar speeds (400000, 500000). At the higher speeds it does seem to take a little longer (1-2 seconds) to sync correctly, maybe some tweaking of the timeouts for retries might help with that (try more times, more frequently?) but it's pretty good.

@projectgus
Copy link
Contributor

(For completeness - I'm on Debian Jessie 3.16.7 so I definitely have the kernel bug mentioned above, too.)

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

@projectgus: Right at time, I just finished unpacking ubuntu kernel tree to build it ;-). And yes, that was it! With your patch applied, and -b921600, I get consistent 200kbit/s, tried 3 times. Btw, I found another adapter and turn out it is also CH341! I used it with another esp8266 module which had this programming speed problems. So, for me the mystery is solved, thanks everyone for help! I'll let @themadinventor close it if he didn't receive similar mystery reports.

@projectgus , so please submit a PR with this patch, btw, the link in your comment shows for me as
https://github.com/themadinventor/esptool/commit/1a9b16f63a8338c067b663e42bcbe2af98c68ba5, so I wondered if you have commit access to @themadinventor's repo and already pushed it, but I didn't find it there and figured it's 1a9b16f

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

Ok, for this to be ultimate benchmarking thread: The above "-b921600 / 200kbit/s" report was with external CH341. With board builtin, 921600 doesn't work, 460800 is highest, but with it it gets up to 290 kbit/s.

@pfalcon
Copy link
Contributor Author

pfalcon commented May 30, 2015

And to add a bit of gossip, at another place (no access now) I had another USB-UART adapter, and I cannot be sure, but it likely was CP2102 (at least I had it in my collection). With it, ecp8266 didn't work well either - it booted, but as soon as intensive WiFi task was started, like scanning, it simply hanged. CP2102 is generally considered a good chip, but builtin 3.3 LDO might be a bit weak to power ESP8266 completely. (Again, information by memory, just to give some hints to a desperate googler).

pfalcon pushed a commit to pfalcon/esptool that referenced this issue Jul 20, 2015
Based on information in espressif#44
espressif#44 (comment)

Looks like if the kernels thinks the serial port is already set to
<baudrate>, it won't set the baud rate in set_termios. Due to the
pre-4.0 bug of always chosing 9600 baud on open, it's possible for the
device to be set to 9600 but the kernel thinks it's set much faster.

Not sure what I was thinking with the other fix in de97c54. It did
seem a bit more reliable but possibly this was because when testing I
kept changing the baud rate(!)
pfalcon pushed a commit to pfalcon/esptool that referenced this issue Jul 20, 2015
Based on information in espressif#44
espressif#44 (comment)

Looks like if the kernels thinks the serial port is already set to
<baudrate>, it won't set the baud rate in set_termios. Due to the
pre-4.0 bug of always chosing 9600 baud on open, it's possible for the
device to be set to 9600 but the kernel thinks it's set much faster.

Not sure what I was thinking with the other fix in de97c54. It did
seem a bit more reliable but possibly this was because when testing I
kept changing the baud rate(!)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants