Guinea pig #1 responding as ordered, sir! ☺ One is the kernel log from connection, the other is what happens if I try to do a modprobe -r. I noticed there's a call trace with registers - I'm wondering if I need to add more symbols packages so that trace can be more verbose and offer up more info. Thoughts? Let me know if you want me to try anything else. I'm going to produce the output now for hot-unplug of the same device, see how that differs. Cheers!
On Sat, 2019-04-20 at 20:26 -0500, [email protected] wrote: > Status update. Nothing really useful to report except that I am seeing some > screwy behavior just > on hotplug / hotunplug operations with the device just sitting idle not being > touched by > anything. In this case I tested an old 29032 model - a very early module but > it's a useful test > subject because it is simpler than the HVR-1950 yet still exercises most of > the key pieces of the > driver. I ran a freshly compiled 5.0.9 kernel (latest stable) for this test. > Sorry this has taken so long. As was guessed earlier, I haven't worked on > this in a very long > time and I had to unbox a lot of stuff. I also spent far too much time today > setting up a > separate purpose-built computer which I can trash / crash / hang with wild > abandon without losing > anything of value. This approach allows me to keep my dev environment on a > machine separate from > the one that is running test kernels. > I was able to cleanly modprobe -r pvrusb2 every time so far, but if the issue > is on the DVB side > of the fence, then the old 29032 model I've just tried won't exhibit that > issue. So a lot more > characterization to do. > Diego: It would useful if you could post to me the section of your > /var/log/kern.log (or > equivalent) should all the kernel messages from the point when you plug in > the device to when the > fireworks are happening after trying to tear down. If I find that same > pattern here then we'll > know for sure that we are chasing the same issue. > -Mike -- Diego Rivera
Apr 20 20:05:14 tvserver kernel: [ 168.512204] usb 1-3: new high-speed USB device number 6 using xhci_hcd Apr 20 20:05:14 tvserver kernel: [ 168.664378] usb 1-3: New USB device found, idVendor=2040, idProduct=7501, bcdDevice= 8.00 Apr 20 20:05:14 tvserver kernel: [ 168.664385] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 20 20:05:14 tvserver kernel: [ 168.664388] usb 1-3: Product: WinTV Apr 20 20:05:14 tvserver kernel: [ 168.664392] usb 1-3: Manufacturer: Hauppauge Apr 20 20:05:14 tvserver kernel: [ 168.664396] usb 1-3: SerialNumber: 7300-00-F080EDCF Apr 20 20:05:14 tvserver kernel: [ 168.691956] media: Linux media interface: v0.10 Apr 20 20:05:14 tvserver kernel: [ 168.705475] videodev: Linux video capture interface: v2.00 Apr 20 20:05:14 tvserver kernel: [ 168.732770] pvrusb2: Hardware description: WinTV HVR-1950 Model 751xx Apr 20 20:05:14 tvserver kernel: [ 168.735094] usbcore: registered new interface driver pvrusb2 Apr 20 20:05:14 tvserver kernel: [ 168.735097] pvrusb2: V4L in-tree version:Hauppauge WinTV-PVR-USB2 MPEG2 Encoder/Tuner Apr 20 20:05:14 tvserver kernel: [ 168.735099] pvrusb2: Debug mask is 31 (0x1f) Apr 20 20:05:15 tvserver kernel: [ 169.763903] pvrusb2: Device microcontroller firmware (re)loaded; it should now reset and reconnect. Apr 20 20:05:16 tvserver kernel: [ 169.795959] usb 1-3: USB disconnect, device number 6 Apr 20 20:05:16 tvserver kernel: [ 169.796237] pvrusb2: Device being rendered inoperable Apr 20 20:05:17 tvserver kernel: [ 171.584224] usb 1-3: new high-speed USB device number 7 using xhci_hcd Apr 20 20:05:17 tvserver kernel: [ 171.741894] usb 1-3: New USB device found, idVendor=2040, idProduct=7501, bcdDevice= 8.00 Apr 20 20:05:17 tvserver kernel: [ 171.741901] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 20 20:05:17 tvserver kernel: [ 171.741905] usb 1-3: Product: WinTV Apr 20 20:05:17 tvserver kernel: [ 171.741908] usb 1-3: Manufacturer: Hauppauge Apr 20 20:05:17 tvserver kernel: [ 171.741912] usb 1-3: SerialNumber: 7300-00-F080EDCF Apr 20 20:05:17 tvserver kernel: [ 171.745377] pvrusb2: Hardware description: WinTV HVR-1950 Model 751xx Apr 20 20:05:17 tvserver kernel: [ 171.780167] pvrusb2: Binding ir_z8f0811_haup to i2c address 0x71. Apr 20 20:05:17 tvserver kernel: [ 171.791676] cx25840 8-0044: cx25843-24 found @ 0x88 (pvrusb2_a) Apr 20 20:05:18 tvserver kernel: [ 171.802309] pvrusb2: Attached sub-driver cx25840 Apr 20 20:05:18 tvserver kernel: [ 171.821598] tuner: 8-0042: Tuner -1 found with type(s) Radio TV. Apr 20 20:05:18 tvserver kernel: [ 171.821652] pvrusb2: Attached sub-driver tuner Apr 20 20:05:18 tvserver kernel: [ 171.842786] ir-kbd-i2c 8-0071: Zilog/Hauppauge IR blaster firmware version 2.1.0 Apr 20 20:05:18 tvserver kernel: [ 171.880179] Registered IR keymap rc-hauppauge Apr 20 20:05:18 tvserver kernel: [ 171.880341] rc rc0: WinTV HVR-1950 Model 751xx as /devices/pci0000:00/0000:00:14.0/usb1/1-3/i2c-8/8-0071/rc/rc0 Apr 20 20:05:18 tvserver kernel: [ 171.880448] input: WinTV HVR-1950 Model 751xx as /devices/pci0000:00/0000:00:14.0/usb1/1-3/i2c-8/8-0071/rc/rc0/input14 Apr 20 20:05:18 tvserver kernel: [ 171.881932] rc rc0: lirc_dev: driver ir_kbd_i2c registered at minor = 0, scancode receiver, raw IR transmitter Apr 20 20:05:20 tvserver kernel: [ 174.029999] cx25840 8-0044: loaded v4l-cx25840.fw firmware (16382 bytes) Apr 20 20:05:20 tvserver kernel: [ 174.141325] tveeprom: Hauppauge model 75111, rev E1F5, serial# 4034981327 Apr 20 20:05:20 tvserver kernel: [ 174.141329] tveeprom: MAC address is 00:0d:fe:80:ed:cf Apr 20 20:05:20 tvserver kernel: [ 174.141332] tveeprom: tuner model is NXP 18271C2 (idx 155, type 54) Apr 20 20:05:20 tvserver kernel: [ 174.141336] tveeprom: TV standards NTSC(M) ATSC/DVB Digital (eeprom 0x88) Apr 20 20:05:20 tvserver kernel: [ 174.141338] tveeprom: audio processor is CX25843 (idx 37) Apr 20 20:05:20 tvserver kernel: [ 174.141340] tveeprom: decoder processor is CX25843 (idx 30) Apr 20 20:05:20 tvserver kernel: [ 174.141342] tveeprom: has radio, has IR receiver, has IR transmitter Apr 20 20:05:20 tvserver kernel: [ 174.141351] pvrusb2: Supported video standard(s) reported available in hardware: PAL-M/N/Nc;NTSC-M/Mj/Mk;ATSC-8VSB/16VSB Apr 20 20:05:20 tvserver kernel: [ 174.141354] pvrusb2: Initial video standard (determined by device type): NTSC-M Apr 20 20:05:20 tvserver kernel: [ 174.141367] pvrusb2: Device initialization completed successfully. Apr 20 20:05:20 tvserver kernel: [ 174.144448] pvrusb2: registered device video0 [mpeg] Apr 20 20:05:20 tvserver kernel: [ 174.144456] dvbdev: DVB: registering new adapter (pvrusb2-dvb) Apr 20 20:05:22 tvserver kernel: [ 176.392367] cx25840 8-0044: loaded v4l-cx25840.fw firmware (16382 bytes) Apr 20 20:05:22 tvserver kernel: [ 176.528783] tda829x 8-0042: setting tuner address to 60 Apr 20 20:05:22 tvserver kernel: [ 176.565698] tda18271 8-0060: creating new instance Apr 20 20:05:22 tvserver kernel: [ 176.612903] tda18271: TDA18271HD/C2 detected @ 8-0060 Apr 20 20:05:23 tvserver kernel: [ 177.076811] tda18271: performing RF tracking filter calibration Apr 20 20:05:44 tvserver kernel: [ 198.760720] tda18271: RF tracking filter calibration complete Apr 20 20:05:45 tvserver kernel: [ 198.820703] tda829x 8-0042: type set to tda8295+18271 Apr 20 20:05:51 tvserver kernel: [ 204.956768] cx25840 8-0044: 0x0000 is not a valid video input! Apr 20 20:05:51 tvserver kernel: [ 205.058130] usb 1-3: DVB: registering adapter 0 frontend 0 (Samsung S5H1411 QAM/8VSB Frontend)... Apr 20 20:05:51 tvserver kernel: [ 205.059511] tda829x 8-0042: type set to tda8295 Apr 20 20:05:51 tvserver kernel: [ 205.100470] tda18271 8-0060: attaching existing instance Apr 20 20:05:54 tvserver kernel: [ 208.492347] random: crng init done Apr 20 20:05:54 tvserver kernel: [ 208.492353] random: 7 urandom warning(s) missed due to ratelimiting Apr 20 20:06:00 tvserver kernel: [ 213.800743] cx25840 8-0044: loaded v4l-cx25840.fw firmware (16382 bytes)
Apr 20 20:06:29 tvserver kernel: [ 242.974411] usbcore: deregistering interface driver pvrusb2 Apr 20 20:06:29 tvserver kernel: [ 242.974446] pvrusb2: Device being rendered inoperable Apr 20 20:06:29 tvserver kernel: [ 242.974577] BUG: unable to handle kernel NULL pointer dereference at 0000000000000500 Apr 20 20:06:29 tvserver kernel: [ 242.974722] PGD 0 P4D 0 Apr 20 20:06:29 tvserver kernel: [ 242.974775] Oops: 0000 [#1] SMP PTI Apr 20 20:06:29 tvserver kernel: [ 242.974839] CPU: 1 PID: 3124 Comm: pvrusb2-context Not tainted 4.18.0-17-generic #18~18.04.1-Ubuntu Apr 20 20:06:29 tvserver kernel: [ 242.974980] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Q1900-ITX, BIOS P1.70 03/31/2016 Apr 20 20:06:29 tvserver kernel: [ 242.975145] RIP: 0010:pvr2_v4l2_internal_check+0x48/0x70 [pvrusb2] Apr 20 20:06:29 tvserver kernel: [ 242.975246] Code: ce e3 ff ff 48 8b 7b 40 e8 c5 e3 ff ff 48 8b 43 38 48 8b 90 00 05 00 00 48 05 00 05 00 00 48 39 d0 74 03 5b 5d c3 48 8b 43 40 <48> 8b 90 00 05 00 00 48 05 00 05 00 00 48 39 d0 75 e7 48 89 df e8 Apr 20 20:06:29 tvserver kernel: [ 242.975616] RSP: 0018:ffffbd97026b7ea0 EFLAGS: 00010246 Apr 20 20:06:29 tvserver kernel: [ 242.975704] RAX: 0000000000000000 RBX: ffff9b5c2fd3b540 RCX: 0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.975818] RDX: ffff9b5c03c48500 RSI: 0000000000000000 RDI: 0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.975933] RBP: ffffbd97026b7ea8 R08: 0000000000000212 R09: ffff9b5c2e4ba218 Apr 20 20:06:29 tvserver kernel: [ 242.976047] R10: 0000000000000000 R11: 0000000000000001 R12: ffff9b5c0e907580 Apr 20 20:06:29 tvserver kernel: [ 242.976161] R13: ffffffffc0dd0a90 R14: 0000000000000000 R15: ffff9b5c31ff0000 Apr 20 20:06:29 tvserver kernel: [ 242.976276] FS: 0000000000000000(0000) GS:ffff9b5c3fc80000(0000) knlGS:0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.976405] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 20 20:06:29 tvserver kernel: [ 242.976499] CR2: 0000000000000500 CR3: 0000000112a0a000 CR4: 00000000001006e0 Apr 20 20:06:29 tvserver kernel: [ 242.976613] Call Trace: Apr 20 20:06:29 tvserver kernel: [ 242.976680] pvr2_context_thread_func+0xcc/0x320 [pvrusb2] Apr 20 20:06:29 tvserver kernel: [ 242.976782] ? wait_woken+0x80/0x80 Apr 20 20:06:29 tvserver kernel: [ 242.976849] kthread+0x121/0x140 Apr 20 20:06:29 tvserver kernel: [ 242.976920] ? pvr2_context_destroy+0xd0/0xd0 [pvrusb2] Apr 20 20:06:29 tvserver kernel: [ 242.977010] ? kthread_create_worker_on_cpu+0x70/0x70 Apr 20 20:06:29 tvserver kernel: [ 242.977098] ret_from_fork+0x35/0x40 Apr 20 20:06:29 tvserver kernel: [ 242.977162] Modules linked in: s5h1411 tda18271 rc_hauppauge tda8290 tuner ir_kbd_i2c rc_core cx25840 pvrusb2(-) tveeprom cx2341x dvb_core v4l2_common videodev media xt_nat veth xt_recent ipt_REJECT nf_reject_ipv4 xt_limit xt_comment xt_multiport xt_hashlimit xt_mark iptable_mangle xt_tcpudp ipt_MASQUERADE xt_CT xfrm_user xfrm_algo iptable_raw xt_addrtype nfnetlink_log xt_conntrack xt_NFLOG nf_log_ipv4 nf_log_common br_netfilter bridge stp xt_LOG llc 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_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 Apr 20 20:06:29 tvserver kernel: [ 242.978292] ts_kmp nf_conntrack_amanda iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter bpfilter arc4 md4 cmac nls_utf8 cifs ccm fscache aufs overlay nls_iso8859_1 xfs libcrc32c snd_hdmi_lpe_audio snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore intel_rapl intel_soc_dts_thermal intel_soc_dts_iosf intel_powerclamp coretemp kvm_intel kvm irqbypass punit_atom_debug crct10dif_pclmul crc32_pclmul ghash_clmulni_intel cryptd intel_cstate i915 joydev input_leds hci_uart drm_kms_helper btqca btbcm btintel drm bluetooth video i2c_algo_bit mei_txe fb_sys_fops lpc_ich mei rfkill_gpio syscopyarea ecdh_generic mac_hid sysfillrect sysimgblt sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 hid_logitech_hidpp Apr 20 20:06:29 tvserver kernel: [ 242.978943] hid_logitech_dj hid_generic usbhid ahci r8169 libahci mii i2c_hid hid Apr 20 20:06:29 tvserver kernel: [ 242.979020] CR2: 0000000000000500 Apr 20 20:06:29 tvserver kernel: [ 242.979056] ---[ end trace 6130eddfe1b2906c ]--- Apr 20 20:06:29 tvserver kernel: [ 242.979111] RIP: 0010:pvr2_v4l2_internal_check+0x48/0x70 [pvrusb2] Apr 20 20:06:29 tvserver kernel: [ 242.979170] Code: ce e3 ff ff 48 8b 7b 40 e8 c5 e3 ff ff 48 8b 43 38 48 8b 90 00 05 00 00 48 05 00 05 00 00 48 39 d0 74 03 5b 5d c3 48 8b 43 40 <48> 8b 90 00 05 00 00 48 05 00 05 00 00 48 39 d0 75 e7 48 89 df e8 Apr 20 20:06:29 tvserver kernel: [ 242.979376] RSP: 0018:ffffbd97026b7ea0 EFLAGS: 00010246 Apr 20 20:06:29 tvserver kernel: [ 242.979425] RAX: 0000000000000000 RBX: ffff9b5c2fd3b540 RCX: 0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.979488] RDX: ffff9b5c03c48500 RSI: 0000000000000000 RDI: 0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.979551] RBP: ffffbd97026b7ea8 R08: 0000000000000212 R09: ffff9b5c2e4ba218 Apr 20 20:06:29 tvserver kernel: [ 242.979614] R10: 0000000000000000 R11: 0000000000000001 R12: ffff9b5c0e907580 Apr 20 20:06:29 tvserver kernel: [ 242.979677] R13: ffffffffc0dd0a90 R14: 0000000000000000 R15: ffff9b5c31ff0000 Apr 20 20:06:29 tvserver kernel: [ 242.979741] FS: 0000000000000000(0000) GS:ffff9b5c3fc80000(0000) knlGS:0000000000000000 Apr 20 20:06:29 tvserver kernel: [ 242.979812] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 20 20:06:29 tvserver kernel: [ 242.979864] CR2: 0000000000000500 CR3: 0000000112a0a000 CR4: 00000000001006e0 Apr 20 20:06:29 tvserver kernel: [ 243.024217] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.024343] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.128216] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.128346] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.232211] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.232341] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.336216] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.336347] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.440210] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.440339] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.548208] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.555652] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.664203] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.671289] rc rc0: error -5 Apr 20 20:06:29 tvserver kernel: [ 243.780218] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:29 tvserver kernel: [ 243.787356] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 243.896197] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 243.903370] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.012208] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.019453] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.128215] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.135966] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.244200] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.251468] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.360216] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.367966] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.476195] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.483882] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.592217] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.599190] rc rc0: error -5 Apr 20 20:06:30 tvserver kernel: [ 244.708212] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:30 tvserver kernel: [ 244.715204] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 244.824215] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 244.831281] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 244.940213] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 244.947297] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.056235] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.063347] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.172202] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.179329] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.288215] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.295409] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.404219] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.411483] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.520213] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.527316] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.636240] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.642962] rc rc0: error -5 Apr 20 20:06:31 tvserver kernel: [ 245.752266] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:31 tvserver kernel: [ 245.758325] rc rc0: error -5 Apr 20 20:06:32 tvserver kernel: [ 245.868202] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:32 tvserver kernel: [ 245.874188] rc rc0: error -5 Apr 20 20:06:32 tvserver kernel: [ 245.980220] pvrusb2: Attempted to execute control transfer when device not ok Apr 20 20:06:32 tvserver kernel: [ 245.986341] rc rc0: error -5 .... etc....
signature.asc
Description: This is a digitally signed message part
_______________________________________________ pvrusb2 mailing list [email protected] http://www.isely.net/cgi-bin/mailman/listinfo/pvrusb2
