usb_bulk_write failed jlink linux STM32

I am trying to get my JLink to program my STM 32 board. It connects OK and I can dump memory and erase flash. I just can’t write to flash. It looks like every time it tries to write the write returns ETIMEDOUT.

Any suggestions would be greatly appreciated. Thanks.

config file:

# script for stm32

# use jlink
interface jlink

# jtag speed
jtag_khz 500

jtag_nsrst_delay 100
jtag_ntrst_delay 100

#use combined on interfaces or targets that can't set TRST/SRST separately
reset_config trst_and_srst

#jtag scan chain
#format L IRC IRCM IDCODE (Length, IR Capture, IR Capture Mask, IDCODE)
jtag_device 4 0x1 0xf 0xe
jtag_device 5 0x1 0x1 0x1e

#target <type> <startup mode>
#target arm7tdmi <reset mode> <chainpos> <endianness> <variant>
target cortex_m3 little 0 0 


working_area 0 0x20000000 16384 nobackup

#flash bank str7x <base> <size> 0 0 <target#> <variant>
flash bank stm32x 0 0 0 0 0

# For more information about the configuration files, take a look at:
# openocd.texi

Commands:

./openocd -f target/target/LPM.cfg -d3 -l log.txt
$ telnet localhost 4444
Trying 127.0.0.1...
Connected to localhost.localdomain (127.0.0.1).
Escape character is '^]'.
Open On-Chip Debugger
> flash probe 0
device id = 0x10016414
flash size = 256kbytes
flash 'stm32x' found at 0x08000000
> mdw 0x08000000 4
0x08000000: ffffffff ffffffff ffffffff ffffffff 
> mdw 0x20000000 4
0x20000000: 4024f8df f04f4d09 60230301 3b02f830 
> poll
target state: halted
target halted due to undefined, current mode: Thread 
xPSR: 0x00000000 pc: 0x00000000
> stm32x mass_erase 0
stm32x mass erase complete
> flash write_image /tmp/foo.bin 0x08000000
usb_bulk_read failed (requested=1629, result=-110)
jlink_tap_execute, wrong result -1, expected 1629
usb_bulk_write failed (requested=3276, result=-110)
jlink_tap_execute, wrong result -1, expected 1636
usb_bulk_write failed (requested=3290, result=-110)
jlink_tap_execute, wrong result -1, expected 1643
Connection closed by foreign host.

LOG:

$ cat log.txt 
Debug:   9 1 configuration.c:88 find_file(): found target/target/LPM.cfg
Debug:   11 1 command.c:82 script_command(): script_command - interface
Debug:   12 1 command.c:99 script_command(): script_command - interface, argv[0]=ocd_interface
Debug:   13 1 command.c:99 script_command(): script_command - interface, argv[1]=jlink
Debug:   15 1 command.c:82 script_command(): script_command - jtag_khz
Debug:   16 1 command.c:99 script_command(): script_command - jtag_khz, argv[0]=ocd_jtag_khz
Debug:   17 1 command.c:99 script_command(): script_command - jtag_khz, argv[1]=500
Debug:   18 1 jtag.c:1965 handle_jtag_khz_command(): handle jtag khz
User:    19 1 command.c:363 command_print(): jtag_khz: 500
Debug:   21 1 command.c:82 script_command(): script_command - jtag_nsrst_delay
Debug:   22 1 command.c:99 script_command(): script_command - jtag_nsrst_delay, argv[0]=ocd_jtag_nsrst_delay
Debug:   23 1 command.c:99 script_command(): script_command - jtag_nsrst_delay, argv[1]=100
Debug:   25 1 command.c:82 script_command(): script_command - jtag_ntrst_delay
Debug:   26 1 command.c:99 script_command(): script_command - jtag_ntrst_delay, argv[0]=ocd_jtag_ntrst_delay
Debug:   27 1 command.c:99 script_command(): script_command - jtag_ntrst_delay, argv[1]=100
Debug:   29 1 command.c:82 script_command(): script_command - reset_config
Debug:   30 1 command.c:99 script_command(): script_command - reset_config, argv[0]=ocd_reset_config
Debug:   31 1 command.c:99 script_command(): script_command - reset_config, argv[1]=trst_and_srst
Debug:   33 1 command.c:82 script_command(): script_command - jtag_device
Debug:   34 1 command.c:99 script_command(): script_command - jtag_device, argv[0]=ocd_jtag_device
Debug:   35 1 command.c:99 script_command(): script_command - jtag_device, argv[1]=4
Debug:   36 1 command.c:99 script_command(): script_command - jtag_device, argv[2]=0x1
Debug:   37 1 command.c:99 script_command(): script_command - jtag_device, argv[3]=0xf
Debug:   38 1 command.c:99 script_command(): script_command - jtag_device, argv[4]=0xe

Debug:   40 1 command.c:82 script_command(): script_command - jtag_device
Debug:   41 1 command.c:99 script_command(): script_command - jtag_device, argv[0]=ocd_jtag_device
Debug:   42 1 command.c:99 script_command(): script_command - jtag_device, argv[1]=5
Debug:   43 1 command.c:99 script_command(): script_command - jtag_device, argv[2]=0x1
Debug:   44 1 command.c:99 script_command(): script_command - jtag_device, argv[3]=0x1
Debug:   45 1 command.c:99 script_command(): script_command - jtag_device, argv[4]=0x1e
Debug:   46 1 target.c:3859 jim_target(): Target command params:
Debug:   47 2 target.c:3860 jim_target(): target cortex_m3 little 0 0 
Debug:   48 2 target.c:3951 jim_target(): Target OLD SYNTAX - converted to new syntax
Debug:   49 2 target.c:3859 jim_target(): Target command params:
Debug:   50 2 target.c:3860 jim_target(): target create target0 cortex_m3 -endian little -chain-position 0 -variant 0 
Debug:   51 2 cortex_m3.c:1493 cortex_m3_init_arch_info(): variant = 8391490

Debug:   52 2 cortex_m3.c:1493 cortex_m3_init_arch_info(): variant = 8391490

Debug:   54 2 command.c:82 script_command(): script_command - working_area
Debug:   55 2 command.c:99 script_command(): script_command - working_area, argv[0]=ocd_working_area
Debug:   56 2 command.c:99 script_command(): script_command - working_area, argv[1]=0
Debug:   57 2 command.c:99 script_command(): script_command - working_area, argv[2]=0x20000000
Debug:   58 2 command.c:99 script_command(): script_command - working_area, argv[3]=16384
Debug:   59 2 command.c:99 script_command(): script_command - working_area, argv[4]=nobackup
Debug:   61 2 command.c:82 script_command(): script_command - bank
Debug:   62 2 command.c:99 script_command(): script_command - bank, argv[0]=ocd_flash_bank
Debug:   63 2 command.c:99 script_command(): script_command - bank, argv[1]=stm32x
Debug:   64 2 command.c:99 script_command(): script_command - bank, argv[2]=0
Debug:   65 2 command.c:99 script_command(): script_command - bank, argv[3]=0
Debug:   66 2 command.c:99 script_command(): script_command - bank, argv[4]=0
Debug:   67 2 command.c:99 script_command(): script_command - bank, argv[5]=0
Debug:   68 2 command.c:99 script_command(): script_command - bank, argv[6]=0
Debug:   70 2 command.c:82 script_command(): script_command - init
Debug:   71 2 command.c:99 script_command(): script_command - init, argv[0]=ocd_init
Debug:   72 4 openocd.c:133 handle_init_command(): target init complete
Info:    73 9 jlink.c:528 jlink_get_version_info(): J-Link ARM V6 compiled Aug 28 2007 19:22:02
Info:    74 11 jlink.c:496 jlink_get_status(): Vref = 3.306 TCK = 1 TDI = 0 TDO = 1 TMS = 0 SRST = 1 TRST = 1

Info:    75 11 jlink.c:317 jlink_init(): J-Link JTAG Interface ready
Debug:   76 11 jlink.c:446 jlink_reset(): trst: 0, srst: 0
Debug:   77 13 openocd.c:140 handle_init_command(): jtag interface init complete
Debug:   78 13 jtag.c:1621 jtag_init_inner(): Init JTAG chain
Debug:   79 13 jtag.c:327 jtag_call_event_callbacks(): jtag event: JTAG controller reset (TLR or TRST)
Debug:   80 13 jtag.c:1301 jtag_reset_callback(): -
Debug:   81 13 jtag.c:1301 jtag_reset_callback(): -
Debug:   82 16 jtag.c:327 jtag_call_event_callbacks(): jtag event: JTAG controller reset (TLR or TRST)
Debug:   83 16 jtag.c:1301 jtag_reset_callback(): -
Debug:   84 16 jtag.c:1301 jtag_reset_callback(): -
Info:    85 51 jtag.c:1410 jtag_examine_chain(): JTAG device found: 0x3ba00477 (Manufacturer: 0x23b, Part: 0xba00, Version: 0x3)
Info:    86 51 jtag.c:1410 jtag_examine_chain(): JTAG device found: 0x06414041 (Manufacturer: 0x020, Part: 0x6414, Version: 0x0)
Debug:   87 51 jtag.c:327 jtag_call_event_callbacks(): jtag event: JTAG controller reset (TLR or TRST)
Debug:   88 51 jtag.c:1301 jtag_reset_callback(): -
Debug:   89 51 jtag.c:1301 jtag_reset_callback(): -
Debug:   90 54 openocd.c:146 handle_init_command(): jtag init complete
Debug:   91 54 cortex_swjdp.c:968 ahbap_debugport_init():  
Debug:   92 137 cortex_swjdp.c:1012 ahbap_debugport_init(): AHB-AP ID Register 0x14770011, Debug ROM Address 0xe00ff003
Debug:   93 166 target.c:1192 target_read_u32(): address: 0xe000ed00, value: 0x411fc231
Debug:   94 166 cortex_m3.c:1365 cortex_m3_examine(): CORTEX-M3 processor detected
Debug:   95 166 cortex_m3.c:1366 cortex_m3_examine(): cpuid: 0x411fc231
Debug:   96 190 target.c:1192 target_read_u32(): address: 0xe000e004, value: 0x00000001
Debug:   97 214 target.c:1192 target_read_u32(): address: 0xe000e100, value: 0x00000000
Debug:   98 214 cortex_m3.c:1374 cortex_m3_examine(): interrupt enable[0] = 0x00000000
Debug:   99 238 target.c:1192 target_read_u32(): address: 0xe000e104, value: 0x00000000
Debug:   100 238 cortex_m3.c:1374 cortex_m3_examine(): interrupt enable[1] = 0x00000000
Debug:   101 262 target.c:1192 target_read_u32(): address: 0xe0002000, value: 0x00000261
Debug:   102 262 cortex_m3.c:1389 cortex_m3_examine(): FPB fpcr 0x261, numcode 6, numlit 2
Debug:   103 286 target.c:1192 target_read_u32(): address: 0xe0001000, value: 0x40000000
Debug:   104 286 openocd.c:149 handle_init_command(): jtag examine complete
Debug:   105 286 openocd.c:155 handle_init_command(): flash init complete
Debug:   106 286 openocd.c:159 handle_init_command(): mflash init complete
Debug:   107 286 openocd.c:163 handle_init_command(): NAND init complete
Debug:   108 286 openocd.c:167 handle_init_command(): pld init complete
Warning: 109 286 telnet_server.c:612 telnet_init(): no telnet port specified, using default port 4444
Warning: 110 287 gdb_server.c:2147 gdb_init(): no gdb port specified, using default port 3333
Debug:   111 287 gdb_server.c:2168 gdb_init(): gdb service for target cortex_m3 at port 3333
Warning: 112 287 tcl_server.c:178 tcl_init(): no tcl port specified, using default port 6666
Info:    113 4010 server.c:84 add_connection(): accepting 'telnet' connection from 0
Debug:   115 18938 command.c:82 script_command(): script_command - probe
Debug:   116 18938 command.c:99 script_command(): script_command - probe, argv[0]=ocd_flash_probe
Debug:   117 18938 command.c:99 script_command(): script_command - probe, argv[1]=0
Debug:   118 18967 target.c:1192 target_read_u32(): address: 0xe0042000, value: 0x10016414
Info:    119 18967 stm32x.c:706 stm32x_probe(): device id = 0x10016414
Debug:   120 18998 target.c:1217 target_read_u16(): address: 0x1ffff7e0, value: 0x0100
Info:    121 18998 stm32x.c:751 stm32x_probe(): flash size = 256kbytes
User:    122 18998 command.c:363 command_print(): flash 'stm32x' found at 0x08000000
Debug:   124 34528 command.c:82 script_command(): script_command - mdw
Debug:   125 34528 command.c:99 script_command(): script_command - mdw, argv[0]=ocd_mdw
Debug:   126 34528 command.c:99 script_command(): script_command - mdw, argv[1]=0x08000000
Debug:   127 34528 command.c:99 script_command(): script_command - mdw, argv[2]=4
User:    128 34565 command.c:363 command_print(): 0x08000000: ffffffff ffffffff ffffffff ffffffff 
Debug:   130 44487 command.c:82 script_command(): script_command - mdw
Debug:   131 44488 command.c:99 script_command(): script_command - mdw, argv[0]=ocd_mdw
Debug:   132 44488 command.c:99 script_command(): script_command - mdw, argv[1]=0x20000000
Debug:   133 44488 command.c:99 script_command(): script_command - mdw, argv[2]=4
User:    134 44524 command.c:363 command_print(): 0x20000000: 4024f8df f04f4d09 60230301 3b02f830 
Debug:   136 53950 command.c:82 script_command(): script_command - poll
Debug:   137 53950 command.c:99 script_command(): script_command - poll, argv[0]=ocd_poll
User:    138 53972 target.c:965 target_arch_state(): target state: halted
User:    139 53972 armv7m.c:465 armv7m_arch_state(): target halted due to undefined, current mode: Thread 
xPSR: 0x00000000 pc: 0x00000000
Debug:   141 63949 command.c:82 script_command(): script_command - mass_erase
Debug:   142 63949 command.c:99 script_command(): script_command - mass_erase, argv[0]=ocd_stm32x_mass_erase
Debug:   143 63949 command.c:99 script_command(): script_command - mass_erase, argv[1]=0
Debug:   144 63949 target.c:1260 target_write_u32(): address: 0x40022004, value: 0x45670123
Debug:   145 63976 target.c:1260 target_write_u32(): address: 0x40022004, value: 0xcdef89ab
Debug:   146 63998 target.c:1260 target_write_u32(): address: 0x40022010, value: 0x00000004
Debug:   147 64020 target.c:1260 target_write_u32(): address: 0x40022010, value: 0x00000044
Debug:   148 64066 target.c:1192 target_read_u32(): address: 0x4002200c, value: 0x00000003
Debug:   149 64066 stm32x.c:128 stm32x_wait_status_busy(): status: 0x3
Debug:   150 64093 target.c:1192 target_read_u32(): address: 0x4002200c, value: 0x00000020
Debug:   151 64093 target.c:1260 target_write_u32(): address: 0x40022010, value: 0x00000080
User:    152 64115 command.c:363 command_print(): stm32x mass erase complete
Debug:   154 122466 command.c:82 script_command(): script_command - write_image
Debug:   155 122466 command.c:99 script_command(): script_command - write_image, argv[0]=ocd_flash_write_image
Debug:   156 122466 command.c:99 script_command(): script_command - write_image, argv[1]=/tmp/foo.bin
Debug:   157 122466 command.c:99 script_command(): script_command - write_image, argv[2]=0x08000000
Debug:   158 122466 configuration.c:88 find_file(): found /tmp/foo.bin
Debug:   159 122466 configuration.c:88 find_file(): found /tmp/foo.bin
Debug:   160 122466 target.c:1260 target_write_u32(): address: 0x40022004, value: 0x45670123
Debug:   161 122493 target.c:1260 target_write_u32(): address: 0x40022004, value: 0xcdef89ab
Debug:   162 122515 target.c:832 target_alloc_working_area(): allocating new working area
Debug:   163 122515 target.c:981 target_write_buffer(): writing buffer of 48 byte at 0x20000000
Debug:   164 122565 target.c:832 target_alloc_working_area(): allocating new working area
Debug:   165 122565 target.c:981 target_write_buffer(): writing buffer of 5736 byte at 0x20000030
Error:   166 122671 jlink.c:839 jlink_usb_message(): usb_bulk_read failed (requested=1629, result=-110)
Error:   167 122672 jlink.c:723 jlink_tap_execute(): jlink_tap_execute, wrong result -1, expected 1629
Error:   168 122773 jlink.c:845 jlink_usb_message(): usb_bulk_write failed (requested=3276, result=-110)
Error:   169 122774 jlink.c:723 jlink_tap_execute(): jlink_tap_execute, wrong result -1, expected 1636
Error:   170 122875 jlink.c:845 jlink_usb_message(): usb_bulk_write failed (requested=3290, result=-110)
Error:   171 122876 jlink.c:723 jlink_tap_execute(): jlink_tap_execute, wrong result -1, expected 1643

[/code]

Fixed the problem by making the usb timeout 10x longer.

$ diff -u src/jtag/jlink.c.orig src/jtag/jlink.c
--- src/jtag/jlink.c.orig       2008-10-29 19:39:59.000000000 -0400
+++ src/jtag/jlink.c    2008-10-29 19:27:38.000000000 -0400
@@ -52,7 +52,7 @@
 #define JLINK_WRITE_ENDPOINT   0x02
 #define JLINK_READ_ENDPOINT            0x81
 
-#define JLINK_USB_TIMEOUT              100
+#define JLINK_USB_TIMEOUT              1000
 
 #define JLINK_IN_BUFFER_SIZE                   8192
 #define JLINK_OUT_BUFFER_SIZE                  8192

Thanks!

Just hit this same little issue myself :slight_smile:

For info what version of libusb are you using?

I will look into it and commit the changes to svn.

Cheers

Spen

yum info libusb output:

Installed Packages
Name   : libusb
Arch   : i386
Version: 0.1.12
Release: 5.1
Size   : 51 k
Repo   : installed
Summary: A library which allows userspace access to USB devices.
Description:
This package provides a way for applications to access USB devices.


/usr/lib(15)$

Thanks,

Dylan