Access to other devices is denied for a minijalied process invoked from udev rule |
|||||
Issue description
The symptom happens from the test image built from the top of the tree by developer. (See lsb-release attached at the end)
Under a udev rule for the firmware upgrader, "huddly-updater", for Huddly camera USB device,
Permission Broker takes precedence over the permissions specified by the udev rule. This leads to the following symptoms.
- The huddly-updater fails to upgrade the firmware.
- The USB device is stuck in the "Bootloader mode", whose PID is 0x0010, and the device becomes unusable for any application purpose.
localhost ~ # lsusb
...
Bus 002 Device 031: ID 2bd9:0011
...
localhost ~ # ls -l /dev/bus/usb/002/031
crw-rw-r-- 1 cfm-firmware-updaters cfm-firmware-updaters 189, 158 May 17 21:33 /dev/bus/usb/002/031
localhost ~ #
And the /var/log/messages show
2017-05-17T21:24:04.195378-07:00 INFO kernel: [ 4306.309383] usb 2-2: USB disconnect, device number 23
2017-05-17T21:24:16.014899-07:00 INFO kernel: [ 4318.139309] usb 2-2: new SuperSpeed USB device number 24 using xhci_hcd
2017-05-17T21:24:16.026900-07:00 INFO kernel: [ 4318.150878] usb 2-2: New USB device found, idVendor=2bd9, idProduct=0011
2017-05-17T21:24:16.026933-07:00 INFO kernel: [ 4318.150901] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2017-05-17T21:24:16.026937-07:00 INFO kernel: [ 4318.150918] usb 2-2: Product: Huddly GO
2017-05-17T21:24:16.026941-07:00 INFO kernel: [ 4318.150930] usb 2-2: Manufacturer: Huddly
2017-05-17T21:24:16.026944-07:00 INFO kernel: [ 4318.150941] usb 2-2: SerialNumber: 43D00105
2017-05-17T21:24:16.028861-07:00 INFO kernel: [ 4318.153666] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
2017-05-17T21:24:16.031868-07:00 INFO kernel: [ 4318.155899] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
2017-05-17T21:24:16.031892-07:00 INFO kernel: [ 4318.156404] uvcvideo: Unable to create debugfs 2-24 directory.
2017-05-17T21:24:16.037012-07:00 INFO minijail0[5599]: libminijail[5599]: not running init loop, exiting immediately
2017-05-17T21:24:16.077889-07:00 INFO kernel: [ 4318.202382] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
2017-05-17T21:24:16.083863-07:00 INFO kernel: [ 4318.207913] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
2017-05-17T21:24:16.088861-07:00 INFO kernel: [ 4318.213564] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
2017-05-17T21:24:16.507123-07:00 INFO kernel: [ 4318.631463] usb 2-2: USB disconnect, device number 24
2017-05-17T21:24:18.716869-07:00 INFO kernel: [ 4320.843164] usb 2-2: new SuperSpeed USB device number 25 using xhci_hcd
2017-05-17T21:24:18.728849-07:00 INFO kernel: [ 4320.855297] usb 2-2: New USB device found, idVendor=2bd9, idProduct=0010
2017-05-17T21:24:18.728863-07:00 INFO kernel: [ 4320.855310] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2017-05-17T21:24:18.728865-07:00 INFO kernel: [ 4320.855320] usb 2-2: Product: Huddly Bootloader
2017-05-17T21:24:18.728866-07:00 INFO kernel: [ 4320.855328] usb 2-2: Manufacturer: Huddly
2017-05-17T21:24:18.728868-07:00 INFO kernel: [ 4320.855335] usb 2-2: SerialNumber: 43D00105
2017-05-17T21:24:18.730836-07:00 INFO kernel: [ 4320.857833] hid-generic 0003:2BD9:0010.0018: hiddev0,hidraw4: USB HID v1.01 Device [Huddly Huddly Bootloader] on usb-0000:00:14.0-2/input0
2017-05-17T21:24:19.216042-07:00 INFO permission_broker[960]: ProcessPath(/dev/bus/usb/002/024)
2017-05-17T21:24:19.247524-07:00 INFO permission_broker[960]: No udev entry found for /dev/bus/usb/002/024, denying access.
2017-05-17T21:24:19.247544-07:00 INFO permission_broker[960]: Verdict for /dev/bus/usb/002/024: DENY
2017-05-17T21:24:19.247551-07:00 ERR permission_broker[960]: OpenPath(...): Domain=permission_broker, Code=permission_denied, Message=Permission to open '/dev/bus/usb/002/024' denied
2017-05-17T21:24:19.247665-07:00 INFO permission_broker[960]: ProcessPath(/dev/bus/usb/002/025)
2017-05-17T21:24:19.269240-07:00 INFO permission_broker[960]: AllowUsbDeviceRule: ALLOW
2017-05-17T21:24:19.269259-07:00 INFO permission_broker[960]: AllowTtyDeviceRule: IGNORE
2017-05-17T21:24:19.296920-07:00 INFO permission_broker[960]: DenyClaimedUsbDeviceRule: DENY
2017-05-17T21:24:19.296938-07:00 INFO permission_broker[960]: Verdict for /dev/bus/usb/002/025: DENY
2017-05-17T21:24:19.296969-07:00 ERR permission_broker[960]: OpenPath(...): Domain=permission_broker, Code=permission_denied, Message=Permission to open '/dev/bus/usb/002/025' denied
and dmesg
[May17 21:24] usb 2-2: USB disconnect, device number 23
[ +11.829926] usb 2-2: new SuperSpeed USB device number 24 using xhci_hcd
[ +0.011569] usb 2-2: New USB device found, idVendor=2bd9, idProduct=0011
[ +0.000023] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ +0.000017] usb 2-2: Product: Huddly GO
[ +0.000012] usb 2-2: Manufacturer: Huddly
[ +0.000011] usb 2-2: SerialNumber: 43D00105
[ +0.002725] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
[ +0.002233] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
[ +0.000505] uvcvideo: Unable to create debugfs 2-24 directory.
[ +0.045978] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
[ +0.005531] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
[ +0.005651] uvcvideo: Found UVC 1.10 device Huddly GO (2bd9:0011)
[ +0.417899] usb 2-2: USB disconnect, device number 24
[ +2.211701] usb 2-2: new SuperSpeed USB device number 25 using xhci_hcd
[ +0.012133] usb 2-2: New USB device found, idVendor=2bd9, idProduct=0010
[ +0.000013] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ +0.000010] usb 2-2: Product: Huddly Bootloader
[ +0.000008] usb 2-2: Manufacturer: Huddly
[ +0.000007] usb 2-2: SerialNumber: 43D00105
[ +0.002498] hid-generic 0003:2BD9:0010.0018: hiddev0,hidraw4: USB HID v1.01 Device [Huddly Huddly Bootloader] on usb-0000:00:14.0-2/input0
localhost log # cat /etc/lsb-release
CHROMEOS_RELEASE_APPID={8AA6D9AC-6EBC-4288-A615-171F56F66B4E}
CHROMEOS_BOARD_APPID={8AA6D9AC-6EBC-4288-A615-171F56F66B4E}
CHROMEOS_CANARY_APPID={90F229CE-83E2-4FAF-8479-E368A34938B1}
DEVICETYPE=CHROMEBOX
CHROMEOS_RELEASE_BOARD=guado
CHROMEOS_DEVSERVER=http://porce-ws.svl.corp.google.com:8080
GOOGLE_RELEASE=9540.0.2017_05_15_1741
CHROMEOS_RELEASE_BUILD_NUMBER=9540
CHROMEOS_RELEASE_BRANCH_NUMBER=0
CHROMEOS_RELEASE_CHROME_MILESTONE=60
CHROMEOS_RELEASE_PATCH_NUMBER=2017_05_15_1741
CHROMEOS_RELEASE_TRACK=testimage-channel
CHROMEOS_RELEASE_DESCRIPTION=9540.0.2017_05_15_1741 (Test Build - porce) developer-build guado
CHROMEOS_RELEASE_NAME=Chromium OS
CHROMEOS_RELEASE_BUILD_TYPE=Test Build - porce
CHROMEOS_RELEASE_VERSION=9540.0.2017_05_15_1741
CHROMEOS_AUSERVER=http://porce-ws.svl.corp.google.com:8080/update
,
May 18 2017
localhost ~ # udevadm monitor -u monitor will print the received events for: UDEV - the event which udev sends out after rule processing -------------- PLUG OUT THE CAMERA UDEV [346.131441] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0/video4linux/video2 (video4linux) UDEV [346.131890] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.1 (usb) UDEV [346.132213] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0 (usb) UDEV [346.132978] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.2/video4linux/video3 (video4linux) UDEV [346.134155] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.2 (usb) UDEV [346.134573] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.3 (usb) UDEV [346.135373] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2 (usb) -------------- PLUG IN THE CAMERA UDEV [360.080431] add /kernel/slab/nf_conntrack_ffff8801691b2280 (slab) UDEV [360.114656] add /devices/pci0000:00/0000:00:14.0/usb2/2-2 (usb) UDEV [360.118623] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0 (usb) UDEV [360.119618] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.1 (usb) UDEV [360.120464] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.2 (usb) UDEV [360.121693] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.3 (usb) UDEV [360.125979] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0/video4linux/video2 (video4linux) UDEV [360.126823] remove /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0/video4linux/video2 (video4linux) UDEV [360.126951] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.2/video4linux/video3 (video4linux) UDEV [360.130234] add /devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2:1.0/video4linux/video2 (video4linux) UDEV [360.400812] remove /kernel/slab/nf_conntrack_ffff8801691b2280 (slab)
,
May 19 2017
,
May 19 2017
> "Permission Broker takes precedence over the permissions specified by the udev rule. " I still don't understand how you conclude this. When permission_broker is logging "2017-05-17T21:24:19.247551-07:00 ERR permission_broker[960]: OpenPath(...): Domain=permission_broker, Code=permission_denied, Message=Permission to open '/dev/bus/usb/002/024' denied" this basically means that the Chrome browser asked to look at the newly plugged USB device and permission_broker denied the browser request (as it is a video camera, the browser is not allowed to interact directly with the USB node). in this case permission_broker basically does nothing (to the USB node or the hardware)
,
May 19 2017
Adding an experimental fact: A USB device X (Huddly camera) has two PIDs depending on its booting mode: X1 (0x0011 APP mode) and X2 (0x0010 Bootloader mode). Udev rule is written such that X1 and X2 are mounted with the same user / group / mode. mode is 644, user / group is cfm-firmware-updaters. Experiment 1. Udev rule starts a minijailed process Y upon detecting X1. Minijail gives the consistent user / group to Y. Y reboots X1 to X2, then attempt to access X2. In libusb level, permission is declined. Experiment 2. Udev rule starts a minijalied process Y upon detecting X1. Minijail gives the consistent user/group to Y. Y reboots X1 to X2, then bails out. Udev rule starts a similarly minijailed proesss Y upon detecting X2. Y accesses X2 with no issue.
,
May 19 2017
Have you run a control experiment to reproduce the issue without permission broker running? You can stop permission broker by running `stop permission_broker` from a root shell in dev mode). As +vpalatin replied in #4, I also doubt it's permission broker related as the log indicated that permission broker denied the OpenPath request from chrome, so neither permission broker nor chrome would do anything to the usb device. Have you run a strace on your updater process to see where the libusb call fails?
,
May 19 2017
Update. Permission Broker is no longer a suspect.
The same symptom occurs even when the Permission Broker stopped working, by `stop permission_broker`.
The libusb error message is shown inside the app's error log
[0519/133909:INFO:main.cc(79)] Starting Huddly Package Updater ..
[0519/133909:INFO:flasher.cc(80)] Upgrade plan: Y
[Y] Bootloader 00000 -> 00000
[Y] App 00000 -> 00000
[0519/133909:INFO:main.cc(166)] .. switching mode from APP to BOOTLOADER.. rebooting (timeout 10 sec)
[0519/133909:INFO:minicam_device.cc(61)] .. setting boot mode: BOOTLOADER
[0519/133909:INFO:minicam_device.cc(70)] .. done setting boot mode. rebooting
[0519/133909:INFO:main.cc(176)] .. waiting to come up
[0519/133912:INFO:usb_device.cc(67)] .. found after waiting for 3 sec.
[0519/133912:INFO:main.cc(185)] .. entered BOOTLOADER mode. VID:PID=2bd9:0010
[0519/133912:ERROR:main.cc(138)] .. failed to get device handle: Error code: LIBUSB_ERROR_ACCESS(-3) : Access denied (insufficient permissions).. failed to setup 2bd9:0010.. failed to flash app in minidev setting up.. failed to flash
Using strace inside the minijail inside the udev rule is tricky and was not successful.
Since minijailed process does not spit out to the console, I used this command but in vain.
ACTION=="add", SUBSYSTEM=="usb", \
ENV{ID_VENDOR_ID}=="2bd9", ENV{ID_MODEL_ID}=="0011", \
MODE="0664", OWNER="cfm-firmware-updaters", GROUP="cfm-firmware-updaters", \
RUN+="/sbin/minijail0 -u cfm-firmware-updaters -g cfm-firmware-updaters -e -i -l -N -v -r -n -- /usr/local/bin/strace /usr/sbin/huddly-updater --force 2>&1 | tee /tmp/ss.log"
,
May 19 2017
Could you update the bug summary to better describe the issue? w.r.t. strace, try `strace -f -o /tmp/ss.log /sbin/minijail0 ... ` instead
,
May 19 2017
strace log https://pastebin.com/sTfje91i
,
May 19 2017
,
May 19 2017
,
May 19 2017
Working case log: minijailed huddly-updater OUTSIDE udev rule
,
May 20 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/huddly-updater/+/8a29911a21a9750a8e0a4aaf34d1e0053747e89e commit 8a29911a21a9750a8e0a4aaf34d1e0053747e89e Author: Jiwoong Lee <porce@google.com> Date: Sat May 20 06:40:39 2017 Split the workflow of huddly updater depending on the mode. This is to accommodate ChromeOS security enforcement of Permission Broker. Now huddly-updater runs in two steps: prep and burn. Prep step performs upgrade eligibility check, and switch to Bootloader mode if upgrade eligibility is met. Otherwise bail out. Burn step performs flashing action. This runs as if it is forced upgrade mode. To accommodate the Permission Broke permission control, two command line options are added: --prep: prep only, and skip burn step. This will be used in App mode. --burn: skip prep, and just burn. This will be used in Bootloader mode. Additionally, to facilitate dev and test engineering, following options are added. --app: switch to app mode and reboot. --boot: switch to bootloader mode and reboot. BUG= chromium:724200 TEST=Build package for Guado board. Run on CFM. Change-Id: I6c8897bb3c5eb89daff3cacb4685c1bdc3001f6f Reviewed-on: https://chromium-review.googlesource.com/509033 Commit-Ready: Jiwoong Lee <porce@chromium.org> Tested-by: Jiwoong Lee <porce@chromium.org> Reviewed-by: Simon Que <sque@chromium.org> [modify] https://crrev.com/8a29911a21a9750a8e0a4aaf34d1e0053747e89e/src/main.cc [modify] https://crrev.com/8a29911a21a9750a8e0a4aaf34d1e0053747e89e/src/flasher.cc
,
May 20 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/third_party/huddly-updater/+/49c6ec6391dee82abd41fa0f734a6531ccc1b23d commit 49c6ec6391dee82abd41fa0f734a6531ccc1b23d Author: Jiwoong Lee <porce@google.com> Date: Sat May 20 20:58:03 2017 Accommodate minijail0's restriction in huddly udev rule The huddly updater fails to access the huddly device booting in a different mode with a different PID, when it is invoked from udev rule via minijail0. See the Bug for detail. This CL is to workaround this permission restriction. Invoke huddly-updater with separate command line option (thus separate work flow) upon detection of different mode of the huddly camera device. --prep option will perform upgrade eligibility check, and switch to bootloader bootloader mode if necessary. --burn option will flash the device. BUG= chromium:724200 TEST=Build package for Guado board. Run on CFM. CQ-DEPEND=CL:509033 Change-Id: I6e382afc47e32623e44d54ebe12ecc75f08cb4e4 Reviewed-on: https://chromium-review.googlesource.com/509271 Commit-Ready: Jiwoong Lee <porce@chromium.org> Tested-by: Jiwoong Lee <porce@chromium.org> Reviewed-by: Simon Que <sque@chromium.org> [modify] https://crrev.com/49c6ec6391dee82abd41fa0f734a6531ccc1b23d/conf/99-huddly.rules
,
May 22 2017
don't run strace inside of minijail, but outside, and don't try to pipe the output RUN+="strace -s4096 -f -o /tmp/log /sbin/minijail0 ........"
,
Jun 9 2017
Is this still a problem?
,
Jun 9 2017
#14 addresses the issue. Thanks for checking.
,
Jan 22 2018
|
|||||
►
Sign in to add a comment |
|||||
Comment 1 by porce@chromium.org
, May 18 2017Labels: -Pri-3 Pri-1
Owner: jorgelo@chromium.org