Attachment 131433 Details for Bug 100215 – ftrace

ftrace

file_100215.txt (text/plain), 84.32 KB, created by Maarten Lankhorst on 2017-05-22 12:29:26 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Maarten Lankhorst

Created: 2017-05-22 12:29:26 UTC

Size: 84.32 KB

patch

obsolete

># tracer: function
>#
># entries-in-buffer/entries-written: 38116/38116   #P:8
>#
>#                              _-----=> irqs-off
>#                             / _----=> need-resched
>#                            | / _---=> hardirq/softirq
>#                            || / _--=> preempt-depth
>#                            ||| /     delay
>#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
>#              | |       |   ||||       |         |
>
>igt_assert(gem_bo_busy(fd, fb->gem_handle));
> kms_cursor_lega-2222  [005] ....   461.647440: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [005] ....   461.647440: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [005] ....   461.647440: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [005] ....   461.647440: i915_gem_busy_ioctl <-drm_ioctl
>
>vblank_start = get_vblank(display->drm_fd, pipe, DRM_VBLANK_NEXTONMISS);
> kms_cursor_lega-2222  [005] ....   461.647440: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [005] ....   461.647440: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [005] ....   461.647440: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [005] ....   461.647441: drm_wait_vblank <-drm_ioctl
> kms_cursor_lega-2222  [005] ....   461.647441: drm_vblank_get <-drm_wait_vblank
> kms_cursor_lega-2222  [005] d..1   461.647441: drm_vblank_enable <-drm_vblank_get
> kms_cursor_lega-2222  [005] ....   461.647441: drm_printk <-drm_wait_vblank
>          <idle>-0     [004] d.h1   461.676607: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.676607: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676608: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676608: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676608: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676610: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676610: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676611: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676611: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676612: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676612: intel_pipe_handle_vblank <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676612: drm_handle_vblank <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h3   461.676612: drm_update_vblank_count <-drm_handle_vblank
>          <idle>-0     [004] d.h3   461.676612: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.676612: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.676613: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.676613: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.676613: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.676613: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] d.h3   461.676613: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.676614: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h4   461.676617: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] d.h3   461.676619: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.676619: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.676619: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.676619: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.676620: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.676621: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.676621: store_vblank <-drm_update_vblank_count
>          <idle>-0     [004] d.h2   461.676621: drm_vblank_count_and_time <-drm_handle_vblank
>          <idle>-0     [004] d.h1   461.676622: intel_finish_page_flip_mmio <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h1   461.676622: intel_check_page_flip <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676623: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676625: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676627: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676629: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.676631: gen6_read32 <-ironlake_irq_handler
> kms_cursor_lega-2222  [006] ....   461.716766: drm_vblank_count_and_time <-drm_wait_vblank
> kms_cursor_lega-2222  [006] ....   461.716767: drm_printk <-drm_wait_vblank
> kms_cursor_lega-2222  [006] ....   461.716767: drm_vblank_put <-drm_wait_vblank
>
>flip_nonblocking(display, pipe, mode >= flip_test_atomic, &fb_info);
> kms_cursor_lega-2222  [006] ....   461.716768: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [006] ....   461.716768: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716768: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716768: drm_is_current_master <-drm_ioctl_permit
> kms_cursor_lega-2222  [006] ....   461.716768: drm_mode_page_flip_ioctl <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716769: drm_mode_object_find <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716769: __drm_mode_object_find <-drm_mode_object_find
> kms_cursor_lega-2222  [006] ....   461.716769: drm_modeset_acquire_init <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716769: drm_modeset_lock <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716769: drm_modeset_lock <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716769: drm_framebuffer_lookup <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716770: __drm_mode_object_find <-drm_framebuffer_lookup
> kms_cursor_lega-2222  [006] ....   461.716770: drm_framebuffer_check_src_coords <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716770: drm_event_reserve_init <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716770: drm_atomic_helper_page_flip <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716770: drm_atomic_state_alloc <-drm_atomic_helper_page_flip
> kms_cursor_lega-2222  [006] ....   461.716770: intel_atomic_state_alloc <-drm_atomic_state_alloc
> kms_cursor_lega-2222  [006] ....   461.716771: drm_atomic_state_init <-intel_atomic_state_alloc
> kms_cursor_lega-2222  [006] ....   461.716771: drm_printk <-drm_atomic_state_init
> kms_cursor_lega-2222  [006] ....   461.716771: page_flip_common <-drm_atomic_helper_page_flip
> kms_cursor_lega-2222  [006] ....   461.716771: drm_atomic_get_crtc_state <-page_flip_common
> kms_cursor_lega-2222  [006] ....   461.716771: drm_modeset_lock <-drm_atomic_get_crtc_state
> kms_cursor_lega-2222  [006] ....   461.716771: intel_crtc_duplicate_state <-drm_atomic_get_crtc_state
> kms_cursor_lega-2222  [006] ....   461.716772: __drm_atomic_helper_crtc_duplicate_state <-intel_crtc_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716772: drm_property_blob_get <-__drm_atomic_helper_crtc_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716772: drm_mode_object_get <-drm_property_blob_get
> kms_cursor_lega-2222  [006] ....   461.716772: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716772: drm_property_blob_get <-__drm_atomic_helper_crtc_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716772: drm_mode_object_get <-drm_property_blob_get
> kms_cursor_lega-2222  [006] ....   461.716772: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716772: drm_printk <-drm_atomic_get_crtc_state
> kms_cursor_lega-2222  [006] ....   461.716772: drm_atomic_get_plane_state <-page_flip_common
> kms_cursor_lega-2222  [006] ....   461.716773: drm_modeset_lock <-drm_atomic_get_plane_state
> kms_cursor_lega-2222  [006] ....   461.716773: intel_plane_duplicate_state <-drm_atomic_get_plane_state
> kms_cursor_lega-2222  [006] ....   461.716773: __drm_atomic_helper_plane_duplicate_state <-intel_plane_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716773: drm_mode_object_get <-__drm_atomic_helper_plane_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716773: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716773: drm_printk <-drm_atomic_get_plane_state
> kms_cursor_lega-2222  [006] ....   461.716773: drm_atomic_get_crtc_state <-drm_atomic_get_plane_state
> kms_cursor_lega-2222  [006] ....   461.716773: drm_atomic_set_crtc_for_plane <-page_flip_common
> kms_cursor_lega-2222  [006] ....   461.716773: drm_atomic_get_crtc_state <-drm_atomic_set_crtc_for_plane
> kms_cursor_lega-2222  [006] ....   461.716773: drm_atomic_get_crtc_state <-drm_atomic_set_crtc_for_plane
> kms_cursor_lega-2222  [006] ....   461.716773: drm_printk <-drm_atomic_set_crtc_for_plane
> kms_cursor_lega-2222  [006] ....   461.716774: drm_atomic_set_fb_for_plane <-page_flip_common
> kms_cursor_lega-2222  [006] ....   461.716774: drm_printk <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716774: drm_mode_object_get <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716774: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716774: drm_mode_object_put <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716774: drm_printk <-drm_mode_object_put
> kms_cursor_lega-2222  [006] ....   461.716774: drm_atomic_nonblocking_commit <-drm_atomic_helper_page_flip
> kms_cursor_lega-2222  [006] ....   461.716775: drm_atomic_check_only <-drm_atomic_nonblocking_commit
> kms_cursor_lega-2222  [006] ....   461.716775: drm_printk <-drm_atomic_check_only
> kms_cursor_lega-2222  [006] ....   461.716775: drm_plane_check_pixel_format <-drm_atomic_check_only
> kms_cursor_lega-2222  [006] ....   461.716775: intel_atomic_check <-drm_atomic_check_only
> kms_cursor_lega-2222  [006] ....   461.716775: drm_atomic_helper_check_modeset <-intel_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716775: drm_mode_equal <-drm_atomic_helper_check_modeset
> kms_cursor_lega-2222  [006] ....   461.716775: drm_mode_equal_no_clocks_no_stereo <-drm_mode_equal
> kms_cursor_lega-2222  [006] ....   461.716776: handle_conflicting_encoders <-drm_atomic_helper_check_modeset
> kms_cursor_lega-2222  [006] ....   461.716776: drm_atomic_helper_check_planes <-intel_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716776: intel_plane_atomic_check <-drm_atomic_helper_check_planes
> kms_cursor_lega-2222  [006] ....   461.716776: intel_plane_atomic_check_with_state <-intel_plane_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716776: intel_check_primary_plane <-intel_plane_atomic_check_with_state
> kms_cursor_lega-2222  [006] ....   461.716776: drm_plane_helper_check_state <-intel_check_primary_plane
> kms_cursor_lega-2222  [006] ....   461.716777: drm_rect_rotate <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716777: drm_rect_calc_hscale <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716777: drm_rect_calc_vscale <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716777: drm_rect_clip_scaled <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716777: drm_rect_rotate_inv <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716777: i9xx_check_plane_surface <-intel_check_primary_plane
> kms_cursor_lega-2222  [006] ....   461.716777: intel_compute_tile_offset <-i9xx_check_plane_surface
> kms_cursor_lega-2222  [006] ....   461.716777: intel_surf_alignment <-intel_compute_tile_offset
> kms_cursor_lega-2222  [006] ....   461.716778: _intel_compute_tile_offset <-intel_compute_tile_offset
> kms_cursor_lega-2222  [006] ....   461.716778: intel_plane_atomic_calc_changes <-intel_plane_atomic_check_with_state
> kms_cursor_lega-2222  [006] ....   461.716778: drm_printk <-intel_plane_atomic_calc_changes
> kms_cursor_lega-2222  [006] ....   461.716778: drm_printk <-intel_plane_atomic_calc_changes
> kms_cursor_lega-2222  [006] ....   461.716778: intel_crtc_atomic_check <-drm_atomic_helper_check_planes
> kms_cursor_lega-2222  [006] ....   461.716778: ilk_compute_pipe_wm <-intel_crtc_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_compute_wm_level.isra.16 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_compute_fbc_wm <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_validate_pipe_wm <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_compute_wm_maximums <-ilk_validate_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_plane_wm_max <-ilk_compute_wm_maximums
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_plane_wm_max <-ilk_compute_wm_maximums
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_validate_wm_level.part.10 <-ilk_validate_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716779: ilk_compute_wm_level.isra.16 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716780: intel_wm_method2 <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_compute_fbc_wm <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_validate_wm_level.part.10 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_compute_wm_level.isra.16 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716780: intel_wm_method2 <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_compute_fbc_wm <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_validate_wm_level.part.10 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_compute_wm_level.isra.16 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716780: intel_wm_method2 <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_compute_fbc_wm <-ilk_compute_wm_level.isra.16
> kms_cursor_lega-2222  [006] ....   461.716780: ilk_validate_wm_level.part.10 <-ilk_compute_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_compute_intermediate_wm <-intel_crtc_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_validate_pipe_wm <-ilk_compute_intermediate_wm
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_compute_wm_maximums <-ilk_validate_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_plane_wm_max <-ilk_compute_wm_maximums
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_plane_wm_max <-ilk_compute_wm_maximums
> kms_cursor_lega-2222  [006] ....   461.716781: ilk_validate_wm_level.part.10 <-ilk_validate_pipe_wm
> kms_cursor_lega-2222  [006] ....   461.716781: intel_fbc_choose_crtc <-intel_atomic_check
> kms_cursor_lega-2222  [006] ....   461.716782: drm_printk <-drm_atomic_nonblocking_commit
> kms_cursor_lega-2222  [006] ....   461.716782: intel_atomic_commit <-drm_atomic_nonblocking_commit
> kms_cursor_lega-2222  [006] ....   461.716782: drm_atomic_helper_setup_commit <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716782: __i915_sw_fence_init <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716782: intel_crtc_has_pending_flip <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716782: drm_atomic_helper_prepare_planes <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716783: intel_prepare_plane_fb <-drm_atomic_helper_prepare_planes
> kms_cursor_lega-2222  [006] ....   461.716783: intel_pin_and_fence_fb_obj <-intel_prepare_plane_fb
> kms_cursor_lega-2222  [006] ....   461.716783: intel_surf_alignment <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716783: intel_runtime_pm_get <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716783: i915_gem_object_pin_to_display_plane <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716783: i915_gem_object_ggtt_pin <-i915_gem_object_pin_to_display_plane
> kms_cursor_lega-2222  [006] ....   461.716783: i915_vma_instance <-i915_gem_object_ggtt_pin
> kms_cursor_lega-2222  [006] ....   461.716784: i915_vma_misplaced <-i915_gem_object_ggtt_pin
> kms_cursor_lega-2222  [006] ....   461.716784: __i915_vma_do_pin <-i915_gem_object_ggtt_pin
> kms_cursor_lega-2222  [006] ....   461.716784: i915_vma_bind <-__i915_vma_do_pin
> kms_cursor_lega-2222  [006] ....   461.716784: __intel_fb_obj_flush <-i915_gem_object_pin_to_display_plane
> kms_cursor_lega-2222  [006] ....   461.716784: intel_frontbuffer_flush <-__intel_fb_obj_flush
> kms_cursor_lega-2222  [006] ....   461.716784: i915_vma_get_fence <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716784: intel_runtime_pm_put <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716785: i915_sw_fence_await_reservation <-intel_prepare_plane_fb
> kms_cursor_lega-2222  [006] ....   461.716785: i915_sw_fence_await_dma_fence <-i915_sw_fence_await_reservation
> kms_cursor_lega-2222  [006] ....   461.716785: i915_fence_signaled <-i915_sw_fence_await_dma_fence
> kms_cursor_lega-2222  [006] ....   461.716785: i915_sw_fence_await <-i915_sw_fence_await_dma_fence
> kms_cursor_lega-2222  [006] d..1   461.716785: i915_fence_enable_signaling <-dma_fence_add_callback
> kms_cursor_lega-2222  [006] d..1   461.716786: intel_engine_enable_signaling <-i915_fence_enable_signaling
> kms_cursor_lega-2222  [006] d..2   461.716786: __intel_engine_add_wait <-intel_engine_enable_signaling
> kms_cursor_lega-2222  [006] ....   461.716787: i915_gem_object_wait_priority <-intel_prepare_plane_fb
> kms_cursor_lega-2222  [006] ....   461.716787: fence_set_priority <-i915_gem_object_wait_priority
> kms_cursor_lega-2222  [006] ....   461.716788: drm_atomic_helper_swap_state <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716788: intel_shared_dpll_swap_state <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716788: i915_gem_track_fb <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716788: i915_sw_fence_commit <-intel_atomic_commit
> kms_cursor_lega-2222  [006] ....   461.716788: i915_sw_fence_complete <-i915_sw_fence_commit
> kms_cursor_lega-2222  [006] ....   461.716788: __i915_sw_fence_complete <-i915_sw_fence_complete
> kms_cursor_lega-2222  [006] ....   461.716789: drm_mode_object_put <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716789: drm_printk <-drm_mode_object_put
> kms_cursor_lega-2222  [006] ....   461.716789: drm_modeset_drop_locks <-drm_mode_page_flip_ioctl
> kms_cursor_lega-2222  [006] ....   461.716789: drm_modeset_acquire_fini <-drm_mode_page_flip_ioctl
>
>delta = get_vblank(display->drm_fd, pipe, 0) - vblank_start;
> kms_cursor_lega-2222  [006] ....   461.716789: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [006] ....   461.716789: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716789: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_wait_vblank <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_vblank_count_and_time <-drm_wait_vblank
>
>do_ioctl(display->drm_fd, DRM_IOCTL_MODE_CURSOR, &arg[0]);
> kms_cursor_lega-2222  [006] ....   461.716790: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_is_current_master <-drm_ioctl_permit
> kms_cursor_lega-2222  [006] ....   461.716790: drm_mode_cursor_ioctl <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716790: drm_mode_cursor_common <-drm_mode_cursor_ioctl
> kms_cursor_lega-2222  [006] ....   461.716791: drm_mode_object_find <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716791: __drm_mode_object_find <-drm_mode_object_find
> kms_cursor_lega-2222  [006] ....   461.716791: drm_modeset_acquire_init <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716791: drm_modeset_lock <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716791: drm_modeset_lock <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716791: drm_mode_cursor_universal <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716791: drm_mode_object_get <-drm_mode_cursor_universal
> kms_cursor_lega-2222  [006] ....   461.716791: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716791: __setplane_internal <-drm_mode_cursor_universal
> kms_cursor_lega-2222  [006] ....   461.716792: drm_framebuffer_check_src_coords <-__setplane_internal
> kms_cursor_lega-2222  [006] ....   461.716792: intel_legacy_cursor_update <-__setplane_internal
> kms_cursor_lega-2222  [006] ....   461.716792: intel_plane_duplicate_state <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716792: __drm_atomic_helper_plane_duplicate_state <-intel_plane_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716792: drm_mode_object_get <-__drm_atomic_helper_plane_duplicate_state
> kms_cursor_lega-2222  [006] ....   461.716792: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716792: drm_atomic_set_fb_for_plane <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716792: drm_printk <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716792: drm_mode_object_get <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716792: drm_printk <-drm_mode_object_get
> kms_cursor_lega-2222  [006] ....   461.716792: drm_mode_object_put <-drm_atomic_set_fb_for_plane
> kms_cursor_lega-2222  [006] ....   461.716793: drm_printk <-drm_mode_object_put
> kms_cursor_lega-2222  [006] ....   461.716793: intel_plane_atomic_check_with_state <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716793: i9xx_check_cursor <-intel_plane_atomic_check_with_state
> kms_cursor_lega-2222  [006] ....   461.716793: intel_check_cursor.isra.85 <-i9xx_check_cursor
> kms_cursor_lega-2222  [006] ....   461.716793: drm_plane_helper_check_state <-intel_check_cursor.isra.85
> kms_cursor_lega-2222  [006] ....   461.716793: drm_rect_rotate <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716793: drm_rect_calc_hscale <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716793: drm_rect_calc_vscale <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716793: drm_rect_clip_scaled <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716793: drm_rect_rotate_inv <-drm_plane_helper_check_state
> kms_cursor_lega-2222  [006] ....   461.716793: intel_compute_tile_offset <-intel_check_cursor.isra.85
> kms_cursor_lega-2222  [006] ....   461.716794: _intel_compute_tile_offset <-intel_compute_tile_offset
> kms_cursor_lega-2222  [006] ....   461.716794: intel_plane_atomic_calc_changes <-intel_plane_atomic_check_with_state
> kms_cursor_lega-2222  [006] ....   461.716794: drm_printk <-intel_plane_atomic_calc_changes
> kms_cursor_lega-2222  [006] ....   461.716794: drm_printk <-intel_plane_atomic_calc_changes
> kms_cursor_lega-2222  [006] ....   461.716794: intel_pin_and_fence_fb_obj <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716794: intel_surf_alignment <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716794: intel_runtime_pm_get <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716794: i915_gem_object_pin_to_display_plane <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716795: i915_gem_object_ggtt_pin <-i915_gem_object_pin_to_display_plane
> kms_cursor_lega-2222  [006] ....   461.716795: i915_vma_instance <-i915_gem_object_ggtt_pin
> kms_cursor_lega-2222  [006] ....   461.716795: i915_vma_misplaced <-i915_gem_object_ggtt_pin
> kms_cursor_lega-2222  [006] ....   461.716795: __intel_fb_obj_flush <-i915_gem_object_pin_to_display_plane
> kms_cursor_lega-2222  [006] ....   461.716795: intel_frontbuffer_flush <-__intel_fb_obj_flush
> kms_cursor_lega-2222  [006] ....   461.716795: intel_edp_drrs_flush <-intel_frontbuffer_flush
> kms_cursor_lega-2222  [006] ....   461.716795: intel_psr_flush <-intel_frontbuffer_flush
> kms_cursor_lega-2222  [006] ....   461.716795: intel_fbc_flush <-intel_frontbuffer_flush
> kms_cursor_lega-2222  [006] ....   461.716795: i915_vma_get_fence <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716796: intel_runtime_pm_put <-intel_pin_and_fence_fb_obj
> kms_cursor_lega-2222  [006] ....   461.716796: i915_gem_track_fb <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716796: i9xx_update_cursor <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716796: intel_cursor_base <-i9xx_update_cursor
> kms_cursor_lega-2222  [006] ....   461.716796: intel_unpin_fb_vma <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716796: i915_gem_object_unpin_from_display_plane <-intel_unpin_fb_vma
> kms_cursor_lega-2222  [006] ....   461.716796: i915_gem_object_bump_inactive_ggtt <-i915_gem_object_unpin_from_display_plane
> kms_cursor_lega-2222  [006] ....   461.716797: intel_plane_destroy_state <-intel_legacy_cursor_update
> kms_cursor_lega-2222  [006] ....   461.716797: drm_atomic_helper_plane_destroy_state <-intel_plane_destroy_state
> kms_cursor_lega-2222  [006] ....   461.716797: __drm_atomic_helper_plane_destroy_state <-drm_atomic_helper_plane_destroy_state
> kms_cursor_lega-2222  [006] ....   461.716797: drm_mode_object_put <-__drm_atomic_helper_plane_destroy_state
> kms_cursor_lega-2222  [006] ....   461.716797: drm_printk <-drm_mode_object_put
> kms_cursor_lega-2222  [006] ....   461.716797: drm_mode_object_put <-__setplane_internal
> kms_cursor_lega-2222  [006] ....   461.716797: drm_printk <-drm_mode_object_put
> kms_cursor_lega-2222  [006] ....   461.716797: drm_modeset_drop_locks <-drm_mode_cursor_common
> kms_cursor_lega-2222  [006] ....   461.716798: drm_modeset_acquire_fini <-drm_mode_cursor_common
>
>delta = get_vblank(display->drm_fd, pipe, 0) - vblank_start;
> kms_cursor_lega-2222  [006] ....   461.716798: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [006] ....   461.716798: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716798: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716798: drm_wait_vblank <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.716798: drm_vblank_count_and_time <-drm_wait_vblank
>
>igt_assert(poll(&pfd, 1, 0) == 0);
> kms_cursor_lega-2222  [006] ....   461.716799: drm_poll <-do_sys_poll
>
>finish_fb_busy(busy); /* end + munmap */
>
>read(display->drm_fd, &vbl, sizeof(vbl));
> kms_cursor_lega-2222  [006] ....   461.716813: drm_read <-__vfs_read
>          <idle>-0     [004] d.h1   461.716837: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.716837: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716838: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716838: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716838: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716839: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716840: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716841: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716841: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716841: snb_gt_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716841: notify_ring <-snb_gt_irq_handler
>   i915/signal:0-485   [007] d..1   461.716841: dma_i915_sw_fence_wake <-dma_fence_signal
>   i915/signal:0-485   [007] d..1   461.716842: i915_sw_fence_complete <-dma_i915_sw_fence_wake
>   i915/signal:0-485   [007] d..1   461.716842: __i915_sw_fence_complete <-i915_sw_fence_complete
>          <idle>-0     [004] d.h1   461.716842: gen6_read32 <-ironlake_irq_handler
>   i915/signal:0-485   [007] d..1   461.716842: intel_atomic_commit_ready <-__i915_sw_fence_complete
>          <idle>-0     [004] d.h1   461.716842: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716842: intel_pipe_handle_vblank <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.716843: drm_handle_vblank <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h3   461.716843: drm_update_vblank_count <-drm_handle_vblank
>          <idle>-0     [004] d.h3   461.716843: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.716843: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.716843: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.716843: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.716843: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.716844: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] d.h3   461.716844: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.716844: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h4   461.716844: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] dnh3   461.716845: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>   i915/signal:0-485   [007] d..1   461.716845: intel_atomic_commit_ready <-__i915_sw_fence_complete
>          <idle>-0     [004] dnh3   461.716854: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] dnh3   461.716855: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716855: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716855: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] dnh3   461.716855: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] dnh3   461.716855: store_vblank <-drm_update_vblank_count
>          <idle>-0     [004] dnh2   461.716855: drm_vblank_count_and_time <-drm_handle_vblank
>          <idle>-0     [004] dnh1   461.716855: vblank_disable_fn <-drm_handle_vblank
>          <idle>-0     [004] dnh2   461.716856: drm_printk <-vblank_disable_fn
>          <idle>-0     [004] dnh2   461.716856: vblank_disable_and_save <-vblank_disable_fn
>          <idle>-0     [004] dnh3   461.716856: drm_crtc_from_index <-vblank_disable_and_save
>          <idle>-0     [004] dnh3   461.716856: ironlake_disable_vblank <-vblank_disable_and_save
>          <idle>-0     [004] dnh4   461.716856: ilk_update_display_irq <-ironlake_disable_vblank
>          <idle>-0     [004] dnh4   461.716856: gen6_write32 <-ilk_update_display_irq
>   i915/signal:0-485   [007] d..1   461.716856: __intel_engine_remove_wait <-intel_breadcrumbs_signaler
>          <idle>-0     [004] dnh4   461.716856: gen6_read32 <-ilk_update_display_irq
>          <idle>-0     [004] dnh3   461.716856: drm_update_vblank_count <-vblank_disable_and_save
>          <idle>-0     [004] dnh3   461.716856: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] dnh3   461.716857: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716857: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716857: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] dnh3   461.716857: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] dnh3   461.716857: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] dnh3   461.716857: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] dnh3   461.716857: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] dnh4   461.716857: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] dnh3   461.716857: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] dnh3   461.716858: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] dnh3   461.716858: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716868: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] dnh3   461.716868: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] dnh3   461.716868: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] dnh1   461.716868: intel_finish_page_flip_mmio <-intel_pipe_handle_vblank
>          <idle>-0     [004] dnh1   461.716868: intel_check_page_flip <-ironlake_irq_handler
>          <idle>-0     [004] dnh1   461.716868: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dnh1   461.716869: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dnh1   461.716869: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dnh1   461.716869: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dnh1   461.716870: gen6_read32 <-ironlake_irq_handler
>     kworker/7:1-126   [007] ....   461.716871: intel_atomic_helper_free_state_worker <-process_one_work
>     kworker/7:1-126   [007] ....   461.716871: intel_atomic_helper_free_state <-intel_atomic_helper_free_state_worker
>          <idle>-0     [004] dNh1   461.716872: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] dNh1   461.716872: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716872: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716872: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716872: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716874: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716874: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716875: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716875: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716875: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716875: intel_pipe_handle_vblank <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716875: drm_handle_vblank <-intel_pipe_handle_vblank
>          <idle>-0     [004] dNh1   461.716876: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716876: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716876: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716876: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.716877: gen6_read32 <-ironlake_irq_handler
>   kworker/u16:2-141   [004] ....   461.716882: intel_atomic_commit_work <-process_one_work
>   kworker/u16:2-141   [004] ....   461.716882: intel_atomic_commit_tail <-intel_atomic_commit_work
>   kworker/u16:2-141   [004] ....   461.716882: drm_atomic_helper_wait_for_dependencies <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716882: intel_update_crtcs <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716882: intel_update_crtc <-intel_update_crtcs
>   kworker/u16:2-141   [004] ....   461.716883: intel_pre_plane_update <-intel_update_crtc
>   kworker/u16:2-141   [004] ....   461.716883: intel_fbc_pre_update <-intel_pre_plane_update
>   kworker/u16:2-141   [004] ....   461.716883: ilk_initial_watermarks <-intel_pre_plane_update
>   kworker/u16:2-141   [004] ....   461.716883: ilk_program_watermarks <-ilk_initial_watermarks
>   kworker/u16:2-141   [004] ....   461.716883: ilk_compute_wm_maximums <-ilk_program_watermarks
>   kworker/u16:2-141   [004] ....   461.716883: ilk_plane_wm_max <-ilk_compute_wm_maximums
>   kworker/u16:2-141   [004] ....   461.716883: ilk_plane_wm_max <-ilk_compute_wm_maximums
>   kworker/u16:2-141   [004] ....   461.716884: ilk_wm_merge <-ilk_program_watermarks
>   kworker/u16:2-141   [004] ....   461.716884: ilk_validate_wm_level.part.10 <-ilk_wm_merge
>   kworker/u16:2-141   [004] ....   461.716884: ilk_validate_wm_level.part.10 <-ilk_wm_merge
>   kworker/u16:2-141   [004] ....   461.716884: ilk_validate_wm_level.part.10 <-ilk_wm_merge
>   kworker/u16:2-141   [004] ....   461.716884: intel_fbc_enable <-intel_update_crtc
>   kworker/u16:2-141   [004] ....   461.716884: drm_atomic_helper_commit_planes_on_crtc <-intel_update_crtc
>   kworker/u16:2-141   [004] ....   461.716885: intel_begin_crtc_commit <-drm_atomic_helper_commit_planes_on_crtc
>   kworker/u16:2-141   [004] ....   461.716885: intel_pipe_update_start <-intel_begin_crtc_commit
>   kworker/u16:2-141   [004] d...   461.716885: drm_crtc_vblank_get <-intel_pipe_update_start
>   kworker/u16:2-141   [004] d...   461.716885: drm_vblank_get <-drm_crtc_vblank_get
>   kworker/u16:2-141   [004] d..1   461.716885: drm_vblank_enable <-drm_vblank_get
>   kworker/u16:2-141   [004] d..2   461.716885: drm_crtc_from_index <-drm_vblank_enable
>   kworker/u16:2-141   [004] d..2   461.716885: ironlake_enable_vblank <-drm_vblank_enable
>   kworker/u16:2-141   [004] d..3   461.716885: ilk_update_display_irq <-ironlake_enable_vblank
>   kworker/u16:2-141   [004] d..3   461.716885: gen6_write32 <-ilk_update_display_irq
>   kworker/u16:2-141   [004] d..3   461.716886: gen6_read32 <-ilk_update_display_irq
>   kworker/u16:2-141   [004] d..2   461.716886: drm_printk <-drm_vblank_enable
>   kworker/u16:2-141   [004] d..2   461.716886: drm_update_vblank_count <-drm_vblank_enable
>   kworker/u16:2-141   [004] d..2   461.716886: __get_vblank_counter <-drm_update_vblank_count
>   kworker/u16:2-141   [004] d..2   461.716886: drm_crtc_from_index <-__get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716886: g4x_get_vblank_counter <-__get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716886: gen6_read32 <-g4x_get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716886: drm_get_last_vbltimestamp <-drm_update_vblank_count
>   kworker/u16:2-141   [004] d..2   461.716886: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>   kworker/u16:2-141   [004] d..2   461.716886: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>   kworker/u16:2-141   [004] d..2   461.716887: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>   kworker/u16:2-141   [004] d..3   461.716887: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>   kworker/u16:2-141   [004] d..2   461.716887: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>   kworker/u16:2-141   [004] d..2   461.716887: __get_vblank_counter <-drm_update_vblank_count
>   kworker/u16:2-141   [004] d..2   461.716887: drm_crtc_from_index <-__get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716887: g4x_get_vblank_counter <-__get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716887: gen6_read32 <-g4x_get_vblank_counter
>   kworker/u16:2-141   [004] d..2   461.716887: drm_printk <-drm_update_vblank_count
>   kworker/u16:2-141   [004] d...   461.716888: intel_get_crtc_scanline <-intel_pipe_update_start
>   kworker/u16:2-141   [004] d..1   461.716897: __intel_get_crtc_scanline <-intel_get_crtc_scanline
>   kworker/u16:2-141   [004] d...   461.716897: drm_crtc_vblank_put <-intel_pipe_update_start
>   kworker/u16:2-141   [004] d...   461.716898: drm_vblank_put <-drm_crtc_vblank_put
>   kworker/u16:2-141   [004] d...   461.716898: intel_crtc_get_vblank_counter <-intel_pipe_update_start
>   kworker/u16:2-141   [004] d...   461.716898: g4x_get_vblank_counter <-intel_crtc_get_vblank_counter
>   kworker/u16:2-141   [004] d...   461.716898: gen6_read32 <-g4x_get_vblank_counter
>   kworker/u16:2-141   [004] d...   461.716898: intel_plane_atomic_update <-drm_atomic_helper_commit_planes_on_crtc
>   kworker/u16:2-141   [004] d...   461.716898: i9xx_update_primary_plane <-intel_plane_atomic_update
>   kworker/u16:2-141   [004] d...   461.716899: intel_finish_crtc_commit <-drm_atomic_helper_commit_planes_on_crtc
>   kworker/u16:2-141   [004] d...   461.716899: intel_pipe_update_end <-intel_finish_crtc_commit
>   kworker/u16:2-141   [004] d...   461.716899: intel_get_crtc_scanline <-intel_pipe_update_end
>   kworker/u16:2-141   [004] d..1   461.716899: __intel_get_crtc_scanline <-intel_get_crtc_scanline
>   kworker/u16:2-141   [004] d...   461.716899: intel_crtc_get_vblank_counter <-intel_pipe_update_end
>   kworker/u16:2-141   [004] d...   461.716899: g4x_get_vblank_counter <-intel_crtc_get_vblank_counter
>   kworker/u16:2-141   [004] d...   461.716899: gen6_read32 <-g4x_get_vblank_counter
>   kworker/u16:2-141   [004] d...   461.716900: drm_crtc_vblank_get <-intel_pipe_update_end
>   kworker/u16:2-141   [004] d...   461.716900: drm_vblank_get <-drm_crtc_vblank_get
>   kworker/u16:2-141   [004] d..1   461.716900: drm_vblank_enable <-drm_vblank_get
>   kworker/u16:2-141   [004] d..1   461.716900: drm_crtc_arm_vblank_event <-intel_pipe_update_end
>   kworker/u16:2-141   [004] ....   461.716900: ilk_optimize_watermarks <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716900: intel_frontbuffer_flip <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716900: intel_frontbuffer_flush <-intel_frontbuffer_flip
>   kworker/u16:2-141   [004] ....   461.716901: intel_edp_drrs_flush <-intel_frontbuffer_flush
>   kworker/u16:2-141   [004] ....   461.716901: intel_psr_flush <-intel_frontbuffer_flush
>   kworker/u16:2-141   [004] ....   461.716901: intel_fbc_flush <-intel_frontbuffer_flush
>   kworker/u16:2-141   [004] ....   461.716901: intel_fbc_post_update <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716901: __intel_fbc_post_update <-intel_fbc_post_update
>   kworker/u16:2-141   [004] ....   461.716901: drm_atomic_helper_commit_hw_done <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716902: drm_atomic_helper_cleanup_planes <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.716902: intel_cleanup_plane_fb <-drm_atomic_helper_cleanup_planes
>   kworker/u16:2-141   [004] ....   461.716902: intel_unpin_fb_vma <-intel_cleanup_plane_fb
>   kworker/u16:2-141   [004] ....   461.716902: i915_gem_object_unpin_from_display_plane <-intel_unpin_fb_vma
>   kworker/u16:2-141   [004] ....   461.716902: i915_gem_object_bump_inactive_ggtt <-i915_gem_object_unpin_from_display_plane
>   kworker/u16:2-141   [004] ....   461.716902: drm_atomic_helper_commit_cleanup_done <-intel_atomic_commit_tail
>          <idle>-0     [005] ..s1   461.724184: __i915_gem_free_object_rcu <-rcu_process_callbacks
>     kworker/5:1-125   [005] ....   461.724189: __i915_gem_free_work <-process_one_work
>     kworker/5:1-125   [005] ....   461.724189: __i915_gem_free_objects <-__i915_gem_free_work
>     kworker/5:1-125   [005] ....   461.724189: intel_runtime_pm_get <-__i915_gem_free_objects
>     kworker/5:1-125   [005] ....   461.724190: i915_vma_close <-__i915_gem_free_objects
>     kworker/5:1-125   [005] ....   461.724190: i915_vma_unbind <-i915_vma_close
>     kworker/5:1-125   [005] ....   461.724190: aliasing_gtt_unbind_vma <-i915_vma_unbind
>     kworker/5:1-125   [005] ....   461.724190: gen6_ppgtt_clear_range <-aliasing_gtt_unbind_vma
>     kworker/5:1-125   [005] ....   461.724190: snb_pte_encode <-gen6_ppgtt_clear_range
>     kworker/5:1-125   [005] ....   461.724190: i915_vma_remove <-i915_vma_unbind
>     kworker/5:1-125   [005] ....   461.724190: drm_mm_remove_node <-i915_vma_remove
>     kworker/5:1-125   [005] ....   461.724191: rm_hole <-drm_mm_remove_node
>     kworker/5:1-125   [005] ....   461.724191: add_hole <-drm_mm_remove_node
>     kworker/5:1-125   [005] ....   461.724191: i915_vma_destroy <-i915_vma_unbind
>     kworker/5:1-125   [005] ....   461.724191: intel_runtime_pm_put <-__i915_gem_free_objects
>     kworker/5:1-125   [005] ....   461.724191: __i915_gem_object_put_pages.part.17 <-__i915_gem_free_objects
>     kworker/5:1-125   [005] ....   461.724191: i915_gem_object_put_pages_gtt <-__i915_gem_object_put_pages.part.17
>     kworker/5:1-125   [005] ....   461.724192: __i915_gem_object_release_shmem <-i915_gem_object_put_pages_gtt
>     kworker/5:1-125   [005] ....   461.724192: i915_gem_gtt_finish_pages <-i915_gem_object_put_pages_gtt
>     kworker/5:1-125   [005] ....   461.724192: i915_fence_release <-dma_fence_release
>     kworker/5:1-125   [005] ....   461.724192: drm_gem_object_release <-__i915_gem_free_objects
>     kworker/5:1-125   [005] ....   461.724193: drm_vma_offset_remove <-drm_gem_object_release
>          <idle>-0     [004] d.h1   461.730506: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.730506: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730507: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730507: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730507: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730508: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730509: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730509: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730510: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730511: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730511: intel_pipe_handle_vblank <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.730511: drm_handle_vblank <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h3   461.730511: drm_update_vblank_count <-drm_handle_vblank
>          <idle>-0     [004] d.h3   461.730511: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.730511: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.730512: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.730512: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.730512: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.730512: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] d.h3   461.730512: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.730512: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h4   461.730512: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] d.h3   461.730513: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.730513: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.730513: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.730513: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.730513: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.730513: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.730513: store_vblank <-drm_update_vblank_count
>          <idle>-0     [004] d.h2   461.730514: drm_vblank_count_and_time <-drm_handle_vblank
>          <idle>-0     [004] d.h2   461.730514: drm_printk <-drm_handle_vblank
>          <idle>-0     [004] d.h2   461.730514: drm_vblank_put <-drm_handle_vblank
>          <idle>-0     [004] d.h2   461.730514: send_vblank_event <-drm_handle_vblank
>          <idle>-0     [004] d.h2   461.730514: drm_send_event_locked <-send_vblank_event
>          <idle>-0     [004] dNh2   461.730517: release_crtc_commit <-drm_send_event_locked
>          <idle>-0     [004] dNh1   461.730518: intel_finish_page_flip_mmio <-intel_pipe_handle_vblank
>          <idle>-0     [004] dNh1   461.730518: intel_check_page_flip <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730518: intel_finish_page_flip_cs <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730518: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730519: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730519: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730519: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.730520: gen6_read32 <-ironlake_irq_handler
>   kworker/u16:2-141   [004] ....   461.730525: __drm_atomic_state_free <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.730525: drm_atomic_state_clear <-__drm_atomic_state_free
>   kworker/u16:2-141   [004] ....   461.730525: intel_atomic_state_clear <-drm_atomic_state_clear
>   kworker/u16:2-141   [004] ....   461.730525: drm_atomic_state_default_clear <-intel_atomic_state_clear
>   kworker/u16:2-141   [004] ....   461.730525: drm_printk <-drm_atomic_state_default_clear
>   kworker/u16:2-141   [004] ....   461.730525: intel_crtc_destroy_state <-drm_atomic_state_default_clear
>   kworker/u16:2-141   [004] ....   461.730525: drm_atomic_helper_crtc_destroy_state <-intel_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: __drm_atomic_helper_crtc_destroy_state <-drm_atomic_helper_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: drm_property_blob_put <-__drm_atomic_helper_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: drm_mode_object_put <-drm_property_blob_put
>   kworker/u16:2-141   [004] ....   461.730526: drm_printk <-drm_mode_object_put
>   kworker/u16:2-141   [004] ....   461.730526: drm_property_blob_put <-__drm_atomic_helper_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: drm_property_blob_put <-__drm_atomic_helper_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: drm_property_blob_put <-__drm_atomic_helper_crtc_destroy_state
>   kworker/u16:2-141   [004] ....   461.730526: drm_mode_object_put <-drm_property_blob_put
>   kworker/u16:2-141   [004] ....   461.730526: drm_printk <-drm_mode_object_put
>   kworker/u16:2-141   [004] ....   461.730527: intel_plane_destroy_state <-drm_atomic_state_default_clear
>   kworker/u16:2-141   [004] ....   461.730527: drm_atomic_helper_plane_destroy_state <-intel_plane_destroy_state
>   kworker/u16:2-141   [004] ....   461.730527: __drm_atomic_helper_plane_destroy_state <-drm_atomic_helper_plane_destroy_state
>   kworker/u16:2-141   [004] ....   461.730527: drm_mode_object_put <-__drm_atomic_helper_plane_destroy_state
>   kworker/u16:2-141   [004] ....   461.730527: drm_printk <-drm_mode_object_put
>   kworker/u16:2-141   [004] ....   461.730527: drm_printk <-__drm_atomic_state_free
>   kworker/u16:2-141   [004] ....   461.730527: intel_atomic_state_free <-__drm_atomic_state_free
>   kworker/u16:2-141   [004] ....   461.730527: drm_atomic_state_default_release <-intel_atomic_state_free
>   kworker/u16:2-141   [004] ....   461.730528: intel_uncore_arm_unclaimed_mmio_detection <-intel_atomic_commit_tail
>   kworker/u16:2-141   [004] ....   461.730528: check_for_unclaimed_mmio <-intel_uncore_arm_unclaimed_mmio_detection
>   kworker/u16:2-141   [004] ....   461.730528: intel_atomic_helper_free_state <-intel_atomic_commit_tail
>
>delta = get_vblank(display->drm_fd, pipe, 0) - vblank_start;
> kms_cursor_lega-2222  [006] ....   461.730561: drm_ioctl <-do_vfs_ioctl
> kms_cursor_lega-2222  [006] ....   461.730562: drm_printk <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.730562: drm_ioctl_permit <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.730562: drm_wait_vblank <-drm_ioctl
> kms_cursor_lega-2222  [006] ....   461.730563: drm_vblank_count_and_time <-drm_wait_vblank
>
># The end..
>          <idle>-0     [004] d.h1   461.747139: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.747140: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747141: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747141: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747141: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747142: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747143: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747144: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747144: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747144: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747144: intel_pipe_handle_vblank <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747144: drm_handle_vblank <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h3   461.747145: drm_update_vblank_count <-drm_handle_vblank
>          <idle>-0     [004] d.h3   461.747145: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747145: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747145: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747145: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.747146: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747146: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] d.h3   461.747146: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.747146: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h4   461.747146: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] d.h3   461.747147: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.747147: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747147: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747147: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747147: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.747147: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747147: store_vblank <-drm_update_vblank_count
>          <idle>-0     [004] d.h2   461.747148: drm_vblank_count_and_time <-drm_handle_vblank
>          <idle>-0     [004] d.h1   461.747148: vblank_disable_fn <-drm_handle_vblank
>          <idle>-0     [004] d.h2   461.747148: drm_printk <-vblank_disable_fn
>          <idle>-0     [004] d.h2   461.747148: vblank_disable_and_save <-vblank_disable_fn
>          <idle>-0     [004] d.h3   461.747148: drm_crtc_from_index <-vblank_disable_and_save
>          <idle>-0     [004] d.h3   461.747148: ironlake_disable_vblank <-vblank_disable_and_save
>          <idle>-0     [004] d.h4   461.747148: ilk_update_display_irq <-ironlake_disable_vblank
>          <idle>-0     [004] d.h4   461.747149: gen6_write32 <-ilk_update_display_irq
>          <idle>-0     [004] d.h4   461.747149: gen6_read32 <-ilk_update_display_irq
>          <idle>-0     [004] d.h3   461.747149: drm_update_vblank_count <-vblank_disable_and_save
>          <idle>-0     [004] d.h3   461.747149: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747149: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747149: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747149: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.747149: drm_get_last_vbltimestamp <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747150: drm_calc_vbltimestamp_from_scanoutpos <-drm_get_last_vbltimestamp
>          <idle>-0     [004] d.h3   461.747150: drm_crtc_from_index <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.747150: i915_get_crtc_scanoutpos <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h4   461.747150: __intel_get_crtc_scanline <-i915_get_crtc_scanoutpos
>          <idle>-0     [004] d.h3   461.747150: drm_printk <-drm_calc_vbltimestamp_from_scanoutpos
>          <idle>-0     [004] d.h3   461.747150: __get_vblank_counter <-drm_update_vblank_count
>          <idle>-0     [004] d.h3   461.747150: drm_crtc_from_index <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747150: g4x_get_vblank_counter <-__get_vblank_counter
>          <idle>-0     [004] d.h3   461.747150: gen6_read32 <-g4x_get_vblank_counter
>          <idle>-0     [004] d.h3   461.747150: drm_printk <-drm_update_vblank_count
>          <idle>-0     [004] d.h1   461.747151: intel_finish_page_flip_mmio <-intel_pipe_handle_vblank
>          <idle>-0     [004] d.h1   461.747151: intel_check_page_flip <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747151: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747151: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747151: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747152: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.747153: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753024: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.753024: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753025: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753025: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753025: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753026: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753027: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753027: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753028: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753028: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753028: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.753028: gen6_rps_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h2   461.753028: gen6_mask_pm_irq <-gen6_rps_irq_handler
>          <idle>-0     [004] d.h2   461.753028: snb_update_pm_irq <-gen6_mask_pm_irq
>          <idle>-0     [004] d.h2   461.753028: gen6_write32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h2   461.753029: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] dNh1   461.753031: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.753031: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.753031: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.753033: gen6_read32 <-ironlake_irq_handler
>     kworker/4:3-1575  [004] ....   461.753037: gen6_pm_rps_work <-process_one_work
>     kworker/4:3-1575  [004] ....   461.753037: intel_set_rps <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] ....   461.753038: intel_set_rps.part.24 <-intel_set_rps
>     kworker/4:3-1575  [004] ....   461.753038: gen6_set_rps <-intel_set_rps.part.24
>     kworker/4:3-1575  [004] ....   461.753038: gen6_set_rps_thresholds <-gen6_set_rps
>     kworker/4:3-1575  [004] ....   461.753039: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.753039: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.753039: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.753039: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.753039: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.753039: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.753040: intel_gpu_freq <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.753040: gen6_unmask_pm_irq <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] d..1   461.753040: snb_update_pm_irq <-gen6_unmask_pm_irq
>     kworker/4:3-1575  [004] d..1   461.753040: gen6_write32 <-snb_update_pm_irq
>     kworker/4:3-1575  [004] d..1   461.753040: gen6_read32 <-snb_update_pm_irq
>   kworker/u16:0-2183  [005] ....   461.755189: i915_gem_idle_work_handler <-process_one_work
>   kworker/u16:0-2183  [005] ....   461.755189: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.756825: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.758834: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.760842: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.762850: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.764859: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.766867: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   461.768876: intel_engines_are_idle <-i915_gem_idle_work_handler
>          <idle>-0     [004] d.h1   461.785108: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.785109: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785109: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785109: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785109: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785110: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785111: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785112: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785112: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785112: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785112: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.785112: gen6_rps_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h2   461.785112: gen6_mask_pm_irq <-gen6_rps_irq_handler
>          <idle>-0     [004] d.h2   461.785113: snb_update_pm_irq <-gen6_mask_pm_irq
>          <idle>-0     [004] d.h2   461.785113: gen6_write32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h2   461.785113: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] dNh1   461.785115: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.785115: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.785115: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.785117: gen6_read32 <-ironlake_irq_handler
>     kworker/4:3-1575  [004] ....   461.785121: gen6_pm_rps_work <-process_one_work
>     kworker/4:3-1575  [004] ....   461.785121: intel_set_rps <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] ....   461.785122: intel_set_rps.part.24 <-intel_set_rps
>     kworker/4:3-1575  [004] ....   461.785122: gen6_set_rps <-intel_set_rps.part.24
>     kworker/4:3-1575  [004] ....   461.785122: gen6_set_rps_thresholds <-gen6_set_rps
>     kworker/4:3-1575  [004] ....   461.785122: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.785122: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.785122: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.785122: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.785123: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.785123: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.785123: intel_gpu_freq <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.785123: gen6_unmask_pm_irq <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] d..1   461.785123: snb_update_pm_irq <-gen6_unmask_pm_irq
>     kworker/4:3-1575  [004] d..1   461.785124: gen6_write32 <-snb_update_pm_irq
>     kworker/4:3-1575  [004] d..1   461.785124: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h1   461.817209: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.817210: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817210: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817210: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817210: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817212: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817212: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817213: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817213: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817213: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817213: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.817214: gen6_rps_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h2   461.817214: gen6_mask_pm_irq <-gen6_rps_irq_handler
>          <idle>-0     [004] d.h2   461.817214: snb_update_pm_irq <-gen6_mask_pm_irq
>          <idle>-0     [004] d.h2   461.817214: gen6_write32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h2   461.817214: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] dNh1   461.817217: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.817217: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.817217: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.817218: gen6_read32 <-ironlake_irq_handler
>     kworker/4:3-1575  [004] ....   461.817223: gen6_pm_rps_work <-process_one_work
>     kworker/4:3-1575  [004] ....   461.817223: intel_set_rps <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] ....   461.817223: intel_set_rps.part.24 <-intel_set_rps
>     kworker/4:3-1575  [004] ....   461.817223: gen6_set_rps <-intel_set_rps.part.24
>     kworker/4:3-1575  [004] ....   461.817224: gen6_set_rps_thresholds <-gen6_set_rps
>     kworker/4:3-1575  [004] ....   461.817224: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.817224: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817224: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.817224: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817225: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.817225: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817225: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.817225: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817226: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.817226: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817226: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.817226: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817226: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.817227: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817227: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.817227: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.817227: intel_gpu_freq <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.817227: gen6_unmask_pm_irq <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] d..1   461.817228: snb_update_pm_irq <-gen6_unmask_pm_irq
>     kworker/4:3-1575  [004] d..1   461.817228: gen6_write32 <-snb_update_pm_irq
>     kworker/4:3-1575  [004] d..1   461.817228: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h1   461.849295: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.849296: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849296: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849296: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849297: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849298: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849298: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849299: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849299: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849300: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849300: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.849300: gen6_rps_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h2   461.849300: gen6_mask_pm_irq <-gen6_rps_irq_handler
>          <idle>-0     [004] d.h2   461.849300: snb_update_pm_irq <-gen6_mask_pm_irq
>          <idle>-0     [004] d.h2   461.849300: gen6_write32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h2   461.849301: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] dNh1   461.849304: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.849304: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.849304: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.849306: gen6_read32 <-ironlake_irq_handler
>     kworker/4:3-1575  [004] ....   461.849311: gen6_pm_rps_work <-process_one_work
>     kworker/4:3-1575  [004] ....   461.849311: intel_set_rps <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] ....   461.849311: intel_set_rps.part.24 <-intel_set_rps
>     kworker/4:3-1575  [004] ....   461.849311: gen6_set_rps <-intel_set_rps.part.24
>     kworker/4:3-1575  [004] ....   461.849311: gen6_set_rps_thresholds <-gen6_set_rps
>     kworker/4:3-1575  [004] ....   461.849312: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.849312: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.849312: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.849312: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.849313: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.849313: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.849313: intel_gpu_freq <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.849313: gen6_unmask_pm_irq <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] d..1   461.849313: snb_update_pm_irq <-gen6_unmask_pm_irq
>     kworker/4:3-1575  [004] d..1   461.849313: gen6_write32 <-snb_update_pm_irq
>     kworker/4:3-1575  [004] d..1   461.849314: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h1   461.881383: ironlake_irq_handler <-__handle_irq_event_percpu
>          <idle>-0     [004] d.h1   461.881383: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881384: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881384: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881384: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881385: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881386: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881387: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881387: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881387: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881387: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] d.h1   461.881387: gen6_rps_irq_handler <-ironlake_irq_handler
>          <idle>-0     [004] d.h2   461.881388: gen6_mask_pm_irq <-gen6_rps_irq_handler
>          <idle>-0     [004] d.h2   461.881388: snb_update_pm_irq <-gen6_mask_pm_irq
>          <idle>-0     [004] d.h2   461.881388: gen6_write32 <-snb_update_pm_irq
>          <idle>-0     [004] d.h2   461.881388: gen6_read32 <-snb_update_pm_irq
>          <idle>-0     [004] dNh1   461.881392: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.881392: gen6_read32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.881392: gen6_write32 <-ironlake_irq_handler
>          <idle>-0     [004] dNh1   461.881393: gen6_read32 <-ironlake_irq_handler
>     kworker/4:3-1575  [004] ....   461.881398: gen6_pm_rps_work <-process_one_work
>     kworker/4:3-1575  [004] ....   461.881399: intel_set_rps <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] ....   461.881399: intel_set_rps.part.24 <-intel_set_rps
>     kworker/4:3-1575  [004] ....   461.881399: gen6_set_rps <-intel_set_rps.part.24
>     kworker/4:3-1575  [004] ....   461.881399: gen6_set_rps_thresholds <-gen6_set_rps
>     kworker/4:3-1575  [004] ....   461.881400: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.881400: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881400: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.881400: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881401: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.881401: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881401: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.881401: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881402: gen6_write32 <-gen6_set_rps_thresholds
>     kworker/4:3-1575  [004] d..1   461.881402: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881402: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.881402: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881403: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.881403: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881403: gen6_write32 <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.881403: __gen6_gt_wait_for_fifo <-gen6_write32
>     kworker/4:3-1575  [004] ....   461.881403: intel_gpu_freq <-gen6_set_rps
>     kworker/4:3-1575  [004] d..1   461.881404: gen6_unmask_pm_irq <-gen6_pm_rps_work
>     kworker/4:3-1575  [004] d..1   461.881404: snb_update_pm_irq <-gen6_unmask_pm_irq
>     kworker/4:3-1575  [004] d..1   461.881404: gen6_write32 <-snb_update_pm_irq
>     kworker/4:3-1575  [004] d..1   461.881404: gen6_read32 <-snb_update_pm_irq
>   kworker/u16:0-2183  [006] ....   462.763259: i915_gem_retire_work_handler <-process_one_work
>   kworker/u16:0-2183  [006] ....   462.763262: i915_gem_retire_requests <-i915_gem_retire_work_handler
>   kworker/u16:0-2183  [006] ....   462.763263: i915_gem_request_retire <-i915_gem_retire_requests
>   kworker/u16:0-2183  [006] ....   462.763265: i915_gem_retire_noop <-i915_gem_request_retire
>   kworker/u16:0-2183  [006] ....   462.763265: i915_vma_retire <-i915_gem_request_retire
>   kworker/u16:0-2183  [006] ....   462.763267: drm_gem_object_free <-i915_vma_retire
>   kworker/u16:0-2183  [006] ....   462.763267: i915_gem_free_object <-drm_gem_object_free
>   kworker/u16:0-2183  [006] ....   462.763268: frontbuffer_retire <-i915_gem_request_retire
>   kworker/u16:0-2183  [006] ....   462.763269: __intel_fb_obj_flush <-frontbuffer_retire
>   kworker/u16:0-2183  [006] ....   462.763269: i915_vma_retire <-i915_gem_request_retire
>   kworker/u16:0-2183  [006] ....   462.763270: intel_ring_context_unpin <-i915_gem_request_retire
>          <idle>-0     [006] ..s1   462.769216: __i915_gem_free_object_rcu <-rcu_process_callbacks
>     kworker/6:1-99    [006] ....   462.769228: __i915_gem_free_work <-process_one_work
>     kworker/6:1-99    [006] ....   462.769229: __i915_gem_free_objects <-__i915_gem_free_work
>     kworker/6:1-99    [006] ....   462.769229: intel_runtime_pm_get <-__i915_gem_free_objects
>     kworker/6:1-99    [006] ....   462.769230: i915_vma_close <-__i915_gem_free_objects
>     kworker/6:1-99    [006] ....   462.769239: i915_vma_unbind <-i915_vma_close
>     kworker/6:1-99    [006] ....   462.769240: aliasing_gtt_unbind_vma <-i915_vma_unbind
>     kworker/6:1-99    [006] ....   462.769240: gen6_ppgtt_clear_range <-aliasing_gtt_unbind_vma
>     kworker/6:1-99    [006] ....   462.769241: snb_pte_encode <-gen6_ppgtt_clear_range
>     kworker/6:1-99    [006] ....   462.769242: i915_vma_remove <-i915_vma_unbind
>     kworker/6:1-99    [006] ....   462.769242: drm_mm_remove_node <-i915_vma_remove
>     kworker/6:1-99    [006] ....   462.769243: add_hole <-drm_mm_remove_node
>     kworker/6:1-99    [006] ....   462.769244: i915_vma_destroy <-i915_vma_unbind
>     kworker/6:1-99    [006] ....   462.769245: intel_runtime_pm_put <-__i915_gem_free_objects
>     kworker/6:1-99    [006] ....   462.769245: __i915_gem_object_put_pages.part.17 <-__i915_gem_free_objects
>     kworker/6:1-99    [006] ....   462.769246: i915_gem_object_put_pages_gtt <-__i915_gem_object_put_pages.part.17
>     kworker/6:1-99    [006] ....   462.769247: __i915_gem_object_release_shmem <-i915_gem_object_put_pages_gtt
>     kworker/6:1-99    [006] ....   462.769247: i915_gem_gtt_finish_pages <-i915_gem_object_put_pages_gtt
>     kworker/6:1-99    [006] ....   462.769249: drm_gem_object_release <-__i915_gem_free_objects
>     kworker/6:1-99    [006] ....   462.769251: drm_vma_offset_remove <-drm_gem_object_release
>   kworker/u16:0-2183  [006] ....   462.891247: i915_gem_idle_work_handler <-process_one_work
>   kworker/u16:0-2183  [006] ....   462.891248: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   462.891249: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891249: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] d..1   462.891250: ___force_wake_auto <-gen6_read32
>   kworker/u16:0-2183  [006] d..1   462.891251: fw_domains_get_with_thread_status <-___force_wake_auto
>   kworker/u16:0-2183  [006] d..1   462.891251: fw_domains_get <-fw_domains_get_with_thread_status
>   kworker/u16:0-2183  [006] d..1   462.891469: __gen6_gt_wait_for_thread_c0 <-fw_domains_get_with_thread_status
>   kworker/u16:0-2183  [006] ....   462.891471: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891471: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] ....   462.891472: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891472: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] ....   462.891474: intel_engines_are_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   462.891474: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891474: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] ....   462.891475: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891475: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] ....   462.891476: intel_engine_is_idle <-intel_engines_are_idle
>   kworker/u16:0-2183  [006] ....   462.891476: gen6_read32 <-intel_engine_is_idle
>   kworker/u16:0-2183  [006] ....   462.891476: intel_engines_mark_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   462.891477: intel_engine_disarm_breadcrumbs <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] d..2   462.891477: irq_disable <-intel_engine_disarm_breadcrumbs
>   kworker/u16:0-2183  [006] d..3   462.891478: gen6_irq_disable <-irq_disable
>   kworker/u16:0-2183  [006] d..3   462.891478: gen6_write32 <-gen6_irq_disable
>   kworker/u16:0-2183  [006] d..4   462.891478: __gen6_gt_wait_for_fifo <-gen6_write32
>   kworker/u16:0-2183  [006] d..3   462.891479: gen5_disable_gt_irq <-gen6_irq_disable
>   kworker/u16:0-2183  [006] d..3   462.891479: ilk_update_gt_irq <-gen5_disable_gt_irq
>   kworker/u16:0-2183  [006] d..3   462.891480: gen6_write32 <-ilk_update_gt_irq
>   kworker/u16:0-2183  [006] ....   462.891480: i915_gem_batch_pool_fini <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891481: intel_engine_disarm_breadcrumbs <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891481: i915_gem_batch_pool_fini <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891481: intel_engine_disarm_breadcrumbs <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891481: i915_gem_batch_pool_fini <-intel_engines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891482: i915_gem_timelines_mark_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   462.891482: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891482: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891483: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891483: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891483: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891483: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891483: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891484: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891484: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891484: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891484: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891485: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891485: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891485: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891485: i915_syncmap_free <-i915_gem_timelines_mark_idle
>   kworker/u16:0-2183  [006] ....   462.891486: gen6_rps_idle <-i915_gem_idle_work_handler
>   kworker/u16:0-2183  [006] ....   462.891486: gen6_disable_rps_interrupts <-gen6_rps_idle
>   kworker/u16:0-2183  [006] d..1   462.891486: gen6_write32 <-gen6_disable_rps_interrupts
>   kworker/u16:0-2183  [006] d..2   462.891486: __gen6_gt_wait_for_fifo <-gen6_write32
>   kworker/u16:0-2183  [006] d..1   462.891487: gen6_disable_pm_irq <-gen6_disable_rps_interrupts
>   kworker/u16:0-2183  [006] d..1   462.891487: snb_update_pm_irq <-gen6_disable_pm_irq
>   kworker/u16:0-2183  [006] d..1   462.891487: gen6_write32 <-snb_update_pm_irq
>   kworker/u16:0-2183  [006] d..1   462.891488: gen6_read32 <-snb_update_pm_irq
>   kworker/u16:0-2183  [006] d..1   462.891488: gen6_write32 <-gen6_disable_pm_irq
>   kworker/u16:0-2183  [006] ....   462.891489: gen6_reset_rps_interrupts <-gen6_disable_rps_interrupts
>   kworker/u16:0-2183  [006] d..1   462.891490: gen6_reset_pm_iir <-gen6_reset_rps_interrupts
>   kworker/u16:0-2183  [006] d..1   462.891490: gen6_write32 <-gen6_reset_pm_iir
>   kworker/u16:0-2183  [006] d..1   462.891490: gen6_write32 <-gen6_reset_pm_iir
>   kworker/u16:0-2183  [006] d..1   462.891490: gen6_read32 <-gen6_reset_pm_iir
>   kworker/u16:0-2183  [006] ....   462.891491: gen6_set_rps <-gen6_rps_idle
>   kworker/u16:0-2183  [006] ....   462.891491: gen6_write32 <-gen6_set_rps
>   kworker/u16:0-2183  [006] d..1   462.891492: __gen6_gt_wait_for_fifo <-gen6_write32
>   kworker/u16:0-2183  [006] ....   462.891493: gen6_write32 <-gen6_set_rps
>   kworker/u16:0-2183  [006] d..1   462.891493: __gen6_gt_wait_for_fifo <-gen6_write32
>   kworker/u16:0-2183  [006] ....   462.891493: intel_gpu_freq <-gen6_set_rps
>   kworker/u16:0-2183  [006] ....   462.891494: gen6_write32 <-gen6_rps_idle
>   kworker/u16:0-2183  [006] d..1   462.891494: __gen6_gt_wait_for_fifo <-gen6_write32
>   kworker/u16:0-2183  [006] ....   462.891495: intel_runtime_pm_put <-i915_gem_idle_work_handler
>          <idle>-0     [006] d.h1   462.893254: intel_uncore_fw_release_timer <-__hrtimer_run_queues
>          <idle>-0     [006] d.h2   462.893255: fw_domains_put <-intel_uncore_fw_release_timer
>          <idle>-0     [004] ..s1   463.723212: intel_breadcrumbs_hangcheck <-call_timer_fn
>   kworker/u16:0-2183  [006] ....   464.747245: i915_gem_retire_work_handler <-process_one_work
>   kworker/u16:0-2183  [006] ....   464.747247: i915_gem_retire_requests <-i915_gem_retire_work_handler

Actions: View

Attachments on bug 100215: 131433 | 131460

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.