)]}'
{"/PATCHSET_LEVEL":[{"author":{"_account_id":1002161,"name":"Anatoly P","email":"kupokupokupopo@gmail.com","username":"ecco_the_dolphin"},"change_message_id":"b575d958e3ad8df029dca63919106be086760a1d","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":4,"id":"9cc4ca58_52e5419c","updated":"2023-07-03 16:23:52.000000000","message":"Hi folks! Sorry for re-animating this old review... If it is more appropriate to start mailing list discussion - please, let me know.\n\nI encounter the \"Haven\u0027t made progress in mpsse_flush\" warning added in this commit. I can reproduce the issue more or less reliably, but it does not happen every time (it seems that this depends on timing, see below for details). And there is no forward progress till OpenOCD is restarted. If it is appropriate - I\u0027d like to request some advise on how to debug this issue. Some details are below.\n\n- I have `FT232H` debug adapter.\n- The issue happens when: communication speed is relatively low (like 500kHz), OpenoOCD is killed (via kill -9) in the middle of some operation upon next invocation of OpenOCD.\n\nHere is debug log from \"-d4\":\n\n```\nDebug: 34 1 command.c:155 script_debug(): command - jtag init\nDebug: 35 1 tcl.c:847 handle_jtag_init_command(): Initializing jtag devices...\nDebug: 36 1 ftdi.c:731 ftdi_initialize(): ftdi interface using shortest path jtag state transitions\nDebug: 37 6 mpsse.c:412 mpsse_purge(): -\nDebug: 38 6 mpsse.c:613 mpsse_set_data_bits_low_byte(): -\nDebug: 39 6 mpsse.c:445 buffer_write_byte(): 80\nDebug: 40 6 mpsse.c:445 buffer_write_byte(): e8\nDebug: 41 6 mpsse.c:445 buffer_write_byte(): eb\nDebug: 42 6 mpsse.c:630 mpsse_set_data_bits_high_byte(): -\nDebug: 43 6 mpsse.c:445 buffer_write_byte(): 82\nDebug: 44 6 mpsse.c:445 buffer_write_byte(): 00\nDebug: 45 6 mpsse.c:445 buffer_write_byte(): 60\nDebug: 46 6 mpsse.c:693 mpsse_loopback_config(): off\nDebug: 47 6 mpsse.c:445 buffer_write_byte(): 85\nDebug: 48 6 mpsse.c:738 mpsse_set_frequency(): target 500000 Hz\nDebug: 49 6 mpsse.c:730 mpsse_rtck_config(): off\nDebug: 50 6 mpsse.c:445 buffer_write_byte(): 97\nDebug: 51 6 mpsse.c:719 mpsse_divide_by_5_config(): off\nDebug: 52 6 mpsse.c:445 buffer_write_byte(): 8a\nDebug: 53 6 mpsse.c:699 mpsse_set_divisor(): 59\nDebug: 54 6 mpsse.c:445 buffer_write_byte(): 86\nDebug: 55 6 mpsse.c:445 buffer_write_byte(): 3b\nDebug: 56 6 mpsse.c:445 buffer_write_byte(): 00\nDebug: 57 6 mpsse.c:762 mpsse_set_frequency(): actually 500000 Hz\nDebug: 58 6 mpsse.c:844 mpsse_flush(): write 12, read 0\nDebug: 59 6 mpsse.c:819 write_cb(): transferred 12 of 12\nDebug: 60 6 mpsse.c:821 write_cb():  80 e8 eb 82 00 60 85 97 8a 86 3b 00\nDebug: 61 6 adapter.c:211 adapter_khz_to_speed(): convert khz to adapter specific speed value\nDebug: 62 6 adapter.c:215 adapter_khz_to_speed(): have adapter set up\nDebug: 63 6 mpsse.c:738 mpsse_set_frequency(): target 500000 Hz\nDebug: 64 6 mpsse.c:730 mpsse_rtck_config(): off\nDebug: 65 6 mpsse.c:445 buffer_write_byte(): 97\nDebug: 66 6 mpsse.c:719 mpsse_divide_by_5_config(): off\nDebug: 67 6 mpsse.c:445 buffer_write_byte(): 8a\nDebug: 68 6 mpsse.c:699 mpsse_set_divisor(): 59\nDebug: 69 6 mpsse.c:445 buffer_write_byte(): 86\nDebug: 70 6 mpsse.c:445 buffer_write_byte(): 3b\nDebug: 71 6 mpsse.c:445 buffer_write_byte(): 00\nDebug: 72 6 mpsse.c:762 mpsse_set_frequency(): actually 500000 Hz\nDebug: 73 6 adapter.c:211 adapter_khz_to_speed(): convert khz to adapter specific speed value\nDebug: 74 6 adapter.c:215 adapter_khz_to_speed(): have adapter set up\nInfo : 75 6 adapter.c:175 adapter_init(): clock speed 500 kHz\nDebug: 76 6 mpsse.c:844 mpsse_flush(): write 5, read 0\nDebug: 77 6 mpsse.c:819 write_cb(): transferred 5 of 5\nDebug: 78 6 mpsse.c:821 write_cb():  97 8a 86 3b 00\nDebug: 79 6 ftdi.c:597 ftdi_reset(): reset trst: 0 srst 0\nDebug: 80 6 mpsse.c:844 mpsse_flush(): write 0, read 0\nDebug: 81 6 core.c:830 jtag_add_reset(): SRST line released\nDebug: 82 6 core.c:855 jtag_add_reset(): TRST line released\nDebug: 83 6 core.c:328 jtag_call_event_callbacks(): jtag event: TAP reset\nDebug: 84 6 mpsse.c:844 mpsse_flush(): write 0, read 0\nDebug: 85 6 command.c:155 script_debug(): command - jtag arp_init\nDebug: 86 6 core.c:1509 jtag_init_inner(): Init JTAG chain\nWarn : 87 6 core.c:1524 jtag_init_inner(): There are no enabled taps.  AUTO PROBING MIGHT NOT WORK!!\nDebug: 88 6 core.c:328 jtag_call_event_callbacks(): jtag event: TAP reset\nDebug: 89 6 ftdi.c:416 ftdi_execute_statemove(): statemove end in RESET\nDebug: 90 6 ftdi.c:326 move_to_state(): start\u003dRESET goal\u003dRESET\nDebug: 91 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 92 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 93 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 94 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 95 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 96 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 97 6 ftdi.c:330 move_to_state(): tap_set_state(RESET)\nDebug: 98 6 mpsse.c:563 mpsse_clock_tms_cs(): out 7 bits, tdi\u003d0\nDebug: 99 6 mpsse.c:445 buffer_write_byte(): 4b\nDebug: 100 6 mpsse.c:445 buffer_write_byte(): 06\nDebug: 101 6 mpsse.c:445 buffer_write_byte(): 7f\nDebug: 102 6 mpsse.c:844 mpsse_flush(): write 3, read 0\nWarn : 105 2009 mpsse.c:906 mpsse_flush(): Haven\u0027t made progress in mpsse_flush() for 2003ms.\nWarn : 108 4012 mpsse.c:906 mpsse_flush(): Haven\u0027t made progress in mpsse_flush() for 4006ms.\nDebug: 109 5007 mpsse.c:819 write_cb(): transferred 0 of 3\nWarn : 113 8011 mpsse.c:906 mpsse_flush(): Haven\u0027t made progress in mpsse_flush() for 8005ms.\nDebug: 115 10007 mpsse.c:819 write_cb(): transferred 0 of 3\nError: unexpected timeout (while waiting for TAP count)\n```\n\nIf OpenOCD is restarted - then the issue is gone. Does anyone has any advice on how to debug this further?","commit_id":"d214cadfef7ba75c7c52849c7946d32f0ad8b668"}]}
