Skip to content
GitLab
Open
Issue created by Derek Bruening@derekbrueningContributor

client.winxfer test output does not always match

This was under #4058 and I put some time into relaxing the output to match, but it is still failing sometimes:

https://github.com/DynamoRIO/dynamorio/pull/4729/checks?check_run_id=1880901026

2021-02-11T16:40:01.9664547Z 128: Test command: D:\a\dynamorio\dynamorio\build_debug-internal-32\bin32\drrun.exe "-s" "90" "-quiet" "-debug" "-use_dll" "D:/a/dynamorio/dynamorio/build_debug-internal-32/lib32/debug/dynamorio.dll" "-exit0" "-stderr_mask" "0xC" "-msgbox_mask" "0" "-dumpcore_mask" "0x7d" "-staged" "-code_api" "-c" "D:/a/dynamorio/dynamorio/build_debug-internal-32/suite/tests/bin/client.flush.dll.dll" "--" "D:/a/dynamorio/dynamorio/build_debug-internal-32/suite/tests/bin/client.flush.exe"
2021-02-11T16:40:01.9666562Z 128: Test timeout computed to be: 600
2021-02-11T16:40:01.9666996Z 126: kernel_xfer_event: type 5
2021-02-11T16:40:01.9667410Z 126: in wnd_callback 0x00008001 0 2
2021-02-11T16:40:01.9667826Z 126: kernel_xfer_event: type 6
2021-02-11T16:40:01.9668210Z 126: Got message 0x00008001 1 3
2021-02-11T16:40:01.9668616Z 126: Before _beginthreadex
2021-02-11T16:40:01.9953198Z 126: kernel_xfer_event: type 2
2021-02-11T16:40:02.3778200Z 126: kernel_xfer_event: type 7
2021-02-11T16:40:02.3778795Z 128: options = 
2021-02-11T16:40:02.5687498Z 126: QueueUserAPC returned 1
2021-02-11T16:40:02.5688052Z 126: kernel_xfer_event: type 2
2021-02-11T16:40:02.5688487Z 126: kernel_xfer_event: type 7
2021-02-11T16:40:02.5689063Z 126: SleepEx returned 192
2021-02-11T16:40:02.5689434Z 126: Apc arg = 37
2021-02-11T16:40:02.5689934Z 126: Result = 100
2021-02-11T16:40:02.5754554Z 126: After _beginthreadex
2021-02-11T16:40:02.6090320Z 126: All done
2021-02-11T16:40:02.6091415Z 128: in synch_flush_completion_callback, user_data=200
2021-02-11T16:40:02.6092082Z 128: kernel_xfer_event: type 9
2021-02-11T16:40:02.6092640Z 128: Flush completion id=200
2021-02-11T16:40:02.6093521Z 128: in synch_flush_completion_callback, user_data=400
2021-02-11T16:40:02.6094149Z 128: kernel_xfer_event: type 9
2021-02-11T16:40:02.6094688Z 128: Flush completion id=400
2021-02-11T16:40:02.6095209Z 128: count = 402
2021-02-11T16:40:02.6366330Z 128/236 Test #126: code_api|client.winxfer ......................................***Failed  Required regular expression not found. Regex=[^.*About to create thread
2021-02-11T16:40:02.8626693Z ?
2021-02-11T16:40:02.8627101Z .*in wnd_callback 0x0*0000024 0
2021-02-11T16:40:02.8627433Z ?
2021-02-11T16:40:02.8627932Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8628247Z ?
2021-02-11T16:40:02.8628576Z kernel_xfer_event: type 5
2021-02-11T16:40:02.8628885Z ?
2021-02-11T16:40:02.8629187Z in wnd_callback 0x0*0000081 0
2021-02-11T16:40:02.8629496Z ?
2021-02-11T16:40:02.8629829Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8630158Z ?
2021-02-11T16:40:02.8630467Z kernel_xfer_event: type 5
2021-02-11T16:40:02.8630794Z ?
2021-02-11T16:40:02.8631095Z .*in wnd_callback 0x0*0000083 0
2021-02-11T16:40:02.8631406Z ?
2021-02-11T16:40:02.8631731Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8632046Z ?
2021-02-11T16:40:02.8632378Z kernel_xfer_event: type 5
2021-02-11T16:40:02.8632695Z ?
2021-02-11T16:40:02.8633004Z in wnd_callback 0x0*0000001 0
2021-02-11T16:40:02.8633311Z ?
2021-02-11T16:40:02.8633616Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8633942Z ?
2021-02-11T16:40:02.8634247Z kernel_xfer_event: type 5
2021-02-11T16:40:02.8634572Z ?
2021-02-11T16:40:02.8634860Z in wnd_callback 0x0*0008001 3 0
2021-02-11T16:40:02.8635171Z ?
2021-02-11T16:40:02.8635453Z About to crash
2021-02-11T16:40:02.8635724Z ?
2021-02-11T16:40:02.8636122Z exception c0000005 addr 0x0*0000040
2021-02-11T16:40:02.8636447Z ?
2021-02-11T16:40:02.8637015Z kernel_xfer_event: type 3
2021-02-11T16:40:02.8637366Z ?
2021-02-11T16:40:02.8637673Z kernel_xfer_event: type 7
2021-02-11T16:40:02.8637997Z ?
2021-02-11T16:40:02.8638273Z Inside handler
2021-02-11T16:40:02.8638577Z ?
2021-02-11T16:40:02.8638895Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8639204Z ?
2021-02-11T16:40:02.8639526Z kernel_xfer_event: type 5
2021-02-11T16:40:02.8639834Z ?
2021-02-11T16:40:02.8640138Z in wnd_callback 0x0*0008001 0 2
2021-02-11T16:40:02.8640433Z ?
2021-02-11T16:40:02.8640754Z kernel_xfer_event: type 6
2021-02-11T16:40:02.8641263Z ?
2021-02-11T16:40:02.8641764Z Got message 0x0*0008001 1 3
2021-02-11T16:40:02.8642083Z ?
2021-02-11T16:40:02.8642421Z Before _beginthreadex
2021-02-11T16:40:02.8642781Z ?
2021-02-11T16:40:02.8643183Z kernel_xfer_event: type 2
2021-02-11T16:40:02.8643510Z ?
2021-02-11T16:40:02.8643855Z kernel_xfer_event: type 7
2021-02-11T16:40:02.8644184Z ?
2021-02-11T16:40:02.8644562Z QueueUserAPC returned 1
2021-02-11T16:40:02.8644950Z ?
2021-02-11T16:40:02.8645292Z kernel_xfer_event: type 2
2021-02-11T16:40:02.8645817Z ?
2021-02-11T16:40:02.8646373Z kernel_xfer_event: type 7
2021-02-11T16:40:02.8646699Z ?
2021-02-11T16:40:02.8647001Z SleepEx returned 192
2021-02-11T16:40:02.8647326Z ?
2021-02-11T16:40:02.8647597Z Apc arg = 37
2021-02-11T16:40:02.8647854Z ?
2021-02-11T16:40:02.8648126Z Result = 100
2021-02-11T16:40:02.8648384Z ?
2021-02-11T16:40:02.8648709Z After _beginthreadex
2021-02-11T16:40:02.8649220Z ?
2021-02-11T16:40:02.8649479Z All done
2021-02-11T16:40:02.8649761Z ?
2021-02-11T16:40:02.8650001Z $
2021-02-11T16:40:02.8650272Z ]  2.13 sec