Re: [drm/nouveau] GeForce 8600 GT boot/suspend grumbling

[Ilia Mirkin]

On Sat, Jul 15, 2017 at 1:40 AM, Mike Galbraith <efault@xxxxxx> wrote:
> Greetings,
>
> box: bog standard [tc]rusty old Nvidia equipped Q6600 Medion (Aldi) deskside
> kernel: master.today (v4.12-11690-gccd5d1b91f22)
>
> lspci -nn -d 10de:
> 01:00.0 VGA compatible controller [0300]: NVIDIA Corporation G84 [GeForce 8600 GT] [10de:0402] (rev a1)
>
> abreviated dmesg:
> ...
> [    3.720990] fb: switching to nouveaufb from VESA VGA
> [    3.744489] Console: switching to colour dummy device 80x25
> [    3.744966] nouveau 0000:01:00.0: NVIDIA G84 (084200a2)
> ...
> [    3.846963] usbcore: registered new interface driver uas
> [    3.849938] nouveau 0000:01:00.0: bios: version 60.84.6e.00.12
> [  321.450262] nouveau 0000:01:00.0: DRM: suspending console...
> [  321.450265] nouveau 0000:01:00.0: DRM: suspending display...
> [  321.450462] e1000e: EEE TX LPI TIMER: 00000000
> [  321.450501] br0: port 1(eth0) entered disabled state
> [  321.473838] ------------[ cut here ]------------
> [  321.473863] WARNING: CPU: 1 PID: 4786 at drivers/gpu/drm/drm_vblank.c:608 drm_calc_vbltimestamp_from_scanoutpos+0x14f/0x330 [drm]
> [  321.473864] Modules linked in: ebtable_filter(E) ebtables(E) fuse(E) rpcsec_gss_krb5(E) nfsv4(E) dns_resolver(E) nfs(E) fscache(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) ip6t_REJECT(E) xt_tcpudp(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ip6table_raw(E) ipt_REJECT(E) iptable_raw(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) saa7134_alsa(E) tda1004x(E) saa7134_dvb(E) videobuf2_dvb(E) dvb_core(E) arc4(E) rt2800usb(E) rt2x00usb(E) rt2800lib(E) crc_ccitt(E) rt2x00lib(E) mac80211(E) cfg80211(E) rc_medion_x10_or2x(E) rfkill(E) ati_remote(E) tda827x(E) tda8290(E) tuner(E) snd_hda_codec_realtek(E) saa7134(E)
> [  321.473905]  snd_hda_codec_generic(E) snd_hda_intel(E) snd_hda_codec(E) snd_hwdep(E) tveeprom(E) coretemp(E) videobuf2_dma_sg(E) videobuf2_memops(E) snd_hda_core(E) videobuf2_v4l2(E) kvm_intel(E) snd_pcm(E) kvm(E) videobuf2_core(E) snd_timer(E) rc_core(E) v4l2_common(E) snd(E) videodev(E) iTCO_wdt(E) media(E) e1000e(E) iTCO_vendor_support(E) ptp(E) pps_core(E) shpchp(E) soundcore(E) i2c_i801(E) lpc_ich(E) mfd_core(E) irqbypass(E) pcspkr(E) thermal(E) acpi_cpufreq(E) fan(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) ext4(E) crc16(E) mbcache(E) jbd2(E) fscrypto(E) sr_mod(E) cdrom(E) sd_mod(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) video(E) i2c_algo_bit(E) ahci(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) libahci(E) sysimgblt(E) fb_sys_fops(E) firewire_ohci(E)
> [  321.473950]  libata(E) firewire_core(E) crc_itu_t(E) ehci_pci(E) serio_raw(E) ttm(E) button(E) drm(E) uhci_hcd(E) ehci_hcd(E) usbcore(E) sg(E) dm_multipath(E) dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) autofs4(E)
> [  321.473966] CPU: 1 PID: 4786 Comm: kworker/u8:17 Tainted: G        W   E   4.12.0.gccd5d1b-master #186
> [  321.473968] Hardware name: MEDIONPC MS-7502/MS-7502, BIOS 6.00 PG 12/26/2007
> [  321.473972] Workqueue: events_unbound async_run_entry_fn
> [  321.473974] task: ffff8801daf93d40 task.stack: ffffc90003edc000
> [  321.473990] RIP: 0010:drm_calc_vbltimestamp_from_scanoutpos+0x14f/0x330 [drm]
> [  321.473992] RSP: 0018:ffffc90003edfb00 EFLAGS: 00010082
> [  321.473994] RAX: ffffffffa03e6100 RBX: ffff880211140000 RCX: 0000000000000001
> [  321.473995] RDX: ffffffffa01dd8c8 RSI: 0000000000000001 RDI: ffffffffa01c8023
> [  321.473996] RBP: ffffc90003edfb80 R08: 0000000000000000 R09: ffffffffa01b0920
> [  321.473998] R10: ffffffffa0376e60 R11: ffff8802131399f8 R12: 0000000000000001
> [  321.473999] R13: ffff880213139800 R14: ffffc90003edfb94 R15: ffffc90003edfbd0
> [  321.474001] FS:  0000000000000000(0000) GS:ffff88022fc80000(0000) knlGS:0000000000000000
> [  321.474003] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  321.474004] CR2: 00007fdd82e8f810 CR3: 0000000214683000 CR4: 00000000000006e0
> [  321.474005] Call Trace:
> [  321.474068]  ? nv50_head_vblank_put+0x22/0x50 [nouveau]
> [  321.474085]  drm_get_last_vbltimestamp+0x41/0x70 [drm]
> [  321.474102]  drm_update_vblank_count+0x61/0x230 [drm]
> [  321.474118]  drm_vblank_disable_and_save+0x59/0xc0 [drm]
> [  321.474134]  drm_crtc_vblank_off+0x1d5/0x210 [drm]
> [  321.474152]  ? drm_modeset_drop_locks+0x4e/0x60 [drm]
> [  321.474203]  nouveau_display_fini+0x56/0xd0 [nouveau]
> [  321.474254]  nouveau_display_suspend+0x4f/0x110 [nouveau]
> [  321.474304]  nouveau_do_suspend+0x7c/0x1e0 [nouveau]
> [  321.474355]  nouveau_pmops_suspend+0x2d/0x70 [nouveau]
> [  321.474358]  pci_pm_suspend+0x70/0x130
> [  321.474360]  ? pci_pm_resume+0x90/0x90
> [  321.474364]  dpm_run_callback+0x4d/0x150
> [  321.474366]  __device_suspend+0x121/0x3b0
> [  321.474369]  ? pm_dev_dbg+0x70/0x70
> [  321.474370]  async_suspend+0x1a/0x90
> [  321.474373]  async_run_entry_fn+0x33/0x160
> [  321.474376]  process_one_work+0x141/0x340
> [  321.474378]  worker_thread+0x47/0x3b0
> [  321.474381]  kthread+0xfc/0x130
> [  321.474384]  ? rescuer_thread+0x360/0x360
> [  321.474386]  ? kthread_park+0x60/0x60
> [  321.474389]  ret_from_fork+0x25/0x30
> [  321.474391] Code: e1 48 c7 c2 c8 d8 1d a0 be 01 00 00 00 48 c7 c7 23 80 1c a0 e8 83 7f fe ff 48 8b 83 70 03 00 00 48 83 78 20 00 0f 84 de fe ff ff <0f> ff 31 c0 e9 d7 fe ff ff 44 89 d0 be d3 4d 62 10 48 c7 c7 23
> [  321.474425] ---[ end trace 6b7e5ebfa79000dc ]---
> [  321.474436] nouveau 0000:01:00.0: DRM: evicting buffers...
> [  321.607070] sd 2:0:0:0: [sde] Stopping disk
> [  321.669140] nouveau 0000:01:00.0: DRM: waiting for kernel channels to go idle...
> [  321.669147] nouveau 0000:01:00.0: DRM: suspending fence...
> [  321.669275] nouveau 0000:01:00.0: DRM: suspending object tree...
> [  325.124778] PM: suspend of devices complete after 3698.373 msecs
> [  325.125130] PM: late suspend of devices complete after 0.349 msecs
> [  325.146080] PM: noirq suspend of devices complete after 20.945 msecs
> [  325.146589] ACPI: Preparing to enter system sleep state S3

OK, so this issue appears to be that we're calling
drm_crtc_vblank_off() on a crtc for which vblank is already disabled.
My guess is that this happens because the crtc is disabled.

Not sure what the proper check is to see if vblanks are already disabled...