Menu ▾ ▴

#4 STM32F072 firmware download is very slow.

none
needsinfo
nobody
None
2020-08-06
2015-08-15
Roger Wolff
No

The firmware download on my STM32F072 is very slow. This was observed with 0.8, but is still present in the current git version. Downloading 70kbytes of firmware takes: (still waiting...) 3:18.

I remember it being a lot faster in the past.

Discussion

  • Tormod Volden

    Tormod Volden - 2015-08-15
    • summary: STM32F072 frmware download is very slow. --> STM32F072 firmware download is very slow.
     

  • Tormod Volden

    Tormod Volden - 2015-08-15

    Thanks for the report. Please attach a log made with -d -d -d. In particular I would like to know if the reported bwPollTimeout values are correct.

     

  • Roger Wolff

    Roger Wolff - 2015-08-25

    I'm running with -v -v -v because specifying the USB VID:PID multiple times does not make sense....

     

    Last edit: Roger Wolff 2015-08-25
    dfu.log

  • Roger Wolff

    Roger Wolff - 2015-08-25

    image for alternate setting 0, (1 elements, total size = 70036)
    parsing element 1, address = 0x08000000, size = 70028
    Download [=========================] 100% 70028 bytes
    Download done.
    done parsing DfuSe file
    0.036u 0.092s 2:47.29 0.0% 0+0k 0+0io 0pf+0w

    Download of 70k took almost 3 minutes. 419 bytes per second.

    Oh... by the way... Hardware has something to do with this. I didn't have this problem on my laptop last week when I was on vacation....

     

  • Tormod Volden

    Tormod Volden - 2015-08-30

    Yeah, -v -v -v is better :)

    It looks like the bPollTimeout values are sane. They will alone accumulate to 39 seconds but not 3 minutes.

    Since you saw this on some hardware and on some not, I wonder if this is a libusb issue. Which version are you using? Can you please try latest git on https://github.com/libusb/libusb which is 1.0.20-rc1+?

     

  • Roger Wolff

    Roger Wolff - 2015-09-07

    Tested on my workstation at work: fast. (It's the one at home that was slow).

     

  • Tormod Volden

    Tormod Volden - 2016-01-27
    • status: open --> pending
    • Milestone: 1.0 --> none
     

  • Tormod Volden

    Tormod Volden - 2016-01-27

    Without further information, I would assume this is a hardware or hardware driver problem.

     

  • Tormod Volden

    Tormod Volden - 2016-01-27
    • status: pending --> needsinfo
     

  • Roger Wolff

    Roger Wolff - 2016-11-17

    Can I close this? It happened once on one specific computer. Let's forget about it.

     

  • Roger Wolff

    Roger Wolff - 2019-04-14

    OK. starting a project again, and the time to download an image (ten minutes) is enough to search for the sources, recompile the wrong sources, find the right sources, update them from git, recompile them, restart the download, search for the home page, find the bug tracker edit another bug, then search for this one and start typing.....

    It is still the same machine having this problem. but I did upgrade the OS from 16.04 to 18.04, so I'm likely running a newer libusb now. Anything I can do to debug this?

     

  • Tormod Volden

    Tormod Volden - 2019-04-14

    Ubuntu 18.04 should have libusb 1.0.21 which is newer than the 1.0.20 in 16.04. However there is now libusb 1.0.23 RC available, maybe you can try to compile it. What would have been useful is if the debug output from libusb could include timestamps, so we could see where things are held up. You can also try using strace, its -ttt option gives wonderful timestamps on the system calls done by libusb but it can be a challenge to combine the information.

    This is still only seen on one single computer, right?

    Does it change anything to have a USB hub between computer and device?

     

  • Anonymous

    Anonymous - 2019-05-02

    I see the same slowdown when I use dfu-util on an STM32F042 that's hooked to a USB3.0 port. If I move it to a USB2.0 port on the same machine then it runs quickly.

     

  • Anonymous

    Anonymous - 2019-07-17

    OK. I have USB3 ports on my system. I checked and it was in an USB2 port I moved it over to the USB 3 port and... still slow.
    Technically, the USB3 port consist of two ports to the system, sharing a single connector. Like those phones that have USB but multiplex "headphone out" on the same connector.
    So it could be that your USB3 port and my USB3 AND USB2 port all use the same USB2 chip/hardware/whatever.
    A hint: When I run with strace AND -v -v -v, the process doesn't finish at all. (I stopped it at 10 minutes).

    This is the strace with -v-v-v. You can see the debug prints in here too.

    1563345451.585083 write(1, "   Poll timeout 40 ms\n", 22) = 22
1563345451.585148 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0
1563345451.625589 write(2, "libusb: debug [libusb_alloc_tran"..., 56) = 56
1563345451.625893 write(2, "libusb: debug [libusb_submit_tra"..., 57) = 57
1563345451.626195 write(2, "libusb: debug [add_to_flying_lis"..., 85) = 85
1563345451.626450 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640688, tv_nsec=791432000}}, NULL) = 0
1563345451.626540 ioctl(9, USBDEVFS_SUBMITURB, 0xd09c80) = 0
1563345451.626626 write(2, "libusb: debug [libusb_handle_eve"..., 84) = 84
1563345451.626725 write(2, "libusb: debug [handle_events] po"..., 67) = 67
1563345451.626800 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345451.626898 write(2, "libusb: debug [handle_events] po"..., 48) = 48
1563345451.626965 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff1048f050) = 0
1563345451.627033 write(2, "libusb: debug [reap_for_handle] "..., 66) = 66
1563345451.627102 write(2, "libusb: debug [handle_control_co"..., 71) = 71
1563345451.627171 write(2, "libusb: debug [disarm_timerfd] \n", 32) = 32
1563345451.627238 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345451.627306 write(2, "libusb: debug [usbi_handle_trans"..., 94) = 94
1563345451.627374 write(2, "libusb: debug [sync_transfer_cb]"..., 49) = 49
1563345451.627440 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff1048f050) = -1 EAGAIN (Resource temporarily unavailable)
1563345451.627510 write(2, "libusb: debug [libusb_free_trans"..., 55) = 55
1563345451.627581 write(1, "   Poll timeout 40 ms\n", 22) = 22
1563345451.627648 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0
1563345451.667977 write(2, "libusb: debug [libusb_alloc_tran"..., 56) = 56
1563345451.668212 write(2, "libusb: debug [libusb_submit_tra"..., 57) = 57
1563345451.668335 write(2, "libusb: debug [add_to_flying_lis"..., 85) = 85
1563345451.668417 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640688, tv_nsec=833593000}}, NULL) = 0
1563345451.668513 ioctl(9, USBDEVFS_SUBMITURB, 0xd09c80) = 0
1563345451.668591 write(2, "libusb: debug [libusb_handle_eve"..., 84) = 84
1563345451.668677 write(2, "libusb: debug [handle_events] po"..., 67) = 67
1563345451.668743 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345451.668837 write(2, "libusb: debug [handle_events] po"..., 48) = 48
1563345451.668904 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff1048f050) = 0
1563345451.668971 write(2, "libusb: debug [reap_for_handle] "..., 66) = 66
1563345451.669039 write(2, "libusb: debug [handle_control_co"..., 71) = 71
1563345451.669108 write(2, "libusb: debug [disarm_timerfd] \n", 32) = 32
1563345451.669176 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345451.669244 write(2, "libusb: debug [usbi_handle_trans"..., 94) = 94
1563345451.669312 write(2, "libusb: debug [sync_transfer_cb]"..., 49) = 49
1563345451.669378 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff1048f050) = -1 EAGAIN (Resource temporarily unavailable)
1563345451.669449 write(2, "libusb: debug [libusb_free_trans"..., 55) = 55
1563345451.669520 write(1, "   Poll timeout 40 ms\n", 22) = 22
1563345451.669587 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0

    So that there is annotated with the debug info writes, but I think it is easier to read without them: 

    1563345003.683199 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640240, tv_nsec=848443000}}, NULL) = 0
1563345003.683489 ioctl(9, USBDEVFS_SUBMITURB, 0x821140) = 0
1563345003.683772 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345003.683907 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = 0
1563345003.684014 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345003.684084 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = -1 EAGAIN (Resource temporarily unavailable)
1563345003.684150 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0
1563345003.724429 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640240, tv_nsec=889683000}}, NULL) = 0
1563345003.724537 ioctl(9, USBDEVFS_SUBMITURB, 0x821140) = 0
1563345003.724616 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345003.724754 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = 0
1563345003.724820 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345003.724888 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = -1 EAGAIN (Resource temporarily unavailable)
1563345003.724957 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0
1563345003.765266 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640240, tv_nsec=930515000}}, NULL) = 0
1563345003.765542 ioctl(9, USBDEVFS_SUBMITURB, 0x821140) = 0
1563345003.765746 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345003.765886 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = 0
1563345003.765952 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345003.766021 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc2e0) = -1 EAGAIN (Resource temporarily unavailable)
1563345003.766089 nanosleep({tv_sec=0, tv_nsec=40000000}, NULL) = 0

    Here we see three complete cycles, about 40ms apart: everything is quick except for the 40ms sleep that is in there.

    The 40ms timeout changes to 72 after a while: 

    1563345048.276322 nanosleep({tv_sec=0, tv_nsec=72000000}, NULL) = 0
1563345048.348643 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640285, tv_nsec=513886000}}, NULL) = 0
1563345048.348925 ioctl(9, USBDEVFS_SUBMITURB, 0x819990) = 0
1563345048.349063 poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
1563345048.349168 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc520) = 0
1563345048.349233 timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
1563345048.349303 ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fffed9dc520) = -1 EAGAIN (Resource temporarily unavailable)
1563345048.349371 nanosleep({tv_sec=0, tv_nsec=72000000}, NULL) = 0
1563345048.421643 timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=9640285, tv_nsec=586914000}}, NULL) = 0

    That was for the succesful run without -v -v -v, near the end. Apparently by the end it was still doing those 72ms waits.
    The unsuccesful run stopped doing the 72ms sleeps after a while.

    Attached is the run from with the USB3 port that took about 49 seconds to load my 18k DFU file. ...

    (the notifications from here go into my spambox, and I haven't cleaned that out in quite a while)

     
    dfu3.str

  • Anonymous

    Anonymous - 2020-08-06

    I have some information to add - I found this article due to my VNA taking hours to update, and I will provide the info I can to see if it helps. My laptop is a Dell G7. When I tried using any of the ports on tha laptop, the update took hours. I purchased a Startech ST4200MINI2 USB adapter and tried it with the firmware update, and it completed in 10 seconds. It's definitely something to do with the USB. At least adding an adapter works as a work-around until it is fixed. If you need any additional info, email me at greatoutdoors1985 at gmail and I will help what I can. - Shannon

     

Anonymous
Anonymous

Add attachments
Cancel