matcher logger

[aarushjain29]

No description provided.

[codecov]

Codecov Report

Attention: Patch coverage is 66.66667% with 5 lines in your changes missing coverage. Please review.

Project coverage is 92.16%. Comparing base (e2e9219) to head (ffd393e).
Report is 43 commits behind head on develop.

Files with missing lines	Patch %	Lines
src/include/migraphx/matcher.hpp	66.66%	5 Missing ⚠️

Additional details and impacted files

@@             Coverage Diff             @@
##           develop    #3500      +/-   ##
===========================================
+ Coverage    92.02%   92.16%   +0.13%     
===========================================
  Files          509      512       +3     
  Lines        21005    21404     +399     
===========================================
+ Hits         19330    19727     +397     
- Misses        1675     1677       +2     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[pfultz2]

1. The time measurements should be done in the find_matches_for function.
2. There should also be an environment variable to enable it like MIGRAPHX_TIME_MATCHERS.
3. Trace filter should probably be used to reduce down the amount of printouts.

[bpickrel]

Update copyright date (think we have a script for that; can't remember how to run it)

[bpickrel]

1. The time measurements should be done in the find_matches_for function.

@pfultz2 does every single matcher go through find_matches_for? If we're going to add this feature to the develop branch then I suggest you add it for every matcher, not just the selected ones that Aarushi added the code to.

2. There should also be an environment variable to enable it like MIGRAPHX_TIME_MATCHERS.

This is a good way to globally enable/disable match timing. But maybe we also want to enable/disable timing programmatically for individual matchers? Aarushi, in your experience would this be helpful?

3. Trace filter should probably be used to reduce down the amount of printouts.

I suggest wrapping the timer function in a macro so you can easily insert/remove it from the list in individual passes' find_matches() methods, eg.

void simplify_algebra::apply(module& m) const
{
    // Run simplifications multiple times
    m.repeat_while_changes(8, [&] {
        match::find_matches(m,
                            LOG_MATCHER_TIMER(find_inner_broadcast{}),    <===new macro
                            find_dot_broadcast{},
 etc.

which would be less repetitive work than wrapping each matcher in curly brackets as Aarushi has done.

What do you think?

[pfultz2]

does every single matcher go through find_matches_for?

Yes.

This is a good way to globally enable/disable match timing. But maybe we also want to enable/disable timing programmatically for individual matchers?

The MIGRAPHX_TRACE_MATCHES_FOR lets you filter the matchers if we use it for timing as well.

What do you think?

I would like to avoid needing to change the source code to get timings. We dont do it for the passes. This will let us get timings on deployed systems so we dont need to rebuild migraphx.

[migraphx-bot]

Test	Batch	Rate new ffd393	Rate old b73def	Diff	Compare
torchvision-resnet50	64	3,258.19	3,257.93	0.01%	✅
torchvision-resnet50_fp16	64	6,975.38	6,992.99	-0.25%	✅
torchvision-densenet121	32	2,431.85	2,432.26	-0.02%	✅
torchvision-densenet121_fp16	32	4,078.23	4,038.39	0.99%	✅
torchvision-inceptionv3	32	1,638.30	1,638.89	-0.04%	✅
torchvision-inceptionv3_fp16	32	2,752.74	2,761.69	-0.32%	✅
cadene-inceptionv4	16	779.83	776.39	0.44%	✅
cadene-resnext64x4	16	808.19	811.37	-0.39%	✅
slim-mobilenet	64	7,468.71	7,532.73	-0.85%	✅
slim-nasnetalarge	64	208.26	211.42	-1.50%	✅
slim-resnet50v2	64	3,436.65	3,507.25	-2.01%	✅
bert-mrpc-onnx	8	1,150.74	1,147.76	0.26%	✅
bert-mrpc-tf	1	314.84	469.91	-33.00%	🔴
pytorch-examples-wlang-gru	1	424.86	514.96	-17.50%	🔴
pytorch-examples-wlang-lstm	1	374.32	386.61	-3.18%	🔴
torchvision-resnet50_1	1	806.28	772.05	4.43%	🔆
cadene-dpn92_1	1	398.39	398.73	-0.09%	✅
cadene-resnext101_1	1	377.55	383.67	-1.60%	✅
onnx-taau-downsample	1	367.09	342.33	7.23%	🔆
dlrm-criteoterabyte	1	35.03	33.33	5.09%	🔆
dlrm-criteoterabyte_fp16	1	58.16	52.70	10.35%	🔆
agentmodel	1	7,723.44	8,056.20	-4.13%	🔴
unet_fp16	2	59.07	58.92	0.25%	✅
resnet50v1_fp16	1	929.07	950.32	-2.24%	✅
resnet50v1_int8	1	1,021.31	1,000.02	2.13%	✅
bert_base_cased_fp16	64	1,171.09	1,169.24	0.16%	✅
bert_large_uncased_fp16	32	363.55	363.69	-0.04%	✅
bert_large_fp16	1	213.29	198.89	7.24%	🔆
distilgpt2_fp16	16	2,200.93	2,203.09	-0.10%	✅
yolov5s	1	542.04	540.85	0.22%	✅
tinyllama	1	43.70	43.43	0.61%	✅
vicuna-fastchat	1	171.62	170.64	0.58%	✅
whisper-tiny-encoder	1	418.77	418.21	0.13%	✅
whisper-tiny-decoder	1	427.53	426.10	0.34%	✅

This build is not recommended to merge 🔴

[migraphx-bot]

     ✅ bert-mrpc-onnx: PASSED: MIGraphX meets tolerance

     ✅ bert-mrpc-tf: PASSED: MIGraphX meets tolerance

     ✅ pytorch-examples-wlang-gru: PASSED: MIGraphX meets tolerance

     ✅ pytorch-examples-wlang-lstm: PASSED: MIGraphX meets tolerance

     ✅ torchvision-resnet50_1: PASSED: MIGraphX meets tolerance

     ✅ cadene-dpn92_1: PASSED: MIGraphX meets tolerance

     ✅ cadene-resnext101_1: PASSED: MIGraphX meets tolerance

     ✅ dlrm-criteoterabyte: PASSED: MIGraphX meets tolerance

     ✅ agentmodel: PASSED: MIGraphX meets tolerance

     ✅ unet: PASSED: MIGraphX meets tolerance

     ✅ resnet50v1: PASSED: MIGraphX meets tolerance

     ✅ bert_base_cased_fp16: PASSED: MIGraphX meets tolerance

🔴bert_large_uncased_fp16: FAILED: MIGraphX is not within tolerance - check verbose output

     ✅ bert_large: PASSED: MIGraphX meets tolerance

     ✅ yolov5s: PASSED: MIGraphX meets tolerance

     ✅ tinyllama: PASSED: MIGraphX meets tolerance

     ✅ vicuna-fastchat: PASSED: MIGraphX meets tolerance

     ✅ whisper-tiny-encoder: PASSED: MIGraphX meets tolerance

     ✅ whisper-tiny-decoder: PASSED: MIGraphX meets tolerance

     ✅ distilgpt2_fp16: PASSED: MIGraphX meets tolerance

[pfultz2]

We should only be timing the match and apply methods. We should also print out the time for each.