Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Debugger sometimes repeating BREAKPOINT_SET events #61

Closed
hurricup opened this issue Mar 4, 2023 · 1 comment
Closed

Debugger sometimes repeating BREAKPOINT_SET events #61

hurricup opened this issue Mar 4, 2023 · 1 comment
Labels
bug

Comments

@hurricup
Copy link
Collaborator

hurricup commented Mar 4, 2023

See logs from failing run-to cursor test.

023-03-04T18:00:34.4092891Z     [ 333647]   WARN - #com.perl5.lang.perl.debugger.PerlDebugThread - Socket closed
2023-03-04T18:01:55.8951691Z     18:01:54,366 FINE   .perl.debugger.PerlDebugThread - Printing: Waiting for process to start... 
2023-03-04T18:01:55.8997978Z     18:01:55,366 FINE   .perl.debugger.PerlDebugThread - Printing: Connecting to localhost:45061... 
2023-03-04T18:01:55.8999534Z     18:01:55,367 FINE   .perl.debugger.PerlDebugThread - Printing: Connected 
2023-03-04T18:01:55.9000209Z     18:01:55,367 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9000942Z     18:01:55,367 FINE   .perl.debugger.PerlDebugThread - Got response: {"event":"READY","version":"2019.1"} 
2023-03-04T18:01:55.9002308Z     18:01:55,368 FINE   .perl.debugger.PerlDebugThread - Going to send string {"breakpoints":[],"charset":"utf8","startMode":"RUN","enableCompileTimeBreakpoints":false,"enableNonInteractiveMode":false,"initCode":"","renderers":[]} 
2023-03-04T18:01:55.9003919Z     18:01:55,368 FINE   .perl.debugger.PerlDebugThread - Sent string {"breakpoints":[],"charset":"utf8","startMode":"RUN","enableCompileTimeBreakpoints":false,"enableNonInteractiveMode":false,"initCode":"","renderers":[]} 
2023-03-04T18:01:55.9005130Z     18:01:55,368 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9018197Z     18:01:55,375 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":{"add":[{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Symbol.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Carp.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO/Socket/INET.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/PerlIO.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO/Socket.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Fcntl.pm","name":null},{"path":"(eval 2)[/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Carp.pm:116]","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/B/Op_private.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Encode/Encoding.pm"},{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/SelectSaver.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/site_perl/5.36.0/Types/Serialiser.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Cwd.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/bytes.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/List/Util.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Encode/Config.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Exporter/Heavy.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO/Select.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Storable.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/warnings.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO/Handle.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/feature.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/re.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/site_perl/5.36.0/x86_64-linux/PadWalker.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/if.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/constant.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/site_perl/5.36.0/x86_64-linux/JSON/XS.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/warnings/register.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO/Socket/UNIX.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Exporter.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Encode.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/XSLoader.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Scalar/Util.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/site_perl/5.36.0/x86_64-linux/Hash/StoredIterator.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/parent.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Encode/Alias.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/strict.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/DynaLoader.pm"},{"path":"(eval 3)[/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/Carp.pm:171]","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/base.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Encode/MIME/Name.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/B/Deparse.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Errno.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/site_perl/5.36.0/x86_64-linux/common/sense.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/overloading.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Socket.pm"},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/B.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/attributes.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/vars.pm"},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/overload.pm","name":null},{"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/IO.pm","name":null},{"name":null,"path":"/home/runner/.plenv/versions/5.36.0/lib/perl5/5.36.0/x86_64-linux/Config.pm"}],"remove":[]},"event":"LOADED_FILES_DELTA"} 
2023-03-04T18:01:55.9079363Z     18:01:55,376 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9080558Z     18:01:55,411 FINE   .perl.debugger.PerlDebugThread - Got response: {"event":"STOP","data":[{"args":[],"file":{"name":null,"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl"},"lexicals":[],"globals":[],"line":15,"main_size":166}]} 
2023-03-04T18:01:55.9081551Z     18:01:55,411 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9082229Z     18:01:55,430 FINE   .perl.debugger.PerlDebugThread - Going to send string o 
2023-03-04T18:01:55.9083171Z     18:01:55,430 FINE   .perl.debugger.PerlDebugThread - Sent string o 
2023-03-04T18:01:55.9084572Z     18:01:55,431 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":[{"globals":[],"main_size":166,"line":16,"file":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":null},"args":[],"lexicals":[]}],"event":"STOP"} 
2023-03-04T18:01:55.9085511Z     18:01:55,432 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9088907Z     18:01:55,453 FINE   .perl.debugger.PerlDebugThread - Going to send string  
2023-03-04T18:01:55.9089844Z     18:01:55,453 FINE   .perl.debugger.PerlDebugThread - Sent string  
2023-03-04T18:01:55.9140277Z     18:01:55,455 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":[{"lexicals":[],"args":[],"file":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":"main::something"},"globals":[],"line":1,"main_size":166},{"globals":[],"main_size":166,"line":16,"lexicals":[],"args":[],"file":{"name":null,"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl"}}],"event":"STOP"} 
2023-03-04T18:01:55.9141896Z     18:01:55,455 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9143680Z     18:01:55,466 FINE   .perl.debugger.PerlDebugThread - Going to send string b [{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":5,"enabled":true,"condition":"","remove":false,"suspend":true}] 
2023-03-04T18:01:55.9145301Z     18:01:55,466 FINE   .perl.debugger.PerlDebugThread - Sent string b [{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":5,"enabled":true,"condition":"","remove":false,"suspend":true}] 
2023-03-04T18:01:55.9147019Z     18:01:55,467 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":5},"event":"BREAKPOINT_SET"} 
2023-03-04T18:01:55.9148139Z     18:01:55,467 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9149210Z     18:01:55,469 FINE   .perl.debugger.PerlDebugThread - Going to send string p {"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":17,"enabled":false,"remove":false,"suspend":false} 
2023-03-04T18:01:55.9150764Z     18:01:55,469 FINE   .perl.debugger.PerlDebugThread - Sent string p {"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":17,"enabled":false,"remove":false,"suspend":false} 
2023-03-04T18:01:55.9152271Z     18:01:55,470 FINE   .perl.debugger.PerlDebugThread - Got response: {"event":"BREAKPOINT_SET","data":{"line":5,"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl"}} 
2023-03-04T18:01:55.9153145Z     18:01:55,470 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9157258Z     18:01:55,512 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":{"logmessage":null,"line":5,"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","suspend":true,"frames":[{"lexicals":[{"expandable":false,"is_utf":false,"key":"SCALAR(0x564835722e78)","size":0,"ref_depth":0,"value":"\"1\"","name":"$scalar","type":"SCALAR(0x564835722e78)","blessed":false},{"type":"SCALAR(0x564835d76238)","blessed":false,"name":"$string","value":"\"test string\"","expandable":false,"key":"SCALAR(0x564835d76238)","is_utf":false,"size":0,"ref_depth":0},{"name":"%hash","type":"HASH(0x564835d76328)","blessed":false,"expandable":true,"key":"HASH(0x564835d76328)","is_utf":false,"size":"2","ref_depth":0,"value":"size = 2"},{"type":"ARRAY(0x564835d76508)","blessed":false,"name":"@array","value":"size = 3","expandable":true,"is_utf":false,"key":"ARRAY(0x564835d76508)","size":"3","ref_depth":0}],"file":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":"main::something"},"args":[],"main_size":166,"line":5,"globals":[]},{"line":16,"main_size":166,"globals":[],"args":[],"file":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":null},"lexicals":[]}]},"event":"BREAKPOINT_REACHED"} 
2023-03-04T18:01:55.9159831Z     18:01:55,512 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9161545Z     18:01:55,515 FINE   .perl.debugger.PerlDebugThread - Going to send string p {"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":17,"enabled":false,"remove":false,"suspend":false} 
2023-03-04T18:01:55.9163278Z     18:01:55,515 FINE   .perl.debugger.PerlDebugThread - Sent string p {"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":17,"enabled":false,"remove":false,"suspend":false} 
2023-03-04T18:01:55.9165686Z     18:01:55,516 FINE   .perl.debugger.PerlDebugThread - Got response: {"event":"BREAKPOINT_SET","data":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":5}} 
2023-03-04T18:01:55.9167491Z     18:01:55,516 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9323265Z     18:01:55,536 FINE   .perl.debugger.PerlDebugThread - Got response: {"event":"BREAKPOINT_SET","data":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","line":5}} 
2023-03-04T18:01:55.9324166Z     18:01:55,536 FINE   .perl.debugger.PerlDebugThread - Reading data from the debugger 
2023-03-04T18:01:55.9326319Z     18:01:55,537 FINE   .perl.debugger.PerlDebugThread - Printing: Disconnected 
2023-03-04T18:01:55.9327452Z     18:01:55,537 FINE   .perl.debugger.PerlDebugThread - Got response: {"data":[{"args":[],"file":{"path":"/tmp/unitTest_RunToCursor_2MYmVXafGHw5B6dalAS03IlifGj/testRunToCursor/testscript.pl","name":null},"lexicals":[],"main_size":166,"line":17,"globals":[]}],"event":"STOP"} 
2023-03-04T18:02:14.5093298Z     [ 433678]   WARN - #com.perl5.lang.perl.debugger.PerlDebugThread - Socket closed

logs_1032.zip
@hurricup hurricup added the bug label Mar 4, 2023
@hurricup
Copy link
Collaborator Author

hurricup commented Mar 4, 2023 •
edited
Loading

From code it looks like this happen all the time when we put run to cursor breakpoint when other breakpoints are active in the same file.

This spammy messages from debugger may confuse IDE, at least this happens in tests. We are failing before getting real answer about stopping at interested place.

hurricup added a commit to Camelcade/Perl5-IDEA that referenced this issue Mar 4, 2023
@hurricup
Camelcade/Devel-Camelcadedb#61 Debugger refactoring
dfa5e97 
For some reason we are stopping process at some point before we got the answer.

- more debug logging
- replaced volatile boolean with atomic
- replaced Thread.sleep with TimeoutUtil.sleep
hurricup added a commit to Camelcade/Perl5-IDEA that referenced this issue Mar 4, 2023
@hurricup
Camelcade/Devel-Camelcadedb#61 Debugger refactoring
06f6733 
For some reason we are stopping process at some point before we got the answer.

- more debug logging
- replaced volatile boolean with atomic
- replaced Thread.sleep with TimeoutUtil.sleep
hurricup added a commit that referenced this issue Mar 5, 2023
@hurricup
#61 introduced CAMELCADEDB_DEV_MODE environment variable
db3baff 
By using this we may get additional output from debugger tests on CI
hurricup added a commit that referenced this issue Mar 5, 2023
@hurricup
#61 do not set same breakpoint multiple times
6607228 
We are removing request for breakpoint removal but keeping requests for set.
This caused multiple BREAKPOINT_SET events sent to IDE each time we are setting breakpoint with other breakpoints in the file.
@hurricup hurricup closed this as completed Mar 5, 2023
hurricup added a commit to Camelcade/Perl5-IDEA that referenced this issue Mar 5, 2023
@hurricup
Enabled debug logging for tests. See Camelcade/Devel-Camelcadedb#61
0ef421c 
Trying to understand why run to cursor test is failing sometimes
hurricup added a commit to Camelcade/Perl5-IDEA that referenced this issue Mar 5, 2023
@hurricup
Enabled debug logging for tests.
c94e8ef 
See Camelcade/Devel-Camelcadedb#61

Trying to understand why run to cursor test is failing sometimes
@hurricup hurricup mentioned this issue Mar 11, 2023
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@hurricup