On Thu, Oct 26, 2017 at 05:18:38PM -0300, Arnaldo Carvalho de Melo wrote:

Em Thu, Oct 26, 2017 at 11:21:07AM -0600, Michael Sartain escreveu:

quoted

We are doing some fairly simple ftrace captures using trace-cmd and we're
missing chunks of events. We are starting the trace via something like ~ this:

    trace-cmd record -i -k -b 2000 -o $startTrace__traceFile \
        -e "amdgpu:amdgpu_vm_flush" -e "amdgpu:amdgpu_cs_ioctl" \
        -e "amdgpu:amdgpu_sched_run_job" -e "drm:drm_vblank_event" \
        -e "*fence:*fence_signaled" -e "amdgpu:amdgpu_ttm_bo_move" \
        -e "sched:sched_switch" &

And then the capture is done with a kill -9 $(pidof trace-cmd)

Can you try with the equivalent 'perf record' (or perf trace) call?

[root@jouet ~]# perf record -m 16384 -e i915:intel_gpu_freq_change,drm:drm_vblank_event,fence*:*fence_signaled,sched:sched_switch^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 2.792 MB perf.data (2895 samples) ]

[root@jouet ~]#

It'll report lost events, replace the i915 with the amdgpu events.

Hi Arnaldo.

Sorry for the delay, got busy doing some other work and took a while to
narrow down a repro case that didn't involve running games and VR
compositors, etc.

I did the following on my Dell XPS i7-6560U laptop with Debian Test 4.13.4-2.

1. Ran: glxgears -fullscreen
2: Ran: sudo perf record -m 16384 -e sched:sched_switch -e sched:sched_process_fork -e sched:sched_process_exec
     -e sched:sched_process_exit -e drm:drm_vblank_event -e drm:drm_vblank_event_queued -e *fence:*fence_signaled
     -e i915:i915_flip_request -e i915:i915_flip_complete -e i915:intel_gpu_freq_change -e i915:i915_gem_request_add
     -e i915:intel_engine_notify -e i915:i915_gem_request_wait_begin -e i915:i915_gem_request_wait_end

  << ... waited ~30 seconds ... >>
^C
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 10.466 MB perf.data (85200 samples) ]

Everything worked as expected in this case. The below is a repro for ~ what
we're seeing with the loaded system.

1. Ran: glxgears -fullscreen
2: Ran: sudo perf record -m 16384 -e sched:sched_switch -e sched:sched_process_fork -e sched:sched_process_exec
     -e sched:sched_process_exit -e drm:drm_vblank_event -e drm:drm_vblank_event_queued -e *fence:*fence_signaled
     -e i915:i915_flip_request -e i915:i915_flip_complete -e i915:intel_gpu_freq_change -e i915:i915_gem_request_add
     -e i915:intel_engine_notify -e i915:i915_gem_request_wait_begin -e i915:i915_gem_request_wait_end
3. Ran: dd oflag=direct if=/home/mikesart/test.tmp of=/home/mikesart/test2.tmp bs=4k count=2000000 && sync
     where test.tmp is a ~7.7G file

  << ... waited ~30 seconds ... >>
^C
[ perf record: Woken up 4 times to write data ]
[ perf record: Captured and wrote 165.687 MB perf.data (1359800 samples) ]

For this case we wound up with a 165MB perf.data file. This is the same
behavior we're seeing with trace-cmd. No reported missing events or anything,
and a huge trace.dat file with missing chunks of events.

Thanks.
 -Mike