akvcam is just unstable

[dx9s]

[fwiw: at * commit 5f94c37 (HEAD -> master, tag: 1.0.4, origin/master, origin/HEAD)]

At first I thought it was an issue with more than one connection, but a single has same issues:

It has been difficult to document what I have so far, because after akvcam stops responding to "capture" programs (in this case cheese for reference), the system is unstable in various ways. Reboots usually lock up, removing the driver fails (it's "busy") so can't reload. Often before a reboot, the system usually stops responding in some fashion (keyboard, mouse, screen lockups].

I've tried older kernels (4.15, 4.18, currently on latest hwe 5.3 / all lowlatency).
At this point not sure what to do -- will continue to poke at it and try to make it usable.

config.ini:

[Cameras]
cameras/size = 2

# /dev/videoN
cameras/1/type = output
cameras/1/mode = mmap, userptr, rw
cameras/1/description = VCam1(4:3/720p)
cameras/1/formats = 1

# /dev/videoN+1
cameras/2/type = capture
cameras/2/mode = mmap, userptr, rw
cameras/2/description = VCam1(4:3/480p/720p)
cameras/2/formats = 2, 3

[Formats]
formats/size = 3

# formats for "output" (into akvcam)
formats/1/format = RGB24, YUY2
formats/1/width = 960
formats/1/height = 720
formats/1/fps = 30/1, 15/1, 15/2

# formats for "capture" (output from akvcam)
formats/2/format = RGB24
formats/2/width = 640
formats/2/height = 480
formats/2/fps = 30/1, 15/1, 15/2

formats/3/format = RGB24
formats/3/width = 960
formats/3/height = 720
formats/3/fps = 30/1, 15/1, 15/2

[Connections]
connections/size = 1
connections/1/connection = 1:2

then simple run cheese at it twice.. Second time Cheese complains about the device not working:

dx@wdp76:~$ sudo modprobe akvcam
dx@wdp76:~$ cheese

(cheese:4499): Gtk-WARNING **: 16:59:30.464: Theme parsing error: cheese.css:7:35: The style property GtkScrollbar:min-slider-length is deprecated and shouldn't be used anymore. It will be removed in a future version
Gtk-Message: 16:59:33.749: GtkDialog mapped without a transient parent. This is discouraged.
dx@wdp76:~$ cheese

(cheese:4584): Gtk-WARNING **: 16:59:41.872: Theme parsing error: cheese.css:7:35: The style property GtkScrollbar:min-slider-length is deprecated and shouldn't be used anymore. It will be removed in a future version
Gtk-Message: 16:59:45.052: GtkDialog mapped without a transient parent. This is discouraged.

(cheese:4584): cheese-WARNING **: 16:59:46.415: Device '/dev/video3' is busy: gstv4l2object.c(3754): gst_v4l2_object_set_format_full (): /GstCameraBin:camerabin/GstWrapperCameraBinSrc:camera_source/GstBin:bin19/GstV4l2Src:v4l2src2:
Call to S_FMT failed for RGB3 @ 640x480: Device or resource busy

dx@wdp76:~$ sudo rmmod akvcam
dx@wdp76:~$ dmesg

[...]

[ 229.307847] BUG: unable to handle page fault for address: ffffffffc0e2de9a
[ 229.307849] #PF: supervisor instruction fetch in kernel mode
[ 229.307850] #PF: error_code(0x0010) - not-present page
[ 229.307850] PGD 34bc0e067 P4D 34bc0e067 PUD 34bc10067 PMD 7e792f067 PTE 0
[ 229.307852] Oops: 0010 [#1] PREEMPT SMP PTI
[ 229.307854] CPU: 3 PID: 4565 Comm: akvcam-thread-3 Tainted: P C OE 5.3.0-51-lowlatency #44~18.04.2-Ubuntu
[ 229.307854] Hardware name: System76 Wild Dog Pro/Z370 HD3P-CF, BIOS F5 Z5 12/15/2017
[ 229.307856] RIP: 0010:0xffffffffc0e2de9a
[ 229.307858] Code: Bad RIP value.
[ 229.307858] RSP: 0018:ffffb0b8c38b7ef0 EFLAGS: 00010246
[ 229.307859] RAX: 0000000000000000 RBX: ffff9b4405ba3700 RCX: 0000000000000000
[ 229.307860] RDX: 0000000000000000 RSI: 0000000000000246 RDI: 0000000000000000
[ 229.307860] RBP: ffffb0b8c38b7f00 R08: 0000000000000000 R09: 000000000002a000
[ 229.307874] R10: ffffb0b8c00e7e18 R11: 0000000000000361 R12: 0000000000000021
[ 229.307875] R13: ffffb0b8c384fce8 R14: ffff9b4405ba3700 R15: ffff9b43ec0fcd80
[ 229.307876] FS: 0000000000000000(0000) GS:ffff9b448e8c0000(0000) knlGS:0000000000000000
[ 229.307876] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 229.307877] CR2: ffffffffc0e2de70 CR3: 000000034bc0a006 CR4: 00000000003606e0
[ 229.307878] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 229.307878] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 229.307879] Call Trace:
[ 229.307882] kthread+0x121/0x140
[ 229.307883] ? kthread_park+0xb0/0xb0
[ 229.307897] ret_from_fork+0x35/0x40
[ 229.307899] Modules linked in: xt_CHECKSUM iptable_mangle xt_MASQUERADE iptable_nat nf_nat xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter bpfilter typec_displayport aufs overlay binfmt_misc nls_iso8859_1 nvidia_uvm(OE) nvidia_drm(POE) nvidia_modeset(POE) nvidia(POE) intel_rapl_msr mei_hdcp intel_rapl_common x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_hdmi coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec_realtek snd_hda_codec_generic ledtrig_audio uvcvideo aesni_intel snd_hda_intel snd_intel_nhlt v4l2_common videobuf2_vmalloc aes_x86_64 drm_kms_helper snd_hda_codec crypto_simd cryptd videobuf2_memops snd_usb_audio snd_hda_core glue_helper snd_usbmidi_lib snd_hwdep intel_cstate videobuf2_v4l2 snd_seq_midi intel_rapl_perf videobuf2_common snd_seq_midi_event drm snd_rawmidi snd_seq videodev ipmi_devintf
[ 229.307914] ipmi_msghandler joydev wmi_bmof mc input_leds snd_pcm fb_sys_fops ucsi_ccg snd_seq_device syscopyarea typec_ucsi snd_timer sysfillrect typec sysimgblt snd mei_me soundcore mei ie31200_edac acpi_pad mac_hid sch_fq_codel cuse parport_pc ppdev lp parport binder_linux ashmem_linux(CE) ip_tables x_tables autofs4 hid_logitech_hidpp hid_logitech_dj hid_plantronics hid_generic usbhid hid e1000e ahci libahci i2c_nvidia_gpu wmi video [last unloaded: akvcam]
[ 229.307924] CR2: ffffffffc0e2de9a
[ 229.307925] ---[ end trace cbf1559a98be27fc ]---
[ 229.307926] RIP: 0010:0xffffffffc0e2de9a
[ 229.307927] Code: Bad RIP value.
[ 229.307927] RSP: 0018:ffffb0b8c38b7ef0 EFLAGS: 00010246
[ 229.307928] RAX: 0000000000000000 RBX: ffff9b4405ba3700 RCX: 0000000000000000
[ 229.307928] RDX: 0000000000000000 RSI: 0000000000000246 RDI: 0000000000000000
[ 229.307929] RBP: ffffb0b8c38b7f00 R08: 0000000000000000 R09: 000000000002a000
[ 229.307929] R10: ffffb0b8c00e7e18 R11: 0000000000000361 R12: 0000000000000021
[ 229.307930] R13: ffffb0b8c384fce8 R14: ffff9b4405ba3700 R15: ffff9b43ec0fcd80
[ 229.307931] FS: 0000000000000000(0000) GS:ffff9b448e8c0000(0000) knlGS:0000000000000000
[ 229.307931] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 229.307932] CR2: ffffffffc0e2de70 CR3: 000000034bc0a006 CR4: 00000000003606e0
[ 229.307932] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 229.307933] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400

[dx9s]

Just installed the non-lowlatency kernel and retested.. no change (never had any issues with low-latency kernel -- the RT patches from Ingo Molnar back in the 2.6 kernel days could cause issues with certain video cards, but that was so 10+ years ago).

Not sure what happened, but akvcam used to be able to be rmmod / insmod (modprobed) no problem. Perhaps I need to roll back to older akvcam code/commit?

[hipersayanX]

Try insmoding with loglevel=7 and check with dmesg if it gives more information.

[vladikoles]

I fully confirm everything this. I have exactly the same problem.
2020-05-24:
Ubuntu 18.04 64-bit
5.3.0-53-generic

[dx9s]

Fresh boot and now some unknown symbol issue:

dx@wdp76:~$ cd git/akvcam/src
dx@wdp76:~/git/akvcam/src$ make all
make -C /lib/modules/5.3.0-53-lowlatency/build M=/home/dx/git/akvcam/src modules
make[1]: Entering directory '/usr/src/linux-headers-5.3.0-53-lowlatency'
Building modules, stage 2.
MODPOST 1 modules
make[1]: Leaving directory '/usr/src/linux-headers-5.3.0-53-lowlatency'
dx@wdp76:~/git/akvcam/src$ sudo insmod akvcam.ko loglevel=7
[sudo] password for dx:
insmod: ERROR: could not insert module akvcam.ko: Unknown symbol in module
dx@wdp76:~/git/akvcam/src$ dmesg
[...]
[ 52.223963] akvcam: Unknown symbol video_unregister_device (err -2)
[ 52.223976] akvcam: Unknown symbol video_device_alloc (err -2)
[ 52.223989] akvcam: Unknown symbol v4l2_device_register (err -2)
[ 52.224006] akvcam: Unknown symbol __video_register_device (err -2)
[ 52.224019] akvcam: Unknown symbol v4l2_device_unregister (err -2)
[ 52.224030] akvcam: Unknown symbol video_device_release (err -2)
[ 52.224043] akvcam: Unknown symbol video_device_release_empty (err -2)
dx@wdp76:~/git/akvcam/src$ lsmod |grep akv
dx@wdp76:~/git/akvcam/src$

P.S.> upgraded from -51 to -53 .. was running 5.3.0-51-lowlatency before.. I can try on 5.6 but don't expect things to get better.

[hipersayanX]

@dx9s you upgraded or changed to a different kernel version, you must make clean && make and then insmod. That's why it gives you this error:

insmod: ERROR: could not insert module akvcam.ko: Unknown symbol in module

[dx9s]

I actually did that and more.. Just updated with another kernel update.. will try again (perhaps this was a known issue in kernel release).

[dx9s]

Updated to the current HWE release (5.3.0.53.110) .. think it was .109 before but wasn't paying attention / HWE are a bit more leading edge. I actually re-checked out the latest master and did a make clean (was on an Apr 7 commit prior, to getting the Apr 12 commit above. made a clean / make all and built test against several different kernels as outlined originally.

-- okay machine locked up but lucky firefox saved what I had in this dialog box. Able to install the kernel module once and run cheese once and point at the vcam .. it locked up the second time I loaded cheese and had to hold power button down.

Cannot tell you what was inside dmesg as the machine hard locked up again.

--Doug

[dx9s]

I pulled the logs from kern.log and it's huge for the parts dealing with akvcam .. not sure where to post it

[dx9s]

forked / create a logs branch and shoved a file in over on my fork here:

https://github.com/dx9s/akvcam/blob/logs/logs/dx9s-2020-05-24-kern.log

https://github.com/dx9s/akvcam/blob/logs/logs/dx9s-2020-05-26-kern.log

[Edit: Added/separated 24th and 26th logs]

[dx9s]

Looks like it locked up because it possibly dropped connection to my USB keyboard/mouse during the kernel oops (page fault in the akvcam kernel module). Page faults are not good!

[dx9s]

switched to older kernel and tried again, was able to reboot machine, but it was not happy during shutdown:

https://github.com/dx9s/akvcam/blob/logs/logs/dx9s-2020-05-26-%232.log

NOTE there might also be a conflict between /dev/video? .. in the dmesg output you can clearly see /dev/video1 reference:

https://github.com/dx9s/akvcam/blob/33a7a394bbf601c1687befd11540555d60ab71f6/logs/dx9s-2020-05-26-%232.log#L53

This is weird because I have an ACTUAL hardware capture device that is using /dev/video0 AND /dev/video1 (the way that the kernel provides two DEVs for a single v4l2 device these days)

--Doug

[hipersayanX]

The problem is here, here and here. The driver keep sending frames after akvcam_node_release() because the client is not sending the VIDIOC_STREAMOFF ioctl.

[vladikoles]

And now what i can do?
I start Cheese, it capture first videodevice /dev/video0 (akvcam), I close it and the desktop freezes.
Impossible to use gstreamer. Is there a workaround for this problem in the code? How do other drivers solve this?

[hipersayanX]

Test latest commit.

[hipersayanX]

This bug may be fixed in 1.1.0, closing.