Andrey, possible workaround: use command 'poll off' before CRC and 'poll on' after? But with a GDB attached, GDB could timeout...
--- ** [tickets:#362] Script performance degradation due to jim_command_dispatch() / target_call_timer_callbacks_now()** **Status:** new **Milestone:** 0.11.0 **Created:** Thu Sep 01, 2022 07:13 PM UTC by Andrey **Last Updated:** Mon Sep 05, 2022 10:14 AM UTC **Owner:** nobody Hi, As of current master we are seeing a severe degradation in the performance of executing some of the TCL scripts (some of our scripts have to pre-process binaries for specific targets or e.g. calculate CRC32). We've traced this down to target_call_timer_callbacks_now() call in jim_command_dispatch() causing a call into the debugger (target_poll()) on pretty much every expression in the TCL script when the script is executing while the target is initialized: ~~~ Debug: 8025 4650 command.c:166 script_debug(): command - expr ($crc_value ^ [scan $c %c])&0xff Debug: 8026 4650 cmsis_dap.c:778 cmsis_dap_swd_write_from_queue(): Executing 2 queued transactions from FIFO index 0 Debug: 8027 4650 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): AP read reg 0 0 Debug: 8028 4650 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): DP read reg c 0 Debug: 8029 4654 cmsis_dap.c:893 cmsis_dap_swd_read_process(): Received results of 2 queued transactions FIFO index 0 Debug: 8030 4654 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8031 4654 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8032 4654 command.c:166 script_debug(): command - expr [lindex $CRCTABLE [expr {($crc_value ^ [scan $c %c])&0xff}]]^(($crc_value>>8)&0xffffff) Debug: 8033 4654 cmsis_dap.c:778 cmsis_dap_swd_write_from_queue(): Executing 2 queued transactions from FIFO index 0 Debug: 8034 4654 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): AP read reg 0 0 Debug: 8035 4654 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): DP read reg c 0 Debug: 8036 4658 cmsis_dap.c:893 cmsis_dap_swd_read_process(): Received results of 2 queued transactions FIFO index 0 Debug: 8037 4658 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8038 4658 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8039 4658 command.c:166 script_debug(): command - expr ($crc_value ^ [scan $c %c])&0xff Debug: 8040 4658 cmsis_dap.c:778 cmsis_dap_swd_write_from_queue(): Executing 2 queued transactions from FIFO index 0 Debug: 8041 4658 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): AP read reg 0 0 Debug: 8042 4658 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): DP read reg c 0 Debug: 8043 4662 cmsis_dap.c:893 cmsis_dap_swd_read_process(): Received results of 2 queued transactions FIFO index 0 Debug: 8044 4662 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8045 4662 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8046 4662 command.c:166 script_debug(): command - expr [lindex $CRCTABLE [expr {($crc_value ^ [scan $c %c])&0xff}]]^(($crc_value>>8)&0xffffff) Debug: 8047 4662 cmsis_dap.c:778 cmsis_dap_swd_write_from_queue(): Executing 2 queued transactions from FIFO index 0 Debug: 8048 4662 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): AP read reg 0 0 Debug: 8049 4662 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): DP read reg c 0 Debug: 8050 4666 cmsis_dap.c:893 cmsis_dap_swd_read_process(): Received results of 2 queued transactions FIFO index 0 Debug: 8051 4666 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8052 4666 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8053 4666 command.c:166 script_debug(): command - expr ($crc_value ^ [scan $c %c])&0xff Debug: 8054 4666 cmsis_dap.c:778 cmsis_dap_swd_write_from_queue(): Executing 2 queued transactions from FIFO index 0 Debug: 8055 4666 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): AP read reg 0 0 Debug: 8056 4666 cmsis_dap.c:798 cmsis_dap_swd_write_from_queue(): DP read reg c 0 Debug: 8057 4670 cmsis_dap.c:893 cmsis_dap_swd_read_process(): Received results of 2 queued transactions FIFO index 0 Debug: 8058 4670 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 Debug: 8059 4670 cmsis_dap.c:904 cmsis_dap_swd_read_process(): Read result: 30003 ... ~~~ Stack trace: ~~~ #0 0x00007f954db3892f in write () from /lib64/libc.so.6 #1 0x00007f954dd39c1e in hid_write () from /lib64/libhidapi-hidraw.so.0 #2 0x000000000041cf95 in cmsis_dap_hid_write (dap=0x242c720, txlen=<optimized out>, timeout_ms=<optimized out>) at src/jtag/drivers/cmsis_dap_usb_hid.c:207 #3 0x0000000000418b92 in cmsis_dap_swd_write_from_queue (dap=<optimized out>) at src/jtag/drivers/cmsis_dap.c:829 #4 0x00000000004190ca in cmsis_dap_swd_run_queue () at src/jtag/drivers/cmsis_dap.c:929 #5 0x0000000000448974 in swd_run_inner (dap=0x2210c30) at src/target/adi_v5_swd.c:97 #6 swd_run (dap=0x2210c30) at src/target/adi_v5_swd.c:553 #7 swd_run (dap=0x2210c30) at src/target/adi_v5_swd.c:545 #8 0x00000000005346dd in cortex_m_read_dhcsr_atomic_sticky (target=0x21c8660) at src/target/cortex_m.c:142 #9 cortex_m_poll (target=0x21c8660) at src/target/cortex_m.c:882 #10 0x000000000045f2c9 in target_poll (target=0x21c8660) at src/target/target.c:567 #11 0x00000000004605f8 in handle_target (priv=<optimized out>) at src/target/target.c:3056 #12 handle_target (priv=<optimized out>) at src/target/target.c:2979 #13 0x00000000004570e1 in target_call_timer_callback (now=<synthetic pointer>, cb=0x242c6e0) at src/target/target.c:1895 #14 target_call_timer_callbacks_check_time (checktime=checktime@entry=0) at src/target/target.c:1939 #15 0x000000000045b46b in target_call_timer_callbacks_check_time (checktime=0) at src/target/target.c:1958 #16 target_call_timer_callbacks_now () at src/target/target.c:1959 #17 0x000000000048649d in jim_command_dispatch (interp=0x2182300, argc=2, argv=0x7ffccf92db20) at src/helper/command.c:952 #18 0x00000000005c01ca in JimInvokeCommand (interp=interp@entry=0x2182300, objc=2, objv=objv@entry=0x7ffccf92db20) at jim.c:10682 #19 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x5d1ae30) at jim.c:11175 #20 0x00000000005c0b58 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x21dde10) at jim.c:11108 #21 0x00000000005bfc7e in JimCallProcedure (interp=interp@entry=0x2182300, cmd=cmd@entry=0x221f150, argc=argc@entry=3, argv=argv@entry=0x7ffccf92dd60) at jim.c:11421 #22 0x00000000005c02a5 in JimInvokeCommand (interp=interp@entry=0x2182300, objc=3, objv=objv@entry=0x7ffccf92dd60) at jim.c:10678 #23 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x5d1a560) at jim.c:11175 #24 0x00000000005c0b58 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=scriptObjPtr@entry=0x245d610) at jim.c:11108 #25 0x00000000005ca85a in JimForeachMapHelper (interp=<optimized out>, argc=<optimized out>, argv=<optimized out>, doMap=0) at jim.c:12497 #26 0x00000000005c01ca in JimInvokeCommand (interp=interp@entry=0x2182300, objc=4, objv=objv@entry=0x7ffccf92dff0) at jim.c:10682 #27 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x21dd9f0) at jim.c:11175 #28 0x00000000005bfc7e in JimCallProcedure (interp=interp@entry=0x2182300, cmd=cmd@entry=0x221f330, argc=argc@entry=2, argv=argv@entry=0x7ffccf92e170) at jim.c:11421 #29 0x00000000005c02a5 in JimInvokeCommand (interp=interp@entry=0x2182300, objc=2, objv=objv@entry=0x7ffccf92e170) at jim.c:10678 #30 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x245ee20) at jim.c:11175 #31 0x00000000005c0b58 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x21dd5d0) at jim.c:11108 #32 0x00000000005bfc7e in JimCallProcedure (interp=interp@entry=0x2182300, cmd=cmd@entry=0x221f500, argc=argc@entry=2, argv=argv@entry=0x7ffccf92e3b0) at jim.c:11421 #33 0x00000000005c02a5 in JimInvokeCommand (interp=interp@entry=0x2182300, objc=2, objv=objv@entry=0x7ffccf92e3b0) at jim.c:10678 #34 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x2453b40) at jim.c:11175 #35 0x00000000005c0b58 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x21dfc40) at jim.c:11108 #36 0x00000000005bfc7e in JimCallProcedure (interp=interp@entry=0x2182300, cmd=cmd@entry=0x221e840, argc=argc@entry=5, argv=argv@entry=0x7ffccf92e5f0) at jim.c:11421 #37 0x00000000005c02a5 in JimInvokeCommand (interp=interp@entry=0x2182300, objc=5, objv=objv@entry=0x7ffccf92e5f0) at jim.c:10678 #38 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=0x21e0060) at jim.c:11175 #39 0x00000000005bfc7e in JimCallProcedure (interp=interp@entry=0x2182300, cmd=cmd@entry=0x221e650, argc=argc@entry=3, argv=argv@entry=0x7ffccf92e770) at jim.c:11421 #40 0x00000000005c02a5 in JimInvokeCommand (interp=interp@entry=0x2182300, objc=3, objv=objv@entry=0x7ffccf92e770) at jim.c:10678 #41 0x00000000005c0aa9 in Jim_EvalObj (interp=interp@entry=0x2182300, scriptObjPtr=scriptObjPtr@entry=0x21f0d00) at jim.c:11175 #42 0x00000000005c16ab in Jim_EvalSource (interp=interp@entry=0x2182300, filename=filename@entry=0x0, lineno=lineno@entry=0, script=script@entry=0x21b40d0 "rtl872x_flash_write_bin p2-system-pa...@5.0.0.bin 0x8060000") at jim.c:11470 #43 0x000000000048609f in command_run_line (context=context@entry=0x21822a0, line=0x21b40d0 "rtl872x_flash_write_bin p2-system-pa...@5.0.0.bin 0x8060000") at src/helper/command.c:591 #44 0x0000000000487928 in parse_config_file (cmd_ctx=cmd_ctx@entry=0x21822a0) at src/helper/configuration.c:136 #45 0x000000000040687d in openocd_thread (cmd_ctx=0x21822a0, argv=0x7ffccf92e9d8, argc=17) at src/openocd.c:356 #46 openocd_main (argc=17, argv=0x7ffccf92e9d8) at src/openocd.c:416 #47 0x00007f954da60550 in __libc_start_call_main () from /lib64/libc.so.6 #48 0x00007f954da60609 in __libc_start_main_impl () from /lib64/libc.so.6 #49 0x0000000000406205 in _start () ~~~ --- Sent from sourceforge.net because openocd-devel@lists.sourceforge.net is subscribed to https://sourceforge.net/p/openocd/tickets/ To unsubscribe from further messages, a project admin can change settings at https://sourceforge.net/p/openocd/admin/tickets/options. Or, if this is a mailing list, you can unsubscribe from the mailing list.