https://pantsbuild.org/ logo
h

hundreds-father-404

11/04/2021, 10:30 PM
Any idea what could be going on here? I've been trying to debug this rule hanging for past few hours 👀
Copy code
@rule(desc="Check Go compilation", level=LogLevel.DEBUG)
async def check_go(request: GoCheckRequest) -> CheckResults:
    build_requests = await MultiGet(
        Get(FallibleBuildGoPackageRequest, BuildGoPackageTargetRequest(field_set.address))
        for field_set in request.field_sets
    )
    invalid_requests = []
    valid_requests = []
    <http://logger.info|logger.info>(("HERE 1", invalid_requests, valid_requests))
    raise ValueError(build_requests)
When I run, I get this:
Copy code
❯ ./pants_from_sources check source:
15:29:35.00 [INFO] ('HERE 1', [], [])
...
Where it keeps spinning running the rule in the dynamic UI. Why would it not raise?
w

witty-crayon-22786

11/04/2021, 10:31 PM
is there CPU time, or no?
h

hundreds-father-404

11/04/2021, 10:32 PM
yeah, 100.5%
w

witty-crayon-22786

11/04/2021, 10:32 PM
what does a profiler report?
h

hundreds-father-404

11/04/2021, 10:32 PM
haven't tried yet - this seemed simpler to try raising an exception
w

witty-crayon-22786

11/04/2021, 10:32 PM
Copy code
sudo py-spy top -p $pid
👀 1
👍 1
h

hundreds-father-404

11/04/2021, 10:34 PM
Huh!
Copy code
nts_loader.py --no-verify-config check source:' (python v3.9.6)
Total Samples 1800
GIL: 100.00%, Active: 100.00%, Threads: 3

  %Own   %Total  OwnTime  TotalTime  Function (filename:line)
 95.00% 100.00%   16.63s    17.82s   __repr__ (<string>:3)
  2.00%   2.00%   0.280s    0.280s   wrapper (dataclasses.py:365)
  0.00% 100.00%   0.260s    17.82s   wrapper (dataclasses.py:370)
  0.00%   0.00%   0.230s    0.230s   wrapper (dataclasses.py:366)
  0.00%   0.00%   0.200s    0.200s   wrapper (dataclasses.py:372)
  3.00%   3.00%   0.170s    0.170s   wrapper (dataclasses.py:368)
  0.00%   0.00%   0.040s    0.040s   execute (pants/engine/internals/scheduler.py:462)
  0.00%   0.00%   0.030s    0.030s   wrapper (dataclasses.py:373)
  0.00%   0.00%   0.020s    0.020s   poll_workunits (pants/engine/internals/scheduler.py:370)
  0.00%   0.00%   0.020s    0.020s   __repr__ (<string>:2)
  0.00%   0.00%   0.010s    0.030s   poll_workunits (pants/engine/streaming_workunit_handler.py:251)
  0.00%   0.00%   0.010s    0.010s   run (pants/engine/streaming_workunit_handler.py:265)
  0.00%   0.00%   0.000s    0.040s   _bootstrap_inner (threading.py:973)
  0.00%   0.00%   0.000s    0.040s   run_default_entrypoint (pants/bin/pants_loader.py:95)
  0.00%   0.00%   0.000s    0.040s   _bootstrap (threading.py:930)
  0.00%   0.00%   0.000s    0.040s   main (pants/bin/pants_loader.py:116)
w

witty-crayon-22786

11/04/2021, 10:35 PM
…infinite recursion in
repr
…?
h

hundreds-father-404

11/04/2021, 10:35 PM
Looks like it! So, I'll try overridding
repr
for now
w

witty-crayon-22786

11/04/2021, 10:35 PM
…or… … hm.
it’s the
repr
impl for
string
👀 1
@hundreds-father-404: switch from
top
to just dump, and run that a few times
h

hundreds-father-404

11/04/2021, 10:36 PM
wait what do you mean?
w

witty-crayon-22786

11/04/2021, 10:36 PM
…to see what the call stack is above any
repr
calls
sudo py-spy dump -p $pid
❤️ 1
h

hundreds-father-404

11/04/2021, 10:38 PM
Copy code
Thread 0x104A6FD40 (idle): "MainThread"
    execute (pants/engine/internals/scheduler.py:462)
    run_goal_rule (pants/engine/internals/scheduler.py:545)
    run_goal_rules (pants/init/engine_initializer.py:134)
    _perform_run_body (pants/bin/local_pants_runner.py:191)
    _perform_run (pants/bin/local_pants_runner.py:174)
    _run_inner (pants/bin/local_pants_runner.py:235)
    run (pants/bin/local_pants_runner.py:264)
    run (pants/bin/pants_runner.py:100)
    run_default_entrypoint (pants/bin/pants_loader.py:95)
    main (pants/bin/pants_loader.py:116)
    main (pants/bin/pants_loader.py:120)
    <module> (pants/bin/pants_loader.py:124)
Thread 0x16D93F000 (idle): "Thread-1"
    poll_workunits (pants/engine/internals/scheduler.py:370)
    poll_workunits (pants/engine/streaming_workunit_handler.py:251)
    run (pants/engine/streaming_workunit_handler.py:264)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x16BBD3000 (active+gil): "Dummy-2"
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    _some_str (traceback.py:155)
    __init__ (traceback.py:514)
    format_exception (traceback.py:120)
    <module> (<string>:1)
Copy code
Thread 0x104A6FD40 (idle): "MainThread"
    execute (pants/engine/internals/scheduler.py:462)
    run_goal_rule (pants/engine/internals/scheduler.py:545)
    run_goal_rules (pants/init/engine_initializer.py:134)
    _perform_run_body (pants/bin/local_pants_runner.py:191)
    _perform_run (pants/bin/local_pants_runner.py:174)
    _run_inner (pants/bin/local_pants_runner.py:235)
    run (pants/bin/local_pants_runner.py:264)
    run (pants/bin/pants_runner.py:100)
    run_default_entrypoint (pants/bin/pants_loader.py:95)
    main (pants/bin/pants_loader.py:116)
    main (pants/bin/pants_loader.py:120)
    <module> (pants/bin/pants_loader.py:124)
Thread 0x16D93F000 (idle): "Thread-1"
    wait (threading.py:316)
    wait (threading.py:574)
    run (pants/engine/streaming_workunit_handler.py:265)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x16BBD3000 (active+gil): "Dummy-2"
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    _some_str (traceback.py:155)
    __init__ (traceback.py:514)
    format_exception (traceback.py:120)
    <module> (<string>:1)
Copy code
Thread 0x104A6FD40 (idle): "MainThread"
    execute (pants/engine/internals/scheduler.py:462)
    run_goal_rule (pants/engine/internals/scheduler.py:545)
    run_goal_rules (pants/init/engine_initializer.py:134)
    _perform_run_body (pants/bin/local_pants_runner.py:191)
    _perform_run (pants/bin/local_pants_runner.py:174)
    _run_inner (pants/bin/local_pants_runner.py:235)
    run (pants/bin/local_pants_runner.py:264)
    run (pants/bin/pants_runner.py:100)
    run_default_entrypoint (pants/bin/pants_loader.py:95)
    main (pants/bin/pants_loader.py:116)
    main (pants/bin/pants_loader.py:120)
    <module> (pants/bin/pants_loader.py:124)
Thread 0x16D93F000 (idle): "Thread-1"
    wait (threading.py:316)
    wait (threading.py:574)
    run (pants/engine/streaming_workunit_handler.py:265)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x16BBD3000 (active+gil): "Dummy-2"
    wrapper (dataclasses.py:369)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    __repr__ (<string>:3)
    wrapper (dataclasses.py:370)
    _some_str (traceback.py:155)
    __init__ (traceback.py:514)
    format_exception (traceback.py:120)
    <module> (<string>:1)
w

witty-crayon-22786

11/04/2021, 10:40 PM
hm. are you maybe rendering a DAG as a string?
h

hundreds-father-404

11/04/2021, 10:41 PM
In fact, yeah, I think we are. We're trying to render
BuildGoPackageRequest
which has
direct_dependencies: tuple[BuildGoPackageRequest, ...]
. Why would that be an issue if there are no cycles?
w

witty-crayon-22786

11/04/2021, 10:41 PM
it’s not infinite recursion (you’d hit the stack limit), but if it’s taking a very long time to do something, my guess is that you have a recursive dataclass (contains itself)
because there is no memoization: so a single node in the graph will be rendered once for each path it is reachable from
👀 1
h

hundreds-father-404

11/04/2021, 10:42 PM
Okay so that makes a ton of sense to override
__repr__
for
BuildGoPackageRequest
. I think we should have it only render the import paths of the direct deps, rather than recursing transitively, right?
w

witty-crayon-22786

11/04/2021, 10:44 PM
yea, probably