Add more logging to sharktank data tests #1017
Conversation
erman-gurses
added
the
infra
|
Will double check and add more logs for the other tests. |
|
@ScottTodd , raised a draft PR, let me know if you have any feedback. I can iterate over that. |
|
Can you link to example logs before/after in the PR description? That would make review easier. |
|
Before logging: https://github.com/nod-ai/shark-ai/actions/runs/13727645858/job/38397644679?pr=1017#step:7:108 Also added those kinds logs: |
Signed-off-by: erman-gurses <[email protected]>
erman-gurses
force-pushed
the
users/erman-gurses/add-more-logging
branch
from
296bb2d to
b086fdf
Compare
Signed-off-by: erman-gurses <[email protected]>
erman-gurses
force-pushed
the
users/erman-gurses/add-more-logging
branch
from
d854f6a to
a09d45b
Compare
Signed-off-by: erman-gurses <[email protected]>
Signed-off-by: erman-gurses <[email protected]>
| class BenchmarkLlama3_1_8B(BaseBenchmarkTest): | ||
| logger.info("Testing BenchmarkLlama3_1_8B...") |
There was a problem hiding this comment.
I would remove these class-scoped log lines and instead rely on the -v option already included on the pytest commands in the workflow files.
I don't think logs at the class scope are doing what you want / are useful: https://github.com/nod-ai/shark-ai/actions/runs/13667985379/job/38212871488?pr=1017#step:7:22
snippet:
collecting ...
----------------------------- live log collection ------------------------------
INFO:tests.models.llama.benchmark_amdgpu_test BenchmarkLlama3_1_8B...
INFO:tests.models.llama.benchmark_amdgpu_test Testing Benchmark8B_f16_Non_Decomposed_Input_Len_128...
INFO:tests.models.llama.benchmark_amdgpu_test Testing Benchmark405B_fp8_TP8_Non_Decomposed...
collected 11 items
Pytest has a few phases while running tests. This is the "collection" phase, which is where pytest discovers test cases from the directory tree based on any conftest.py files, setting/configuration files, and command line options. These log lines are running during that collection phase, when you really want them when the tests are actually starting. Only after collection completes are individual tests actually ran, then there are a few other phases.
I can't find docs on the phases, but https://docs.pytest.org/en/stable/reference/reference.html#hooks is close enough to get the point across:
- bootstrapping
- initialization
- collection
- test running
- reporting
However, pytest can already log when a test starts. See https://docs.pytest.org/en/stable/how-to/output.html and the -v option in particular which changes from
=========================== test session starts ============================
collected 4 items
test_verbosity_example.py .FFF [100%]
================================= FAILURES =================================
to
=========================== test session starts ============================
collecting ... collected 4 items
test_verbosity_example.py::test_ok PASSED [ 25%]
test_verbosity_example.py::test_words_fail FAILED [ 50%]
test_verbosity_example.py::test_numbers_fail FAILED [ 75%]
test_verbosity_example.py::test_long_text_fail FAILED [100%]
================================= FAILURES =================================
| logger.info("Compiling MLIR file...") | ||
| self.llama8b_f16_torch_sdpa_artifacts.compile_to_vmfb( |
There was a problem hiding this comment.
This helper already does some logging, but the extra logs don't hurt. What we could do in these places is provide context for what or why we're compiling/running. The "IREE Benchmark Prefill..." logs you added are a good example of that. Just seeing iree-run-module ... in the logs doesn't immediately provide such context, but "benchmark prefill" does.
INFO:tests.models.llama.benchmark_amdgpu_test Compiling MLIR file...
INFO:eval Launching compile command:
cd /home/runner/_work/shark-ai/shark-ai && iree-compile /home/runner/_work/shark-ai/shark-ai/2025-03-05/llama-8b/f16_torch_128.mlir --iree-hip-target=gfx942 -o=/home/runner/_work/shark-ai/shark-ai/2025-03-05/llama-8b/f16_torch_128.vmfb --iree-hal-target-device=hip --iree-hal-dump-executable-files-to=/home/runner/_work/shark-ai/shark-ai/2025-03-05/llama-8b/f16_torch_128/files --iree-dispatch-creation-enable-aggressive-fusion=true --iree-global-opt-propagate-transposes=true --iree-opt-aggressively-propagate-transposes=true --iree-opt-data-tiling=false --iree-preprocessing-pass-pipeline='builtin.module(util.func(iree-preprocessing-generalize-linalg-matmul-experimental))' --iree-stream-resource-memory-model=discrete --iree-hal-indirect-command-buffers=true --iree-hal-memoization=true --iree-opt-strip-assertions
INFO:eval compile_to_vmfb: 16.77 secs
| # benchmark prefill | ||
| logger.info("IREE Benchmark Prefill...") |
There was a problem hiding this comment.
nit: when comments and logs are saying the same thing, you can remove the comments
Add more logging to sharktank data tests
It continues on this PR #917