cros_camera_service aborts repeatedly with "Check failed: rv == 0 (22 vs. 0). Invalid argument#012/usr/lib64/libbase-core-456626.so" |
||||
Issue descriptionFrom issue 913153: It looks like cros_camera_service is crashing repeatedly on login when run in a VM on the Chrome CQ, which makes disks fill up and causes tests to fail. For example, from https://ci.chromium.org/p/chromium/builders/luci.chromium.try/chromeos-amd64-generic-rel/148695: https://isolateserver.appspot.com/browse?namespace=default-gzip&hash=17323762f002daf7f47e50f36a6f5e47a9f02ba9 2018-12-10T18:11:43.762712+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/' -> '/' type '' flags 0x1001 2018-12-10T18:11:43.762836+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/proc' -> '/proc' type '' flags 0x1001 2018-12-10T18:11:43.762888+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/sys' -> '/sys' type '' flags 0x1001 2018-12-10T18:11:43.762932+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/dev' -> '/dev' type '' flags 0x1001 2018-12-10T18:11:43.762972+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/var' -> '/var' type '' flags 0x1001 2018-12-10T18:11:43.763466+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/dev/shm' -> '/dev/shm' type '' flags 0x1000 2018-12-10T18:11:43.763590+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/sys/kernel/debug' -> '/sys/kernel/debug' type '' flags 0x1001 2018-12-10T18:11:43.763626+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/sys/kernel/debug/tracing' -> '/sys/kernel/debug/tracing' type '' flags 0x1000 2018-12-10T18:11:43.763767+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount 'tmpfs' -> '/run' type 'tmpfs' flags 0xe 2018-12-10T18:11:43.763815+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/run/camera' -> '/run/camera' type '' flags 0x1000 2018-12-10T18:11:43.763966+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/run/udev/data' -> '/run/udev/data' type '' flags 0x1001 2018-12-10T18:11:43.764015+00:00 INFO cros_camera_service[1599]: libminijail[2]: mount '/var/empty/run' -> '/var/run' type 'bind' flags 0x5000 2018-12-10T18:11:43.874323+00:00 INFO cros_camera_service[1649]: OnSocketFileStatusChange(): Connected to CameraHalDispatcher 2018-12-10T18:11:43.874655+00:00 INFO cros_camera_service[1649]: main(): Started camera HAL v3 adapter 2018-12-10T18:11:43.884992+00:00 INFO cros_camera_service[1649]: RegisterCameraHal(): Try to load camera hal /usr/lib64/camera_hal/usb.so 2018-12-10T18:11:44.264653+00:00 INFO cros_camera_service[1649]: RegisterCameraHal(): Running camera HAL adapter on 3 2018-12-10T18:11:44.269790+00:00 INFO cros_camera_service[1649]: StartOnThread(): Camera module 0 has 0 cameras 2018-12-10T18:11:44.270534+00:00 WARNING cros_camera_service[1649]: InitializeAndGetVendorTags(): Portrait processor binary is not found. Disable portrait mode 2018-12-10T18:11:44.270863+00:00 INFO cros_camera_service[1649]: StartOnThread(): SuperHAL started with 1 modules and 0 built-in cameras 2018-12-10T18:11:44.277579+00:00 INFO cros_camera_service[1649]: RegisterCameraHal(): Registered camera HAL 2018-12-10T18:11:46.218667+00:00 INFO cros_camera_algo[1939]: libminijail[2]: mount '/usr' -> '/usr' type 'none' flags 0x1000 2018-12-10T18:11:46.218790+00:00 INFO cros_camera_algo[1939]: libminijail[2]: mount '/proc' -> '/proc' type 'proc' flags 0xe 2018-12-10T18:11:46.218827+00:00 INFO cros_camera_algo[1939]: libminijail[2]: mount '/dev/urandom' -> '/dev/urandom' type 'none' flags 0x1001 2018-12-10T18:11:46.218872+00:00 INFO cros_camera_algo[1939]: libminijail[2]: mount '/run/camera' -> '/run/camera' type '' flags 0x1000 2018-12-10T18:11:46.603809+00:00 INFO cros_camera_service[1649]: OnDeviceAdded(): New vivid camera device at /dev/video0 2018-12-10T18:11:46.604541+00:00 ERR cros_camera_service[1649]: GetPowerLineFrequency(): Power line frequency should support auto or 50/60Hz 2018-12-10T18:11:46.624639+00:00 INFO cros_camera_service[1649]: CameraDeviceStatusChange(): module_id = 0, internal_camera_id = 0, new_status = 1 2018-12-10T18:11:46.624813+00:00 INFO cros_camera_service[1649]: CameraDeviceStatusChange(): External camera plugged, external_camera_id = 0 2018-12-10T18:11:56.868461+00:00 INFO cros_camera_service[1649]: OnServiceMojoChannelError(): Mojo connection to CameraHalDispatcher is broken 2018-12-10T18:11:56.898161+00:00 CRIT cros_camera_service[1649]: Check failed: rv == 0 (22 vs. 0). Invalid argument#012/usr/lib64/libbase-core-456626.so(_ZN4base5debug10StackTraceC1Em+0x1c) [0x7d6dc6b7a9bc]#012 2018-12-10T18:11:57.977100+00:00 WARNING crash_reporter[2256]: [user] Received crash notification for cros_camera_service[1649] sig 6, user 603 group 603 (developer build - not testing - always dumping) 2018-12-10T18:11:58.900740+00:00 INFO crash_reporter[2256]: Stored minidump to /var/spool/crash/cros_camera_service.20181210.101157.1649.dmp 2018-12-10T18:11:58.902706+00:00 INFO crash_reporter[2256]: Leaving core file at /proc/self/fd/5/cros_camera_service.20181210.101157.1649.core due to developer image I don't know who owns this code, so I'm just adding some people who have modified it recently.
,
Dec 12
,
Dec 12
It seems that cros_camera_service does not properly shutdown itself when Chrome is exited.
,
Dec 12
It seems that this crash happens when cros_camera_service's mojo connection for an external camera is broken. This crash doesn't happen on Chromebooks because they have their own webcam and don't use external ones. On the other hand, on VM boards, upstart service always loads vivid at start-up time and cros_camera_service recognizes it as an external camera.
,
Dec 12
Did you try it on Chromebook with DCHECK enabled (USE=cros-debug)? We have saw several similar crashes/check fails before due to wrong lifetimes, and I suspect this is the same case. There are some extra DCHECKs for lock/file/... in libchrome that we might violate. I will try to get a stack trace with symbols tomorrow.
,
Dec 12
#5: Ah, I didn't try DCHECK-enabled image on Chromebook. Your idea sounds reasonable. Thanks!
,
Dec 13
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 #1 0x00007ed59f480d61 in __GI_abort () at abort.c:79 #2 0x00007ed59fc0fe81 in base::debug::(anonymous namespace)::DebugBreak () at base/debug/debugger_posix.cc:221 #3 base::debug::BreakDebugger () at base/debug/debugger_posix.cc:251 #4 0x00007ed59fc35c7f in logging::LogMessage::~LogMessage (this=0x7fff04d06628) at base/logging.cc:774 #5 0x00007ed59fc8ca0e in base::internal::LockImpl::Lock (this=<optimized out>) at base/synchronization/lock_impl_posix.cc:65 #6 0x00007ed59d457318 in base::Lock::Acquire (this=<optimized out>) at ../../../../../../../../usr/include/base-456626/base/synchronization/lock.h:45 #7 base::AutoLock::AutoLock (this=<optimized out>, lock=...) at ../../../../../../../../usr/include/base-456626/base/synchronization/lock.h:115 #8 cros::CameraMojoChannelManagerImpl::TearDownMojoEnv () at ../../../cros-camera-libcamera_ipc-0.0.1/platform/arc-camera/common/camera_mojo_channel_manager_impl.cc:163 #9 0x00007ed59ff21f67 in _dl_fini () at dl-fini.c:138 The lock is already destroyed in TearDownMojoEnv(). https://chromium.git.corp.google.com/chromiumos/platform/arc-camera/+/44c34946304cef80bc0335e3bd941b6b77dad83e/common/camera_mojo_channel_manager_impl.cc#163
,
Dec 13
Per offline discussion we are going to change the lock to be leaky to avoid the race condition.
,
Dec 14
See https://issuetracker.google.com/121047293 - possibly a dupe of this as derat@ suggested?
,
Dec 14
Note I filed that bug in response to a CQ failure.
,
Dec 17
This doesn't seem to be VM specific. For example, I see lots of cros_camera_service crashes at b/121001699#comment10 and I believe the device is nocturne. The log message is the same -- 'Check failed: rv == ...'. See sysinfo/var/log/messages at https://stainless.corp.google.com/browse/chromeos-autotest-results/267275588-chromeos-test/ for example.
,
Dec 17
This might be causing b/121001699 (Pri-0 CQ failure) BTW.
,
Dec 18
The fix https://crrev.com/c/1375524 is uploaded for review.
,
Dec 18
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform/arc-camera/+/220de68e4c7f0138e87a53bedfe1129cf2fe93d0 commit 220de68e4c7f0138e87a53bedfe1129cf2fe93d0 Author: Shik Chen <shik@chromium.org> Date: Tue Dec 18 12:28:56 2018 common: make the static lock leaky The lock was already destroyed before TearDownMojoEnv(). Make it leaky to have the correct lifetime span. http://go/cstyle#Static_and_Global_Variables BUG= chromium:914110 TEST=Run `restart ui` on a cros-debug vm build and check cros_camera_service does not hit the DCHECK at exit. TEST=CCA preview works on Nautilus. Change-Id: I03b19ed03097c47d0b42167b6b2b2155fddb9d46 Reviewed-on: https://chromium-review.googlesource.com/1375524 Commit-Ready: Shik Chen <shik@chromium.org> Tested-by: Shik Chen <shik@chromium.org> Reviewed-by: Ricky Liang <jcliang@chromium.org> [modify] https://crrev.com/220de68e4c7f0138e87a53bedfe1129cf2fe93d0/common/camera_mojo_channel_manager_impl.cc [modify] https://crrev.com/220de68e4c7f0138e87a53bedfe1129cf2fe93d0/common/camera_mojo_channel_manager_impl.h
,
Dec 18
|
||||
►
Sign in to add a comment |
||||
Comment 1 by derat@chromium.org
, Dec 11