Skip to content

Instantly share code, notes, and snippets.

/dmesg | tail

Created October 20, 2017 15:20
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save anonymous/d1cfe9ef5ebef0f96bb8d9ac451140f0 to your computer and use it in GitHub Desktop.
Save anonymous/d1cfe9ef5ebef0f96bb8d9ac451140f0 to your computer and use it in GitHub Desktop.
Download ZIP
vfio - usb drops out with Win 10 guest
Raw
dmesg | tail
[ 40.130760] device virbr0-nic entered promiscuous mode
[ 40.206508] nf_conntrack version 0.5.0 (65536 buckets, 262144 max)
[ 40.255921] virbr0: port 1(virbr0-nic) entered blocking state
[ 40.255925] virbr0: port 1(virbr0-nic) entered listening state
[ 40.288187] virbr0: port 1(virbr0-nic) entered disabled state
[ 142.669242] virbr0: port 2(vnet0) entered blocking state
[ 142.669245] virbr0: port 2(vnet0) entered disabled state
[ 142.669295] device vnet0 entered promiscuous mode
[ 142.669461] virbr0: port 2(vnet0) entered blocking state
[ 142.669465] virbr0: port 2(vnet0) entered listening state
[ 143.710017] vfio-pci 0000:01:00.0: enabling device (0100 -> 0103)
[ 143.710139] vfio_ecap_init: 0000:01:00.0 hiding ecap 0x1e@0x258
[ 143.710145] vfio_ecap_init: 0000:01:00.0 hiding ecap 0x19@0x900
[ 144.690016] virbr0: port 2(vnet0) entered learning state
[ 146.823314] virbr0: port 2(vnet0) entered forwarding state
[ 146.823320] virbr0: topology change detected, propagating
[ 259.716835] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 260.086828] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 260.330163] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 269.910153] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 271.083489] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 271.316820] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 308.466820] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 308.666805] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 309.869134] virbr0: port 2(vnet0) entered disabled state
[ 309.872860] device vnet0 left promiscuous mode
[ 309.872866] virbr0: port 2(vnet0) entered disabled state
[ 309.937594] input: Logitech Logitech G930 Headset as /devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4.3/3-4.3:1.3/0003:046D:0A1F.0005/input/input20
[ 309.993587] hid-generic 0003:046D:0A1F.0005: input,hiddev1,hidraw2: USB HID v1.01 Device [Logitech Logitech G930 Headset] on usb-0000:00:14.0-4.3/input3
[ 310.012030] input: Sony PLAYSTATION(R)3 Controller Motion Sensors as /devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4.1/3-4.1:1.0/0003:054C:0268.0006/input/input22
[ 310.066801] input: Sony PLAYSTATION(R)3 Controller as /devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4.1/3-4.1:1.0/0003:054C:0268.0006/input/input21
[ 310.067020] sony 0003:054C:0268.0006: input,hiddev2,hidraw3: USB HID v81.11 Joystick [Sony PLAYSTATION(R)3 Controller] on usb-0000:00:14.0-4.1/input0
[ 315.687951] virbr0: port 2(vnet0) entered blocking state
[ 315.687954] virbr0: port 2(vnet0) entered disabled state
[ 315.687996] device vnet0 entered promiscuous mode
[ 315.688114] virbr0: port 2(vnet0) entered blocking state
[ 315.688116] virbr0: port 2(vnet0) entered listening state
[ 316.643395] vfio_ecap_init: 0000:01:00.0 hiding ecap 0x1e@0x258
[ 316.643401] vfio_ecap_init: 0000:01:00.0 hiding ecap 0x19@0x900
[ 317.703349] virbr0: port 2(vnet0) entered learning state
[ 318.106814] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 318.300150] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 318.486797] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 318.680114] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 319.836619] virbr0: port 2(vnet0) entered forwarding state
[ 319.836620] virbr0: topology change detected, propagating
[ 332.236814] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 332.606812] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 332.913462] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 333.313494] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 335.470166] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 335.663494] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 335.860146] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 336.053489] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 336.300110] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 336.493430] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 336.680098] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 336.876799] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 339.360167] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 339.553478] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 339.740176] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 339.936768] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 340.273488] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 340.466843] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 341.250152] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 341.650152] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 342.613426] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 342.846785] usb 3-4.3: reset full-speed USB device number 5 using xhci_hcd
[ 343.176792] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 343.423436] usb 3-4.1: reset full-speed USB device number 4 using xhci_hcd
[ 362.631641] uurb->buffer_length is too short 5644 vs 0
[ 362.631688] ------------[ cut here ]------------
[ 362.631699] WARNING: CPU: 0 PID: 2094 at drivers/usb/core/devio.c:1583 proc_do_submiturb+0x993/0xd60 [usbcore]
[ 362.631700] Modules linked in: xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack libcrc32c crc32c_generic ipt_REJECT nf_reject_ipv4 xt_tcpudp tun bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter devlink fuse snd_hda_codec_hdmi nvidia_drm(PO) nvidia_modeset(PO) snd_usb_audio snd_hda_codec_realtek snd_usbmidi_lib nvidia(PO) snd_hda_codec_generic snd_rawmidi snd_seq_device intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel drm_kms_helper kvm crct10dif_pclmul crc32_pclmul iTCO_wdt snd_hda_intel ghash_clmulni_intel iTCO_vendor_support mxm_wmi drm snd_hda_codec pcbc e1000e snd_hda_core agpgart snd_hwdep syscopyarea sysfillrect sysimgblt aesni_intel fb_sys_fops
[ 362.631746] aes_x86_64 snd_pcm crypto_simd glue_helper cryptd evdev tpm_tis mei_me snd_timer joydev intel_cstate tpm_tis_core input_leds mousedev ptp intel_rapl_perf mac_hid pcspkr i2c_i801 snd soundcore lpc_ich mei pps_core shpchp tpm wmi button sch_fq_codel vboxnetflt(O) vboxnetadp(O) pci_stub vboxpci(O) vboxdrv(O) sg ip_tables x_tables ext4 crc16 mbcache jbd2 fscrypto dm_mod dax hid_sony ff_memless led_class hid_generic usbhid hid sd_mod crc32c_intel ahci libahci xhci_pci ehci_pci xhci_hcd libata ehci_hcd usbcore scsi_mod usb_common serio vfio_pci irqbypass vfio_virqfd vfio_iommu_type1 vfio
[ 362.631797] CPU: 0 PID: 2094 Comm: qemu-system-x86 Tainted: P O 4.13.7-1-ARCH #1
[ 362.631798] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./X99 Extreme4, BIOS P2.10 12/23/2015
[ 362.631800] task: ffff9306082d8f00 task.stack: ffffae01c2650000
[ 362.631807] RIP: 0010:proc_do_submiturb+0x993/0xd60 [usbcore]
[ 362.631809] RSP: 0018:ffffae01c2653d38 EFLAGS: 00010282
[ 362.631811] RAX: 000000000000002a RBX: ffff9305e2e54300 RCX: ffffffffb8a55328
[ 362.631812] RDX: 0000000000000000 RSI: 0000000000000096 RDI: 0000000000000283
[ 362.631814] RBP: ffffae01c2653dc0 R08: 0000000000000423 R09: ffffffffb8ca68e0
[ 362.631815] R10: 0000000000000200 R11: 0000000000000000 R12: 0000000000000001
[ 362.631816] R13: ffff9306071d7ea0 R14: 00007efeb03136b8 R15: ffffae01c2653e00
[ 362.631819] FS: 00007efec1b5a340(0000) GS:ffff93060f200000(0000) knlGS:0000000000000000
[ 362.631820] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 362.631822] CR2: 00007efc8d8d0a30 CR3: 0000000462d2e000 CR4: 00000000001426f0
[ 362.631824] Call Trace:
[ 362.631831] ? compat_poll_select_copy_remaining+0x120/0x120
[ 362.631839] usbdev_do_ioctl+0xa34/0x1170 [usbcore]
[ 362.631843] ? compat_poll_select_copy_remaining+0x120/0x120
[ 362.631850] usbdev_ioctl+0xe/0x20 [usbcore]
[ 362.631853] do_vfs_ioctl+0xa5/0x600
[ 362.631858] ? __fget+0x6e/0x90
[ 362.631860] SyS_ioctl+0x79/0x90
[ 362.631865] entry_SYSCALL_64_fastpath+0x1a/0xa5
[ 362.631867] RIP: 0033:0x7efeba922157
[ 362.631868] RSP: 002b:00007ffc2ec84b38 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 362.631871] RAX: ffffffffffffffda RBX: 00007efca8e23100 RCX: 00007efeba922157
[ 362.631872] RDX: 00007efeb0313680 RSI: 000000008038550a RDI: 0000000000000031
[ 362.631873] RBP: 00007ffc2ec7ee70 R08: 0000000000000060 R09: 0000000000001800
[ 362.631875] R10: 00007efeb03a5580 R11: 0000000000000246 R12: 0000000000000043
[ 362.631876] R13: 00000000000000a8 R14: 0000000000000001 R15: 00007efca88dd1c0
[ 362.631878] Code: 00 c7 45 a8 00 00 00 00 48 c7 45 b8 00 00 00 00 0f 85 5e f8 ff ff 89 c2 48 c7 c7 40 0f 35 c0 c6 05 37 2b 01 00 01 e8 ce 8c d9 f7 <0f> ff 49 63 47 18 e9 3e f8 ff ff c7 45 8c 00 00 00 00 c7 45 98
[ 362.631930] ---[ end trace 4ae423ae3e43d6e9 ]---
[ 362.632706] DMAR: DRHD: handling fault status reg 2
[ 362.632714] DMAR: [DMA Read] Request device [00:14.0] fault addr 0 [fault reason 06] PTE Read access is not set
@petermaloney
Copy link

I got something similar on 4.13 but no problems on any other kernel I tried (such as 4.12 which I was using before that

Oct 21 18:49:03 peter kernel: [28026.624165] ------------[ cut here ]------------
Oct 21 18:49:03 peter kernel: [28026.624174] Modules linked in: tun xt_REDIRECT nf_nat_redirect xt_nat xt_recent xt_comment xt_iprange xt_hashlimit iptable_nat nf_nat_ipv4 ipt_REJECT nf_reject_ipv4 xt_addrtype xt_physdev br_netfilter xt_mark iptable_mangle xt_tcpudp xt_CT iptable_raw xt_multiport nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack xt_NFLOG nfnetlink_log nf_log_ipv4 nf_log_common xt_LOG nf_conntrack_sane nf_conntrack_netlink nfnetlink nf_nat_tftp nf_nat_snmp_basic nf_conntrack_snmp nf_nat_sip nf_nat_pptp nf_nat_proto_gre nf_nat_irc nf_nat_h323 nf_nat_ftp nf_nat_amanda nf_nat nf_conntrack_tftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_proto_gre nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp ts_kmp nf_conntrack_amanda nf_conntrack libcrc32c crc32c_generic iptable_filter
Oct 21 18:49:03 peter kernel: [28026.624257] Hardware name: Gigabyte Technology Co., Ltd. To be filled by O.E.M./X99-UD3-CF, BIOS F20 01/12/2016
Oct 21 18:49:03 peter kernel: [28026.624262] RIP: 0010:proc_do_submiturb+0x993/0xd60 [usbcore]
Oct 21 18:49:03 peter kernel: [28026.624264] RAX: 000000000000002a RBX: ffff9934f8ff9240 RCX: ffffffffbec555a8
Oct 21 18:49:03 peter kernel: [28026.624266] RBP: ffffa794c2423da8 R08: 00000000000005de R09: ffffffffbeea78a0
Oct 21 18:49:03 peter kernel: [28026.624267] R13: ffff9934fd0e31e0 R14: 00007f89ce9b1738 R15: ffffa794c2423de8
Oct 21 18:49:03 peter kernel: [28026.624270] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Oct 21 18:49:03 peter kernel: [28026.624276] Call Trace:
Oct 21 18:49:03 peter kernel: [28026.624292]  usbdev_do_ioctl+0xa34/0x1170 [usbcore]
Oct 21 18:49:03 peter kernel: [28026.624296]  usbdev_ioctl+0xe/0x20 [usbcore]
Oct 21 18:49:03 peter kernel: [28026.624318]  do_vfs_ioctl+0xa5/0x600
Oct 21 18:49:03 peter kernel: [28026.624322]  ? getnstimeofday64+0xe/0x20
Oct 21 18:49:03 peter kernel: [28026.624325]  ? __audit_syscall_entry+0xb5/0x100
Oct 21 18:49:03 peter kernel: [28026.624328]  ? __fget+0x6e/0x90
Oct 21 18:49:03 peter kernel: [28026.624330]  SyS_ioctl+0x79/0x90
Oct 21 18:49:03 peter kernel: [28026.624332]  do_syscall_64+0x54/0xc0
Oct 21 18:49:03 peter kernel: [28026.624336]  entry_SYSCALL64_slow_path+0x25/0x25
Oct 21 18:49:03 peter kernel: [28026.624337] RIP: 0033:0x7f8ae99e90c7
Oct 21 18:49:03 peter kernel: [28026.624337] RSP: 002b:00007ffe76275218 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Oct 21 18:49:03 peter kernel: [28026.624339] RAX: ffffffffffffffda RBX: 00007f8adedbda50 RCX: 00007f8ae99e90c7
Oct 21 18:49:03 peter kernel: [28026.624339] RDX: 00007f89ce9b1700 RSI: 000000008038550a RDI: 0000000000000028
Oct 21 18:49:03 peter kernel: [28026.624340] RBP: 0000000000000001 R08: 0000000000000000 R09: fffffffffffffff8
Oct 21 18:49:03 peter kernel: [28026.624341] R10: 00007f8adee49500 R11: 0000000000000246 R12: 000000008038550a
Oct 21 18:49:03 peter kernel: [28026.624342] R13: 00007f8aded45b00 R14: 0000000000000000 R15: 0000000000000000
Oct 21 18:49:03 peter kernel: [28026.624343] Code: 00 c7 45 a8 00 00 00 00 48 c7 45 b8 00 00 00 00 0f 85 5e f8 ff ff 89 c2 48 c7 c7 40 5f 48 c0 c6 05 37 2b 01 00 01 e8 ee 3d c6 fd <0f> ff 49 63 47 18 e9 3e f8 ff ff c7 45 8c 00 00 00 00 c7 45 98 
Oct 21 18:49:03 peter kernel: [28026.624368] ---[ end trace cae918a9e98241c2 ]---

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment