search

eclipse-cdt-cloud / cdt-gdb-adapter

CDT GDB Debug Adapter
Eclipse Public License 2.0
28 stars 40 forks source link

GitHub Actions for Windows shows some flakiness #222

Closed jonahgraham closed 1 year ago

jonahgraham commented 1 year ago

I am seeing some flaky tests on GHA when running on Windows.

Variables CPP Test Suite."before each" hook for "/defaults/can read and set a cpp object variable" Timeout of 2000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (D:\a\cdt-gdb-adapter\cdt-gdb-adapter\src\integration-tests\vars_cpp.spec.ts)

My initial guess is this is too short a timeout on Windows as numerous tests take ~2 seconds on Windows.

jonahgraham commented 1 year ago

Sometimes even 5 seconds isn't enough - here is a bad run:

[17:16:27.883 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"server","output":"Listening on port 62414\r\n"}}
[17:16:28.103 UTC] GDB notify async: thread-group-added,id="i1"
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"GNU gdb (GDB for MinGW-W64 x86_64, built by Brecht Sanders) 10.2\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Copyright (C) 2021 Free Software Foundation, Inc.\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>\nThis is free software: you are free to change and redistribute it.\nThere is NO WARRANTY, to the extent permitted by law."}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"\nType \"show copying\" and \"show warranty\" for details.\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"This GDB was configured as \"x86_64-w64-mingw32\".\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Type \"show configuration\" for configuration details.\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"For bug reporting instructions, please see:\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"<https://www.gnu.org/software/gdb/bugs/>.\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Find the GDB manual and other documentation resources online at:\n    <http://www.gnu.org/software/gdb/documentation/>."}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"\n\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"For help, type \"help\".\n"}}
[17:16:28.103 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Type \"apropos word\" to search for commands related to \"word\".\n"}}
[17:16:28.103 UTC] GDB command: 0 -gdb-set non-stop off
[17:16:28.136 UTC] GDB result: 0 done
[17:16:28.136 UTC] GDB command: 1 -gdb-set mi-async on
[17:16:28.173 UTC] GDB result: 1 done
[17:16:28.173 UTC] GDB command: 2 -file-exec-and-symbols "D:\\a\\cdt-gdb-adapter\\cdt-gdb-adapter\\src\\integration-tests\\test-programs\\empty"
[17:16:29.137 UTC] GDB result: 2 done
[17:16:29.137 UTC] GDB command: 3 -enable-pretty-printing
[17:16:29.161 UTC] GDB result: 3 done
[17:16:29.161 UTC] GDB command: 4 -target-select remote localhost:62413
[17:16:29.294 UTC] GDB notify async: thread-group-started,id="i1",pid="42000"
[17:16:29.294 UTC] GDB notify async: thread-created,id="1",group-id="i1"
[17:16:29.294 UTC] GDB notify async: thread-created,id="2",group-id="i1"
[17:16:29.297 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\SYSTEM32\\ntdll.dll from remote target...\n"}}
[17:16:29.297 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"log","output":"warning: File transfers from remote targets can be slow. Use \"set sysroot\" to access files locally instead.\n"}}
[17:16:29.749 UTC] GDB notify async: library-loaded,id="C:\\Windows\\SYSTEM32\\ntdll.dll",target-name="C:\\Windows\\SYSTEM32\\ntdll.dll",host-name="target:C:\\Windows\\SYSTEM32\\ntdll.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ff9ce381000",to="0x00007ff9ce580538"}]
[17:16:29.749 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\System32\\kernel32.dll from remote target...\n"}}
[17:16:30.223 UTC] GDB notify async: library-loaded,id="C:\\Windows\\System32\\kernel32.dll",target-name="C:\\Windows\\System32\\kernel32.dll",host-name="target:C:\\Windows\\System32\\kernel32.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ff9cd1a1000",to="0x00007ff9cd25b324"}]
[17:16:30.223 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\System32\\KernelBase.dll from remote target...\n"}}
[17:16:32.763 UTC] GDB notify async: library-loaded,id="C:\\Windows\\System32\\KernelBase.dll",target-name="C:\\Windows\\System32\\KernelBase.dll",host-name="target:C:\\Windows\\System32\\KernelBase.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ff9cb951000",to="0x00007ff9cbcb258c"}]
[17:16:32.763 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\SYSTEM32\\apphelp.dll from remote target...\n"}}

And here is a good run:

[14:26:54.893 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"server","output":"Listening on port 60132\r\n"}}
[14:26:55.107 UTC] GDB notify async: thread-group-added,id="i1"
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"GNU gdb (GDB for MinGW-W64 x86_64, built by Brecht Sanders) 10.2\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Copyright (C) 2021 Free Software Foundation, Inc.\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>\nThis is free software: you are free to change and redistribute it.\nThere is NO WARRANTY, to the extent permitted by law."}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"\nType \"show copying\" and \"show warranty\" for details.\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"This GDB was configured as \"x86_64-w64-mingw32\".\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Type \"show configuration\" for configuration details.\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"For bug reporting instructions, please see:\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"<https://www.gnu.org/software/gdb/bugs/>.\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Find the GDB manual and other documentation resources online at:\n    <http://www.gnu.org/software/gdb/documentation/>."}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"\n\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"For help, type \"help\".\n"}}
[14:26:55.107 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Type \"apropos word\" to search for commands related to \"word\".\n"}}
[14:26:55.107 UTC] GDB command: 0 -gdb-set non-stop off
[14:26:55.133 UTC] GDB result: 0 done
[14:26:55.133 UTC] GDB command: 1 -gdb-set mi-async on
[14:26:55.156 UTC] GDB result: 1 done
[14:26:55.156 UTC] GDB command: 2 -file-exec-and-symbols "D:\\a\\cdt-gdb-adapter\\cdt-gdb-adapter\\src\\integration-tests\\test-programs\\empty"
[14:26:55.256 UTC] GDB result: 2 done
[14:26:55.256 UTC] GDB command: 3 -enable-pretty-printing
[14:26:55.257 UTC] GDB result: 3 done
[14:26:55.257 UTC] GDB command: 4 -target-select remote localhost:60131
[14:26:55.296 UTC] GDB notify async: thread-group-started,id="i1",pid="42000"
[14:26:55.296 UTC] GDB notify async: thread-created,id="1",group-id="i1"
[14:26:55.296 UTC] GDB notify async: thread-created,id="2",group-id="i1"
[14:26:55.296 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\SYSTEM32\\ntdll.dll from remote target...\n"}}
[14:26:55.296 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"log","output":"warning: File transfers from remote targets can be slow. Use \"set sysroot\" to access files locally instead.\n"}}
[14:26:55.448 UTC] GDB notify async: library-loaded,id="C:\\Windows\\SYSTEM32\\ntdll.dll",target-name="C:\\Windows\\SYSTEM32\\ntdll.dll",host-name="target:C:\\Windows\\SYSTEM32\\ntdll.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ffbc7b01000",to="0x00007ffbc7d00538"}]
[14:26:55.448 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\System32\\kernel32.dll from remote target...\n"}}
[14:26:55.549 UTC] GDB notify async: library-loaded,id="C:\\Windows\\System32\\kernel32.dll",target-name="C:\\Windows\\System32\\kernel32.dll",host-name="target:C:\\Windows\\System32\\kernel32.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ffbc67a1000",to="0x00007ffbc685b324"}]
[14:26:55.549 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\System32\\KernelBase.dll from remote target...\n"}}
[14:26:56.300 UTC] GDB notify async: library-loaded,id="C:\\Windows\\System32\\KernelBase.dll",target-name="C:\\Windows\\System32\\KernelBase.dll",host-name="target:C:\\Windows\\System32\\KernelBase.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ffbc5301000",to="0x00007ffbc5662598"}]
[14:26:56.300 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\SYSTEM32\\apphelp.dll from remote target...\n"}}
[14:26:56.346 UTC] GDB notify async: library-loaded,id="C:\\Windows\\SYSTEM32\\apphelp.dll",target-name="C:\\Windows\\SYSTEM32\\apphelp.dll",host-name="target:C:\\Windows\\SYSTEM32\\apphelp.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ffbc0501000",to="0x00007ffbc0590718"}]
[14:26:56.346 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"Reading C:\\Windows\\System32\\msvcrt.dll from remote target...\n"}}
[14:26:56.374 UTC] GDB notify async: library-loaded,id="C:\\Windows\\System32\\msvcrt.dll",target-name="C:\\Windows\\System32\\msvcrt.dll",host-name="target:C:\\Windows\\System32\\msvcrt.dll",symbols-loaded="0",thread-group="i1",ranges=[{from="0x00007ffbc60f1000",to="0x00007ffbc61924b4"}]
[14:26:56.514 UTC] To client: {"seq":0,"type":"event","event":"output","body":{"category":"stdout","output":"0x00007ffbc7bd4d85 in ntdll!LdrInitShimEngineDynamic () from target:C:\\Windows\\SYSTEM32\\ntdll.dll\n"}}
[14:26:56.514 UTC] GDB exec async: stopped,frame={addr="0x00007ffbc7bd4d85",func="ntdll!LdrInitShimEngineDynamic",args=[],from="target:C:\\Windows\\SYSTEM32\\ntdll.dll",arch="i386:x86-64"},thread-id="1",stopped-threads="all"
[14:26:56.514 UTC] GDB result: 4 connected

In the first run it is >5 seconds to do what took ~1.5 seconds in the first run. This is very reminiscent of why we have huge multipliers on timeouts when running DSF-GDB tests on test machine.

I think we'll do the same here.