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

"usb bulk write failed" errors flashing Tang Nano 9k #415

Open
silversquirl opened this issue Jan 2, 2024 · 12 comments
Open

"usb bulk write failed" errors flashing Tang Nano 9k #415

silversquirl opened this issue Jan 2, 2024 · 12 comments

Comments

@silversquirl
Copy link

This definitely worked a few months ago, but I've changed laptops since then and now it doesn't:

$ openFPGALoader -b tangnano9k --verbose-level=2 build/counter.fs
empty
Jtag frequency : requested 6.00MHz   -> real 6.00MHz  
Raw IDCODE:
- 0 -> 0x1100481b
- 1 -> 0xffffffff
Fetched TDI, end-of-chain
found 1 devices
index 0:
        idcode 0x100481b
        manufacturer Gowin
        family GW1N
        model  GW1N(R)-9C
        irlength 8
File type : fs
Parse file Parse build/counter.fs: 
checksum 0x76e7
Done
DONE
bitstream header infos
CRCCheck: ON
Compress: OFF
ConfDataLength: 712
LoadingRate: 2500000
ProgramDoneBypass: OFF
SPIAddr: 00fff000
SecurityBit: ON
idcode: 1100481b
before program sram: displayReadReg 0003f020
        Memory Erase
        Gowin VLD
        Done Final
        Security Final
        Ready
        POR
        FLASH lock
Erase SRAM before erase sram: displayReadReg 0003f020
        Memory Erase
        Gowin VLD
        Done Final
        Security Final
        Ready
        POR
        FLASH lock
pollFlag: 3f0a0 (80)
pollFlag: 3d080 (0)
pollFlag: 3d080 (0)
pollFlag: 3d080 (0)
pollFlag: 390a0 (20)
after erase sram: displayReadReg 000390a0
        Memory Erase
        System Edit Mode
        Gowin VLD
        Ready
        POR
        FLASH lock
pollFlag: 39020 (0)
Load SRAM before write sram: displayReadReg 00039020
        Memory Erase
        Gowin VLD
        Ready
        POR
        FLASH lock
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
[... continues indefinitely ...]
@silversquirl
Copy link
Author

If left alone for several minutes, it finally does actually stop and print this:

mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_read: fail to store with error: -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_read: fail to store with error: -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
after write sram: displayReadReg 00000000
FAIL
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_read: fail to store with error: -1 (usb bulk write failed)
Loopback failed, expect problems on later runs -1
unable to config pins : -1 unable to configure bitbang mode. Perhaps not a BM/2232C type chip?

I've tried with multiple different known-good cables, so it's unlikely to be that. Not really sure how to debug this.

@loopj
Copy link

loopj commented Jan 16, 2024

I'm seeing this exact same issue on an M2 Macbook Air and openFPGALoader v0.11.0

@trabucayre
Copy link
Owner

Could you paste dmesg output when you plug the device?
This problem seems related to low level layer.

@loopj
Copy link

loopj commented Jan 18, 2024

This seems to be related to using a usb hub, plugging into the computer directly with a known good cable solves the issue.

@trabucayre
Copy link
Owner

Weird: I have bought an 9k to do some tests. I have a long USB extender and and usb switch + usb cable and not seen anything like that.
Problem is definitively related to hardware...

@hackguy25
Copy link

I'm having the same issue on the Raspberry Pi 4 with 64-bit Raspberry Pi OS. I tried different USB cables and flashing fails in a similar manner on all of them. I will try with a laptop instead, and post an update.

@trabucayre
Copy link
Owner

Could you share dmesg output. By the past FTDI implementation was really unstable with raspberryPI.

@hackguy25
Copy link

hackguy25 commented Apr 29, 2024

Sometimes it works:

[  172.736329] usb 1-1.3: new full-speed USB device number 3 using xhci_hcd
[  172.838286] usb 1-1.3: not running at top speed; connect to a high speed hub
[  172.846288] usb 1-1.3: New USB device found, idVendor=0403, idProduct=6010, bcdDevice= 5.00
[  172.846308] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  172.846321] usb 1-1.3: Product: JTAG Debugger
[  172.846331] usb 1-1.3: Manufacturer: SIPEED
[  172.846340] usb 1-1.3: SerialNumber: FactoryAIOT Pro
[  172.973783] usbcore: registered new interface driver usbserial_generic
[  172.973831] usbserial: USB Serial support registered for generic
[  172.983869] usbcore: registered new interface driver ftdi_sio
[  172.983939] usbserial: USB Serial support registered for FTDI USB Serial Device
[  172.984059] ftdi_sio 1-1.3:1.0: FTDI USB Serial Device converter detected
[  172.984246] usb 1-1.3: Detected FT2232C/D
[  172.989666] usb 1-1.3: FTDI USB Serial Device converter now attached to ttyUSB0
[  172.989880] ftdi_sio 1-1.3:1.1: FTDI USB Serial Device converter detected
[  172.989931] usb 1-1.3: Detected FT2232C/D
[  172.993157] usb 1-1.3: FTDI USB Serial Device converter now attached to ttyUSB1

Sometimes it errors out:

[  488.070602] usb 1-1.2: new full-speed USB device number 4 using xhci_hcd
[  488.172511] usb 1-1.2: not running at top speed; connect to a high speed hub
[  488.176511] usb 1-1.2: config index 0 descriptor too short (expected 55, got 9)
[  488.176518] usb 1-1.2: config 1 has 0 interfaces, different from the descriptor's value: 2
[  488.179767] usb 1-1.2: string descriptor 0 read error: -75
[  488.179774] usb 1-1.2: New USB device found, idVendor=0403, idProduct=6010, bcdDevice= 5.00
[  488.179779] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  488.180760] usb 1-1.2: can't set config #1, error -75

I used a different USB port here, but it doesn't seem to be linked to a specific USB port.

@DavidVentura
Copy link

DavidVentura commented Jun 4, 2024

I'm hitting the same issue on a Framework laptop:

dmesg on plug

[987306.248589] usb 1-1: new full-speed USB device number 13 using xhci_hcd
[987306.405238] usb 1-1: not running at top speed; connect to a high speed hub
[987306.433236] usb 1-1: New USB device found, idVendor=0403, idProduct=6010, bcdDevice= 5.00
[987306.433243] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[987306.433245] usb 1-1: Product: JTAG Debugger
[987306.433247] usb 1-1: Manufacturer: SIPEED
[987306.433248] usb 1-1: SerialNumber: FactoryAIOT Pro
[987306.439273] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
[987306.439301] usb 1-1: Detected FT2232C/D
[987306.446300] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
[987306.446724] ftdi_sio 1-1:1.1: FTDI USB Serial Device converter detected
[987306.446741] usb 1-1: Detected FT2232C/D
[987306.452288] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB1

Error on flash:

$ openFPGALoader -m -b tangnano9k --verbose-level=2  /home/david/git/TangNano-9K-example/hdmi/impl/pnr/hdmi.fs 
Jtag frequency : requested 6.00MHz   -> real 6.00MHz  
Raw IDCODE:
- 0 -> 0x1100481b
- 1 -> 0xffffffff
Fetched TDI, end-of-chain
found 1 devices
index 0:
        idcode 0x100481b
        manufacturer Gowin
        family GW1N
        model  GW1N(R)-9C
        irlength 8
File type : fs
Parse file Parse /home/david/git/TangNano-9K-example/hdmi/impl/pnr/hdmi.fs: 
checksum 0xee33
Done
DONE
bitstream header infos
CRCCheck: ON
Compress: OFF
ConfDataLength: 1224
LoadingRate: 2500000
ProgramDoneBypass: OFF
SPIAddr: 00000000
SecurityBit: ON
idcode: 1100481b
before program sram: displayReadReg 0003f020
        Memory Erase
        Gowin VLD
        Done Final
        Security Final
        Ready
        POR
        FLASH lock
Erase SRAM before erase sram: displayReadReg 0003f020
        Memory Erase
        Gowin VLD
        Done Final
        Security Final
        Ready
        POR
        FLASH lock
pollFlag: 3f0a0 (80)
pollFlag: 3d080 (0)
pollFlag: 3d080 (0)
pollFlag: 3d080 (0)
pollFlag: 3d080 (0)
pollFlag: 81faf3fa (20)
after erase sram: displayReadReg 7d02fa02
        Bad Command
        Reserved9
        Bypass
        Gowin VLD
        Done Final
        Security Final
        Ready
        FLASH lock
pollFlag: 82fa00fa (80)
pollFlag: 7d73fa02 (0)
Load SRAM before write sram: displayReadReg fffa00fa
        Bad Command
        Timeout
        Reserved4
        Memory Erase
        Preamble
        System Edit Mode
        FLASH lock
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed

Before seeing the first mpsse_write: fail to write with error -1 (usb bulk write failed), the kernel logs also show the device getting disconnected:

[987311.723449] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[987311.723461] ftdi_sio 1-1:1.0: device disconnected

@trabucayre
Copy link
Owner

The two lines mentioned are perfectly normal. To be able to take control to the FTDI (or clone) from userspace, it's required first to detach the driver.
For a different board but using an FTDI device I have these two lines:

[127777.428335] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[127777.428352] ftdi_sio 3-1.4:1.0: device disconnected

The real problem here are errors (usb bulk write failed) returned by the libusb (used by the libftdi). I have no real idea why this occur: it's usual with FTDI clone, I have sometime similars errors with an USB hub or with one connector partly physically broken. Maybe power is not enough and device reboot?

@DavidVentura
Copy link

Other log lines I've gotten:

Jtag frequency : requested 6.00MHz   -> real 6.00MHz  
Raw IDCODE:
- 0 -> 0xfffafffa
JTAG init failed with: Unknown device with IDCODE: 0xfffafffa (manufacturer: 0x7fd (), part: 0x7f vers: 0xf
FTDI flush buffer error with code -2 (FTDI purge of RX buffer failed)
JTAG init failed with: low level FTDI init failed
Can't read iProduct field from FTDI: considered as empty string
FTDI reset error with code -1 (FTDI reset failed)
JTAG init failed with: low level FTDI init failed

another run got a bit farther:

Jtag frequency : requested 6.00MHz   -> real 6.00MHz  
Raw IDCODE:
- 0 -> 0x1100481b
- 1 -> 0xffffffff
- 2 -> 0xffffffff
- 3 -> 0xffffffff
- 4 -> 0xffffffff
found 1 devices
index 0:
        idcode 0x100481b
        manufacturer Gowin
        family GW1N
        model  GW1N(R)-9C
        irlength 8
File type : fs
Parse file Parse /home/david/git/TangNano-9K-example/hdmi/impl/pnr/hdmi.fs: 
checksum 0xee33
Done
DONE
bitstream header infos
CRCCheck: ON
Compress: OFF
ConfDataLength: 1224
ProgramDoneBypass: OFF
SPIAddr: 00000000
SecurityBit: ON
idcode: 1100481b
loading_rate: 0
Jtag frequency : requested 2.50MHz   -> real 2.00MHz  
displayReadReg 0003f020
        Memory Erase
        Gowin VLD
        Done Final
        Security Final
        Ready
        POR
        Flash Lock
pollFlag: ffffff01
pollFlag: 1f0a080
erase SRAM pollFlag: 78200100
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 78200000
pollFlag: 90030000
pollFlag: 90000003
pollFlag: 90000003
pollFlag: 90000003
pollFlag: 90000003
pollFlag: 90000003
pollFlag: fa0003
pollFlag: 3f020
Done
pollFlag: 3f020
pollFlag: 3f020
pollFlag: 3f0a0
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
Flash SRAM: [==                                                ] 3.92%
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
mpsse_store: fails to first flush -1 usb bulk write failed
mpsse_write: fail to write with error -1 (usb bulk write failed)
...

The first 3 also logged in dmesg:

[1051876.507788] ftdi_sio ttyUSB1: Unable to read latency timer: -71
[1051876.509786] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB1
[1051884.019900] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[1051884.019916] ftdi_sio 1-1:1.0: device disconnected
[1051901.567938] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
[1051901.568034] usb 1-1: Detected FT2232C/D
[1051901.570530] ftdi_sio ttyUSB0: Unable to read latency timer: -121
[1051904.483129] ftdi_sio ttyUSB0: Unable to write latency timer: -71
[1051904.483499] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
[1051955.828615] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[1051955.828631] ftdi_sio 1-1:1.0: device disconnected
[1051956.653034] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
[1051956.653131] usb 1-1: Detected FT2232C/D
[1051957.747695] ftdi_sio ttyUSB0: Unable to write latency timer: -71

another try got up to 39% while logging the mpsse_* messages way quicker

I've tried two cables that have worked with other devices, but after replacing it again with an USB-C charging cable (thicker, rated to 60W), it succeeded repeatedly.

@trabucayre
Copy link
Owner

Yes: cables are not always good or enough. I don't know the exact reason (maybe to electrical noise, or lost of current). It's usual to have to switch between cables...

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

5 participants