Attachment 134377 Details for Bug 102480 – output (GLK)

output (GLK)

PerfOaExponents-output (text/plain), 54.61 KB, created by Hector Velazquez on 2017-09-20 16:56:55 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Hector Velazquez

Created: 2017-09-20 16:56:55 UTC

Size: 54.61 KB

patch

obsolete

>IGT-Version: 1.19-gda197b5 (x86_64) (Linux: 4.14.0-rc1-drm-tip-ww38-commit-ab2e3a0+ x86_64)
>(perf:1466) igt-core-DEBUG: Test requirement passed: !igt_run_in_simulation()
>(perf:1466) DEBUG: Test requirement passed: stat("/proc/sys/dev/i915/perf_stream_paranoid", &sb) == 0
>(perf:1466) DEBUG: Test requirement passed: stat("/proc/sys/dev/i915/oa_max_sample_rate", &sb) == 0
>(perf:1466) igt-debugfs-DEBUG: Opening debugfs directory '/sys/kernel/debug/dri/0'
>(perf:1466) DEBUG: TestOa metric set UUID = dd3fd789-e783-4204-8cd0-b671bbccb0cf
>(perf:1466) DEBUG: Test requirement passed: init_sys_info()
>(perf:1466) DEBUG: Test requirement passed: render_copy
>(perf:1466) igt-core-DEBUG: Starting subtest: oa-exponents
>(perf:1466) DEBUG: requesting pinned GT freq = 450mhz
>(perf:1466) DEBUG: Testing OA timer exponents with requested GT frequency = 450mhz
>(perf:1466) DEBUG: ITER 0: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 1e0ec00f, timestamp = 97244fe0, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 1e0ec00f, timestamp = 97245020, exponent mask=3f
>(perf:1466) DEBUG: ITER 0: time delta = 3333(ns) clock delta = 830 freq = 249(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 972e3660, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 972e36a0, exponent mask=3f
>(perf:1466) DEBUG: ITER 1: time delta = 3333(ns) clock delta = 1499 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9738bd20, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9738bd60, exponent mask=3f
>(perf:1466) DEBUG: ITER 2: time delta = 3333(ns) clock delta = 1498 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97447960, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 974479a0, exponent mask=3f
>(perf:1466) DEBUG: ITER 3: time delta = 3333(ns) clock delta = 1494 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97502860, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 975028a0, exponent mask=3f
>(perf:1466) DEBUG: ITER 4: time delta = 3333(ns) clock delta = 1494 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 975bc8a0, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 975bc8e0, exponent mask=3f
>(perf:1466) DEBUG: ITER 5: time delta = 3333(ns) clock delta = 1494 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 976796a0, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 976796e0, exponent mask=3f
>(perf:1466) DEBUG: ITER 6: time delta = 3333(ns) clock delta = 1498 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 977346a0, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 977346e0, exponent mask=3f
>(perf:1466) DEBUG: ITER 7: time delta = 3333(ns) clock delta = 1489 freq = 446(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 977f1720, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 977f1760, exponent mask=3f
>(perf:1466) DEBUG: ITER 8: time delta = 3333(ns) clock delta = 1498 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 5 (period = 3333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 97899b60, exponent mask=3f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97899ba0, exponent mask=3f
>(perf:1466) DEBUG: ITER 9: time delta = 3333(ns) clock delta = 1494 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 9
>(perf:1466) DEBUG: ITER 0: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 979554c0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97955540, exponent mask=7f
>(perf:1466) DEBUG: ITER 0: time delta = 6666(ns) clock delta = 2988 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97a0a440, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97a0a4c0, exponent mask=7f
>(perf:1466) DEBUG: ITER 1: time delta = 6666(ns) clock delta = 2992 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 97abdbc0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97abdc40, exponent mask=7f
>(perf:1466) DEBUG: ITER 2: time delta = 6666(ns) clock delta = 2997 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97b74840, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97b748c0, exponent mask=7f
>(perf:1466) DEBUG: ITER 3: time delta = 6666(ns) clock delta = 2988 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97c26ac0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97c26b40, exponent mask=7f
>(perf:1466) DEBUG: ITER 4: time delta = 6666(ns) clock delta = 2997 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97cddc40, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97cddcc0, exponent mask=7f
>(perf:1466) DEBUG: ITER 5: time delta = 6666(ns) clock delta = 2992 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97d8fec0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97d8ff40, exponent mask=7f
>(perf:1466) DEBUG: ITER 6: time delta = 6666(ns) clock delta = 2997 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97e46fc0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97e47040, exponent mask=7f
>(perf:1466) DEBUG: ITER 7: time delta = 6666(ns) clock delta = 2997 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97efdb40, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97efdbc0, exponent mask=7f
>(perf:1466) DEBUG: ITER 8: time delta = 6666(ns) clock delta = 2997 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 6 (period = 6666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 97fb38c0, exponent mask=7f
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 97fb3940, exponent mask=7f
>(perf:1466) DEBUG: ITER 9: time delta = 6666(ns) clock delta = 2988 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98066f80, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98067080, exponent mask=ff
>(perf:1466) DEBUG: ITER 0: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98119080, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98119180, exponent mask=ff
>(perf:1466) DEBUG: ITER 1: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 981cb180, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 981cb280, exponent mask=ff
>(perf:1466) DEBUG: ITER 2: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98266480, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98266580, exponent mask=ff
>(perf:1466) DEBUG: ITER 3: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9831c380, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9831c480, exponent mask=ff
>(perf:1466) DEBUG: ITER 4: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 983cdf80, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 983ce080, exponent mask=ff
>(perf:1466) DEBUG: ITER 5: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98480580, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98480680, exponent mask=ff
>(perf:1466) DEBUG: ITER 6: time delta = 13333(ns) clock delta = 5985 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98532780, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 98532880, exponent mask=ff
>(perf:1466) DEBUG: ITER 7: time delta = 13333(ns) clock delta = 5985 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 985e9180, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 985e9280, exponent mask=ff
>(perf:1466) DEBUG: ITER 8: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9869b980, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9869ba80, exponent mask=ff
>(perf:1466) DEBUG: ITER 9: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9874d900, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9874db00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 0: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 987ffd00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 987fff00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 1: time delta = 26666(ns) clock delta = 11961 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 988b2500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 988b2700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 2: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98963b00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98963d00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 3: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98a15f00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98a16100, exponent mask=1ff
>(perf:1466) DEBUG: ITER 4: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98ac8100, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98ac8300, exponent mask=1ff
>(perf:1466) DEBUG: ITER 5: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98b7a500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98b7a700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 6: time delta = 26666(ns) clock delta = 11965 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98c2c500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98c2c700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 7: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98cde100, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98cde300, exponent mask=1ff
>(perf:1466) DEBUG: ITER 8: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98d90700, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98d90900, exponent mask=1ff
>(perf:1466) DEBUG: ITER 9: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98e43a00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98e43e00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 0: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98f0c600, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98f0ca00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 1: time delta = 53333(ns) clock delta = 23922 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98fa7200, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98fa7600, exponent mask=3ff
>(perf:1466) DEBUG: ITER 2: time delta = 53333(ns) clock delta = 23944 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9906fe00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99070200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 3: time delta = 53333(ns) clock delta = 23922 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99121e00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99122200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 4: time delta = 53333(ns) clock delta = 23926 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 991d5200, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 991d5600, exponent mask=3ff
>(perf:1466) DEBUG: ITER 5: time delta = 53333(ns) clock delta = 23931 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9926ee00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9926f200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 6: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 99334a00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99334e00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 7: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 993cea00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 993cee00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 8: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99481600, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99481a00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 9: time delta = 53333(ns) clock delta = 23926 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99532c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99533400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 0: time delta = 106666(ns) clock delta = 47876 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 995fc400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 995fcc00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 1: time delta = 106666(ns) clock delta = 47866 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 996ae400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 996aec00, exponent mask=7ff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 3: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9974a400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9974ac00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 3: time delta = 106666(ns) clock delta = 47871 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 997fbc00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 997fc400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 4: time delta = 106666(ns) clock delta = 47858 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 998c4c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 998c5400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 5: time delta = 106666(ns) clock delta = 47862 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99973c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99974400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 6: time delta = 106666(ns) clock delta = 47862 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99a0d400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99a0dc00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 7: time delta = 106666(ns) clock delta = 47867 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 99abfc00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ac0400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 8: time delta = 106666(ns) clock delta = 47875 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99b89400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99b89c00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 9: time delta = 106666(ns) clock delta = 47858 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 10: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99c23c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99c24400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 10: time delta = 106666(ns) clock delta = 47875 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99cd6800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 99cd7800, exponent mask=fff
>(perf:1466) DEBUG: ITER 0: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99d9f800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99da0800, exponent mask=fff
>(perf:1466) DEBUG: ITER 1: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99e4d800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 99e4e800, exponent mask=fff
>(perf:1466) DEBUG: ITER 2: time delta = 213333(ns) clock delta = 95729 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ee8800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ee9800, exponent mask=fff
>(perf:1466) DEBUG: ITER 3: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99f9a800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99f9b800, exponent mask=fff
>(perf:1466) DEBUG: ITER 4: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a04b800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a04c800, exponent mask=fff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 6: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a0fe800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a0ff800, exponent mask=fff
>(perf:1466) DEBUG: ITER 6: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 9a1b1800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 9a1b2800, exponent mask=fff
>(perf:1466) DEBUG: ITER 7: time delta = 213333(ns) clock delta = 95737 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a27a800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a27b800, exponent mask=fff
>(perf:1466) DEBUG: ITER 8: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a314800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9a315800, exponent mask=fff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 10: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a3c6800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a3c7800, exponent mask=fff
>(perf:1466) DEBUG: ITER 10: time delta = 213333(ns) clock delta = 95737 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 11: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a475800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a476800, exponent mask=fff
>(perf:1466) DEBUG: ITER 11: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 12 (period = 426666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a527000, exponent mask=1fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a529000, exponent mask=1fff
>(perf:1466) DEBUG: ITER 0: time delta = 426666(ns) clock delta = 191480 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 12 (period = 426666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a5d5000, exponent mask=1fff
>(perf:1466) DEBUG: read report: reason = 300ec018, timestamp = 9a5d709d, exponent mask=1fff
>(perf:1466) DEBUG: timestamp0 = 2589806592/0x9a5d5000
>(perf:1466) DEBUG: timestamp1 = 2589814941/0x9a5d709d
>(perf:1466) CRITICAL: Test assertion failure function test_oa_exponents, file perf.c:1482:
>(perf:1466) CRITICAL: Failed assertion: timestamp_delta == expected_timestamp_delta
>(perf:1466) CRITICAL: error: 8349 != 8192
>Subtest oa-exponents failed.
>**** DEBUG ****
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 981cb280, exponent mask=ff
>(perf:1466) DEBUG: ITER 2: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98266480, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98266580, exponent mask=ff
>(perf:1466) DEBUG: ITER 3: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9831c380, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9831c480, exponent mask=ff
>(perf:1466) DEBUG: ITER 4: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 983cdf80, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 983ce080, exponent mask=ff
>(perf:1466) DEBUG: ITER 5: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98480580, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98480680, exponent mask=ff
>(perf:1466) DEBUG: ITER 6: time delta = 13333(ns) clock delta = 5985 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98532780, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 98532880, exponent mask=ff
>(perf:1466) DEBUG: ITER 7: time delta = 13333(ns) clock delta = 5985 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 985e9180, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 985e9280, exponent mask=ff
>(perf:1466) DEBUG: ITER 8: time delta = 13333(ns) clock delta = 5994 freq = 449(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 7 (period = 13333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9869b980, exponent mask=ff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9869ba80, exponent mask=ff
>(perf:1466) DEBUG: ITER 9: time delta = 13333(ns) clock delta = 5976 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9874d900, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9874db00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 0: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 987ffd00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 987fff00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 1: time delta = 26666(ns) clock delta = 11961 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 988b2500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 988b2700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 2: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98963b00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98963d00, exponent mask=1ff
>(perf:1466) DEBUG: ITER 3: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98a15f00, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98a16100, exponent mask=1ff
>(perf:1466) DEBUG: ITER 4: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98ac8100, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98ac8300, exponent mask=1ff
>(perf:1466) DEBUG: ITER 5: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98b7a500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98b7a700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 6: time delta = 26666(ns) clock delta = 11965 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98c2c500, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98c2c700, exponent mask=1ff
>(perf:1466) DEBUG: ITER 7: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98cde100, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98cde300, exponent mask=1ff
>(perf:1466) DEBUG: ITER 8: time delta = 26666(ns) clock delta = 11966 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 8 (period = 26666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98d90700, exponent mask=1ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98d90900, exponent mask=1ff
>(perf:1466) DEBUG: ITER 9: time delta = 26666(ns) clock delta = 11970 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98e43a00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98e43e00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 0: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98f0c600, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 98f0ca00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 1: time delta = 53333(ns) clock delta = 23922 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98fa7200, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 98fa7600, exponent mask=3ff
>(perf:1466) DEBUG: ITER 2: time delta = 53333(ns) clock delta = 23944 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9906fe00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99070200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 3: time delta = 53333(ns) clock delta = 23922 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99121e00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99122200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 4: time delta = 53333(ns) clock delta = 23926 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 991d5200, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 991d5600, exponent mask=3ff
>(perf:1466) DEBUG: ITER 5: time delta = 53333(ns) clock delta = 23931 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9926ee00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9926f200, exponent mask=3ff
>(perf:1466) DEBUG: ITER 6: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 99334a00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99334e00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 7: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 993cea00, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 993cee00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 8: time delta = 53333(ns) clock delta = 23940 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 9 (period = 53333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99481600, exponent mask=3ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99481a00, exponent mask=3ff
>(perf:1466) DEBUG: ITER 9: time delta = 53333(ns) clock delta = 23926 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99532c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99533400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 0: time delta = 106666(ns) clock delta = 47876 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 995fc400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 995fcc00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 1: time delta = 106666(ns) clock delta = 47866 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 996ae400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 996aec00, exponent mask=7ff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 3: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9974a400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9974ac00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 3: time delta = 106666(ns) clock delta = 47871 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 997fbc00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 997fc400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 4: time delta = 106666(ns) clock delta = 47858 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 998c4c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 998c5400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 5: time delta = 106666(ns) clock delta = 47862 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 6: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99973c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99974400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 6: time delta = 106666(ns) clock delta = 47862 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99a0d400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99a0dc00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 7: time delta = 106666(ns) clock delta = 47867 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 99abfc00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ac0400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 8: time delta = 106666(ns) clock delta = 47875 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99b89400, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99b89c00, exponent mask=7ff
>(perf:1466) DEBUG: ITER 9: time delta = 106666(ns) clock delta = 47858 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 10: testing OA exponent 10 (period = 106666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99c23c00, exponent mask=7ff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99c24400, exponent mask=7ff
>(perf:1466) DEBUG: ITER 10: time delta = 106666(ns) clock delta = 47875 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99cd6800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 99cd7800, exponent mask=fff
>(perf:1466) DEBUG: ITER 0: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99d9f800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99da0800, exponent mask=fff
>(perf:1466) DEBUG: ITER 1: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 2: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99e4d800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 99e4e800, exponent mask=fff
>(perf:1466) DEBUG: ITER 2: time delta = 213333(ns) clock delta = 95729 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 3: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ee8800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99ee9800, exponent mask=fff
>(perf:1466) DEBUG: ITER 3: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 4: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99f9a800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 99f9b800, exponent mask=fff
>(perf:1466) DEBUG: ITER 4: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 5: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a04b800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a04c800, exponent mask=fff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 6: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a0fe800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a0ff800, exponent mask=fff
>(perf:1466) DEBUG: ITER 6: time delta = 213333(ns) clock delta = 95738 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 7: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec81b, timestamp = 9a1b1800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ee01b, timestamp = 9a1b2800, exponent mask=fff
>(perf:1466) DEBUG: ITER 7: time delta = 213333(ns) clock delta = 95737 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 8: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read restart: OA trigger collision / report lost
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a27a800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a27b800, exponent mask=fff
>(perf:1466) DEBUG: ITER 8: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 9: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a314800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ed01b, timestamp = 9a315800, exponent mask=fff
>(perf:1466) DEBUG: skipping OA reports pair due to GT frequency change according to sysfs
>(perf:1466) DEBUG: ITER 10: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a3c6800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a3c7800, exponent mask=fff
>(perf:1466) DEBUG: ITER 10: time delta = 213333(ns) clock delta = 95737 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 11: testing OA exponent 11 (period = 213333ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a475800, exponent mask=fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a476800, exponent mask=fff
>(perf:1466) DEBUG: ITER 11: time delta = 213333(ns) clock delta = 95733 freq = 448(mhz)
>(perf:1466) DEBUG: number of iterations with expected clock frequency = 10
>(perf:1466) DEBUG: ITER 0: testing OA exponent 12 (period = 426666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a527000, exponent mask=1fff
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a529000, exponent mask=1fff
>(perf:1466) DEBUG: ITER 0: time delta = 426666(ns) clock delta = 191480 freq = 448(mhz)
>(perf:1466) DEBUG: ITER 1: testing OA exponent 12 (period = 426666ns) with sysfs GT freq = 450mhz +- 45
>(perf:1466) DEBUG: read report: reason = 360ec01b, timestamp = 9a5d5000, exponent mask=1fff
>(perf:1466) DEBUG: read report: reason = 300ec018, timestamp = 9a5d709d, exponent mask=1fff
>(perf:1466) DEBUG: timestamp0 = 2589806592/0x9a5d5000
>(perf:1466) DEBUG: timestamp1 = 2589814941/0x9a5d709d
>(perf:1466) CRITICAL: Test assertion failure function test_oa_exponents, file perf.c:1482:
>(perf:1466) CRITICAL: Failed assertion: timestamp_delta == expected_timestamp_delta
>(perf:1466) CRITICAL: error: 8349 != 8192
>(perf:1466) igt-core-INFO: Stack trace:
>(perf:1466) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
>(perf:1466) igt-core-INFO:   #1 [test_oa_exponents+0x35d]
>(perf:1466) igt-core-INFO:   #2 [<unknown>+0x35d]
>****  END  ****
>Stack trace:
>  #0 [__igt_fail_assert+0x101]
>  #1 [test_oa_exponents+0x35d]
>  #2 [<unknown>+0x35d]
>Subtest oa-exponents: FAIL (3.069s)
>(perf:1466) DEBUG: restoring GT frequency range: min = 100mhz, max =800mhz, current: min=450mhz, max=450mhz
>(perf:1466) igt-core-DEBUG: Exiting with status code 99
>(perf:1466) igt-debugfs-DEBUG: Opening debugfs directory '/sys/kernel/debug/dri/0'

Actions: View

Attachments on bug 102480: 133882 | 133884 | 133885 | 134012 | 134377 | 134378

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.