Bug 196297

Summary: nouveau 0000:03:00.0: disp: outp 03:0006:0f42: link training failed
Product: Drivers Reporter: sun.nagarajan
Component: Console/FramebuffersAssignee: drivers_video-dri
Status: NEW ---    
Severity: normal    
Priority: P1    
Hardware: x86-64   
OS: Linux   
Kernel Version: 4.12.0 Subsystem:
Regression: No Bisected commit-id:
Attachments: edid2.bin
Kernel config
dmesg
dmidecode output
edid-decode run on custom edid2.bin
/proc/version
sudo lspci -vv output
Original Seiki monitor EDID (binary)
Original EDID edid-decode output
/proc/cmdline
/proc/iomem
/proc/ioports
/proc/modules
/sys/class/drm/card-DP-1/edid (binary)
/sys/class/drm/card0-DP-1/modes
kernel trace
output of ver_linux

Description sun.nagarajan 2017-07-08 08:10:56 UTC
Created attachment 257403 [details]
edid2.bin

Setup and brief environment:
    - Kernel 4.12.0 - vanilla, no patches
    - Dual-monitor setup
    - Monitor 1:
        - Dell U3011 30-inch 2560x1600 over DVI-I
        - Never has a problem
    - Monitor 2:
        - Seiki SE39UY04 (TV) over DisplayPort @3840x2160
        - Has a problem ONLY when monitor is SWITCHED OFF AND ON AGAIN
    - Graphics card:
        - GeForce GTX 750Ti 2GB GDDR5 128bit, Dual-Link DVI-I, HDMI, DP 1.2 Graphics Card
        - eVGA 02G-P4-3753-KR
        - eVGA link: http://www.evga.com/Products/Product.aspx?pn=02G-P4-3753-KR
    - Seiki monitor EDID:
        - The monitor has a bad EDID
        - I have a modified EDID file - see attached edid2.bin with ONLY the 
            correct resolution
        - I use video=DP-1:3840x2160 drm_kms_helper.edid_firmware=DP-1:edid/edid2.bin
            to specify the exact resolution and use my custom EDID file

What works (perfectly):
    - Both monitors startup at full resolution
    - xorg starts up at full resolution on both monitors
    - Monitor 1 (Dell U3011) NEVER has any problem
    - While booting, nouveau finds and uses my custom EDID file

Problem:
    - When DPMS kicks in, the Dell U3011 monitor goes to sleep (normal) and 
        the Seiki monitor shows 'No Signal' on the screen
    - About 15 mins after DPMS kicks in, the Seiki monitor switches off 
    - The Seiki monitor has to be manually switched on with the power button
    - This behavior cannot be changed - no setting for this on the monitor
    - When I switch the Seiki monitor ON, the screen will be blank and 
        'xrandr -q' shows it as disconnected
    - When I switch to a virtual console (using CTRL-ALT-F1), the following message appears
        on the console:

Jul  7 23:34:28 smaug kernel: [ 8340.750889] nouveau 0000:03:00.0: disp: outp 03:0006:0f42: link training failed
Jul  7 23:34:28 smaug kernel: [ 8340.750940] nouveau 0000:03:00.0: disp: outp 03:0006:0f42: link not trained before attach

    - This message appears ONLY when I switch to the virtual console, and NOT until then
    - When the monitor is switched on, the attached kernel trace appears in the kernel log 
    - After switching to the virtual console and back to X, the monitor will show
        a SERIES of garbled screens (probably bad timings, but I am not sure), each
        lasting about 10-15 secs. After a few MINUTES (perhaps 2-3 minutes),
        the Seiki monitor will be restored back to full resolution
    - As the monitor is restored to full resolution, the following message will
        appear in the kernel log:

Jul  7 23:37:44 smaug kernel: [ 8537.487664] [drm] Got external EDID base block and 1 extension from "edid/edid2.bin" for connector "DP-1"

    - The problem only happens if the Seiki monitor is in the OFF state for QUITE A LONG TIME
    - E.g., if I turn it back on within 5 mins, the problem does not occur
    - The kernel trace ALWAYS appears when the Seiki monitor has switched off, when it is switched on


Problem wasn't happening until about 4-5 months ago (when I was using an older kernel version).
I have gone back to 4.11, but it still happens. Must be a version older than that. Unfortunately, I do not remember which version worked, but was a 4.x version.

Kernel trace:
------------

Jul  7 23:33:40 smaug kernel: [ 8293.081909] ------------[ cut here ]------------
Jul  7 23:33:40 smaug kernel: [ 8293.081981] WARNING: CPU: 27 PID: 20223 at drivers/gpu/drm/nouveau/nouveau_bo.c:137 nouveau_bo_del_ttm+0x6e/0x80 [nouveau]
Jul  7 23:33:40 smaug kernel: [ 8293.081982] Modules linked in: nvram msr rfcomm uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_core videodev media bnep binfmt_misc nls_iso8859_1 btusb btrtl btbcm btintel bluetooth ecdh_generic cp210x ftdi_sio usbserial input_leds joydev snd_usb_audio snd_usbmidi_lib snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore ipmi_ssif intel_rapl sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd glue_helper cryptd intel_cstate intel_rapl_perf lpc_ich mei_me mei ioatdma dca ipmi_si shpchp ipmi_devintf ipmi_msghandler mac_hid kvm_intel kvm irqbypass sunrpc parport_pc ppdev lp parport autofs4 raid10 raid456 async_raid6_recov async_memcpy
Jul  7 23:33:40 smaug kernel: [ 8293.082019]  async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear overlay mlx4_en hid_generic uas usb_storage hid_logitech_hidpp hid_logitech_dj usbhid hid nouveau mxm_wmi video i2c_algo_bit ttm drm_kms_helper mlx4_core syscopyarea sysfillrect e1000e sysimgblt devlink fb_sys_fops isci mpt3sas ahci ptp libsas nvme libahci drm pps_core raid_class nvme_core scsi_transport_sas wmi
Jul  7 23:33:40 smaug kernel: [ 8293.082045] CPU: 27 PID: 20223 Comm: Xorg Tainted: G        W       4.12.0 #1
Jul  7 23:33:40 smaug kernel: [ 8293.082046] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./EP2C602-4L/D16, BIOS P1.70 12/04/2013
Jul  7 23:33:40 smaug kernel: [ 8293.082047] task: ffff8a4b8f46e580 task.stack: ffffb7a6af470000
Jul  7 23:33:40 smaug kernel: [ 8293.082074] RIP: 0010:nouveau_bo_del_ttm+0x6e/0x80 [nouveau]
Jul  7 23:33:40 smaug kernel: [ 8293.082075] RSP: 0018:ffffb7a6af473bd0 EFLAGS: 00010206 
Jul  7 23:33:40 smaug kernel: [ 8293.082076] RAX: 0000000000000006 RBX: ffff8a4bae276000 RCX: 0000000180400035
Jul  7 23:33:40 smaug kernel: [ 8293.082077] RDX: 0000000180400036 RSI: ffffe3e038f6e280 RDI: ffff8a4bae276000
Jul  7 23:33:40 smaug kernel: [ 8293.082078] RBP: ffffb7a6af473be0 R08: 00000000bdb8a301 R09: 0000000180400035
Jul  7 23:33:40 smaug kernel: [ 8293.082079] R10: ffffb7a6af473bc8 R11: 0000000000000000 R12: ffff8a4bb9d43800
Jul  7 23:33:40 smaug kernel: [ 8293.082080] R13: 0000000000050880 R14: ffff8a4bba3371e0 R15: ffff8a4bba3371e0
Jul  7 23:33:40 smaug kernel: [ 8293.082081] FS:  00007fed0f943a00(0000) GS:ffff8a59c74c0000(0000) knlGS:0000000000000000
Jul  7 23:33:40 smaug kernel: [ 8293.082082] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul  7 23:33:40 smaug kernel: [ 8293.082082] CR2: 00005613f2291014 CR3: 0000000e3ab7d000 CR4: 00000000000406e0
Jul  7 23:33:40 smaug kernel: [ 8293.082084] Call Trace:
Jul  7 23:33:40 smaug kernel: [ 8293.082094]  ttm_bo_release_list+0xbf/0x1a0 [ttm]
Jul  7 23:33:40 smaug kernel: [ 8293.082098]  ttm_bo_unref+0x19d/0x1f0 [ttm]
Jul  7 23:33:40 smaug kernel: [ 8293.082124]  nouveau_gem_object_del+0x9a/0xe0 [nouveau]
Jul  7 23:33:40 smaug kernel: [ 8293.082141]  drm_gem_object_free+0x1f/0x40 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082148]  drm_gem_object_put_unlocked+0x40/0x70 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082156]  drm_gem_object_handle_put_unlocked+0x66/0xa0 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082164]  drm_gem_object_release_handle+0x53/0x90 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082171]  drm_gem_handle_delete+0x5e/0x90 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082179]  drm_gem_close_ioctl+0x20/0x30 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082187]  drm_ioctl+0x219/0x4c0 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082194]  ? drm_gem_handle_create+0x40/0x40 [drm]
Jul  7 23:33:40 smaug kernel: [ 8293.082200]  ? __handle_mm_fault+0x915/0xfd0
Jul  7 23:33:40 smaug kernel: [ 8293.082226]  nouveau_drm_ioctl+0x68/0xc0 [nouveau]
Jul  7 23:33:40 smaug kernel: [ 8293.082230]  do_vfs_ioctl+0xa1/0x5e0
Jul  7 23:33:40 smaug kernel: [ 8293.082232]  ? handle_mm_fault+0xf3/0x210
Jul  7 23:33:40 smaug kernel: [ 8293.082235]  ? __do_page_fault+0x265/0x4e0
Jul  7 23:33:40 smaug kernel: [ 8293.082237]  SyS_ioctl+0x79/0x90
Jul  7 23:33:40 smaug kernel: [ 8293.082241]  entry_SYSCALL_64_fastpath+0x1e/0xa9
Jul  7 23:33:40 smaug kernel: [ 8293.082242] RIP: 0033:0x7fed0d7aaf07
Jul  7 23:33:40 smaug kernel: [ 8293.082243] RSP: 002b:00007ffdcf5f2af8 EFLAGS: 00003246 ORIG_RAX: 0000000000000010
Jul  7 23:33:40 smaug kernel: [ 8293.082244] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fed0d7aaf07
Jul  7 23:33:40 smaug kernel: [ 8293.082245] RDX: 00007ffdcf5f2b30 RSI: 0000000040086409 RDI: 000000000000000e
Jul  7 23:33:40 smaug kernel: [ 8293.082246] RBP: 00007ffdcf5f29e0 R08: 0000000000000068 R09: 0000000000000001
Jul  7 23:33:40 smaug kernel: [ 8293.082247] R10: 0000000000000068 R11: 0000000000003246 R12: 0000000000000000
Jul  7 23:33:40 smaug kernel: [ 8293.082247] R13: 0000000000000000 R14: 00005613f228dbd0 R15: 00007ffdcf5f2a08
Jul  7 23:33:40 smaug kernel: [ 8293.082248] Code: e9 8d 22 e2 5b 41 5c 5d c3 48 89 f9 31 f6 48 c7 c2 00 3e 67 c0 48 c7 c7 74 ff 67 c0 e8 6c 0a c3 ff 8b 83 20 04 00 00 85 c0 7e c0 <0f> ff eb bc 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 66 66 66  
Jul  7 23:33:40 smaug kernel: [ 8293.082272] ---[ end trace 0cfecd44a1eff640 ]---
Jul  7 23:34:28 smaug kernel: [ 8340.750889] nouveau 0000:03:00.0: disp: outp 03:0006:0f42: link training failed
Jul  7 23:34:28 smaug kernel: [ 8340.750940] nouveau 0000:03:00.0: disp: outp 03:0006:0f42: link not trained before attach
Jul  7 23:37:44 smaug kernel: [ 8537.487664] [drm] Got external EDID base block and 1 extension from "edid/edid2.bin" for connector "DP-1"
Jul  7 23:37:44 smaug kernel: [ 8537.567072] [drm] Got external EDID base block and 1 extension from "edid/edid2.bin" for connector "DP-1"
Comment 1 sun.nagarajan 2017-07-08 08:12:07 UTC
Created attachment 257405 [details]
Kernel config
Comment 2 sun.nagarajan 2017-07-08 08:12:25 UTC
Created attachment 257407 [details]
dmesg
Comment 3 sun.nagarajan 2017-07-08 08:12:43 UTC
Created attachment 257409 [details]
dmidecode output
Comment 4 sun.nagarajan 2017-07-08 08:13:20 UTC
Created attachment 257411 [details]
edid-decode run on custom edid2.bin
Comment 5 sun.nagarajan 2017-07-08 08:13:53 UTC
Created attachment 257413 [details]
/proc/version
Comment 6 sun.nagarajan 2017-07-08 08:14:29 UTC
Created attachment 257415 [details]
sudo lspci -vv output
Comment 7 sun.nagarajan 2017-07-08 08:15:07 UTC
Created attachment 257417 [details]
Original Seiki monitor EDID (binary)
Comment 8 sun.nagarajan 2017-07-08 08:15:34 UTC
Created attachment 257419 [details]
Original EDID edid-decode output
Comment 9 sun.nagarajan 2017-07-08 08:15:55 UTC
Created attachment 257421 [details]
/proc/cmdline
Comment 10 sun.nagarajan 2017-07-08 08:16:15 UTC
Created attachment 257423 [details]
/proc/iomem
Comment 11 sun.nagarajan 2017-07-08 08:16:39 UTC
Created attachment 257425 [details]
/proc/ioports
Comment 12 sun.nagarajan 2017-07-08 08:16:57 UTC
Created attachment 257427 [details]
/proc/modules
Comment 13 sun.nagarajan 2017-07-08 08:17:28 UTC
Created attachment 257429 [details]
/sys/class/drm/card-DP-1/edid (binary)
Comment 14 sun.nagarajan 2017-07-08 08:18:00 UTC
Created attachment 257431 [details]
/sys/class/drm/card0-DP-1/modes
Comment 15 sun.nagarajan 2017-07-08 08:18:19 UTC
Created attachment 257433 [details]
kernel trace
Comment 16 sun.nagarajan 2017-07-08 08:18:38 UTC
Created attachment 257435 [details]
output of ver_linux