Any idea what could be going on here I ve been trying to deb Pants #development

Join Slack

Any idea what could be going on here? I've been tr...

# development

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 👀

hundreds-father-404

11/04/2021, 10:31 PM

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?

witty-crayon-22786

11/04/2021, 10:31 PM

is there CPU time, or no?

hundreds-father-404

11/04/2021, 10:32 PM

yeah, 100.5%

witty-crayon-22786

11/04/2021, 10:32 PM

what does a profiler report?

hundreds-father-404

11/04/2021, 10:32 PM

haven't tried yet - this seemed simpler to try raising an exception

witty-crayon-22786

11/04/2021, 10:32 PM

Copy code

sudo py-spy top -p $pid

👀 1

👍 1

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)

witty-crayon-22786

11/04/2021, 10:35 PM

…infinite recursion in

repr

…?

hundreds-father-404

11/04/2021, 10:35 PM

Looks like it! So, I'll try overridding

repr

for now

witty-crayon-22786

11/04/2021, 10:35 PM

…or… … hm.

witty-crayon-22786

11/04/2021, 10:36 PM

it’s the

repr

impl for

string

👀 1

witty-crayon-22786

11/04/2021, 10:36 PM

@hundreds-father-404: switch from

top

to just dump, and run that a few times

hundreds-father-404

11/04/2021, 10:36 PM

wait what do you mean?

witty-crayon-22786

11/04/2021, 10:36 PM

…to see what the call stack is above any

repr

calls

witty-crayon-22786

11/04/2021, 10:36 PM

sudo py-spy dump -p $pid

❤️ 1

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)

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"
    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)

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"
    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)

witty-crayon-22786

11/04/2021, 10:40 PM

hm. are you maybe rendering a DAG as a string?

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?

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)

witty-crayon-22786

11/04/2021, 10:42 PM

because there is no memoization: so a single node in the graph will be rendered once for each path it is reachable from

👀 1

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?

witty-crayon-22786

11/04/2021, 10:44 PM

yea, probably

Open in Slack

Previous Next