Attachment 121822 Details for Bug 93746 – Annotated and trimmed kernel log which points to the cause of the problem.

Annotated and trimmed kernel log which points to the cause of the problem.

drm_annotated_debuglog.txt (text/plain), 56.67 KB, created by Mario Kleiner on 2016-02-17 23:09:28 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Mario Kleiner

Created: 2016-02-17 23:09:28 UTC

Size: 56.67 KB

patch

obsolete

>Annotate kernel log for Bernd's last debugging session:
>
>
>Feb 16 21:44:31.825301 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41632, wptr 41648
>Feb 16 21:44:31.825454 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 2
>Feb 16 21:44:31.825570 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 1 : v 0x7 p(1378,-36)@ 73.453289 -> 73.453766 [e 1 us, 0 rep]
>Feb 16 21:44:31.825704 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 3
>Feb 16 21:44:31.825867 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=3970, diff=1, hw=3479 hw_last=3478
>Feb 16 21:44:31.825982 orionis kernel: [drm:cik_irq_process] IH: D2 vblank
>Feb 16 21:44:31.828317 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41648, wptr 41664
>Feb 16 21:44:31.828536 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1227
>Feb 16 21:44:31.828652 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1897,-28)@ 73.456888 -> 73.457254 [e 1 us, 0 rep]
>Feb 16 21:44:31.828757 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1224
>Feb 16 21:44:31.828885 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4280, diff=1, hw=3495 hw_last=3494
>Feb 16 21:44:31.829020 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.840744 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41664, wptr 41680
>Feb 16 21:44:31.840942 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1226
>Feb 16 21:44:31.841060 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1710,-27)@ 73.469315 -> 73.469669 [e 1 us, 0 rep]
>Feb 16 21:44:31.841218 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1223
>Feb 16 21:44:31.841424 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3981, diff=1, hw=3484 hw_last=3483
>Feb 16 21:44:31.841567 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.841698 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41680, wptr 41696
>Feb 16 21:44:31.841817 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 2
>Feb 16 21:44:31.841950 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 1 : v 0x7 p(542,-35)@ 73.469753 -> 73.470223 [e 1 us, 0 rep]
>Feb 16 21:44:31.842073 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 3
>Feb 16 21:44:31.842188 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=3971, diff=1, hw=3480 hw_last=3479
>Feb 16 21:44:31.842346 orionis kernel: [drm:cik_irq_process] IH: D2 vblank
>Feb 16 21:44:31.844725 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41696, wptr 41712
>Feb 16 21:44:31.844966 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1227
>Feb 16 21:44:31.845081 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(2060,-28)@ 73.473298 -> 73.473663 [e 1 us, 0 rep]
>Feb 16 21:44:31.845186 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1224
>Feb 16 21:44:31.845308 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4281, diff=1, hw=3496 hw_last=3495
>Feb 16 21:44:31.845522 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.849424 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41712, wptr 41728
>
>--> Display powered off -> connection cut -> HPD5
>--> radeon_connector_hotplug() for DP triggers dpms off for crtc 1.
>
>Feb 16 21:44:31.849617 orionis kernel: [drm:cik_irq_process] IH: HPD5
>Feb 16 21:44:31.857477 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41728, wptr 41744
>Feb 16 21:44:31.857787 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:31.857928 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(499,-35)@ 73.485610 -> 73.486079 [e 1 us, 0 rep]
>Feb 16 21:44:31.858104 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:31.858229 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3982, diff=1, hw=3485 hw_last=3484
>Feb 16 21:44:31.858434 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.858583 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41744, wptr 41760
>Feb 16 21:44:31.858708 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 3
>Feb 16 21:44:31.858841 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 1 : v 0x7 p(1624,-35)@ 73.486217 -> 73.486679 [e 1 us, 0 rep]
>Feb 16 21:44:31.858968 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 4
>Feb 16 21:44:31.859099 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=3972, diff=1, hw=3481 hw_last=3480
>Feb 16 21:44:31.859227 orionis kernel: [drm:cik_irq_process] IH: D2 vblank
>Feb 16 21:44:31.859378 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41760, wptr 41776
>Feb 16 21:44:31.859542 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start -1229
>Feb 16 21:44:31.859674 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 1 : v 0x7 p(1851,-32)@ 73.486258 -> 73.486678 [e 1 us, 0 rep]
>Feb 16 21:44:31.859802 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start -1228
>Feb 16 21:44:31.859932 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=3973, diff=0, hw=3481 hw_last=3481
>Feb 16 21:44:31.860061 orionis kernel: [drm:cik_irq_process] IH: D2 vblank
>Feb 16 21:44:31.860189 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41776, wptr 41776
>Feb 16 21:44:31.861055 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41776, wptr 41792
>Feb 16 21:44:31.861222 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:31.861354 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(308,-35)@ 73.489603 -> 73.490074 [e 1 us, 0 rep]
>Feb 16 21:44:31.861466 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.861573 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4282, diff=1, hw=3497 hw_last=3496
>Feb 16 21:44:31.861710 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.873499 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41792, wptr 41808
>Feb 16 21:44:31.873701 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:31.873842 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(12,-35)@ 73.502016 -> 73.502488 [e 1 us, 0 rep]
>Feb 16 21:44:31.873981 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:31.874123 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3983, diff=1, hw=3486 hw_last=3485
>Feb 16 21:44:31.874264 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.874443 orionis kernel: [drm:atombios_crtc_dpms] DPMS OFF Waiting for crtc 1 really off.
>Feb 16 21:44:31.874578 orionis kernel: [drm:atombios_crtc_dpms] DPMS OFF crtc 1 is really off. old lb_lead 3
>Feb 16 21:44:31.874709 orionis kernel: [drm:atombios_crtc_dpms] DPMS OFF crtc 1 is really off. new lb_lead 3
>
>-> crtc 1 is off, no more vblank irqs, scanout rests at line 0 of real vblank.
>
>
>Feb 16 21:44:31.877529 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41808, wptr 41824
>Feb 16 21:44:31.877701 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1227
>Feb 16 21:44:31.877795 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(814,-29)@ 73.506095 -> 73.506481 [e 1 us, 0 rep]
>Feb 16 21:44:31.877875 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1224
>Feb 16 21:44:31.877965 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4283, diff=1, hw=3498 hw_last=3497
>Feb 16 21:44:31.878072 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.889948 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41824, wptr 41840
>Feb 16 21:44:31.890141 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1228
>Feb 16 21:44:31.890244 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1381,-31)@ 73.518487 -> 73.518896 [e 1 us, 0 rep]
>Feb 16 21:44:31.890378 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1227
>Feb 16 21:44:31.890524 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3984, diff=1, hw=3487 hw_last=3486
>Feb 16 21:44:31.890635 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.893949 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41840, wptr 41856
>Feb 16 21:44:31.894148 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1227
>Feb 16 21:44:31.894263 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1853,-28)@ 73.522524 -> 73.522890 [e 1 us, 0 rep]
>Feb 16 21:44:31.894408 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1224
>Feb 16 21:44:31.894529 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4284, diff=1, hw=3499 hw_last=3498
>Feb 16 21:44:31.894662 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.906380 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41856, wptr 41872
>Feb 16 21:44:31.906579 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1227
>Feb 16 21:44:31.906733 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1453,-28)@ 73.534936 -> 73.535305 [e 1 us, 0 rep]
>Feb 16 21:44:31.906848 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1224
>Feb 16 21:44:31.906982 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3985, diff=1, hw=3488 hw_last=3487
>Feb 16 21:44:31.907119 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.910218 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41872, wptr 41888
>Feb 16 21:44:31.910386 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:31.910500 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(995,-35)@ 73.538834 -> 73.539300 [e 1 us, 0 rep]
>Feb 16 21:44:31.910603 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
>Feb 16 21:44:31.910721 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4285, diff=1, hw=3500 hw_last=3499
>Feb 16 21:44:31.910853 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.912409 orionis kernel: [drm:drm_sysfs_hotplug_event] generating hotplug event
>
>--> Userspace gets notified of new state via hotplug event.
>--> ddx starts doing stuff in response.
>
>Feb 16 21:44:31.916386 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETRESOURCES
>Feb 16 21:44:31.916544 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETRESOURCES
>Feb 16 21:44:31.916633 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.923447 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41888, wptr 41904
>Feb 16 21:44:31.923619 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:31.923732 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(508,-35)@ 73.551246 -> 73.551715 [e 1 us, 0 rep]
>Feb 16 21:44:31.923844 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:31.923951 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3986, diff=1, hw=3489 hw_last=3488
>Feb 16 21:44:31.924061 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.926727 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41904, wptr 41920
>Feb 16 21:44:31.926926 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:31.927062 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1931,-36)@ 73.555236 -> 73.555709 [e 1 us, 0 rep]
>Feb 16 21:44:31.927195 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.927355 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4286, diff=1, hw=3501 hw_last=3500
>Feb 16 21:44:31.927497 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.939136 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41920, wptr 41936
>Feb 16 21:44:31.939422 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:31.939609 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1533,-36)@ 73.567648 -> 73.568124 [e 1 us, 0 rep]
>Feb 16 21:44:31.939800 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:31.939968 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3987, diff=1, hw=3490 hw_last=3489
>Feb 16 21:44:31.940188 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.943125 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41936, wptr 41952
>Feb 16 21:44:31.943408 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:31.943589 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1470,-36)@ 73.571642 -> 73.572118 [e 1 us, 0 rep]
>Feb 16 21:44:31.943763 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.943929 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4287, diff=1, hw=3502 hw_last=3501
>Feb 16 21:44:31.944099 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.947474 orionis kernel: [drm:drm_property_unreference_blob] ffff88040ddb0200: blob ID: 45 (1)
>Feb 16 21:44:31.947724 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.947900 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.948123 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.948290 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPBLOB
>Feb 16 21:44:31.948541 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPBLOB
>Feb 16 21:44:31.948674 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.948804 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.948930 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949059 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949186 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949320 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949465 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949593 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949723 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.949889 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950015 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950144 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950273 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950425 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950553 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950681 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950809 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.950939 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:31.951066 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.955594 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41952, wptr 41968
>Feb 16 21:44:31.955790 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1227
>Feb 16 21:44:31.955946 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1808,-28)@ 73.584165 -> 73.584531 [e 1 us, 0 rep]
>Feb 16 21:44:31.956062 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1224
>Feb 16 21:44:31.956204 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3988, diff=1, hw=3491 hw_last=3490
>Feb 16 21:44:31.956374 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.959575 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41968, wptr 41984
>Feb 16 21:44:31.959775 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.959888 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(712,-34)@ 73.588072 -> 73.588527 [e 1 us, 0 rep]
>Feb 16 21:44:31.960010 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
>Feb 16 21:44:31.960153 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4288, diff=1, hw=3503 hw_last=3502
>Feb 16 21:44:31.960277 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.972001 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 41984, wptr 42000
>Feb 16 21:44:31.972200 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1227
>Feb 16 21:44:31.972322 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1831,-28)@ 73.600574 -> 73.600940 [e 1 us, 0 rep]
>Feb 16 21:44:31.972473 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1224
>Feb 16 21:44:31.972589 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3989, diff=1, hw=3492 hw_last=3491
>Feb 16 21:44:31.972698 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.975888 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42000, wptr 42016
>Feb 16 21:44:31.976089 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.976213 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1339,-35)@ 73.604472 -> 73.604936 [e 1 us, 0 rep]
>Feb 16 21:44:31.976389 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
>Feb 16 21:44:31.976558 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4289, diff=1, hw=3504 hw_last=3503
>Feb 16 21:44:31.976680 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:31.979364 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.979505 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.985484 orionis kernel: [drm:drm_property_unreference_blob] ffff88040b8dfe00: blob ID: 119 (1)
>Feb 16 21:44:31.985695 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.986382 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:31.988262 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42016, wptr 42032
>Feb 16 21:44:31.988395 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:31.988501 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1039,-35)@ 73.616885 -> 73.617351 [e 1 us, 0 rep]
>Feb 16 21:44:31.988604 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 4
>Feb 16 21:44:31.988735 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3990, diff=1, hw=3493 hw_last=3492
>Feb 16 21:44:31.988839 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:31.992355 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42032, wptr 42048
>Feb 16 21:44:31.992469 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:31.992571 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(1160,-36)@ 73.620867 -> 73.621345 [e 1 us, 0 rep]
>Feb 16 21:44:31.992670 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:31.992770 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4290, diff=1, hw=3505 hw_last=3504
>Feb 16 21:44:31.992872 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.005349 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42048, wptr 42064
>Feb 16 21:44:32.005432 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 1
>Feb 16 21:44:32.005522 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(655,-36)@ 73.633287 -> 73.633769 [e 1 us, 0 rep]
>Feb 16 21:44:32.005600 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:32.005678 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3991, diff=1, hw=3494 hw_last=3493
>Feb 16 21:44:32.005756 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.009348 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42064, wptr 42080
>Feb 16 21:44:32.009439 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 1
>Feb 16 21:44:32.009515 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(608,-36)@ 73.637289 -> 73.637771 [e 1 us, 0 rep]
>Feb 16 21:44:32.009592 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:32.009668 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4291, diff=1, hw=3506 hw_last=3505
>Feb 16 21:44:32.009745 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.021093 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42080, wptr 42096
>Feb 16 21:44:32.021203 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:32.021309 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(1373,-36)@ 73.649733 -> 73.650210 [e 1 us, 0 rep]
>Feb 16 21:44:32.021414 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:32.021490 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3992, diff=1, hw=3495 hw_last=3494
>Feb 16 21:44:32.021567 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.025348 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42096, wptr 42112
>Feb 16 21:44:32.025438 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:32.025515 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(768,-36)@ 73.653731 -> 73.654212 [e 1 us, 0 rep]
>Feb 16 21:44:32.025590 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:32.025667 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4292, diff=1, hw=3507 hw_last=3506
>Feb 16 21:44:32.025759 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.038347 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42112, wptr 42128
>Feb 16 21:44:32.038438 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 1
>Feb 16 21:44:32.038514 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(644,-36)@ 73.666169 -> 73.666651 [e 1 us, 0 rep]
>Feb 16 21:44:32.038589 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:32.038666 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3993, diff=1, hw=3496 hw_last=3495
>Feb 16 21:44:32.038757 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.042347 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42128, wptr 42144
>Feb 16 21:44:32.042438 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 1
>Feb 16 21:44:32.042512 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(550,-36)@ 73.670170 -> 73.670653 [e 1 us, 0 rep]
>Feb 16 21:44:32.042588 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:32.042677 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4293, diff=1, hw=3508 hw_last=3507
>Feb 16 21:44:32.042755 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.045355 orionis kernel: [drm:drm_property_unreference_blob] ffff88040b8dfa00: blob ID: 59 (1)
>Feb 16 21:44:32.045989 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETCONNECTOR
>Feb 16 21:44:32.046235 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.046712 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.046905 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPBLOB
>Feb 16 21:44:32.047074 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPBLOB
>Feb 16 21:44:32.047460 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.047622 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.047718 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.047806 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.047914 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048000 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048085 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048173 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048270 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048373 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048460 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048542 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048625 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048709 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048790 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048872 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.048956 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.049057 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_GETPROPERTY
>Feb 16 21:44:32.049137 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.049222 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.049306 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.049402 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.049487 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.049570 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.049650 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.049736 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.049818 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.049911 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.049996 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050078 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.050157 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050240 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.050323 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050412 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.050495 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050581 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.050666 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050749 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.050825 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.050903 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051003 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051088 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051172 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051256 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051352 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051431 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051513 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051591 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051674 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051755 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.051833 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.051931 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052018 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.052106 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052193 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.052282 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052381 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.052469 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052557 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.052645 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052733 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.052825 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.052919 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053008 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.053126 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053213 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.053308 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053422 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.053510 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053597 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.053684 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053772 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.053856 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.053999 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054089 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.054181 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054261 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.054415 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054495 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.054568 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054647 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.054722 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054795 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.054872 orionis kernel: [drm:drm_ioctl] pid=1200, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.054954 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.055039 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.055189 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42144, wptr 42160
>Feb 16 21:44:32.055276 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:32.055376 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(901,-35)@ 73.682624 -> 73.683091 [e 1 us, 0 rep]
>Feb 16 21:44:32.055463 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 4
>Feb 16 21:44:32.055566 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3994, diff=1, hw=3497 hw_last=3496
>Feb 16 21:44:32.055654 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.055859 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.055945 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.047708 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper: RRNotify_OutputProperty (ignored)
>Feb 16 21:44:32.047735 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Output:  85
>Feb 16 21:44:32.047771 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Property:  EDIDI156%
>Feb 16 21:44:32.047790 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         State (newValue, Deleted):  1
>Feb 16 21:44:32.047887 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper: RRNotify_OutputProperty (ignored)
>Feb 16 21:44:32.047906 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Output:  85
>Feb 16 21:44:32.047925 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Property:  EDIDRALTe
>Feb 16 21:44:32.058513 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42160, wptr 42176
>Feb 16 21:44:32.058595 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 2
>Feb 16 21:44:32.058677 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(662,-35)@ 73.686625 -> 73.687093 [e 1 us, 0 rep]
>Feb 16 21:44:32.058756 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
>Feb 16 21:44:32.058836 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4294, diff=1, hw=3509 hw_last=3508
>Feb 16 21:44:32.058913 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.047945 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         State (newValue, Deleted):  1
>Feb 16 21:44:32.059358 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059447 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059531 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059618 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059699 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059782 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059866 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.059950 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060032 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060118 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060265 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060364 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060459 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060557 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060637 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060719 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060803 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060885 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.060969 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.061049 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.061131 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.061211 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.061296 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_WAIT_IDLE
>Feb 16 21:44:32.061392 orionis kernel: [drm:drm_ioctl] pid=1230, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.061495 orionis kernel: [drm:drm_ioctl] pid=1162, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.061574 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.061672 orionis kernel: [drm:drm_wait_vblank] waiting on vblank count 4295, crtc 0
>Feb 16 21:44:32.061752 orionis kernel: [drm:drm_wait_vblank] returning 4295 to client
>Feb 16 21:44:32.061833 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.061913 orionis kernel: [drm:drm_queue_vblank_event] event on vblank count 4296, current 4295, crtc 0
>Feb 16 21:44:32.047966 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper: RRotify_OutputChange
>Feb 16 21:44:32.047983 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Output:  85
>Feb 16 21:44:32.062636 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_INFO
>Feb 16 21:44:32.048001 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         CRTC:  80
>Feb 16 21:44:32.048019 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Mode:  88
>Feb 16 21:44:32.048039 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Rotation:  "Rotate_0"
>Feb 16 21:44:32.063629 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.063719 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.063808 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_CREATE
>Feb 16 21:44:32.063889 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.063989 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_CREATE
>Feb 16 21:44:32.064069 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.064150 orionis kernel: [drm:drm_ioctl] pid=1163, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.064231 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_WAIT_IDLE
>Feb 16 21:44:32.064371 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.064453 orionis kernel: [drm:drm_wait_vblank] waiting on vblank count 4295, crtc 0
>Feb 16 21:44:32.064539 orionis kernel: [drm:drm_wait_vblank] returning 4295 to client
>Feb 16 21:44:32.064620 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.064703 orionis kernel: [drm:drm_queue_vblank_event] event on vblank count 4296, current 4295, crtc 0
>Feb 16 21:44:32.048058 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Connection:  "Disconnected"
>Feb 16 21:44:32.048075 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Subpixel Order:  1
>Feb 16 21:44:32.048197 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper: RRScreenChangeNotify
>Feb 16 21:44:32.048216 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Window: 20971524
>Feb 16 21:44:32.048233 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Root: 1213
>Feb 16 21:44:32.048252 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Rotation:  "Rotate_0"
>Feb 16 21:44:32.048271 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Size ID: 65535
>Feb 16 21:44:32.048291 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Size:  5760 1200
>Feb 16 21:44:32.048309 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         SizeMM:  1524 317
>Feb 16 21:44:32.048350 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper: RRotify_OutputChange
>Feb 16 21:44:32.048368 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Output:  85
>Feb 16 21:44:32.048387 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         CRTC:  80
>Feb 16 21:44:32.048405 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Mode:  88
>Feb 16 21:44:32.048424 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Rotation:  "Rotate_0"
>Feb 16 21:44:32.048443 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Connection:  "Disconnected"
>Feb 16 21:44:32.048461 orionis kscreen_backend_launcher[1120]: kscreen.xcb.helper:         Subpixel Order:  1
>Feb 16 21:44:32.054818 orionis kwin_x11[1132]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 5011, resource id: 31457310, major code: 15 (QueryTree), minor code: 0
>Feb 16 21:44:32.070448 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42176, wptr 42192
>Feb 16 21:44:32.070555 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 2
>Feb 16 21:44:32.070639 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(270,-35)@ 73.699061 -> 73.699532 [e 1 us, 0 rep]
>Feb 16 21:44:32.070739 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start 3
>Feb 16 21:44:32.070822 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3995, diff=1, hw=3498 hw_last=3497
>Feb 16 21:44:32.070905 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.074548 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42192, wptr 42208
>Feb 16 21:44:32.074715 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
>Feb 16 21:44:32.074841 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0 : v 0x7 p(463,-31)@ 73.703117 -> 73.703533 [e 1 us, 0 rep]
>Feb 16 21:44:32.074955 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start -1228
>Feb 16 21:44:32.075064 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=4295, diff=1, hw=3510 hw_last=3509
>Feb 16 21:44:32.075169 orionis kernel: [drm:drm_handle_vblank_events] vblank event on 4296, current 4296
>Feb 16 21:44:32.075275 orionis kernel: [drm:drm_handle_vblank_events] vblank event on 4296, current 4296
>Feb 16 21:44:32.075483 orionis kernel: [drm:cik_irq_process] IH: D1 vblank
>Feb 16 21:44:32.075614 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.075728 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.075855 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.075966 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.076091 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.076228 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.076385 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.076560 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.076674 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.076795 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_GEM_CLOSE
>Feb 16 21:44:32.076907 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.077024 orionis kernel: [drm:drm_ioctl] pid=954, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.077159 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.077275 orionis kernel: [drm:drm_ioctl] pid=954, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.077423 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.077551 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.077667 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.077782 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.077892 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_CREATE
>Feb 16 21:44:32.078010 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.078147 orionis kernel: [drm:drm_ioctl] pid=954, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.078270 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_BUSY
>
>-> "Tearfree" radeon_scanout_flip() does its update thing.
>
>Feb 16 21:44:32.078422 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_PAGE_FLIP
>Feb 16 21:44:32.078550 orionis kernel: [drm:radeon_crtc_page_flip] flip-ioctl() cur_rbo = ffff88041e2f9000, new_rbo = ffff88041e2f9800
>Feb 16 21:44:32.078664 orionis kernel: [drm:drm_framebuffer_unreference] ffff88041e2eecc0: FB ID: 112 (2)
>Feb 16 21:44:32.078811 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.078922 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.079037 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.079148 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.079260 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_CREATE
>Feb 16 21:44:32.079400 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.079525 orionis kernel: [drm:drm_ioctl] pid=954, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.079643 orionis kernel: [drm:cik_irq_set] cik_irq_set: sw int gfx
>Feb 16 21:44:32.079801 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 0
>Feb 16 21:44:32.079919 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 1
>Feb 16 21:44:32.080054 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 2
>Feb 16 21:44:32.080173 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 3
>Feb 16 21:44:32.080268 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 1
>Feb 16 21:44:32.080737 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 2
>Feb 16 21:44:32.080855 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 3
>Feb 16 21:44:32.080940 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 5
>Feb 16 21:44:32.081031 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_PAGE_FLIP
>Feb 16 21:44:32.081121 orionis kernel: [drm:radeon_crtc_page_flip] flip-ioctl() cur_rbo = ffff88041e2fc000, new_rbo = ffff88041e2fb800
>Feb 16 21:44:32.081206 orionis kernel: [drm:drm_framebuffer_unreference] ffff88041e2ee600: FB ID: 115 (2)
>Feb 16 21:44:32.081288 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.081420 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.081503 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.081593 orionis kernel: [drm:drm_ioctl] ret = -16
>Feb 16 21:44:32.081675 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_CREATE
>Feb 16 21:44:32.081755 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, RADEON_GEM_VA
>Feb 16 21:44:32.081841 orionis kernel: [drm:drm_ioctl] pid=954, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.081924 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_MODE_PAGE_FLIP
>Feb 16 21:44:32.082003 orionis kernel: [drm:radeon_crtc_page_flip] flip-ioctl() cur_rbo = ffff88041e2fd000, new_rbo = ffff88041e2fe000
>Feb 16 21:44:32.082094 orionis kernel: [drm:drm_framebuffer_unreference] ffff88041e2ee3c0: FB ID: 116 (2)
>
>-> "Successfully" calls pageflip ioctl on all crtcs, apparently ignores dpms off state of crtc 1.
>
>Feb 16 21:44:32.082175 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_INFO
>Feb 16 21:44:32.082256 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.082359 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42208, wptr 42224
>Feb 16 21:44:32.082461 orionis kernel: [drm:cik_irq_process] IH: CP EOP
>Feb 16 21:44:32.082539 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_BUSY
>Feb 16 21:44:32.082625 orionis kernel: [drm:drm_ioctl] pid=1163, dev=0xe200, auth=1, RADEON_CS
>Feb 16 21:44:32.082707 orionis kernel: [drm:drm_ioctl] pid=1132, dev=0xe200, auth=1, RADEON_GEM_WAIT_IDLE
>Feb 16 21:44:32.082788 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.082880 orionis kernel: [drm:drm_wait_vblank] waiting on vblank count 4296, crtc 0
>Feb 16 21:44:32.082962 orionis kernel: [drm:drm_wait_vblank] returning 4296 to client
>Feb 16 21:44:32.083042 orionis kernel: [drm:drm_ioctl] pid=952, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
>Feb 16 21:44:32.083133 orionis kernel: [drm:drm_queue_vblank_event] event on vblank count 4297, current 4296, crtc 0
>Feb 16 21:44:32.084057 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42224, wptr 42240
>Feb 16 21:44:32.084257 orionis kernel: [drm:cik_irq_process] IH: CP EOP
>Feb 16 21:44:32.084400 orionis kernel: [drm:cik_irq_set] cik_irq_set: sw int gfx
>Feb 16 21:44:32.084549 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 0
>Feb 16 21:44:32.084656 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 1
>Feb 16 21:44:32.084788 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 2
>Feb 16 21:44:32.084895 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 3
>Feb 16 21:44:32.085009 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 1
>Feb 16 21:44:32.085114 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 2
>Feb 16 21:44:32.085227 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 3
>Feb 16 21:44:32.085361 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 5
>Feb 16 21:44:32.085474 orionis kernel: [drm:radeon_flip_work_func] crtc_id 0: stat 5, vpos -503, hpos -506
>Feb 16 21:44:32.085581 orionis kernel: [drm:radeon_flip_work_func] Flip submitted: work->crtc_id 0, radeon_crtc->crtc_id 0
>Feb 16 21:44:32.087034 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42240, wptr 42256
>Feb 16 21:44:32.087253 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1226
>Feb 16 21:44:32.087440 orionis kernel: [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 2 : v 0x7 p(154,-27)@ 73.715607 -> 73.715971 [e 1 us, 0 rep]
>Feb 16 21:44:32.087537 orionis kernel: [drm:radeon_get_vblank_counter_kms] crtc 2: dist from vblank start -1224
>Feb 16 21:44:32.087653 orionis kernel: [drm:drm_update_vblank_count] updating vblank count on crtc 2: current=3996, diff=1, hw=3499 hw_last=3498
>Feb 16 21:44:32.087762 orionis kernel: [drm:cik_irq_process] IH: D3 vblank
>Feb 16 21:44:32.087865 orionis kernel: [drm:cik_irq_process] cik_irq_process start: rptr 42256, wptr 42272
>Feb 16 21:44:32.087973 orionis kernel: [drm:cik_irq_process] IH: CP EOP
>Feb 16 21:44:32.088073 orionis kernel: [drm:cik_irq_set] cik_irq_set: sw int gfx
>Feb 16 21:44:32.088180 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 0
>Feb 16 21:44:32.088286 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 1
>Feb 16 21:44:32.088425 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 2
>Feb 16 21:44:32.088534 orionis kernel: [drm:cik_irq_set] cik_irq_set: vblank 3
>Feb 16 21:44:32.088670 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 1
>Feb 16 21:44:32.088776 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 2
>Feb 16 21:44:32.088885 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 3
>Feb 16 21:44:32.088986 orionis kernel: [drm:cik_irq_set] cik_irq_set: hpd 5
>Feb 16 21:44:32.089094 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.089193 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>
>-> radeon_flip_work_func executes for the disabled crtc, gets stuck in an endless "delay loop",
>as crtc is off and scanout is no longer moving.
>
>-> Pageflip hangs on DP monitor, no further display updates, except mouse cursor movements. Game over.
>
>
>Feb 16 21:44:32.089300 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.089435 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.089542 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.089638 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.089743 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.089842 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.089972 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.090088 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.090194 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.090294 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.090420 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>Feb 16 21:44:32.090619 orionis kernel: [drm:radeon_flip_work_func] Delay flip: crtc_id 1: scanlines 1, linedur usecs 13, min_udelay 13
>Feb 16 21:44:32.090737 orionis kernel: [drm:radeon_flip_work_func] crtc_id 1: stat 7, vpos 3, hpos 0
>
>... and so on...

Actions: View

Attachments on bug 93746: 121189 | 121190 | 121821 | 121822 | 121834 | 121835

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.