**** BEGIN LOGGING AT Tue Mar 27 02:59:56 2007 Mar 27 13:50:56 hello vmaster... Mar 27 13:51:32 hey xela Mar 27 13:51:59 debugging works fine so far (i uploaded my config to openfacts) Mar 27 13:52:24 but on larger files i get the error "could not allocate... workspace..." Mar 27 13:52:30 do you have an idea for this? Mar 27 14:04:37 where's that error from? Mar 27 14:04:45 OpenOCD? Mar 27 14:04:48 from openocd Mar 27 14:04:50 yes Mar 27 14:05:30 do you have a log, or a screenshot? Mar 27 14:05:40 gotta run, i'll be back in 30minutes or so Mar 27 14:34:35 ok, i'm back Mar 27 14:48:04 sorry, have to go for a meeting :-( Mar 27 14:48:07 will ask again Mar 27 16:26:11 vmaster: i am back Mar 27 16:26:14 you still there? Mar 27 16:26:58 yeah Mar 27 16:27:27 > flash erase 0 0 9 Mar 27 16:27:28 erased sectors 0 through 9 on flash bank 0 in 3s 984375us Mar 27 16:27:30 > flash write 0 ../app/src/output/app.bin 0 Mar 27 16:27:31 > flash write 0 ../app/src/output/app.bin 0 Mar 27 16:27:33 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 16:27:34 flash program error Mar 27 16:27:40 and in the openocd window i got: Mar 27 16:27:55 Warning: target.c:537 target_alloc_working_area(): not enough working area available Mar 27 16:27:56 Error: armv4_5.c:584 armv4_5_run_algorithm(): timeout waiting for algorithm to complete, trying to halt target Mar 27 16:27:58 Error: str7x.c:539 str7x_write_block(): error executing str7x flash write algorithm Mar 27 16:27:59 Error: str7x.c:627 str7x_write(): flash writing failed with error code: 0x0 Mar 27 16:28:08 do you have a "working_area" line your .cfg? Mar 27 16:28:28 working_area 0 0x40000000 0x4000 nobackup Mar 27 16:29:08 too big? (stack issues?) Mar 27 16:29:14 disable irqs? Mar 27 16:29:26 irqs should be disabled Mar 27 16:29:43 you're using the str750 iirc? Mar 27 16:29:47 yep Mar 27 16:31:47 ok, the working_area msg isn't critical. the code first tries to allocate a 8kb buffer and then decreases the size Mar 27 16:31:56 ah ok Mar 27 16:32:27 since our last conversation i have flash the bootloader (which has 2 x 16KB) several dozen times without an error Mar 27 16:32:47 but the app has 232KB and I have a hard time to get it flashed Mar 27 16:36:06 could you try again with "-d -l " - that should show us where the algorithm execution stopped Mar 27 16:36:23 ok Mar 27 16:42:22 ok Mar 27 16:42:26 it worked several times Mar 27 16:42:33 but now i have the reset again Mar 27 16:42:52 sorry, error Mar 27 16:42:59 the file is pretty big... Mar 27 16:43:10 interested in a special portion? Mar 27 16:43:42 it should compress quite well Mar 27 16:43:51 Error: armv4_5.c:584 armv4_5_run_algorithm(): timeout waiting for algorithm to complete, trying to halt target Mar 27 16:44:08 yeah, mostly the stuff after that Mar 27 16:44:58 how can i send it to you? Mar 27 16:45:14 Dominic Rath gmx de Mar 27 16:45:23 or pastebin.ca Mar 27 16:46:19 sent Mar 27 16:47:07 ok, got it... let me check what's in there Mar 27 16:54:58 hum, looks like interrupts were indeed enabled - but i remember fixing that more than half a year ago Mar 27 16:56:03 the executable is from openocd-2007re131 Mar 27 17:05:04 what i dont understand... Mar 27 17:07:50 who enables the interrupts? Mar 27 17:07:58 if i issue an "soft_reset_halt" Mar 27 17:08:23 and then "flash write..." i would think there is no such thing like enabled interrupts Mar 27 17:09:37 yeah, the interrupts should be disabled, and there should also be a bit in the EmbeddedICE control register set to keep interrupts disabled, no matter what's in CPSR Mar 27 17:10:17 can i set this in openocd? at least as a workaround for now? Mar 27 17:32:02 there are several things that i don't understand with this log Mar 27 17:32:22 anything i can help? information you need from me? Mar 27 17:32:28 CPSR has I and F set to zero, i.e. interrupts enabled, but the soft_reset_halt should have set them Mar 27 17:33:20 can you show me the telnet log from when the flashing failed? Mar 27 17:33:36 openocd crashed several times in the meantime... Mar 27 17:33:43 but i will retry it Mar 27 17:36:13 Open On-Chip Debugger Mar 27 17:36:14 > soft_reset_halt Mar 27 17:36:16 requesting target halt and executing a soft reset Mar 27 17:36:17 Target 0 halted Mar 27 17:36:19 target halted in ARM state due to debug request, current mode: Supervisor Mar 27 17:36:20 cpsr: 0x600000d3 pc: 0x00000000 Mar 27 17:36:22 > flash erase 0 0 9 Mar 27 17:36:23 erased sectors 0 through 9 on flash bank 0 in 3s 843750us Mar 27 17:36:25 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:36:26 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:36:28 flash program error Mar 27 17:36:29 > Mar 27 17:36:31 i just sent the log to your email address Mar 27 17:38:06 ok, thanks Mar 27 17:41:01 when i retry flashing after this i get: Mar 27 17:41:03 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:41:04 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:41:05 flash program error Mar 27 17:41:07 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:41:09 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:41:10 flash program error Mar 27 17:41:12 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:41:13 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:41:15 flash program error Mar 27 17:41:16 > Mar 27 17:43:25 ok, this time the CPSR was ok, so it isn't interrupt related Mar 27 17:45:47 when i try flashing from within gdb i get something like Mar 27 17:46:11 (gdb) monitor flash write 0 ../app/src/output/app.bin 0 Mar 27 17:46:13 Ignoring packet error, continuing... Mar 27 17:46:14 (gdb) Reply contains invalid hex digit 116 Mar 27 17:46:23 but i think this is a different problem Mar 27 17:47:02 (ah, and after that ignoring... the telnet is sloooooow, or doesnt respond for several minutes) Mar 27 17:49:02 openocd shows: Mar 27 17:49:04 Warning: gdb_server.c:195 gdb_put_packet(): negative reply, retrying Mar 27 17:49:33 hum, that's totally unrelated (but shouldn't happen either) Mar 27 17:50:32 is there a bugtracker for openocd? maybe the one on berlios? Mar 27 17:51:01 well, yeah, but i'm the only one who monitors that bugtracker, so it's not much use... Mar 27 17:51:35 ok Mar 27 17:51:41 some more info Mar 27 17:51:46 after flashing has failed Mar 27 17:52:07 every time i try to flash after that error i get the same flash error Mar 27 17:52:24 after several retries it seems to work or at least "do" something Mar 27 17:52:35 the output in openocd is: Mar 27 17:52:39 ok, but did it ever work on a "fresh" start? Mar 27 17:52:49 Warning: target.c:537 target_alloc_working_area(): not enough working area available Mar 27 17:52:51 Warning: str7x.c:511 str7x_write_block(): no large enough working area available, can't do block memory writes Mar 27 17:52:52 Warning: str7x.c:620 str7x_write(): couldn't use block writes, falling back to single memory accesses Mar 27 17:53:13 what do you mean with fresh start? restart openocd? powerdown/powerup`? Mar 27 17:53:31 did you leave it runnig after the "falling back" message? did it finish? Mar 27 17:53:45 yeah, by "fresh start" i mean a power-up Mar 27 17:53:55 or at least "restart openocd" Mar 27 17:54:15 the fall back should take /long/ Mar 27 17:54:31 like 15 or 20 minutes for your 200+kb file Mar 27 17:54:41 i didnt leave it on running Mar 27 17:55:55 did you ever succeed with writing the whole image? Mar 27 17:56:09 yes Mar 27 17:59:00 > reset Mar 27 17:59:02 > Target 0 halted Mar 27 17:59:04 target halted in ARM state due to debug request, current mode: System Mar 27 17:59:05 cpsr: 0x8000001f pc: 0x2000058c Mar 27 17:59:07 > soft_reset_halt Mar 27 17:59:08 requesting target halt and executing a soft reset Mar 27 17:59:10 Target 0 halted Mar 27 17:59:11 target halted in ARM state due to debug request, current mode: Supervisor Mar 27 17:59:13 cpsr: 0x800000d3 pc: 0x00000000 Mar 27 17:59:14 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:59:16 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:59:17 flash program error Mar 27 17:59:19 > reset Mar 27 17:59:20 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:59:22 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:59:23 can't work with this flash while target is running Mar 27 17:59:25 > Target 0 halted Mar 27 17:59:26 target halted in Thumb state due to debug request, current mode: System Mar 27 17:59:28 cpsr: 0xffffffff pc: 0xa1a1a191 Mar 27 17:59:29 > reset Mar 27 17:59:31 > Target 0 halted Mar 27 17:59:33 target halted in ARM state due to debug request, current mode: IRQ Mar 27 17:59:35 cpsr: 0x80000092 pc: 0x00000000 Mar 27 17:59:37 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:59:39 failed writing file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 Mar 27 17:59:41 flash program error Mar 27 17:59:43 > flash write 0 ../app/src/output/app.bin 0 Mar 27 17:59:45 wrote file ../app/src/output/app.bin to flash bank 0 at offset 0x00000000 in 33s 843750us Mar 27 17:59:47 > Mar 27 18:00:00 ok, retrying after it failed once is definitely not a good idea Mar 27 18:00:26 ah, you issued "reset" in between Mar 27 18:00:44 was a thing i wanted to try now after all those errors Mar 27 18:01:08 ok, that's your current state? Mar 27 18:01:35 i.e. you have the image in flash, and the OpenOCD reported that it worked? Mar 27 18:01:44 yes Mar 27 18:02:13 but i need several approaches until it works Mar 27 18:02:21 could you verify that the flashing worked by dumping to a file (dump binary

)? Mar 27 18:07:58 moment... Mar 27 18:12:42 the files are identical Mar 27 18:15:15 hum, we could break on any exception... that should allow us to see why the algorithm execution is aborted Mar 27 18:15:27 s/any/every/ Mar 27 18:15:28 vmaster meant: hum, we could break on every exception... that should allow us to see why the algorithm execution is aborted Mar 27 18:18:44 gotta run some checks here first Mar 27 18:33:14 yes Mar 27 18:33:23 (had some pizza...) Mar 27 18:41:10 vmaster: did you set up the OpenFacts page with the example scripts as well? Mar 27 18:42:15 mhh, i think the example scripts page was contributed Mar 27 18:48:34 well, i though about indenting the script with one space Mar 27 18:48:47 so they would be formatted as source code (courier new) or alike Mar 27 18:49:14 but since i am new here i dont want to just trample about and change whatever i see... Mar 27 18:49:25 (but willing to contribute) Mar 27 18:59:31 s/though/though/ Mar 27 19:13:02 xela: ok, got something for you to test Mar 27 19:13:13 great! Mar 27 19:13:37 make sure everything is "clean", i.e. the flash erased, board freshly powered up, openocd restarted Mar 27 19:14:02 ok Mar 27 19:15:12 use the "reg" command to set these registers: Mar 27 19:15:15 (47) watch 1 addr value (/32): 0x00000000 (dirty: 0, valid: 1) Mar 27 19:15:15 (48) watch 1 addr mask (/32): 0x0000001f (dirty: 0, valid: 1) Mar 27 19:15:15 (49) watch 1 data value (/32): 0x00000000 (dirty: 0, valid: 1) Mar 27 19:15:15 (50) watch 1 data mask (/32): 0xffffffff (dirty: 0, valid: 1) Mar 27 19:15:15 (51) watch 1 control value (/32): 0x00000100 (dirty: 0, valid: 1) Mar 27 19:15:18 (52) watch 1 control mask (/32): 0x000000f7 (dirty: 0, valid: 1) Mar 27 19:15:44 this causes a breakpoint to be taken on every vector Mar 27 19:15:50 then try the flash write sequence Mar 27 19:15:59 make sure logging is enabled Mar 27 19:16:03 ok Mar 27 19:18:00 it might seems as if it worked, but you'll only know after comparing with a dump Mar 27 19:18:53 whats the command to set a register? Mar 27 19:19:09 "reg e.g. "reg 47 0x0" Mar 27 19:20:51 ok Mar 27 19:21:32 1 try succeeded Mar 27 19:21:50 i will erase and restart Mar 27 19:21:52 no Mar 27 19:21:55 dump Mar 27 19:22:03 ok Mar 27 19:22:05 only a dump shows you if it really succeeded Mar 27 19:22:18 to the algorithm code, the breakpoint we set looks like it completed Mar 27 19:35:35 moment have to install cygwin (the hexdump tool i used is win32 crap that produced invalid results) Mar 27 19:36:36 hmm, just send me the log you've got Mar 27 19:36:45 i guess i'll be able to see if it worked Mar 27 19:37:03 the PC is recorded on reentering debug state Mar 27 19:38:02 ok, sent Mar 27 19:39:56 ok, files are identical Mar 27 19:42:20 hmm, yeah, debug was always entered at: Mar 27 19:42:21 Debug: arm7_9_common.c:1011 arm7_9_debug_entry(): entered debug state at PC 0x4000004c Mar 27 19:59:50 anything i can do? Mar 27 20:01:15 if you want you can try again until the dump fails Mar 27 20:01:39 and send a log from that run Mar 27 20:01:46 ideally you'd start the OpenOCD again on each try Mar 27 20:01:55 hm. Mar 27 20:02:43 or use the additional breakpoint each time you have to flash anyway Mar 27 20:03:19 you mean the reg... sequence? Mar 27 20:03:28 yeah Mar 27 20:03:33 you can put the commands into a script file Mar 27 20:03:39 (a normal text file) Mar 27 20:03:44 and call that with "script" Mar 27 20:03:50 ok Mar 27 20:27:54 can i run openocd from the commandline, so it only executed some steps and then returns? Mar 27 20:28:23 hmm? Mar 27 20:30:19 i would like to automize this task Mar 27 20:30:21 you know Mar 27 20:30:25 ah, yeah, that's possible Mar 27 20:30:28 erase/flash/dump/compare Mar 27 20:30:44 hold on, i think there's already an example on the net somewhere Mar 27 20:31:13 http://www.siwawi.arubi.uni-kl.de/avr_projects/arm_projects/openocd_intro/index.html Mar 27 20:31:35 not sure if'll get used to that new nick... but vmaster really is from way back in the gaming days... ;) Mar 27 20:31:45 :-) Mar 27 20:32:40 hm. should i use dcc_downloads as well? Mar 27 20:32:44 you define a target script that gets called after "run_and_halt" Mar 27 20:32:50 no, that's only a speed improvement Mar 27 20:33:00 which might furhter complicate things Mar 27 20:33:06 ok Mar 27 21:16:34 i have setup such a script using python and telnetlib Mar 27 21:23:00 from telnetlib import Telnet Mar 27 21:23:01 import re Mar 27 21:23:03 t=Telnet('127.0.0.1', 4444) Mar 27 21:23:04 FILTER=''.join([(len(repr(chr(x)))==3) and chr(x) or '.' for x in range(256)]) Mar 27 21:23:06 def hexDump(src, length=8): Mar 27 21:23:07 N=0; result='' Mar 27 21:23:09 while src: Mar 27 21:23:10 s,src = src[:length],src[length:] Mar 27 21:23:12 hexa = ' '.join(["%02X"%ord(x) for x in s]) Mar 27 21:23:14 s = s.translate(FILTER) Mar 27 21:23:15 result += "%04X %-*s %s\n" % (N, length*3, hexa, s) Mar 27 21:23:17 N+=length Mar 27 21:23:18 return result Mar 27 21:23:20 def dumpFile(bin_file, hex_file): Mar 27 21:23:21 f=open(bin_file, 'rb') Mar 27 21:23:23 blob=f.read() Mar 27 21:23:24 f.close() Mar 27 21:23:26 dump=hexDump(blob) Mar 27 21:23:27 f=open(hex_file, 'w') Mar 27 21:23:29 f.write(dump) Mar 27 21:23:31 f.close() Mar 27 21:23:33 return dump Mar 27 21:23:35 def cmd(args): Mar 27 21:23:37 args += '\n' Mar 27 21:23:39 print args Mar 27 21:23:41 t.write(args) Mar 27 21:23:43 x=t.read_until('>') #,5) Mar 27 21:23:45 print x Mar 27 21:23:47 if re.search("error",x): Mar 27 21:23:49 raise Exception('Error in command %s' % (args)) Mar 27 21:23:51 Mar 27 21:23:53 BIN='../app/src/output/app.bin' Mar 27 21:23:55 HEX='app.hex' Mar 27 21:23:57 DUMP='dump.bin' Mar 27 21:23:59 DUMP_HEX='dump.hex' Mar 27 21:24:01 app_hex=dumpFile(BIN,HEX) Mar 27 21:24:03 t.read_until('>') Mar 27 21:24:05 cmd('halt') Mar 27 21:24:07 cmd('reset') Mar 27 21:24:09 cmd('soft_reset_halt') Mar 27 21:24:11 cmd('flash erase 0 0 9') Mar 27 21:24:13 cmd('reg 47 0x00000000 ') Mar 27 21:24:15 cmd('reg 48 0x0000001f ') Mar 27 21:24:17 cmd('reg 49 0x00000000 ') Mar 27 21:24:19 cmd('reg 50 0xffffffff ') Mar 27 21:24:21 cmd('reg 51 0x00000100 ') Mar 27 21:24:23 cmd('reg 52 0x000000f7 ') Mar 27 21:24:25 cmd('flash write 0 %s 0' % (BIN)) Mar 27 21:24:27 cmd('soft_reset_halt') Mar 27 21:24:29 cmd('dump %s 0x20000000 0x3A000' % (DUMP)) Mar 27 21:24:31 dump_hex=dumpFile(DUMP,DUMP_HEX) Mar 27 21:24:33 if app_hex != dump_hex: Mar 27 21:24:35 print "Verify failed!!!" Mar 27 21:25:16 drath: still there? Mar 27 21:31:09 yeah Mar 27 21:31:43 so, did it eventually fail? Mar 27 21:31:43 well. i guess i have to get some sleep soon Mar 27 21:32:00 i didnt manage to get it flashed Mar 27 21:32:26 so now i am commenting out the erase Mar 27 21:32:33 maybe thats the problem (here) Mar 27 21:43:50 now i created a loop in my script to program only blocks of 1024 bytes Mar 27 21:43:53 this worked fine Mar 27 21:44:10 will increase the blocksize to 16384 or so Mar 27 21:50:06 heh, just don't wear out your flash because of this problem Mar 27 21:50:38 well, should make no difference whether i program it in one large piece or smaller ones Mar 27 22:31:53 hm even using blocks i get this error **** ENDING LOGGING AT Wed Mar 28 02:59:56 2007