matcher logger

[aarushjain29]

No description provided.

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 92.14%. Comparing base (e2e9219) to head (a3a5fcc).
Report is 59 commits behind head on develop.

Additional details and impacted files

@@             Coverage Diff             @@
##           develop    #3500      +/-   ##
===========================================
+ Coverage    92.02%   92.14%   +0.12%     
===========================================
  Files          509      512       +3     
  Lines        21005    21428     +423     
===========================================
+ Hits         19330    19745     +415     
- Misses        1675     1683       +8     

☔ 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 a3a5fc	Rate old 538898	Diff	Compare
torchvision-resnet50	64	3,258.74	3,259.25	-0.02%	✅
torchvision-resnet50_fp16	64	6,965.73	6,987.98	-0.32%	✅
torchvision-densenet121	32	2,431.24	2,435.18	-0.16%	✅
torchvision-densenet121_fp16	32	4,084.20	4,107.65	-0.57%	✅
torchvision-inceptionv3	32	1,637.86	1,638.45	-0.04%	✅
torchvision-inceptionv3_fp16	32	2,755.86	2,765.03	-0.33%	✅
cadene-inceptionv4	16	780.10	776.04	0.52%	✅
cadene-resnext64x4	16	808.09	811.47	-0.42%	✅
slim-mobilenet	64	7,464.54	7,532.97	-0.91%	✅
slim-nasnetalarge	64	208.54	211.47	-1.39%	✅
slim-resnet50v2	64	3,438.20	3,506.08	-1.94%	✅
bert-mrpc-onnx	8	1,151.26	1,145.67	0.49%	✅
bert-mrpc-tf	1	317.64	464.12	-31.56%	🔴
pytorch-examples-wlang-gru	1	424.97	415.28	2.33%	✅
pytorch-examples-wlang-lstm	1	378.88	382.85	-1.04%	✅
torchvision-resnet50_1	1	772.27	775.95	-0.47%	✅
cadene-dpn92_1	1	396.02	403.42	-1.84%	✅
cadene-resnext101_1	1	381.94	383.63	-0.44%	✅
onnx-taau-downsample	1	366.81	341.73	7.34%	🔆
dlrm-criteoterabyte	1	35.05	33.34	5.15%	🔆
dlrm-criteoterabyte_fp16	1	58.20	52.72	10.41%	🔆
agentmodel	1	7,983.59	8,136.83	-1.88%	✅
unet_fp16	2	58.98	58.73	0.43%	✅
resnet50v1_fp16	1	969.11	968.97	0.01%	✅
resnet50v1_int8	1	977.22	1,017.05	-3.92%	🔴
bert_base_cased_fp16	64	1,171.49	1,171.55	-0.01%	✅
bert_large_uncased_fp16	32	363.74	363.37	0.10%	✅
bert_large_fp16	1	213.40	199.99	6.70%	🔆
distilgpt2_fp16	16	2,198.49	2,203.14	-0.21%	✅
yolov5s	1	542.88	530.68	2.30%	✅
tinyllama	1	43.49	43.42	0.16%	✅
vicuna-fastchat	1	173.64	178.25	-2.59%	✅
whisper-tiny-encoder	1	418.45	417.77	0.16%	✅
whisper-tiny-decoder	1	427.08	435.63	-1.96%	✅

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