Adding MIGRAPHX_TIME_MATCHERS

[aarushjain29]

No description provided.

[codecov]

Codecov Report

Attention: Patch coverage is 83.33333% with 1 line in your changes missing coverage. Please review.

Project coverage is 92.33%. Comparing base (7832892) to head (c6a6d37).

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

Additional details and impacted files

@@           Coverage Diff            @@
##           develop    #3500   +/-   ##
========================================
  Coverage    92.33%   92.33%           
========================================
  Files          519      519           
  Lines        22261    22265    +4     
========================================
+ Hits         20555    20559    +4     
  Misses        1706     1706           

☔ 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]

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 c6a6d3	Rate old 3aee3a	Diff	Compare
torchvision-resnet50	64	3,236.05	3,235.04	0.03%	✅
torchvision-resnet50_fp16	64	6,879.24	6,877.66	0.02%	✅
torchvision-densenet121	32	2,436.78	2,436.52	0.01%	✅
torchvision-densenet121_fp16	32	4,192.28	4,189.80	0.06%	✅
torchvision-inceptionv3	32	1,615.66	1,613.28	0.15%	✅
torchvision-inceptionv3_fp16	32	2,680.36	2,677.62	0.10%	✅
cadene-inceptionv4	16	750.97	750.18	0.11%	✅
cadene-resnext64x4	16	809.45	808.82	0.08%	✅
slim-mobilenet	64	6,664.24	6,663.29	0.01%	✅
slim-nasnetalarge	64	199.10	198.98	0.06%	✅
slim-resnet50v2	64	3,428.46	3,424.55	0.11%	✅
bert-mrpc-onnx	8	1,144.74	1,141.83	0.26%	✅
bert-mrpc-tf	1	485.29	473.12	2.57%	✅
pytorch-examples-wlang-gru	1	535.75	473.81	13.07%	🔆
pytorch-examples-wlang-lstm	1	439.71	426.27	3.15%	🔆
torchvision-resnet50_1	1	812.46	796.61	1.99%	✅
cadene-dpn92_1	1	432.31	428.61	0.87%	✅
cadene-resnext101_1	1	390.48	389.68	0.20%	✅
onnx-taau-downsample	1	371.32	372.29	-0.26%	✅
dlrm-criteoterabyte	1	31.79	30.54	4.09%	🔆
dlrm-criteoterabyte_fp16	1	51.06	49.05	4.08%	🔆
agentmodel	1	8,628.20	8,978.43	-3.90%	🔴
unet_fp16	2	57.95	57.93	0.03%	✅
resnet50v1_fp16	1	1,037.60	1,010.88	2.64%	✅
resnet50v1_int8	1	815.43	802.03	1.67%	✅
bert_base_cased_fp16	64	1,173.06	1,172.65	0.03%	✅
bert_large_uncased_fp16	32	362.38	362.27	0.03%	✅
bert_large_fp16	1	199.80	198.55	0.63%	✅
distilgpt2_fp16	16	2,216.91	2,215.63	0.06%	✅
yolov5s	1	529.34	530.86	-0.29%	✅
tinyllama	1	43.63	43.55	0.19%	✅
vicuna-fastchat	1	43.87	43.92	-0.11%	✅
whisper-tiny-encoder	1	411.77	410.51	0.31%	✅
whisper-tiny-decoder	1	411.77	407.47	1.05%	✅

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

[lakhinderwalia]

It seems there is very little difference in the debug outputs, between the new environment variable, MIGRAPHX_TIME_MATCHERS being set, and the result of trace_for option match.

Does one even need this new variable in that case: unless your print clauses are gated by if(time_matchers and trace_for) -- The or is replaced by and.

I am approving this PR, never-the-less, for it gives out the necessary time-related info that one is interested in.