Subject: Bug#983466: linux-image-5.10.0-3-686-pae: Black screen at dual monitor with warn from i915_gem_ww_ctx_backoff

From: Gert van de Kraats <[email-masked]>
Date: Wed, 24 Feb 2021 17:52:42 +0100

Package: src:linux
Version: 5.10.13-1
Severity: normal
Tags: upstream

Dear Maintainer,

I am running Debian bullseye with wayland on dual monitor, above each 
other.
I use package dash-to-dock version 69 (newest).

At each dock there are 13 buttons defined to startup applications; each 
monitor
has it's own dock copy.
Black screen appears if button "Show Applications" to show the 
applications is
clicked the third time,
  to show the applications for the second time (the button is a toggle to
show/hide applications).
Gnome-shell is terminating with error "intel_do_flush_locked failed: 
Invalid
argument".

Problem started probably at 29-01-2021 with updates to Linux debian
5.10.0-2-686-pae, and gnome-shell/mutter to i386 3.38.3-1.
I reported a bug on dash-to-dock at https://github.com/micheleg/dash-to-
dock/issues/1383,
because there were some new errors at syslog, which only were present if 
dash-
to-dock was used.
Also the error-text "Invalid argument" suggests there is some 
application error
at the call of "intel_do_flush_locked".
Below is the syslog of the problem:

Feb 19 00:47:56 debian gnome-shell[8067]: intel_do_flush_locked failed: 
Invalid
argument
Feb 19 00:47:56 debian kernel: [22326.421460] ------------[ cut here
]------------
Feb 19 00:47:56 debian kernel: [22326.421468] WARN_ON(!ww->contended)
Feb 19 00:47:56 debian kernel: [22326.421655] WARNING: CPU: 0 PID: 8067 at
drivers/gpu/drm/i915/i915_gem.c:1359 i915_gem_ww_ctx_backoff+0xaf/0xc0 
[i915]
Feb 19 00:47:56 debian kernel: [22326.421660] Modules linked in: ctr
aes_generic libaes crypto_simd cryptd ccm squashfs loop uinput binfmt_misc
snd_hda_codec_hdmi snd_hda_codec_idt snd_hda_codec_generic snd_hda_intel
snd_intel_dspcfg b43 soundwire_intel cordic soundwire_generic_allocation 
bcma
snd_soc_core dell_rbtn mac80211 snd_compress dell_laptop cfg80211
soundwire_cadence ledtrig_audio snd_hda_codec rfkill coretemp snd_hda_core
libarc4 soundwire_bus kvm_intel dell_smbios snd_hwdep kvm 
dell_wmi_descriptor
snd_pcm wmi dcdbas irqbypass iTCO_wdt dell_smm_hwmon snd_timer joydev
intel_pmc_bxt snd serio_raw iTCO_vendor_support pcspkr yenta_socket 
soundcore
pcmcia_rsrc watchdog sg evdev ac rng_core acpi_cpufreq videodev mc 
parport_pc
ppdev lp parport fuse configfs ip_tables x_tables autofs4 ext4 crc16 
mbcache
jbd2 crc32c_generic hid_generic usbhid hid sd_mod sr_mod t10_pi crc_t10dif
cdrom crct10dif_generic crct10dif_common ata_generic i915 i2c_algo_bit ssb
ata_piix mmc_core uhci_hcd drm_kms_helper libata psmouse scsi_mod
Feb 19 00:47:56 debian kernel: [22326.421879]  i2c_i801 i2c_smbus ehci_pci
pcmcia lpc_ich ehci_hcd usbcore tg3 libphy cec ptp usb_common pps_core drm
pcmcia_core button battery video
Feb 19 00:47:56 debian kernel: [22326.421929] CPU: 0 PID: 8067 Comm: gnome-
shell Not tainted 5.10.0-3-686-pae #1 Debian 5.10.13-1
Feb 19 00:47:56 debian kernel: [22326.421933] Hardware name: Dell Inc. 
Latitude
D620                   /0TD761, BIOS A02 04/11/2006
Feb 19 00:47:56 debian kernel: [22326.422025] EIP:
i915_gem_ww_ctx_backoff+0xaf/0xc0 [i915]
Feb 19 00:47:56 debian kernel: [22326.422033] Code: 00 00 00 8b 43 1c 89 
da 8b
80 98 00 00 00 e8 28 41 86 e0 85 c0 74 9a eb d5 66 90 68 30 88 09 f8 68 
2d 88
09 f8 e8 60 f0 82 e0 <0f> 0b 58 5a 8d 65 f4 b8 ea ff ff ff 5b 5e 5f 5d 
c3 3e 8d
74 26 00
Feb 19 00:47:56 debian kernel: [22326.422038] EAX: 00000017 EBX: 
00000000 ECX:
f6fc2180 EDX: ffffffd8
Feb 19 00:47:56 debian kernel: [22326.422042] ESI: 00000000 EDI: 
f4827cd0 EBP:
f4827c74 ESP: f4827c58
Feb 19 00:47:56 debian kernel: [22326.422048] DS: 007b ES: 007b FS: 00d8 
GS:
00e0 SS: 0068 EFLAGS: 00010296
Feb 19 00:47:56 debian kernel: [22326.422053] CR0: 80050033 CR2: 
534d9e18 CR3:
2ce1a000 CR4: 000006f0
Feb 19 00:47:56 debian kernel: [22326.422056] Call Trace:
Feb 19 00:47:56 debian kernel: [22326.422151]
i915_gem_do_execbuffer+0x10b9/0x1e10 [i915]
Feb 19 00:47:56 debian kernel: [22326.422163]  ?
dma_fence_signal_locked+0x40/0xd0
Feb 19 00:47:56 debian kernel: [22326.422263]
i915_gem_execbuffer2_ioctl+0xcb/0x1e0 [i915]
Feb 19 00:47:56 debian kernel: [22326.422352]  ?
i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Feb 19 00:47:56 debian kernel: [22326.422376] drm_ioctl_kernel+0x99/0xe0 
[drm]
Feb 19 00:47:56 debian kernel: [22326.422463]  ?
i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Feb 19 00:47:56 debian kernel: [22326.422486] drm_ioctl+0x21b/0x390 [drm]
Feb 19 00:47:56 debian kernel: [22326.422572]  ?
i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Feb 19 00:47:56 debian kernel: [22326.422587]  ? 
tomoyo_path_chmod+0x20/0x20
Feb 19 00:47:56 debian kernel: [22326.422592]  ? 
tomoyo_file_ioctl+0x17/0x20
Feb 19 00:47:56 debian kernel: [22326.422599]  ? 
security_file_ioctl+0x30/0x50
Feb 19 00:47:56 debian kernel: [22326.422621]  ? drm_ioctl_kernel+0xe0/0xe0
[drm]
Feb 19 00:47:56 debian kernel: [22326.422629] __ia32_sys_ioctl+0x145/0x760
Feb 19 00:47:56 debian kernel: [22326.422638]  ? 
tick_program_event+0x41/0xa0
Feb 19 00:47:56 debian kernel: [22326.422646]  ? 
hrtimer_interrupt+0x142/0x260
Feb 19 00:47:56 debian kernel: [22326.422654]  ?
exit_to_user_mode_prepare+0x2e/0x100
Feb 19 00:47:56 debian kernel: [22326.422662] 
__do_fast_syscall_32+0x45/0x80
Feb 19 00:47:56 debian kernel: [22326.422667] do_fast_syscall_32+0x29/0x60
Feb 19 00:47:56 debian kernel: [22326.422672] do_SYSENTER_32+0x15/0x20
Feb 19 00:47:56 debian kernel: [22326.422678] entry_SYSENTER_32+0x9f/0xf2
Feb 19 00:47:56 debian kernel: [22326.422684] EIP: 0xb7fa6559
Feb 19 00:47:56 debian kernel: [22326.422691] Code: 03 74 c0 01 10 05 03 
74 b8
01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 
51 52
55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 
00 cd 80
90 8d 76
Feb 19 00:47:56 debian kernel: [22326.422696] EAX: ffffffda EBX: 
00000009 ECX:
c0406469 EDX: bff99c2c
Feb 19 00:47:56 debian kernel: [22326.422700] ESI: 02890dc0 EDI: 
c0406469 EBP:
00000009 ESP: bff99b98
Feb 19 00:47:56 debian kernel: [22326.422705] DS: 007b ES: 007b FS: 0000 
GS:
0033 SS: 007b EFLAGS: 00000292
Feb 19 00:47:56 debian kernel: [22326.422713]  ? asm_exc_nmi+0xc5/0x2ab
Feb 19 00:47:56 debian kernel: [22326.422717] ---[ end trace 
83a8cc2040a339f1
]---

The strace for gnom-shell shows:
14:29:04 getpid()                       = 32522
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_PWRITE,
0xbfdc548c) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>,
DRM_IOCTL_I915_GEM_EXECBUFFER2_WR, 0xbfdc546c) = 0
14:29:04 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=26187, 
tv_nsec=194820832}) =
0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_MADVISE,
0xbfdc5430) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_MADVISE,
0xbfdc5470) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_BUSY,
0xbfdc5444) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_MADVISE,
0xbfdc54ac) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, 
DRM_IOCTL_I915_GEM_SET_DOMAIN,
0xbfdc5490) = 0
14:29:04 clock_gettime64(CLOCK_MONOTONIC, {tv_sec=26187, 
tv_nsec=195786872}) =
0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_MADVISE,
0xbfdc5420) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_MADVISE,
0xbfdc5460) = 0
14:29:04 getpid()                       = 32522
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>, DRM_IOCTL_I915_GEM_PWRITE,
0xbfdc291c) = 0
14:29:04 ioctl(9</dev/dri/card0<char 226:0>>,
DRM_IOCTL_I915_GEM_EXECBUFFER2_WR, 0xbfdc28fc) = -1 EINVAL (Invalid 
argument)
14:29:04 write(2<UNIX:[336876->336877]>, "intel_do_flush_locked failed: 
Invalid
argument\n", 47) = 47
14:29:04 close(13</dev/dri/card0<char 226:0>>) = 0

At libdrm-2.4.104/intel/intel_bufmgr_gem.c routine do_exec2 I added a 
call to
drm_intel_gem_dump_validation_list(bufmgr_gem) at the error-situation, 
which
shows the buffer:

Feb 22 12:54:53 debian gnome-shell[1475]:  GK_do_exec2 failed: Invalid 
argument
Feb 22 12:54:53 debian gnome-shell[1475]:  0: 68 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  1: 71 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  2: 73 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  3: 75 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  4: 77 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  5: 79 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  6: 81 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  7: 83 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  8: 85 (region)
Feb 22 12:54:53 debian gnome-shell[1475]:  9: 87 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 10: 89 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 11: 91 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 12: 93 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 13: 95 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 14: 98 (region)
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000010 -> 68 (region)@0x00000000 05a00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000030 -> 71 (region)@0x00000000 05d00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000050 -> 73 (region)@0x00000000 05f00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000070 -> 75 (region)@0x00000000 06900000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000090 -> 77 (region)@0x00000000 06b00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
000000b0 -> 79 (region)@0x00000000 06d00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
000000d0 -> 81 (region)@0x00000000 06f00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
000000f0 -> 83 (region)@0x00000000 07100000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000110 -> 85 (region)@0x00000000 07300000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000130 -> 87 (region)@0x00000000 07500000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000150 -> 89 (region)@0x00000000 07700000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000170 -> 91 (region)@0x00000000 07900000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
00000190 -> 93 (region)@0x00000000 07b00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
000001b0 -> 95 (region)@0x00000000 07d00000 + 0x00000000
Feb 22 12:54:53 debian gnome-shell[1475]: 15: 29 (batchbuffer)@0x00000000
000001d0 -> 98 (region)@0x00000000 07f00000 + 0x00000000

Notice the 15 regions, where 14 is the limit set at
libdrm-2.4.104/intel/intel_bufmgr_gem.c.

I forced an abort to get a stacktrace which showed the last call to
intel_batchbuffer_flush was from intelClearWithBlit.

I added a line to  routine intelClearWithBlit at
mesa-20.3.4/src/mesa/drivers/dri/i915/intel_blit.c to show it's name just
before the call to drm_intel_bufmgr_check_aperture_space and displayed the
number of fences at routine drm_intel_gem_total_fences at
libdrm-2.4.104/intel/intel_bufmgr_gem.c.

This gives the next messages at the error-situation:
Feb 22 20:09:51 debian gnome-shell[1468]: 13
Feb 22 20:09:51 debian gnome-shell[1468]: 13 0
Feb 22 20:09:51 debian gnome-shell[1468]: 13 0 1 1
Feb 22 20:09:51 debian gnome-shell[1468]: 0 0 1 1
Feb 22 20:09:51 debian gnome-shell[1468]: 2
Feb 22 20:09:51 debian gnome-shell[1468]: 2 0
Feb 22 20:09:51 debian gnome-shell[1468]: 2 0 1 1
Feb 22 20:09:51 debian gnome-shell[1468]: 4
Feb 22 20:09:51 debian gnome-shell[1468]: 4 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 0 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 1 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 2 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 3 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 4 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 5 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 6 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 7 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 8 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 9 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 10 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 11 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 12 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 13 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 14 0
Feb 22 20:09:51 debian gnome-shell[1468]: GK_intelClearWithBlit_fences 15 0
Feb 22 20:09:51 debian gnome-shell[1468]:  GK_do_exec2 failed: Invalid 
argument

Normally the first column is the sum of all columns of the previous line.
If this sum > 14 then a buffer flush is done and the first column is 
reset to
zero.
This doesnot happen at intelClearWithBlit. Here the second column is zero
but at the next line somehow the first column is incremented by 1.
Zero fence registers are reserved, but 1 fence register is used.
This causes a buffer flush, which comes too late, because 15 
fence-registers
are needed

If the allowed number of fences is lowered to 13 at
libdrm-2.4.104/intel/intel_bufmgr_gem.c, then the problem disappears.
We see the messages:
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 0 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 1 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 2 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 3 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 4 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 5 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 6 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 7 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 8 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 9 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 10 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 11 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 12 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 13 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 14 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 1 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 2 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 3 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 4 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 5 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 6 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 7 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 8 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 9 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 10 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 11 0
Feb 22 21:04:40 debian gnome-shell[1476]: GK_intelClearWithBlit_fences 12 1
Feb 22 21:04:40 debian gnome-shell[1476]: 13 1 1

Next exmple of messages also is interesting:

Feb 22 20:19:06 debian gnome-shell[2412]: 11 0 1
Feb 22 20:19:06 debian gnome-shell[2412]: 12
Feb 22 20:19:06 debian gnome-shell[2412]: 12 0
Feb 22 20:19:06 debian gnome-shell[2412]: 12 0
Feb 22 20:19:06 debian gnome-shell[2412]: 12
Feb 22 20:19:06 debian gnome-shell[2412]: 12 0
Feb 22 20:19:06 debian gnome-shell[2412]: GK_intelClearWithBlit_fences 12 1
Feb 22 20:19:06 debian gnome-shell[2412]: GK_intelClearWithBlit_fences 13 1
Feb 22 20:19:06 debian gnome-shell[2412]: GK_intelClearWithBlit_fences 14 0
Feb 22 20:19:06 debian gnome-shell[2412]: 15 1 1 1
Feb 22 20:19:06 debian gnome-shell[2412]: 0 1 1 1

It shows:
1 intelClearWithBlit sometimes correctly reserves 1 fence register
2 usage of the 15th register  not always causes a failure.
   The failure specially occurs if intelClearWithBlit does use this 
register.

The bug at intel_blit.c is not new. I already had troubles with this bug at
Ubuntu 3 years ago (see 
https://gitlab.freedesktop.org/mesa/mesa/-/issues/790
), but then the bug disappeared by some other modification.

This time it looks like a new problem at kernel driver:
drivers/gpu/drm/i915/i915_gem.c:1359 .

-- Package-specific info:
** Version:
Linux version 5.10.0-3-686-pae ([email-masked]) (gcc-10 
(Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 
2.35.1) #1 SMP Debian 5.10.13-1 (2021-02-06)

** Command line:
BOOT_IMAGE=/boot/vmlinuz-5.10.0-3-686-pae 
root=UUID=46142e97-4b97-48c7-b38f-d6342ed9d4a8 ro 
resume=UUID=8abdc6ff-87d0-4e60-9b78-7e23b6fb8dc7 quiet splash

** Not tainted

** Kernel log:
[  856.064453] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[  856.067210] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[  856.067671] wlan0: associated
[  856.102197] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  901.005098] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[  901.256472] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1105.428534] b43-phy0: Radio hardware status changed to DISABLED
[ 1110.556555] b43-phy0: Radio hardware status changed to ENABLED
[ 1110.740552] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1138.812544] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1140.431756] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1140.460609] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1140.462633] wlan0: authenticated
[ 1140.472408] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1140.475181] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[ 1140.475627] wlan0: associated
[ 1140.510123] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1186.007568] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[ 1186.288428] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1189.915735] EXT4-fs (sda5): mounted filesystem with ordered data 
mode. Opts: (null)
[ 1203.560492] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1205.169157] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1205.204731] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1205.206904] wlan0: authenticated
[ 1205.216463] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1205.219410] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[ 1205.219858] wlan0: associated
[ 1205.244998] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1251.006280] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[ 1251.276420] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1254.456439] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1256.025027] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1256.052694] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1256.054589] wlan0: authenticated
[ 1256.068413] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1256.071181] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[ 1256.071648] wlan0: associated
[ 1256.096946] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1301.009555] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[ 1301.264453] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1305.660549] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1307.229341] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1307.256545] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1307.259341] wlan0: authenticated
[ 1307.265649] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1307.270926] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[ 1307.271376] wlan0: associated
[ 1307.308333] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1353.007963] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[ 1353.276440] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1356.404504] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1358.002860] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1358.020742] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1358.022476] wlan0: authenticated
[ 1358.024933] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1358.027808] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x11 
status=0 aid=4)
[ 1358.028256] wlan0: associated
[ 1358.061339] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1403.006385] wlan0: deauthenticating from 38:60:77:e2:10:d3 by local 
choice (Reason: 3=DEAUTH_LEAVING)
[ 1403.272458] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1704.248466] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1705.860809] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1705.896563] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1705.898678] wlan0: authenticated
[ 1705.900507] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1705.907078] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x411 
status=0 aid=3)
[ 1705.920488] wlan0: associated
[ 1705.943671] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1749.312878] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1749.344612] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1749.548500] wlan0: send auth to 38:60:77:e2:10:d3 (try 2/3)
[ 1749.752473] wlan0: send auth to 38:60:77:e2:10:d3 (try 3/3)
[ 1749.960539] wlan0: authentication with 38:60:77:e2:10:d3 timed out
[ 1751.276490] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1841.652507] b43-phy0: Loading firmware version 666.2 (2011-02-23 
01:15:07)
[ 1843.274384] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1843.320598] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1843.322407] wlan0: authenticated
[ 1843.324696] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1843.335000] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x411 
status=0 aid=2)
[ 1843.335445] wlan0: associated
[ 1843.384471] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1886.332157] wlan0: deauthenticated from 38:60:77:e2:10:d3 (Reason: 
7=CLASS3_FRAME_FROM_NONASSOC_STA)
[ 1886.397907] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1886.424724] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1886.426692] wlan0: authenticated
[ 1886.428442] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1886.636469] wlan0: associate with 38:60:77:e2:10:d3 (try 2/3)
[ 1886.840450] wlan0: associate with 38:60:77:e2:10:d3 (try 3/3)
[ 1887.048477] wlan0: association with 38:60:77:e2:10:d3 timed out
[ 1888.888553] wlan0: authenticate with 38:60:77:e2:10:d3
[ 1888.916697] wlan0: send auth to 38:60:77:e2:10:d3 (try 1/3)
[ 1888.923670] wlan0: authenticated
[ 1888.932450] wlan0: associate with 38:60:77:e2:10:d3 (try 1/3)
[ 1888.938279] wlan0: RX AssocResp from 38:60:77:e2:10:d3 (capab=0x411 
status=0 aid=1)
[ 1888.938720] wlan0: associated
[ 3388.312202] systemd-journald[207]: Retention time reached.
[ 3448.642510] systemd-journald[207]: Retention time reached.
[ 4032.908473] perf: interrupt took too long (2507 > 2500), lowering 
kernel.perf_event_max_sample_rate to 79750
[ 5947.753770] perf: interrupt took too long (3151 > 3133), lowering 
kernel.perf_event_max_sample_rate to 63250

** Model information

** Loaded modules:
ctr
aes_generic
libaes
crypto_simd
cryptd
ccm
squashfs
loop
uinput
binfmt_misc
b43
cordic
bcma
mac80211
dell_rbtn
snd_hda_codec_hdmi
snd_hda_codec_idt
cfg80211
dell_laptop
snd_hda_codec_generic
ledtrig_audio
snd_hda_intel
libarc4
rfkill
snd_intel_dspcfg
soundwire_intel
soundwire_generic_allocation
snd_soc_core
dell_smbios
coretemp
snd_compress
dell_wmi_descriptor
iTCO_wdt
kvm_intel
soundwire_cadence
wmi
intel_pmc_bxt
snd_hda_codec
dcdbas
snd_hda_core
soundwire_bus
kvm
snd_hwdep
iTCO_vendor_support
yenta_socket
dell_smm_hwmon
pcspkr
irqbypass
watchdog
pcmcia_rsrc
joydev
sg
snd_pcm
snd_timer
serio_raw
snd
soundcore
evdev
ac
rng_core
acpi_cpufreq
videodev
mc
parport_pc
ppdev
lp
parport
fuse
configfs
ip_tables
x_tables
autofs4
ext4
crc16
mbcache
jbd2
crc32c_generic
hid_generic
usbhid
hid
sr_mod
sd_mod
t10_pi
cdrom
crc_t10dif
crct10dif_generic
crct10dif_common
ata_generic
i915
i2c_algo_bit
drm_kms_helper
ata_piix
cec
libata
tg3
ssb
drm
ehci_pci
libphy
mmc_core
uhci_hcd
psmouse
scsi_mod
ehci_hcd
usbcore
i2c_i801
i2c_smbus
lpc_ich
pcmcia
ptp
pps_core
pcmcia_core
usb_common
button
battery
video

** PCI devices:
00:00.0 Host bridge [0600]: Intel Corporation Mobile 945GM/PM/GMS, 
943/940GML and 945GT Express Memory Controller Hub [8086:27a0] (rev 03)
     Subsystem: Dell Mobile 945GM/PM/GMS, 943/940GML and 945GT Express 
Memory Controller Hub [1028:01c2]
     Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort+ >SERR- <PERR- INTx-
     Latency: 0
     Capabilities: <access denied>

00:02.0 VGA compatible controller [0300]: Intel Corporation Mobile 
945GM/GMS, 943/940GML Express Integrated Graphics Controller [8086:27a2] 
(rev 03) (prog-if 00 [VGA controller])
     Subsystem: Dell Mobile 945GM/GMS, 943/940GML Express Integrated 
Graphics Controller [1028:01c2]
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin A routed to IRQ 16
     Region 0: Memory at dff00000 (32-bit, non-prefetchable) [size=512K]
     Region 1: I/O ports at eff8 [size=8]
     Region 2: Memory at c0000000 (32-bit, prefetchable) [size=256M]
     Region 3: Memory at dfec0000 (32-bit, non-prefetchable) [size=256K]
     Expansion ROM at 000c0000 [virtual] [disabled] [size=128K]
     Capabilities: <access denied>
     Kernel driver in use: i915
     Kernel modules: i915

00:02.1 Display controller [0380]: Intel Corporation Mobile 
945GM/GMS/GME, 943/940GML Express Integrated Graphics Controller 
[8086:27a6] (rev 03)
     Subsystem: Dell Mobile 945GM/GMS/GME, 943/940GML Express Integrated 
Graphics Controller [1028:01c2]
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Region 0: Memory at dff80000 (32-bit, non-prefetchable) [size=512K]
     Capabilities: <access denied>

00:1b.0 Audio device [0403]: Intel Corporation NM10/ICH7 Family High 
Definition Audio Controller [8086:27d8] (rev 01)
     Subsystem: Dell NM10/ICH7 Family High Definition Audio Controller 
[1028:01c2]
     Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx+
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin A routed to IRQ 27
     Region 0: Memory at dfebc000 (64-bit, non-prefetchable) [size=16K]
     Capabilities: <access denied>
     Kernel driver in use: snd_hda_intel
     Kernel modules: snd_hda_intel

00:1c.0 PCI bridge [0604]: Intel Corporation NM10/ICH7 Family PCI 
Express Port 1 [8086:27d0] (rev 01) (prog-if 00 [Normal decode])
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx+
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin A routed to IRQ 24
     Bus: primary=00, secondary=0b, subordinate=0b, sec-latency=0
     I/O behind bridge: 00002000-00002fff [size=4K]
     Memory behind bridge: 94000000-941fffff [size=2M]
     Prefetchable memory behind bridge: 
0000000094200000-00000000943fffff [size=2M]
     Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort+ <SERR- <PERR-
     BridgeCtl: Parity- SERR+ NoISA- VGA- VGA16- MAbort- >Reset- FastB2B-
         PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
     Capabilities: <access denied>
     Kernel driver in use: pcieport

00:1c.1 PCI bridge [0604]: Intel Corporation NM10/ICH7 Family PCI 
Express Port 2 [8086:27d2] (rev 01) (prog-if 00 [Normal decode])
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx+
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin B routed to IRQ 25
     Bus: primary=00, secondary=0c, subordinate=0c, sec-latency=0
     I/O behind bridge: 00003000-00003fff [size=4K]
     Memory behind bridge: dfd00000-dfdfffff [size=1M]
     Prefetchable memory behind bridge: 
0000000094400000-00000000945fffff [size=2M]
     Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- <SERR- <PERR-
     BridgeCtl: Parity- SERR+ NoISA- VGA- VGA16- MAbort- >Reset- FastB2B-
         PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
     Capabilities: <access denied>
     Kernel driver in use: pcieport

00:1c.2 PCI bridge [0604]: Intel Corporation NM10/ICH7 Family PCI 
Express Port 3 [8086:27d4] (rev 01) (prog-if 00 [Normal decode])
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx+
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin C routed to IRQ 26
     Bus: primary=00, secondary=09, subordinate=09, sec-latency=0
     I/O behind bridge: 00004000-00004fff [size=4K]
     Memory behind bridge: dfc00000-dfcfffff [size=1M]
     Prefetchable memory behind bridge: 
0000000094600000-00000000947fffff [size=2M]
     Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- <SERR- <PERR-
     BridgeCtl: Parity- SERR+ NoISA- VGA- VGA16- MAbort- >Reset- FastB2B-
         PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
     Capabilities: <access denied>
     Kernel driver in use: pcieport

00:1d.0 USB controller [0c03]: Intel Corporation NM10/ICH7 Family USB 
UHCI Controller #1 [8086:27c8] (rev 01) (prog-if 00 [UHCI])
     Subsystem: Dell NM10/ICH7 Family USB UHCI Controller [1028:01c2]
     Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin A routed to IRQ 20
     Region 4: I/O ports at bf80 [size=32]
     Kernel driver in use: uhci_hcd
     Kernel modules: uhci_hcd

00:1d.1 USB controller [0c03]: Intel Corporation NM10/ICH7 Family USB 
UHCI Controller #2 [8086:27c9] (rev 01) (prog-if 00 [UHCI])
     Subsystem: Dell NM10/ICH7 Family USB UHCI Controller [1028:01c2]
     Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin B routed to IRQ 21
     Region 4: I/O ports at bf60 [size=32]
     Kernel driver in use: uhci_hcd
     Kernel modules: uhci_hcd

00:1d.2 USB controller [0c03]: Intel Corporation NM10/ICH7 Family USB 
UHCI Controller #3 [8086:27ca] (rev 01) (prog-if 00 [UHCI])
     Subsystem: Dell NM10/ICH7 Family USB UHCI Controller [1028:01c2]
     Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin C routed to IRQ 22
     Region 4: I/O ports at bf40 [size=32]
     Kernel driver in use: uhci_hcd
     Kernel modules: uhci_hcd

00:1d.3 USB controller [0c03]: Intel Corporation NM10/ICH7 Family USB 
UHCI Controller #4 [8086:27cb] (rev 01) (prog-if 00 [UHCI])
     Subsystem: Dell NM10/ICH7 Family USB UHCI Controller [1028:01c2]
     Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin D routed to IRQ 23
     Region 4: I/O ports at bf20 [size=32]
     Kernel driver in use: uhci_hcd
     Kernel modules: uhci_hcd

00:1d.7 USB controller [0c03]: Intel Corporation NM10/ICH7 Family USB2 
EHCI Controller [8086:27cc] (rev 01) (prog-if 20 [EHCI])
     Subsystem: Dell NM10/ICH7 Family USB2 EHCI Controller [1028:01c2]
     Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin A routed to IRQ 20
     Region 0: Memory at ffa80000 (32-bit, non-prefetchable) [size=1K]
     Capabilities: <access denied>
     Kernel driver in use: ehci-pci
     Kernel modules: ehci_pci

00:1e.0 PCI bridge [0604]: Intel Corporation 82801 Mobile PCI Bridge 
[8086:2448] (rev e1) (prog-if 01 [Subtractive decode])
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Bus: primary=00, secondary=03, subordinate=04, sec-latency=32
     I/O behind bridge: 00005000-00005fff [size=4K]
     Memory behind bridge: 80000000-93ffffff [size=320M]
     Prefetchable memory behind bridge: [disabled]
     Secondary status: 66MHz- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort+ <SERR- <PERR-
     BridgeCtl: Parity- SERR+ NoISA- VGA- VGA16- MAbort- >Reset- FastB2B-
         PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
     Capabilities: <access denied>

00:1f.0 ISA bridge [0601]: Intel Corporation 82801GBM (ICH7-M) LPC 
Interface Bridge [8086:27b9] (rev 01)
     Subsystem: Dell 82801GBM (ICH7-M) LPC Interface Bridge [1028:01c2]
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Capabilities: <access denied>
     Kernel driver in use: lpc_ich
     Kernel modules: intel_rng, lpc_ich, leds_ss4200

00:1f.2 IDE interface [0101]: Intel Corporation 82801GBM/GHM (ICH7-M 
Family) SATA Controller [IDE mode] [8086:27c4] (rev 01) (prog-if 80 [ISA 
Compatibility mode-only controller, supports bus mastering])
     Subsystem: Dell 82801GBM/GHM (ICH7-M Family) SATA Controller [IDE 
mode] [1028:01c2]
     Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR- FastB2B- DisINTx-
     Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0
     Interrupt: pin B routed to IRQ 17
     Region 0: I/O ports at 01f0 [size=8]
     Region 1: I/O ports at 03f4
     Region 2: I/O ports at 0170 [size=8]
     Region 3: I/O ports at 0374
     Region 4: I/O ports at bfa0 [size=16]
     Capabilities: <access denied>
     Kernel driver in use: ata_piix
     Kernel modules: ata_piix, ata_generic

00:1f.3 SMBus [0c05]: Intel Corporation NM10/ICH7 Family SMBus 
Controller [8086:27da] (rev 01)
     Subsystem: Dell NM10/ICH7 Family SMBus Controller [1028:01c2]
     Control: I/O+ Mem- BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx-
     Status: Cap- 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Interrupt: pin B routed to IRQ 17
     Region 4: I/O ports at 10c0 [size=32]
     Kernel driver in use: i801_smbus
     Kernel modules: i2c_i801

03:01.0 CardBus bridge [0607]: O2 Micro, Inc. OZ601/6912/711E0 
CardBus/SmartCardBus Controller [1217:6972] (rev 40)
     Subsystem: Dell OZ601/6912/711E0 CardBus/SmartCardBus Controller 
[1028:01c2]
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping+ SERR- FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=slow >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 168
     Interrupt: pin A routed to IRQ 18
     Region 0: Memory at 80000000 (32-bit, non-prefetchable) [size=4K]
     Bus: primary=03, secondary=04, subordinate=04, sec-latency=176
     Memory window 0: 84000000-87ffffff (prefetchable)
     Memory window 1: 88000000-8bffffff
     I/O window 0: 00005000-000050ff
     I/O window 1: 00005400-000054ff
     BridgeCtl: Parity- SERR- ISA- VGA- MAbort- >Reset- 16bInt+ PostWrite+
     16-bit legacy interface ports at 0001
     Capabilities: <access denied>
     Kernel driver in use: yenta_cardbus
     Kernel modules: yenta_socket

09:00.0 Ethernet controller [0200]: Broadcom Inc. and subsidiaries 
NetXtreme BCM5752 Gigabit Ethernet PCI Express [14e4:1600] (rev 02)
     Subsystem: Dell Latitude D620 [1028:01c2]
     Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx+
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin A routed to IRQ 28
     Region 0: Memory at dfcf0000 (64-bit, non-prefetchable) [size=64K]
     Expansion ROM at <ignored> [disabled]
     Capabilities: <access denied>
     Kernel driver in use: tg3
     Kernel modules: tg3

0c:00.0 Network controller [0280]: Broadcom Inc. and subsidiaries 
BCM4311 802.11a/b/g [14e4:4312] (rev 01)
     Subsystem: Dell Wireless 1490 Dual Band WLAN Mini-Card [1028:0007]
     Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- 
Stepping- SERR+ FastB2B- DisINTx-
     Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- 
<TAbort- <MAbort- >SERR- <PERR- INTx-
     Latency: 0, Cache Line Size: 64 bytes
     Interrupt: pin A routed to IRQ 17
     Region 0: Memory at dfdfc000 (32-bit, non-prefetchable) [size=16K]
     Capabilities: <access denied>
     Kernel driver in use: b43-pci-bridge
     Kernel modules: ssb

** USB devices:
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 002: ID 046d:c016 Logitech, Inc. Optical Wheel Mouse
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 004: ID 0b97:7762 O2 Micro, Inc. Oz776 SmartCard Reader
Bus 001 Device 003: ID 0b97:7761 O2 Micro, Inc. Oz776 1.1 Hub
Bus 001 Device 002: ID 413c:a005 Dell Computer Corp. Internal 2.0 Hub
Bus 001 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub

-- System Information:
Debian Release: bullseye/sid
   APT prefers testing
   APT policy: (500, 'testing')
Architecture: i386 (i686)

Kernel: Linux 5.10.0-3-686-pae (SMP w/2 CPU threads)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), 
LANGUAGE=en_US:en
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages linux-image-5.10.0-3-686-pae depends on:
ii  initramfs-tools [linux-initramfs-tool]  0.139
ii  kmod                                    28-1
ii  linux-base                              4.6

Versions of packages linux-image-5.10.0-3-686-pae recommends:
ii  apparmor             2.13.6-9
ii  firmware-linux-free  20200122-1

Versions of packages linux-image-5.10.0-3-686-pae suggests:
pn  debian-kernel-handbook  <none>
ii  grub-pc                 2.04-15
pn  linux-doc-5.10          <none>

Versions of packages linux-image-5.10.0-3-686-pae is related to:
pn  firmware-amd-graphics     <none>
pn  firmware-atheros          <none>
pn  firmware-bnx2             <none>
pn  firmware-bnx2x            <none>
pn  firmware-brcm80211        <none>
pn  firmware-cavium           <none>
pn  firmware-intel-sound      <none>
pn  firmware-intelwimax       <none>
pn  firmware-ipw2x00          <none>
pn  firmware-ivtv             <none>
pn  firmware-iwlwifi          <none>
pn  firmware-libertas         <none>
pn  firmware-linux-nonfree    <none>
pn  firmware-misc-nonfree     <none>
pn  firmware-myricom          <none>
pn  firmware-netxen           <none>
pn  firmware-qlogic           <none>
pn  firmware-realtek          <none>
pn  firmware-samsung          <none>
pn  firmware-siano            <none>
pn  firmware-ti-connectivity  <none>
pn  xen-hypervisor            <none>

-- no debconf information

---

From: Gert van de Kraats <[email-masked]>
Date: Mon, 8 Mar 2021 21:42:04 +0100

because wayland itself needs 2 fence registers for 2 momitors  i
and X11 only 1.
A trace without using wayland shows the 15th register is used without
giving any problem:

Feb 24 20:10:59 debian systemd[1270]: Started GNOME Shell on X11.

Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 0 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 1 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 2 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 3 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 4 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 5 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 6 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 7 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 8 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 9 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 10 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 11 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 12 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 13 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 14 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 15 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 1 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 2 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 3 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 4 0
Feb 24 20:11:29 debian gnome-shell[1505]: GK_intelClearWithBlit_fences 5 0
.....
....
So this seems to be  a mesa bug and an exact duplicate
of https://gitlab.freedesktop.org/mesa/mesa/-/issues/790 .

Only the kernel-driver-error has changed and is misleading now.

I add the mesa-2.3.4-patch I currently use, which solves the problem.

Testing for register-overflow is done after updating the batch, If 
overflow occurs

the batch is restored to the situation before the last update, the 
buffer is flushed

and the batch again is updated with the last update.

--- a/src/mesa/drivers/dri/i915/intel_blit.c	2021-01-29 19:33:19.919872300 +0100
+++ b/src/mesa/drivers/dri/i915/intel_blit.c	2021-02-27 11:52:41.779536510 +0100
@@ -93,9 +93,10 @@
    GLuint CMD, BR13, pass = 0;
    int dst_y2 = dst_y + h;
    int dst_x2 = dst_x + w;
-   drm_intel_bo *aper_array[3];
+   drm_intel_bo *aper_array[1];
    bool dst_y_tiled = dst_tiling == I915_TILING_Y;
    bool src_y_tiled = src_tiling == I915_TILING_Y;
+   int reloc_count;
    BATCH_LOCALS;
 
    if (dst_tiling != I915_TILING_NONE) {
@@ -109,22 +110,6 @@
    if (dst_y_tiled || src_y_tiled)
       return false;
 
-   /* do space check before going any further */
-   do {
-       aper_array[0] = intel->batch.bo;
-       aper_array[1] = dst_buffer;
-       aper_array[2] = src_buffer;
-
-       if (dri_bufmgr_check_aperture_space(aper_array, 3) != 0) {
-           intel_batchbuffer_flush(intel);
-           pass++;
-       } else
-           break;
-   } while (pass < 2);
-
-   if (pass >= 2)
-      return false;
-
    intel_batchbuffer_require_space(intel, 8 * 4);
    DBG("%s src:buf(%p)/%d+%d %d,%d dst:buf(%p)/%d+%d %d,%d sz:%dx%d\n",
        __func__,
@@ -177,15 +162,32 @@
    assert(dst_x < dst_x2);
    assert(dst_y < dst_y2);
 
-   BEGIN_BATCH(8);
+   do {
+       reloc_count = drm_intel_gem_bo_get_reloc_count(intel->batch.bo);
+       BEGIN_BATCH(8);
+
+       OUT_BATCH(CMD | (8 - 2));
+       OUT_BATCH(BR13 | (uint16_t)dst_pitch);
+       OUT_BATCH((dst_y << 16) | dst_x);
+       OUT_BATCH((dst_y2 << 16) | dst_x2);
+       OUT_RELOC_FENCED(dst_buffer,
+		        I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
+		        dst_offset);
+       /* do space check before going any further */
+       aper_array[0] = intel->batch.bo;
+       if (dri_bufmgr_check_aperture_space(aper_array, 1) != 0) {
+           drm_intel_gem_bo_clear_relocs(intel->batch.bo, reloc_count);
+           intel_batchbuffer_emit_reset(intel);
+           intel_batchbuffer_flush(intel);
+           pass++;
+       } else
+	    break;
+   } while (pass < 2);
+
+   if (pass >= 2)
+       return false;
+
 
-   OUT_BATCH(CMD | (8 - 2));
-   OUT_BATCH(BR13 | (uint16_t)dst_pitch);
-   OUT_BATCH((dst_y << 16) | dst_x);
-   OUT_BATCH((dst_y2 << 16) | dst_x2);
-   OUT_RELOC_FENCED(dst_buffer,
-		    I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
-		    dst_offset);
    OUT_BATCH((src_y << 16) | src_x);
    OUT_BATCH((uint16_t)src_pitch);
    OUT_RELOC_FENCED(src_buffer,
@@ -335,6 +337,8 @@
    GLuint clear_depth_value, clear_depth_mask;
    GLint cx, cy, cw, ch;
    GLbitfield fail_mask = 0;
+   int reloc_count;
+   bool flushed;
    BATCH_LOCALS;
 
    /* Note: we don't use this function on Gen7+ hardware, so we can safely
@@ -378,7 +382,7 @@
       uint32_t BR13, CMD;
       struct intel_region *region;
       int pitch, cpp;
-      drm_intel_bo *aper_array[2];
+      drm_intel_bo *aper_array[1];
 
       mask &= ~(1 << buf);
 
@@ -463,23 +467,29 @@
       assert(x1 < x2);
       assert(y1 < y2);
 
-      /* do space check before going any further */
-      aper_array[0] = intel->batch.bo;
-      aper_array[1] = region->bo;
-
-      if (drm_intel_bufmgr_check_aperture_space(aper_array,
-						ARRAY_SIZE(aper_array)) != 0) {
-	 intel_batchbuffer_flush(intel);
-      }
+      flushed = false;
+      while (true) {
+          reloc_count = drm_intel_gem_bo_get_reloc_count(intel->batch.bo);
+          BEGIN_BATCH(6);
+          OUT_BATCH(CMD | (6 - 2));
+          OUT_BATCH(BR13);
+          OUT_BATCH((y1 << 16) | x1);
+          OUT_BATCH((y2 << 16) | x2);
+          OUT_RELOC_FENCED(region->bo,
+		           I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
+		           0);
+          /* do space check before going any further */
+          aper_array[0] = intel->batch.bo;
+          if ((!flushed) && dri_bufmgr_check_aperture_space(aper_array, 1) != 0) {
+              drm_intel_gem_bo_clear_relocs(intel->batch.bo, reloc_count);
+              intel_batchbuffer_emit_reset(intel);
+              intel_batchbuffer_flush(intel);
+	      flushed = true;
+	  } else
+	      break;
+      } 
+
 
-      BEGIN_BATCH(6);
-      OUT_BATCH(CMD | (6 - 2));
-      OUT_BATCH(BR13);
-      OUT_BATCH((y1 << 16) | x1);
-      OUT_BATCH((y2 << 16) | x2);
-      OUT_RELOC_FENCED(region->bo,
-		       I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
-		       0);
       OUT_BATCH(clear_val);
       ADVANCE_BATCH();
 
@@ -632,7 +642,9 @@
    struct intel_region *region = mt->region;
    uint32_t BR13, CMD;
    int pitch, cpp;
-   drm_intel_bo *aper_array[2];
+   drm_intel_bo *aper_array[1];
+   int reloc_count;
+   bool flushed;
    BATCH_LOCALS;
 
    pitch = region->pitch;
@@ -647,23 +659,28 @@
 
    BR13 |= pitch;
 
-   /* do space check before going any further */
-   aper_array[0] = intel->batch.bo;
-   aper_array[1] = region->bo;
-
-   if (drm_intel_bufmgr_check_aperture_space(aper_array,
-					     ARRAY_SIZE(aper_array)) != 0) {
-      intel_batchbuffer_flush(intel);
-   }
+   flushed = false;
+   while (true) {
+       reloc_count = drm_intel_gem_bo_get_reloc_count(intel->batch.bo);
+       BEGIN_BATCH(6);
+       OUT_BATCH(CMD | (6 - 2));
+       OUT_BATCH(BR13);
+       OUT_BATCH((y << 16) | x);
+       OUT_BATCH(((y + height) << 16) | (x + width));
+       OUT_RELOC_FENCED(region->bo,
+		        I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
+		        0);
+       /* do space check before going any further */
+       aper_array[0] = intel->batch.bo;
+       if ((!flushed) && dri_bufmgr_check_aperture_space(aper_array, 1) != 0) {
+           drm_intel_gem_bo_clear_relocs(intel->batch.bo, reloc_count);
+           intel_batchbuffer_emit_reset(intel);
+           intel_batchbuffer_flush(intel);
+           flushed = true;
+       } else
+           break;
+   } 
 
-   BEGIN_BATCH(6);
-   OUT_BATCH(CMD | (6 - 2));
-   OUT_BATCH(BR13);
-   OUT_BATCH((y << 16) | x);
-   OUT_BATCH(((y + height) << 16) | (x + width));
-   OUT_RELOC_FENCED(region->bo,
-		    I915_GEM_DOMAIN_RENDER, I915_GEM_DOMAIN_RENDER,
-		    0);
    OUT_BATCH(0xffffffff); /* white, but only alpha gets written */
    ADVANCE_BATCH();
 
--- a/src/mesa/drivers/dri/i915/intel_batchbuffer.h	2021-01-29 19:33:19.919872300 +0100
+++ b/src/mesa/drivers/dri/i915/intel_batchbuffer.h	2021-02-25 18:14:09.773491087 +0100
@@ -90,6 +90,12 @@
 }
 
 static inline void
+intel_batchbuffer_emit_reset(struct intel_context *intel)
+{
+   intel->batch.used = intel->batch.emit;
+}
+
+static inline void
 intel_batchbuffer_require_space(struct intel_context *intel,
                                 GLuint sz)
 {

---

From: Salvatore Bonaccorso <[email-masked]>
Date: Sat, 13 Mar 2021 14:03:19 +0100

Control: retitle -1 Black screen at dual monitor with warn from i915_gem_ww_ctx_backoff
Control: reassign -1 src:mesa 20.3.4-1
Control: forwarded -1 https://gitlab.freedesktop.org/mesa/mesa/-/issues/790

Hi,

On Mon, Mar 08, 2021 at 09:42:04PM +0100, Gert van de Kraats wrote:
> Testing for register-overflow is done after updating the batch, If overflow
> occurs
> 
> the batch is restored to the situation before the last update, the buffer is
> flushed
> 

So reassigning this for now to src:mesa and updating the metadata.

Regards,
Salvatore