On 30.1.2018. 13:34, Martin Pieuchot wrote:
> On 30/01/18(Tue) 13:12, Hrvoje Popovski wrote:
>> Hi all,
>>
>> I've checkouted cvs tree few minutes ago on desktop pc and enabled
>> WITNESS. While booting pc with new kernel i'm getting "lock order reversal"
>>
>> http://kosjenka.srce.hr/~hrvoje/zaprocvat/IMG_20180130_125928.jpg
>
> I'd say this is known. With a working keyboard you could print the
> traces and run "show witness /b".
>
>>
>> in ddb i can't do nothing with keyboard
>
> Putting machdep.forceukbd=1 into sysctl.conf(5) should help with that.
now without uefi output to serial port is working :)
login: lock order reversal:
1st 0xffffffff81bf6aa8 &sched_lock (&sched_lock) @
/sys/kern/kern_synch.c:292
2nd 0xffff800000218240 &dev_priv->irq_lock (&dev_priv->irq_lock) @
/sys/dev/pc
i/drm/i915/intel_ringbuffer.c:1787
Stopped at db_enter+0x5: popq %rbp
ddb{2}>
ddb{2}> trace
db_enter() at db_enter+0x5
witness_checkorder(ffffffff81886033,6fb,ffff800000218240,ffff800000218230,0)
at
witness_checkorder+0xaf2
_mtx_enter(ffff800000211000,ffff800000218230,ffff80000021b000) at
_mtx_enter+0x
30
gen6_ring_put_irq(ffff800033083370) at gen6_ring_put_irq+0x36
__i915_wait_request(0,ffffff0219e0d008,ffff800000ade850,0,ffff800000211000)
at _
_i915_wait_request+0x330
i915_wait_request(0) at i915_wait_request+0x87
i915_gem_object_wait_rendering(0,ffff800000ade740) at
i915_gem_object_wait_rend
ering+0x18e
i915_gem_object_set_cache_level(ffff8000330834e0,ffff800000ade740) at
i915_gem_
object_set_cache_level+0x20d
i915_gem_object_pin_to_display_plane(ffff800000ade740,ffff800000211000,ffff8000
330834e0,0,ffffffff8130d56d) at i915_gem_object_pin_to_display_plane+0x6d
intel_pin_and_fence_fb_obj() at intel_pin_and_fence_fb_obj+0x1c0
intel_crtc_page_flip(ffff800000a80a00,ffff80000021c000,ffff800033083ab0,ffff800
00021b000) at intel_crtc_page_flip+0x4dd
drm_mode_page_flip_ioctl(ffff80000021b000,ffffffff8171b440,c01864b0) at
drm_mod
e_page_flip_ioctl+0x39b
drm_do_ioctl(0,ffff80000021b0d8,ffff80000021b000,ffff80000021b108) at
drm_do_io
ctl+0x201
drmioctl(ffffff01dfe55ae0,ffff800033084030,ffffff01ddaf4e88,c01864b0,ffffff01dd
af4e88) at drmioctl+0xe8
VOP_IOCTL(6e8804fd365ed36d,ffff800033084030,ffffff021e5d3ba0,3,ffff800033083ab0
,c01864b0) at VOP_IOCTL+0x3e
vn_ioctl(ffff800033084030,ffff800033083ba0,ffffff01ddaf4e88,18) at
vn_ioctl+0x5
d
sys_ioctl(360,ffff800033084030,0) at sys_ioctl+0x343
syscall() at syscall+0x279
--- syscall (number 54) ---
end of kernel
end trace frame: 0x7f7fffff2e80, count: -18
0x1dc9e137593a:
ddb{2}>
ddb{2}> show witness /b
Number of known direct relationships is 300
Lock order reversal between "&sched_lock"(sched_lock) and
"&dev_priv->irq_lock"
(mutex)!
Lock order "&sched_lock"(sched_lock) -> "&dev_priv->irq_lock"(mutex)
first seen
at:
#0 witness_checkorder+0x466
#1 _mtx_enter+0x30
#2 gen6_ring_put_irq+0x36
#3 __i915_wait_request+0x330
#4 i915_wait_request+0x87
#5 i915_gem_object_wait_rendering+0x18e
#6 i915_gem_object_set_cache_level+0x20d
#7 i915_gem_object_pin_to_display_plane+0x6d
#8 intel_pin_and_fence_fb_obj+0x1c0
#9 intel_crtc_page_flip+0x4dd
#10 drm_mode_page_flip_ioctl+0x39b
#11 drm_do_ioctl+0x201
#12 drmioctl+0xe8
#13 VOP_IOCTL+0x3e
#14 vn_ioctl+0x5d
#15 sys_ioctl+0x343
#16 syscall+0x279
Lock order "&dev_priv->irq_lock"(mutex) -> "&sched_lock"(sched_lock)
first seen
at:
#0 witness_checkorder+0x466
#1 ___mp_lock+0x6f
#2 wakeup_n+0x39
#3 task_add+0x85
#4 gen6_rps_boost+0x110
#5 __i915_wait_request+0x13c
#6 i915_gem_object_wait_rendering__nonblocking+0x1c6
#7 i915_gem_set_domain_ioctl+0xce
#8 drm_do_ioctl+0x201
#9 drmioctl+0xe8
#10 VOP_IOCTL+0x3e
#11 vn_ioctl+0x5d
#12 sys_ioctl+0x343
#13 syscall+0x279
Lock order reversal between "&mp->mnt_lock"(rwlock) and
"&ip->i_lock"(rrwlock)!
Lock order "&mp->mnt_lock"(rwlock) -> "&ip->i_lock"(rrwlock) first seen at:
#0 witness_checkorder+0x466
#1 _rw_enter+0x56
#2 _rrw_enter+0x32
#3 VOP_LOCK+0x31
#4 vn_lock+0x36
#5 vget+0xba
#6 cache_lookup+0x173
#7 ufs_lookup+0x10e
#8 VOP_LOOKUP+0x33
#9 vfs_lookup+0x26e
#10 namei+0x1eb
#11 ffs_mount+0x111
#12 sys_mount+0x33c
#13 syscall+0x279
Lock order "&ip->i_lock"(rrwlock) -> "&mp->mnt_lock"(rwlock) first seen at:
#0 witness_checkorder+0x466
#1 _rw_enter+0x56
#2 vfs_busy+0x64
#3 vfs_lookup+0x38b
#4 namei+0x1eb
#5 doreadlinkat+0x6d
#6 syscall+0x279
ddb{2}>
ddb{2}> mach ddbcpu 0
Stopped at x86_ipi_db+0x5: popq %rbp
ddb{0}> trace
x86_ipi_db(ffff8000002119e0) at x86_ipi_db+0x5
x86_ipi_handler() at x86_ipi_handler+0x6a
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1f
--- interrupt ---
end of kernel
end trace frame: 0x33a79405c75250cc, count: -3
0x41cb8c419c524153:
ddb{0}> mach ddbcpu 1
Stopped at x86_ipi_db+0x5: popq %rbp
ddb{1}> trace
x86_ipi_db(ffffffff81180405) at x86_ipi_db+0x5
x86_ipi_handler() at x86_ipi_handler+0x6a
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1f
--- interrupt ---
end of kernel
end trace frame: 0x33a79405c75250cc, count: -3
0x41cb8c419c524153:
ddb{1}> mach ddbcpu 3
Stopped at x86_ipi_db+0x5: popq %rbp
ddb{3}> trace
x86_ipi_db(ffffffff81180405) at x86_ipi_db+0x5
x86_ipi_handler() at x86_ipi_handler+0x6a
Xresume_lapic_ipi() at Xresume_lapic_ipi+0x1f
--- interrupt ---
end of kernel
end trace frame: 0x33a79405c75250cc, count: -3
0x41cb8c419c524153:
ddb{3}>
ddb{2}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
72958 123536 58709 676 3 0x82 poll ibus-engine-simp
72958 125540 58709 676 3 0x4000082 poll ibus-engine-simp
72958 115195 58709 676 3 0x4000082 poll ibus-engine-simp
78620 441611 1 694 3 0x82 poll colord
78620 449762 1 694 3 0x4000082 poll colord
78620 349165 1 694 3 0x4000082 fsleep colord
78620 324130 1 694 3 0x4000082 poll colord
25438 164426 1212 676 3 0x82 poll gsd-sound
25438 360495 1212 676 3 0x4000082 poll gsd-sound
25438 478900 1212 676 3 0x4000082 poll gsd-sound
25438 76466 1212 676 3 0x4000082 poll gsd-sound
99876 365932 1212 676 3 0x82 poll gsd-smartcard
99876 371849 1212 676 3 0x4000082 poll gsd-smartcard
99876 229934 1212 676 3 0x4000082 poll gsd-smartcard
99876 55158 1212 676 3 0x4000082 poll gsd-smartcard
99876 263490 1212 676 3 0x4000082 poll gsd-smartcard
48520 241761 1212 676 3 0x82 poll gsd-dummy
48520 6996 1212 676 3 0x4000082 poll gsd-dummy
48520 22377 1212 676 3 0x4000082 poll gsd-dummy
21381 77347 1212 676 3 0x82 poll gsd-screensaver-
21381 472729 1212 676 3 0x4000082 poll gsd-screensaver-
21381 292542 1212 676 3 0x4000082 fsleep gsd-screensaver-
21381 380863 1212 676 3 0x4000082 poll gsd-screensaver-
93505 389702 1212 676 3 0x82 poll gsd-dummy
93505 224307 1212 676 3 0x4000082 poll gsd-dummy
93505 379235 1212 676 3 0x4000082 poll gsd-dummy
6817 75371 1212 676 3 0x82 poll gsd-print-notifi
6817 119479 1212 676 3 0x4000082 poll gsd-print-notifi
6817 157385 1212 676 3 0x4000082 poll gsd-print-notifi
28441 190993 1212 676 3 0x82 poll gsd-power
28441 488131 1212 676 3 0x4000082 poll gsd-power
28441 427054 1212 676 3 0x4000082 fsleep gsd-power
28441 250012 1212 676 3 0x4000082 poll gsd-power
28441 488318 1212 676 3 0x4000082 poll gsd-power
49388 108092 1212 676 3 0x82 poll gsd-mouse
49388 54464 1212 676 3 0x4000082 poll gsd-mouse
49388 172047 1212 676 3 0x4000082 poll gsd-mouse
9782 412711 1212 676 3 0x82 poll gsd-media-keys
9782 477414 1212 676 3 0x4000082 poll gsd-media-keys
9782 508035 1212 676 3 0x4000082 poll gsd-media-keys
9782 246742 1212 676 3 0x4000082 fsleep gsd-media-keys
9782 499170 1212 676 3 0x4000082 poll gsd-media-keys
96348 210430 1212 676 3 0x82 poll gsd-keyboard
96348 336449 1212 676 3 0x4000082 poll gsd-keyboard
96348 319887 1212 676 3 0x4000082 poll gsd-keyboard
96348 408545 1212 676 3 0x4000082 poll gsd-keyboard
96348 412448 1212 676 3 0x4000082 fsleep gsd-keyboard
78533 275422 1212 676 3 0x82 poll gsd-housekeeping
78533 91093 1212 676 3 0x4000082 poll gsd-housekeeping
78533 149099 1212 676 3 0x4000082 fsleep gsd-housekeeping
78533 488926 1212 676 3 0x4000082 poll gsd-housekeeping
38660 316597 1212 676 3 0x82 poll gsd-datetime
38660 199669 1212 676 3 0x4000082 poll gsd-datetime
38660 368587 1212 676 3 0x4000082 poll gsd-datetime
77338 101324 1212 676 3 0x82 poll gsd-color
77338 299012 1212 676 3 0x4000082 poll gsd-color
77338 416768 1212 676 3 0x4000082 poll gsd-color
77338 166981 1212 676 3 0x4000082 poll gsd-color
77338 181138 1212 676 3 0x4000082 fsleep gsd-color
77338 286356 1212 676 3 0x4000082 fsleep gsd-color
71971 410334 1212 676 3 0x82 poll gsd-clipboard
71971 313223 1212 676 3 0x4000082 poll gsd-clipboard
71971 445679 1212 676 3 0x4000082 poll gsd-clipboard
52888 108275 1212 676 3 0x82 poll gsd-a11y-setting
52888 110984 1212 676 3 0x4000082 poll gsd-a11y-setting
52888 429770 1212 676 3 0x4000082 poll gsd-a11y-setting
52888 288567 1212 676 3 0x4000082 poll gsd-a11y-setting
68006 326939 1212 676 3 0x82 poll gsd-a11y-keyboar
68006 17613 1212 676 3 0x4000082 poll gsd-a11y-keyboar
68006 413713 1212 676 3 0x4000082 poll gsd-a11y-keyboar
68006 202552 1212 676 3 0x4000082 poll gsd-a11y-keyboar
85819 482974 1212 676 3 0x82 poll gsd-xsettings
85819 346640 1212 676 3 0x4000082 poll gsd-xsettings
85819 65069 1212 676 3 0x4000082 poll gsd-xsettings
85819 136196 1212 676 3 0x4000082 fsleep gsd-xsettings
85819 18133 1212 676 3 0x4000082 poll gsd-xsettings
62251 145599 1212 676 3 0x82 poll gsd-dummy
62251 478557 1212 676 3 0x4000082 poll gsd-dummy
62251 187423 1212 676 3 0x4000082 poll gsd-dummy
69676 133643 1 731 3 0x82 poll geoclue
69676 86660 1 731 3 0x4000082 poll geoclue
69676 7599 1 731 3 0x4000082 fsleep geoclue
69676 291290 1 731 3 0x4000082 poll geoclue
53862 273064 1 676 3 0x82 poll ibus-x11
53862 488759 1 676 3 0x4000082 poll ibus-x11
53862 269010 1 676 3 0x4000082 poll ibus-x11
23674 1645 58709 676 3 0x82 poll ibus-dconf
23674 368881 58709 676 3 0x4000082 poll ibus-dconf
23674 132030 58709 676 3 0x4000082 poll ibus-dconf
23674 383583 58709 676 3 0x4000082 poll ibus-dconf
58709 135414 79657 676 3 0x82 poll ibus-daemon
58709 376318 79657 676 3 0x4000082 poll ibus-daemon
58709 120777 79657 676 3 0x4000082 fsleep ibus-daemon
58709 4864 79657 676 3 0x4000082 poll ibus-daemon
7065 418532 43036 0 7 0x100002 ctfconv
43036 386481 49019 0 3 0x10008a pause sh
49019 371813 64979 0 3 0x10008a pause sh
89073 181186 1 0 3 0x82 poll upowerd
89073 275410 1 0 3 0x4000082 poll upowerd
89073 235136 1 0 3 0x4000082 poll upowerd
89073 454091 1 0 3 0x4000082 fsleep upowerd
79657 201629 1212 676 3 0x200082 poll gnome-shell
79657 72016 1212 676 3 0x4200082 poll gnome-shell
79657 446640 1212 676 3 0x4200082 poll gnome-shell
79657 427515 1212 676 3 0x4200082 fsleep gnome-shell
79657 47544 1212 676 3 0x4200082 poll gnome-shell
79657 232819 1212 676 3 0x4200082 fsleep gnome-shell
79657 126344 1212 676 3 0x4200082 fsleep gnome-shell
79657 523407 1212 676 3 0x4200082 fsleep gnome-shell
79657 158875 1212 676 3 0x4200082 fsleep gnome-shell
79657 169079 1212 676 3 0x4200082 fsleep gnome-shell
79657 16420 1212 676 3 0x4200082 fsleep gnome-shell
79657 295325 1212 676 3 0x4200082 fsleep gnome-shell
79657 254556 1212 676 3 0x4200082 fsleep gnome-shell
79657 393337 1212 676 3 0x4200082 fsleep gnome-shell
79539 325626 1 676 3 0x82 poll at-spi2-registry
79539 410753 1 676 3 0x4000082 poll at-spi2-registry
79539 412365 1 676 3 0x4000082 poll at-spi2-registry
11879 73478 49592 676 3 0x82 poll dbus-daemon
49592 17342 1 676 3 0x82 poll at-spi-bus-launc
49592 491646 1 676 3 0x4000082 poll at-spi-bus-launc
49592 169000 1 676 3 0x4000082 poll at-spi-bus-launc
49592 271063 1 676 3 0x4000082 fsleep at-spi-bus-launc
49592 258079 1 676 3 0x4000082 poll at-spi-bus-launc
1212 470197 39860 676 3 0x82 poll gnome-session-bi
1212 155045 39860 676 3 0x4000082 poll gnome-session-bi
1212 365128 39860 676 3 0x4000082 poll gnome-session-bi
1212 130866 39860 676 3 0x4000082 poll gnome-session-bi
1212 252803 39860 676 3 0x4000082 fsleep gnome-session-bi
44003 427508 39860 676 3 0x82 poll dbus-daemon
39860 7875 14844 676 3 0x82 wait dbus-run-session
14822 296665 1 0 3 0x82 poll console-kit-daem
14822 377625 1 0 3 0x4000082 poll console-kit-daem
14822 325070 1 0 3 0x4000082 fsleep console-kit-daem
14822 336674 1 0 3 0x4000082 poll console-kit-daem
14822 282269 1 0 3 0x4000082 fsleep console-kit-daem
14844 151532 79098 0 3 0x92 poll gdm-session-work
14844 56457 79098 0 3 0x4000092 poll gdm-session-work
14844 75535 79098 0 3 0x4000092 poll gdm-session-work
64979 241672 85608 0 3 0x10008a pause make
20848 443582 1 0 3 0x100083 ttyin getty
56650 168387 1 0 3 0x100083 ttyin getty
98582 81470 1 0 3 0x100083 ttyin getty
64919 183721 1 0 3 0x100083 ttyin getty
4502 509093 1 0 3 0x100083 ttyin getty
86360 347031 1 0 3 0x100083 ttyin getty
85608 292092 1 0 3 0x10008b pause ksh
15334 86887 1 0 3 0x100098 poll cron
60844 453844 91676 0 3 0x1000b0 netio Xorg
*91676 413737 79098 35 7 0x32 wseq Xorg
91676 220582 79098 35 3 0x40000b2 poll Xorg
42712 142257 1 701 3 0x92 poll polkitd
42712 513035 1 701 3 0x4000092 poll polkitd
42712 39527 1 701 3 0x4000092 poll polkitd
42712 52275 1 701 3 0x4000092 fsleep polkitd
42712 311541 1 701 3 0x4000092 fsleep polkitd
42712 395421 1 701 3 0x4000092 poll polkitd
42712 239297 1 701 3 0x4000092 fsleep polkitd
45808 457886 1 0 3 0x82 poll accounts-daemon
45808 184767 1 0 3 0x4000082 poll accounts-daemon
45808 391931 1 0 3 0x4000082 fsleep accounts-daemon
45808 274081 1 0 3 0x4000082 poll accounts-daemon
79098 343496 1 0 3 0x83 poll gdm
79098 298341 1 0 3 0x4000083 poll gdm
79098 213419 1 0 3 0x4000083 poll gdm
79098 203283 1 0 3 0x4000083 fsleep gdm
34802 156253 1 629 3 0x90 poll avahi-daemon
88879 429050 1 572 3 0x90 poll dbus-daemon
57203 193395 1 99 3 0x100090 poll sndiod
48063 223977 1 110 3 0x100090 poll sndiod
35268 869 34250 95 3 0x100092 kqread smtpd
24400 150469 34250 103 3 0x100092 kqread smtpd
17611 132809 34250 95 3 0x100092 kqread smtpd
29894 331861 34250 95 3 0x100092 kqread smtpd
92927 465785 34250 95 3 0x100092 kqread smtpd
17181 426042 34250 95 3 0x100092 kqread smtpd
34250 184915 1 0 3 0x100080 kqread smtpd
21062 476711 1 0 3 0x80 select sshd
95954 492377 92910 83 3 0x100092 poll ntpd
92910 300896 59001 83 3 0x100092 poll ntpd
59001 182754 1 0 3 0x100080 poll ntpd
2376 191370 2809 74 3 0x100092 bpf pflogd
2809 491105 1 0 3 0x80 netio pflogd
51264 193214 40415 73 2 0x100090 syslogd
40415 404988 1 0 3 0x100082 netio syslogd
91333 480479 84928 115 3 0x100092 kqread slaacd
38730 319086 84928 115 3 0x100092 kqread slaacd
84928 445617 1 0 3 0x80 kqread slaacd
66268 278240 0 0 3 0x14200 pgzero zerothread
43124 441511 0 0 3 0x14200 aiodoned aiodoned
54734 423548 0 0 3 0x14200 syncer update
53403 18496 0 0 3 0x14200 cleaner cleaner
7644 498111 0 0 3 0x14200 reaper reaper
68396 139613 0 0 3 0x14200 pgdaemon pagedaemon
77795 58116 0 0 3 0x14200 bored crynlk
62682 287849 0 0 3 0x14200 bored crypto
52905 205709 0 0 3 0x14200 usbtsk usbtask
10324 423902 0 0 3 0x14200 usbatsk usbatsk
99159 22150 0 0 3 0x14200 bored i915-hangcheck
32794 28405 0 0 3 0x14200 bored i915-dp
77301 78101 0 0 3 0x14200 bored i915
92050 377007 0 0 3 0x40014200 acpi0 acpi0
4944 295517 0 0 7 0x40014200 idle3
39844 387911 0 0 3 0x40014200 idle2
70304 493125 0 0 3 0x40014200 idle1
25039 162102 0 0 3 0x14200 bored sensors
17697 262091 0 0 3 0x14200 bored softnet
48945 151742 0 0 3 0x14200 bored systqmp
7639 327165 0 0 3 0x14200 bored systq
99891 300726 0 0 3 0x40014200 bored softclock
5535 445837 0 0 7 0x40014200 idle0
1 511887 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{2}>
