@rule workunits should be able to include runtime information #7907

blorente · 2019-06-20T14:13:08Z

In the context of the V2 UI, the only way we render Nodes is by having a static string representation of their arguments. We would like to redesign this, in order to allow:

@rules (TaskNodes inside Rust) should maybe be able to define their own string representation. Ideally, they would like to be able to access their arguments to insert in their string representation (e.g. an @rule(CompiledScala, [ScalaTarget, Dependencies]) might want to be represented as "Compiling target <name of the target>"). This is a bit challenging because when the workunit for a @rule is created, we don't yet have its argument values... but it would still be possible to adjust the workunit name in the TaskNode code after the arguments are determined, here.
Additionally, @rules with non-exception-but-still failure results would like to be able to change the level of their workunit to warning or error in order to affect rendering. A sketch of this might involve adding a Python interface that return types could implement that would allow them to affect their level. For example: LintResult and TestResult would implement the interface in order to render failing targets as error.

Some related discussions around porting Workunits to v2: #7071

The text was updated successfully, but these errors were encountered:

#7745, we should revisit this solution when #7907 is decided upon

stuhood · 2019-12-12T22:00:31Z

A large portion of this was tackled in #8592! The last portion appears to be the templating of arguments/params. cc @gshuflin

Eric-Arellano · 2020-05-18T14:06:57Z

Closing as mostly implemented by recent work on workunits like #8592.

stuhood · 2020-05-30T17:58:04Z

Reopening this, because it's not possible to template or otherwise affect rule names, and the more we use them, the more clear it is that they don't add much information without that.

### Problem Post #9894, it's clear that many named rules are redundant, because the processes that run below them have better descriptions (relates to #7907, although it's possible that we'd like to drive the names of a workunit in some other way). Example for a `--no-process-execution-use-local-cache` run: ``` 18:00:22:852 [INFO] Starting tests: tests/python/pants_test/util:strutil 18:00:22:870 [INFO] Completed: Create a PEX from targets 18:00:24:029 [INFO] Completed: Building test_runner.pex 18:00:24:030 [INFO] Completed: Building requirements.pex 18:00:24:031 [INFO] Completed: Create PEX 18:00:24:031 [INFO] Completed: Create PEX 18:00:32:638 [INFO] Completed: Building pytest.pex with 8 requirements: ipdb, pygments, <snip> 18:00:32:639 [INFO] Completed: Create PEX 18:00:34:480 [INFO] Completed: Run Pytest for tests/python/pants_test/util:strutil 18:00:34:480 [INFO] Completed: Run pytest 18:00:34:481 [INFO] Tests succeeded: tests/python/pants_test/util:strutil ✓ tests/python/pants_test/util:strutil ============================= test session starts ============================== <snip> ============================== 6 passed in 0.03s =============================== 18:00:34:481 [INFO] Completed: `test` goal ``` Likewise, when the process cache is hit on a run without `pantsd`, the `@rules` will run ("Create PEX" etc) but the processes won't because they'll have been persistently cached... which makes the output even less useful. ### Solution While we should pursue #7907, and likely also allow `@rule`s to explicitly declare their level, some rule names just won't be useful when compared to the process names we've generated. Prune a few. ### Result Output for the same uncached command is: ``` 00:35:51:820 [INFO] Completed: Building requirements.pex 00:35:51:821 [INFO] Completed: Building test_runner.pex 00:36:02:208 [INFO] Completed: Building pytest.pex with 8 requirements: ipdb, pygments, <snip> 00:36:04:487 [INFO] Completed: Run Pytest for tests/python/pants_test/util:strutil 00:36:04:488 [INFO] Tests succeeded: tests/python/pants_test/util:strutil ✓ tests/python/pants_test/util:strutil ============================= test session starts ============================== <snip> ============================== 6 passed in 0.03s =============================== 18:05:23:318 [INFO] Completed: `test` goal ``` See also: the travis output for this run. [ci skip-jvm-tests] [ci skip-rust-tests]

stuhood · 2020-06-01T18:26:56Z

Updated the name and title to encapsulate two cases that had consensus in #9921.

cc @asherf

### Problem #9894 and #9921 added workunit completion logging in order to improve the experience when the `--dynamic-ui` is disabled, and to prepare to render streaming warnings/errors and stdio when tests or lints fail, even when the UI is enabled. But further tweaks are needed in order to achieve minimal output in the common case. ### Solution After those changes, it's become clear that `@rules` should default to debug level, because it continues to be the case that processes are the bread and butter of our runs. Even if/when we implement #7907, the processes that run will continue to represent the bulk of the work and the thing that we cache. This change defaults all `@rules` to debug, and allows `@rules` to set their own `level`s. Additionally, it removes `@named_rule`, because it's become clear that any `@rule` should be able to set a `canonical_name` (all rules already have one, so we might as well let them set it), `description`, or `level`. ### Result After this change, only processes (that actually ran, as opposed to hitting cache) will be rendered. `@rules` can opt in to higher log levels, but most should not (unless they are computationally expensive...?): ``` $ ./v2 --changed-parent=master fmt 18:35:35:904 [INFO] Completed: Run Black on 14 targets: src/python/pants/backend/awslambda/python, src/python/pants/backend/codegen/protobuf/python, src/python/pants/backend/python/lint/bandit, src/python/pants/backend/python/lint/... (403 characters truncated) 18:35:38:233 [INFO] Completed: Run Docformatter on 14 targets: src/python/pants/backend/awslambda/python, src/python/pants/backend/codegen/protobuf/python, src/python/pants/backend/python/lint/bandit, src/python/pants/backend/pytho... (410 characters truncated) 18:35:40:530 [INFO] Completed: Run isort on 14 targets: src/python/pants/backend/awslambda/python, src/python/pants/backend/codegen/protobuf/python, src/python/pants/backend/python/lint/bandit, src/python/pants/backend/python/lint/... (403 characters truncated) 𐄂 Black made changes. reformatted src/python/pants/engine/internals/engine_test.py All done! ✨ 🍰 ✨ 1 file reformatted, 84 files left unchanged. ✓ Docformatter made no changes. 𐄂 isort made changes. Fixing src/python/pants/engine/internals/engine_test.py ```

stuhood · 2020-06-11T03:17:58Z

@Eric-Arellano experienced a variant of this today: the Graph's cycle detection uses the Display representation of the nodes in the cycle, and the Params to the @rules that walk the dep graph got quite a bit larger recently (including the OptionsBootstrapper).

If we had something like the first item here, then those rules could have better string representations. Even a default string representation of rules that contained only their literal arguments would go a long way (because the arguments to a rule are likely smaller than the Params), even without users doing any customization.

stuhood · 2020-06-23T22:35:36Z

@gshuflin: Another thought here (related to my previous comment).

It's possible that rendering the Params of a Node would actually make for a good default here if we apply a strategy similar to the EngineAware trait, that would opt params in and out of the description. Because rendering:

format!("@rule {}({})", task.task.display_info.name, task.params)

...is almost a good representation. The issue is that it includes too much information. If we were to include/exclude types, and render a simplified version of the type, you might be able to get something like:

@rule coordinator_of_tests((OptionsBootstrapper(..), tests/python/pants_test/util:argutil))

### Problem cf. #10518 , it's possible for pants to emit extremely large log messages whenever it prints a long containing the string representation of large Python types. In the above issue, the large Python types are `FieldSet` subclasses (which can include lots of e.g. file path names) in their Python `__str__` representation. These types appear as the `params` field on a `Task`, and are part of the Rust `Display` representation of a `Task`, which is part of the log message when a node is invalidated because of a file system change, and might more generally show up in any pants log message. ### Solution A quick fix for the above problem is to simply remove the `Params` from the `Display` implementation of an `@rule`'s task, and only include the name of the Python function corresponding to the rule. cf. #7907 , we probably want to eventually implement a more sophisticated way of deciding what Python type information we do and do not need to include in useful pants logs from Rust.

### Problem cf. #10334 , the `Engine traceback` strings don't provide enough information about the arguments to the `@rule`s they represent to be useful for debugging. ### Solution This commit introduces a new "EngineAware" method `debug_hint`, which can be implemented for the parameters of an `@rule` (cf. #7907 (comment) ) to provide a concise debugging string. This is implemented for the `TestFieldSet` type, writing the address of the test in question, and the value of this method is plumbed to the `EngineTraceback` string. This commit also splits up the `EngineAware` class into two separate classes: `EngineAwareParams` to be implemented by input parameters to a rule; and `EngineAwareReturnType` to be implemented by rule return types. Additionally this commit does a bit of cleanup to the string representation of the `Params` type, and puts the code for manipulating `EngineAware` methods into a new submodule. ### Result https://asciinema.org/a/354849 demonstrates the expanded information in `Engine traceback` strings.

gshuflin · 2020-08-23T07:42:32Z

@gshuflin: Another thought here (related to my previous comment).

It's possible that rendering the Params of a Node would actually make for a good default here if we apply a strategy similar to the EngineAware trait, that would opt params in and out of the description. Because rendering:
format!("@rule {}({})", task.task.display_info.name, task.params)
...is almost a good representation. The issue is that it includes too much information. If we were to include/exclude types, and render a simplified version of the type, you might be able to get something like:
@rule coordinator_of_tests((OptionsBootstrapper(..), tests/python/pants_test/util:argutil))

#10665 introduces a new debug_hint method for rule parameters that we now can leverage to build better parameter debug messages.

stuhood · 2020-08-24T19:39:15Z

Thanks @gshuflin!

IMO, the EngineAware types provide enough power to call this issue resolved. Great stuff!

Native graph cycles don't currently render the `EngineAware` parameters which were added in #7907, which makes it impossible to see the actual source of a cycle in many cases. Begin rendering them. Extracted as prework from #12539. [ci skip-build-wheels]

blorente added the engine label Jun 20, 2019

gshuflin mentioned this issue Jun 20, 2019

Don't memoize description in process execute memoization #7916

Merged

illicitonion pushed a commit that referenced this issue Jun 24, 2019

Don't memoize description in process execute memoization (#7916)

b396810

#7745, we should revisit this solution when #7907 is decided upon

This comment has been minimized.

Sign in to view

stuhood mentioned this issue Oct 9, 2019

Render cyclic path in node error to avoid --print-exception-stacktrace #8422

Merged

gshuflin mentioned this issue Nov 8, 2019

Allow @rule-authors to give rules names #8592

Merged

gshuflin self-assigned this Nov 15, 2019

stuhood mentioned this issue Dec 12, 2019

Add Flake8 linter to V2 #8791

Merged

stuhood changed the title ~~[V2 UI] Figure out how and when Nodes should be rendered.~~ [V2 UI] Add templating to rule names. Dec 12, 2019

stuhood mentioned this issue Dec 14, 2019

Call for proposals: improved @rule display #7509

Closed

Eric-Arellano closed this as completed May 18, 2020

stuhood reopened this May 30, 2020

This was referenced May 30, 2020

Remove redundant names and logging. #9921

Merged

Workunit logging has duplicate lines & lines w/o details #9925

Closed

stuhood changed the title ~~[V2 UI] Add templating to rule names.~~ Rule descriptions and workunits should be able to include runtime information Jun 1, 2020

stuhood changed the title ~~Rule descriptions and workunits should be able to include runtime information~~ @rule workunits should be able to include runtime information Jun 1, 2020

stuhood mentioned this issue Jun 2, 2020

Allow @rules to set their levels, and default to debug #9940

Merged

stuhood added the ui label Jun 9, 2020

stuhood mentioned this issue Jun 23, 2020

Retry for filesystem changes more quickly, indefinitely, and with logging #10139

Merged

This was referenced Jul 13, 2020

Missing context (target name) when failing to resolve requirements. #10334

Closed

Improve error message for target cycles #10390

Closed

stuhood mentioned this issue Jul 31, 2020

[v2] Noisy console message when file system changes #10518

Closed

stuhood mentioned this issue Aug 3, 2020

EngineAware rules should possibly log when starting when --no-dynamic-ui #10536

Open

gshuflin mentioned this issue Aug 19, 2020

Reduce noisy log messages from @rule params #10658

Merged

Eric-Arellano mentioned this issue Aug 20, 2020

Stream output of typecheck, rather than dumping at the end #10656

Merged

gshuflin mentioned this issue Aug 21, 2020

Provide better debugging information for rule parameters #10665

Merged

stuhood closed this as completed Aug 24, 2020

Eric-Arellano mentioned this issue Apr 6, 2021

Add Shell support with Shellcheck, shmft, and shunit2 test runner #11844

Merged

stuhood mentioned this issue Aug 26, 2021

Improve the rendering of cycle errors in Graph. #12668

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

@rule workunits should be able to include runtime information #7907

@rule workunits should be able to include runtime information #7907

blorente commented Jun 20, 2019 •

edited by stuhood

Loading

This comment has been minimized.

stuhood commented Dec 12, 2019 •

edited

Loading

Eric-Arellano commented May 18, 2020

stuhood commented May 30, 2020 •

edited

Loading

stuhood commented Jun 1, 2020 •

edited

Loading

stuhood commented Jun 11, 2020 •

edited

Loading

stuhood commented Jun 23, 2020 •

edited

Loading

gshuflin commented Aug 23, 2020

stuhood commented Aug 24, 2020

@rule workunits should be able to include runtime information #7907

@rule workunits should be able to include runtime information #7907

Comments

blorente commented Jun 20, 2019 • edited by stuhood Loading

This comment has been minimized.

stuhood commented Dec 12, 2019 • edited Loading

Eric-Arellano commented May 18, 2020

stuhood commented May 30, 2020 • edited Loading

stuhood commented Jun 1, 2020 • edited Loading

stuhood commented Jun 11, 2020 • edited Loading

stuhood commented Jun 23, 2020 • edited Loading

gshuflin commented Aug 23, 2020

stuhood commented Aug 24, 2020

blorente commented Jun 20, 2019 •

edited by stuhood

Loading

stuhood commented Dec 12, 2019 •

edited

Loading

stuhood commented May 30, 2020 •

edited

Loading

stuhood commented Jun 1, 2020 •

edited

Loading

stuhood commented Jun 11, 2020 •

edited

Loading

stuhood commented Jun 23, 2020 •

edited

Loading