New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

failure to attach USB devices from sys-usb to fedora-kernel appvm (Update: kernel-modules-extra missing) #4041

Open
homotopycolimit opened this Issue Jun 28, 2018 · 4 comments

Comments

Projects
None yet
3 participants
@homotopycolimit

homotopycolimit commented Jun 28, 2018

Qubes OS version:

R4.0

Affected component(s):

qubes-usb-proxy (presumably)


Steps to reproduce the behavior:

Create an appvm based on Fedora28 and set the AppVM to use the fedora distribution kernel.
Start the AppVM and then try to attach a USB device to it.

Expected behavior:

I expect the USB device to be available in the AppVM

Actual behavior:

The attaching operation fails with an error notification but no actual error message. The dmesg output of the AppVM shows messages like:

[ 6718.250243] audit: type=1100 audit(1530193705.290:218): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:authentication grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6718.253883] audit: type=1103 audit(1530193705.292:219): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'

(full log is included below)

General notes:

Kernel Version:
Linux app-vm-name 4.16.9-300.fc28.x86_64 #1 SMP Thu May 17 06:39:18 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

qubes-usb-proxy version:

$ sudo dnf install qubes-usb-proxy
Last metadata expiration check: 2:58:45 ago on Thu 28 Jun 2018 12:55:33 PM CEST.
Package qubes-usb-proxy-1.0.18-1.fc28.noarch is already installed, skipping.

Related issues:

None of this would be an issue for me if it would be possible to compile kernel modules for the qubes kernel instead of only the fedora distribution's own kernel ( #3835 and #2844 )

Full errror log:

[ 6718.250243] audit: type=1100 audit(1530193705.290:218): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:authentication grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6718.253883] audit: type=1103 audit(1530193705.292:219): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6718.272225] audit: type=1101 audit(1530193705.311:220): pid=2646 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:accounting grantors=pam_unix acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6718.278249] audit: type=1006 audit(1530193705.311:221): pid=2646 uid=0 subj=kernel old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=5 res=1
[ 6718.281222] audit: type=1105 audit(1530193705.311:222): pid=2646 uid=0 auid=0 ses=5 subj=kernel msg='op=PAM:session_open grantors=pam_selinux,pam_selinux,pam_loginuid,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6718.317358] audit: type=1130 audit(1530193705.354:223): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6718.320294] audit: type=1105 audit(1530193705.355:224): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_lastlog acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6719.563729] audit: type=1106 audit(1530193706.603:225): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_close grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_lastlog acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6719.569140] audit: type=1104 audit(1530193706.603:226): pid=2645 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_rootok acct="root" exe="/usr/lib/qubes/qrexec-agent" hostname=? addr=? terminal=? res=success'
[ 6719.590771] audit: type=1131 audit(1530193706.630:227): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Jun 28, 2018

Member

See sudo journalctl -b output in that AppVM.

Member

marmarek commented Jun 28, 2018

See sudo journalctl -b output in that AppVM.

@homotopycolimit

This comment has been minimized.

Show comment
Hide comment
@homotopycolimit

homotopycolimit Jun 28, 2018

Sure.
Full logs are here:
https://pastebin.com/CmgAAFfB

at the time I connected the device, I got:

Jun 28 17:05:35 app-vm-name sudo[1238]: pam_unix(sudo:session): session closed for user root
Jun 28 17:05:35 app-vm-name audit[1238]: USER_END pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_close grantors=pam_keyinit,pam_li>
Jun 28 17:05:35 app-vm-name audit[1238]: CRED_DISP pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred grantors=pam_env,pam_unix acct=">
Jun 28 17:05:35 app-vm-name kernel: audit: type=1106 audit(1530198335.464:165): pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_clo>
Jun 28 17:05:35 app-vm-name kernel: audit: type=1104 audit(1530198335.464:166): pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred gra>
Jun 28 17:05:39 app-vm-name qrexec-agent[710]: executed root:QUBESRPC qubes.USBAttach dom0 pid 1249
Jun 28 17:05:39 app-vm-name audit[1249]: USER_AUTH pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:authentication grantors=p>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1100 audit(1530198339.726:167): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1103 audit(1530198339.730:168): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name audit[1249]: CRED_ACQ pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_rooto>
Jun 28 17:05:39 app-vm-name systemd[1]: Created slice User Slice of root.
Jun 28 17:05:39 app-vm-name systemd[1]: Starting User Manager for UID 0...
Jun 28 17:05:39 app-vm-name systemd[1]: Started Session c6 of user root.
Jun 28 17:05:39 app-vm-name systemd[1250]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Jun 28 17:05:39 app-vm-name audit[1250]: USER_ACCT pid=1250 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:accounting grantors=pam_u>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1101 audit(1530198339.748:169): pid=1250 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1006 audit(1530198339.748:170): pid=1250 uid=0 subj=kernel old-auid=4294967295 auid=0 tty=(none) o>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1105 audit(1530198339.749:171): pid=1250 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_open g>
Jun 28 17:05:39 app-vm-name audit[1250]: USER_START pid=1250 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_open grantors=pam_selinux,pam_seli>
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Timers.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Paths.
Jun 28 17:05:39 app-vm-name systemd[1250]: Starting D-Bus User Message Bus Socket.
Jun 28 17:05:39 app-vm-name systemd[1250]: Listening on D-Bus User Message Bus Socket.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Sockets.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Basic System.
Jun 28 17:05:39 app-vm-name audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/u>
Jun 28 17:05:39 app-vm-name systemd[1]: Started User Manager for UID 0.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Default.
Jun 28 17:05:39 app-vm-name systemd[1250]: Startup finished in 31ms.
Jun 28 17:05:39 app-vm-name kernel: audit: type=1130 audit(1530198339.788:172): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=u>
Jun 28 17:05:39 app-vm-name qrexec-agent[1249]: pam_unix(qrexec:session): session opened for user root by (uid=0)
Jun 28 17:05:39 app-vm-name audit[1249]: USER_START pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_open grantors=pa>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1105 audit(1530198339.794:173): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:40 app-vm-name sudo[1281]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/bin/journalctl -b
Jun 28 17:05:40 app-vm-name audit[1281]: USER_CMD pid=1281 uid=1000 auid=1000 ses=1 subj=kernel msg='cwd="/home/user" cmd=6A6F75726E616C63746C202D>
Jun 28 17:05:40 app-vm-name kernel: audit: type=1123 audit(1530198340.756:174): pid=1281 uid=1000 auid=1000 ses=1 subj=kernel msg='cwd="/home/user>
Jun 28 17:05:40 app-vm-name kernel: audit: type=1110 audit(1530198340.761:175): pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred gra>
Jun 28 17:05:40 app-vm-name audit[1281]: CRED_REFR pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred grantors=pam_env,pam_unix acct=">
Jun 28 17:05:40 app-vm-name audit[1281]: USER_START pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_open grantors=pam_keyinit,pam_l>
Jun 28 17:05:40 app-vm-name sudo[1281]: pam_systemd(sudo:session): Cannot create session: Already running in a session
Jun 28 17:05:40 app-vm-name sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 28 17:05:40 app-vm-name kernel: audit: type=1105 audit(1530198340.769:176): pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_ope>
Jun 28 17:05:41 app-vm-name qrexec-agent[1249]: pam_unix(qrexec:session): session closed for user root
Jun 28 17:05:41 app-vm-name audit[1249]: USER_END pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_close grantors=pam>
Jun 28 17:05:41 app-vm-name kernel: audit: type=1106 audit(1530198341.022:177): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: send exit code 1
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: pid 1249 exited with 1
Jun 28 17:05:41 app-vm-name audit[1249]: CRED_DISP pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_root>
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: eintr
Jun 28 17:05:41 app-vm-name kernel: audit: type=1104 audit(1530198341.022:178): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:41 app-vm-name systemd[1]: Stopping User Manager for UID 0...
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Default.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Basic System.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Sockets.
Jun 28 17:05:41 app-vm-name systemd[1250]: Closed D-Bus User Message Bus Socket.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Timers.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Paths.
Jun 28 17:05:41 app-vm-name systemd[1250]: Reached target Shutdown.
Jun 28 17:05:41 app-vm-name systemd[1250]: Starting Exit the Session...
Jun 28 17:05:41 app-vm-name systemd[1250]: Started Exit the Session.
Jun 28 17:05:41 app-vm-name systemd[1250]: Received SIGRTMIN+24 from PID 1286 (n/a).
Jun 28 17:05:41 app-vm-name systemd[1251]: pam_unix(systemd-user:session): session closed for user root
Jun 28 17:05:41 app-vm-name audit[1251]: USER_END pid=1251 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_close grantors=pam_selinux,pam_selin>
Jun 28 17:05:41 app-vm-name systemd[1]: Stopped User Manager for UID 0.
Jun 28 17:05:41 app-vm-name systemd[1]: Removed slice User Slice of root.
Jun 28 17:05:41 app-vm-name kernel: audit: type=1106 audit(1530198341.049:179): pid=1251 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_close >
Jun 28 17:05:41 app-vm-name audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/us>
Jun 28 17:05:41 app-vm-name kernel: audit: type=1131 audit(1530198341.051:180): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=u>

homotopycolimit commented Jun 28, 2018

Sure.
Full logs are here:
https://pastebin.com/CmgAAFfB

at the time I connected the device, I got:

Jun 28 17:05:35 app-vm-name sudo[1238]: pam_unix(sudo:session): session closed for user root
Jun 28 17:05:35 app-vm-name audit[1238]: USER_END pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_close grantors=pam_keyinit,pam_li>
Jun 28 17:05:35 app-vm-name audit[1238]: CRED_DISP pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred grantors=pam_env,pam_unix acct=">
Jun 28 17:05:35 app-vm-name kernel: audit: type=1106 audit(1530198335.464:165): pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_clo>
Jun 28 17:05:35 app-vm-name kernel: audit: type=1104 audit(1530198335.464:166): pid=1238 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred gra>
Jun 28 17:05:39 app-vm-name qrexec-agent[710]: executed root:QUBESRPC qubes.USBAttach dom0 pid 1249
Jun 28 17:05:39 app-vm-name audit[1249]: USER_AUTH pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:authentication grantors=p>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1100 audit(1530198339.726:167): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1103 audit(1530198339.730:168): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name audit[1249]: CRED_ACQ pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_rooto>
Jun 28 17:05:39 app-vm-name systemd[1]: Created slice User Slice of root.
Jun 28 17:05:39 app-vm-name systemd[1]: Starting User Manager for UID 0...
Jun 28 17:05:39 app-vm-name systemd[1]: Started Session c6 of user root.
Jun 28 17:05:39 app-vm-name systemd[1250]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Jun 28 17:05:39 app-vm-name audit[1250]: USER_ACCT pid=1250 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:accounting grantors=pam_u>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1101 audit(1530198339.748:169): pid=1250 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1006 audit(1530198339.748:170): pid=1250 uid=0 subj=kernel old-auid=4294967295 auid=0 tty=(none) o>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1105 audit(1530198339.749:171): pid=1250 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_open g>
Jun 28 17:05:39 app-vm-name audit[1250]: USER_START pid=1250 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_open grantors=pam_selinux,pam_seli>
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Timers.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Paths.
Jun 28 17:05:39 app-vm-name systemd[1250]: Starting D-Bus User Message Bus Socket.
Jun 28 17:05:39 app-vm-name systemd[1250]: Listening on D-Bus User Message Bus Socket.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Sockets.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Basic System.
Jun 28 17:05:39 app-vm-name audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/u>
Jun 28 17:05:39 app-vm-name systemd[1]: Started User Manager for UID 0.
Jun 28 17:05:39 app-vm-name systemd[1250]: Reached target Default.
Jun 28 17:05:39 app-vm-name systemd[1250]: Startup finished in 31ms.
Jun 28 17:05:39 app-vm-name kernel: audit: type=1130 audit(1530198339.788:172): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=u>
Jun 28 17:05:39 app-vm-name qrexec-agent[1249]: pam_unix(qrexec:session): session opened for user root by (uid=0)
Jun 28 17:05:39 app-vm-name audit[1249]: USER_START pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_open grantors=pa>
Jun 28 17:05:39 app-vm-name kernel: audit: type=1105 audit(1530198339.794:173): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:40 app-vm-name sudo[1281]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/bin/journalctl -b
Jun 28 17:05:40 app-vm-name audit[1281]: USER_CMD pid=1281 uid=1000 auid=1000 ses=1 subj=kernel msg='cwd="/home/user" cmd=6A6F75726E616C63746C202D>
Jun 28 17:05:40 app-vm-name kernel: audit: type=1123 audit(1530198340.756:174): pid=1281 uid=1000 auid=1000 ses=1 subj=kernel msg='cwd="/home/user>
Jun 28 17:05:40 app-vm-name kernel: audit: type=1110 audit(1530198340.761:175): pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred gra>
Jun 28 17:05:40 app-vm-name audit[1281]: CRED_REFR pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:setcred grantors=pam_env,pam_unix acct=">
Jun 28 17:05:40 app-vm-name audit[1281]: USER_START pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_open grantors=pam_keyinit,pam_l>
Jun 28 17:05:40 app-vm-name sudo[1281]: pam_systemd(sudo:session): Cannot create session: Already running in a session
Jun 28 17:05:40 app-vm-name sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 28 17:05:40 app-vm-name kernel: audit: type=1105 audit(1530198340.769:176): pid=1281 uid=0 auid=1000 ses=1 subj=kernel msg='op=PAM:session_ope>
Jun 28 17:05:41 app-vm-name qrexec-agent[1249]: pam_unix(qrexec:session): session closed for user root
Jun 28 17:05:41 app-vm-name audit[1249]: USER_END pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:session_close grantors=pam>
Jun 28 17:05:41 app-vm-name kernel: audit: type=1106 audit(1530198341.022:177): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: send exit code 1
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: pid 1249 exited with 1
Jun 28 17:05:41 app-vm-name audit[1249]: CRED_DISP pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=PAM:setcred grantors=pam_root>
Jun 28 17:05:41 app-vm-name qrexec-agent[710]: eintr
Jun 28 17:05:41 app-vm-name kernel: audit: type=1104 audit(1530198341.022:178): pid=1249 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='op=>
Jun 28 17:05:41 app-vm-name systemd[1]: Stopping User Manager for UID 0...
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Default.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Basic System.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Sockets.
Jun 28 17:05:41 app-vm-name systemd[1250]: Closed D-Bus User Message Bus Socket.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Timers.
Jun 28 17:05:41 app-vm-name systemd[1250]: Stopped target Paths.
Jun 28 17:05:41 app-vm-name systemd[1250]: Reached target Shutdown.
Jun 28 17:05:41 app-vm-name systemd[1250]: Starting Exit the Session...
Jun 28 17:05:41 app-vm-name systemd[1250]: Started Exit the Session.
Jun 28 17:05:41 app-vm-name systemd[1250]: Received SIGRTMIN+24 from PID 1286 (n/a).
Jun 28 17:05:41 app-vm-name systemd[1251]: pam_unix(systemd-user:session): session closed for user root
Jun 28 17:05:41 app-vm-name audit[1251]: USER_END pid=1251 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_close grantors=pam_selinux,pam_selin>
Jun 28 17:05:41 app-vm-name systemd[1]: Stopped User Manager for UID 0.
Jun 28 17:05:41 app-vm-name systemd[1]: Removed slice User Slice of root.
Jun 28 17:05:41 app-vm-name kernel: audit: type=1106 audit(1530198341.049:179): pid=1251 uid=0 auid=0 ses=3 subj=kernel msg='op=PAM:session_close >
Jun 28 17:05:41 app-vm-name audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=user@0 comm="systemd" exe="/us>
Jun 28 17:05:41 app-vm-name kernel: audit: type=1131 audit(1530198341.051:180): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=u>
@marmarek

This comment has been minimized.

Show comment
Hide comment
@marmarek

marmarek Jun 28, 2018

Member

Hmm, there are no more details here (just qrexec-agent[710]: pid 1249 exited with 1). Try qvm-usb command line utility (from dom0), maybe it will provide more details. Check also if you have vhci_hcd module loaded in the AppVM (it should be loaded automatically).

Member

marmarek commented Jun 28, 2018

Hmm, there are no more details here (just qrexec-agent[710]: pid 1249 exited with 1). Try qvm-usb command line utility (from dom0), maybe it will provide more details. Check also if you have vhci_hcd module loaded in the AppVM (it should be loaded automatically).

@homotopycolimit

This comment has been minimized.

Show comment
Hide comment
@homotopycolimit

homotopycolimit Jun 29, 2018

FIXED!
thank you.
TL;DR kernel-modules-extra was not installed in fc28 template.

From dom0

$ qvm-usb attach app-vm-name sys-usb:4-2
Device attach failed:

Not very helpull at all. Shouldn't there be some kind of error message?
But:

aha!

[user@app-vm-name ~]$ lsmod | grep vhci
[user@app-vm-name ~]$ modprobe vhci_hcd
modprobe: FATAL: Module vhci_hcd not found in directory /lib/modules/4.16.9-300.fc28.x86_64

Steps to fix:

  1. Install kernel-modules-extra in template VM
    $ sudo dnf install kernel-modules-extra
  2. For some reason this installs the newest kernel modules 4.17.2-200.fc28, but the appvm still boots into 4.16.9-300.fc28. Why? So let's fix that manually:
dracut -f /boot/initramfs-4.17.2-200.fc28.x86_64.img 4.17.2-200.fc28.x86_64
grub2-mkconfig -o /boot/grub2/grub.cfg 

Shutdown template and reboot appvm.

In dom0:
qvm-usb attach app-vm-name sys-usb:4-2

SUCESS!

FIXED!
thank you.
TL;DR kernel-modules-extra was not installed in fc28 template.

From dom0

$ qvm-usb attach app-vm-name sys-usb:4-2
Device attach failed:

Not very helpull at all. Shouldn't there be some kind of error message?
But:

aha!

[user@app-vm-name ~]$ lsmod | grep vhci
[user@app-vm-name ~]$ modprobe vhci_hcd
modprobe: FATAL: Module vhci_hcd not found in directory /lib/modules/4.16.9-300.fc28.x86_64

Steps to fix:

  1. Install kernel-modules-extra in template VM
    $ sudo dnf install kernel-modules-extra
  2. For some reason this installs the newest kernel modules 4.17.2-200.fc28, but the appvm still boots into 4.16.9-300.fc28. Why? So let's fix that manually:
dracut -f /boot/initramfs-4.17.2-200.fc28.x86_64.img 4.17.2-200.fc28.x86_64
grub2-mkconfig -o /boot/grub2/grub.cfg 

Shutdown template and reboot appvm.

In dom0:
qvm-usb attach app-vm-name sys-usb:4-2

SUCESS!

@homotopycolimit homotopycolimit changed the title from failure to attach USB devices from sys-usb to fedora-kernel appvm to failure to attach USB devices from sys-usb to fedora-kernel appvm (Update: kernel-modules-extra missing) Jun 29, 2018

@andrewdavidwong andrewdavidwong added C: Fedora and removed C: other labels Jun 30, 2018

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