Installing nfs-kernel-server on a Debian template prevents the template from opening a terminal after boot up

gasull commented 5 years ago

Qubes OS version:

R4.0

Affected component(s):

Debian template.

Steps to reproduce the behavior:

sudo apt install nfs-common nfs-kernel-server

Then shutdown the template and try to open a terminal in it afterwards.

Expected behavior:

NFS installation should work just fine.

Actual behavior:

The installation fails to start the NFS server, then after shutdown the terminal doesn't start.

General notes:

Output from the attempted installation on the template:

$ sudo apt install nfs-kernel-server nfs-common
Reading package lists... Done
Building dependency tree       
Reading state information... Done
The following additional packages will be installed:
  keyutils libnfsidmap2 libtirpc1 rpcbind
Suggested packages:
  open-iscsi watchdog
The following NEW packages will be installed:
  keyutils libnfsidmap2 libtirpc1 nfs-common nfs-kernel-server rpcbind
0 upgraded, 6 newly installed, 0 to remove and 0 not upgraded.
Need to get 566 kB of archives.
After this operation, 1,688 kB of additional disk space will be used.
Do you want to continue? [Y/n] 
[...]
Setting up nfs-common (1:1.3.4-2.1) ...

Creating config file /etc/idmapd.conf with new version
Adding system user `statd' (UID 115) ...
Adding new user `statd' (UID 115) with group `nogroup' ...
Not creating home directory `/var/lib/nfs'.
Created symlink /etc/systemd/system/multi-user.target.wants/nfs-client.target → /lib/systemd/system/nfs-client.target.
Created symlink /etc/systemd/system/remote-fs.target.wants/nfs-client.target → /lib/systemd/system/nfs-client.target.
nfs-utils.service is a disabled or a static unit, not starting it.
Setting up nfs-kernel-server (1:1.3.4-2.1) ...
Created symlink /etc/systemd/system/multi-user.target.wants/nfs-server.service → /lib/systemd/system/nfs-server.service.
Job for nfs-server.service failed because the control process exited with error code.
See "systemctl status nfs-server.service" and "journalctl -xe" for details.
nfs-server.service couldn't start.

Creating config file /etc/exports with new version

Creating config file /etc/default/nfs-kernel-server with new version
Job for nfs-server.service failed because the control process exited with error code.
See "systemctl status nfs-server.service" and "journalctl -xe" for details.
invoke-rc.d: initscript nfs-kernel-server, action "start" failed.
● nfs-server.service - NFS server and services
   Loaded: loaded (/lib/systemd/system/nfs-server.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2018-12-19 16:40:16 UTC; 10ms ago
  Process: 3759 ExecStart=/usr/sbin/rpc.nfsd $RPCNFSDARGS (code=exited, status=1/FAILURE)
  Process: 3756 ExecStartPre=/usr/sbin/exportfs -r (code=exited, status=0/SUCCESS)
 Main PID: 3759 (code=exited, status=1/FAILURE)

Dec 20 16:35:37 debian-9-mod1-nfs systemd[1]: Starting NFS server and servic…...
Dec 20 16:40:16 debian-9-mod1-nfs rpc.nfsd[3759]: rpc.nfsd: writing fd to ker…d)
Dec 20 16:40:16 debian-9-mod1-nfs rpc.nfsd[3759]: rpc.nfsd: unable to set any…sd
Dec 20 16:40:16 debian-9-mod1-nfs systemd[1]: nfs-server.service: Main proce…URE
Dec 20 16:40:16 debian-9-mod1-nfs systemd[1]: Failed to start NFS server and…es.
Dec 20 16:40:16 debian-9-mod1-nfs systemd[1]: nfs-server.service: Unit enter…te.
Dec 20 16:40:16 debian-9-mod1-nfs systemd[1]: nfs-server.service: Failed wit…e'.
Hint: Some lines were ellipsized, use -l to show in full.
Failed to start nfs-kernel-server, ignoring.
Processing triggers for libc-bin (2.24-11+deb9u3) ...
Processing triggers for systemd (232-25+deb9u6) ...

Related issues:

unman commented 5 years ago

@gasull I cant replicate this. Of course, the install fails (it seems to be blocking on opening a prompt for password, although I haven't dug in to this: absence of network interface may also be an issue). However I can open terminals in both Template and TemplateBasedVMs without a problem. Are you reporting a failure in opening a terminal in Template or appVM? Are you unable to open Xterm? UXterm? Any gui elements? Whichever, can yousudo xl console debian-9-mod1-nfs to get a console and check what's happening? If you can login you could try xterm from there.

gasull commented 5 years ago

This is the output:

$ sudo xl console debian-9-mod1-nfs
[    0.000000] Linux version 4.14.74-1.pvops.qubes.x86_64 (user@build-fedora4) (gcc version 6.4.1 20170727 (Red Hat 6.4.1-1) (GCC)) #1 SMP Mon Oct 8 17:14:24 UTC 2018
[    0.000000] Command line: root=/dev/mapper/dmroot ro nomodeset console=hvc0 rd_NO_PLYMOUTH rd.plymouth.enable=0 plymouth.enable=0 nopat
[    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x008: 'MPX bounds registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x010: 'MPX CSR'
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: xstate_offset[3]:  832, xstate_sizes[3]:   64
[    0.000000] x86/fpu: xstate_offset[4]:  896, xstate_sizes[4]:   64
[    0.000000] x86/fpu: Enabled xstate features 0x1f, context size is 960 bytes, using 'compacted' format.
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000a0000-0x00000000000fefff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000ff000-0x00000000000fffff] ACPI data
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000fa0003ff] usable
[    0.000000] BIOS-e820: [mem 0x00000000fc000000-0x00000000fc007fff] ACPI data
[    0.000000] x86/PAT: PAT support disabled.
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] Hypervisor detected: Xen HVM
[    0.000000] Xen version 4.8.
[    0.000000] Xen Platform PCI: unrecognised magic value
[    0.000000] tsc: Fast TSC calibration failed
[    0.000000] tsc: Unable to calibrate against PIT
[    0.000000] tsc: No reference (HPET/PMTIMER) available
[    0.000000] e820: last_pfn = 0xfa000 max_arch_pfn = 0x400000000
[    0.000000] MTRR: Disabled
[    0.000000] CPU MTRRs all blank - virtualized system.
[    0.000000] x86/PAT: Configuration [0-7]: WB  WT  UC- UC  WB  WT  UC- UC  
[    0.000000] Using GB pages for direct mapping
[    0.000000] RAMDISK: [mem 0x02aa2000-0x039e4fff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000FFFC0 000024 (v02 Xen   )
[    0.000000] ACPI: XSDT 0x00000000FC007F70 000034 (v01 Xen    HVM      00000000 HVML 00000000)
[    0.000000] ACPI: FACP 0x00000000FC007D70 00010C (v05 Xen    HVM      00000000 HVML 00000000)
[    0.000000] ACPI: DSDT 0x00000000FC001050 006C9B (v05 Xen    HVM      00000000 INTL 20160831)
[    0.000000] ACPI: FACS 0x00000000FC001010 000040
[    0.000000] ACPI: FACS 0x00000000FC001010 000040
[    0.000000] ACPI: APIC 0x00000000FC007E80 00003C (v02 Xen    HVM      00000000 HVML 00000000)
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x00000000f9ffffff]
[    0.000000] NODE_DATA(0) allocated [mem 0xf9fd5000-0xf9ffffff]
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x00000000f9ffffff]
[    0.000000]   Normal   empty
[    0.000000]   Device   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x00000000f9ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x00000000f9ffffff]
[    0.000000] ACPI: No IOAPIC entries present
[    0.000000] Using ACPI for processor (LAPIC) configuration information
[    0.000000] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[    0.000000] e820: [mem 0xfc008000-0xffffffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on Xen PVH
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.000000] random: get_random_bytes called from start_kernel+0xc3/0x6c3 with crng_init=0
[    0.000000] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:2 nr_node_ids:1
[    0.000000] percpu: Embedded 44 pages/cpu @ffff8800f9c00000 s139928 r8192 d32104 u1048576
[    0.000000] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes)
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1007881
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: root=/dev/mapper/dmroot ro nomodeset console=hvc0 rd_NO_PLYMOUTH rd.plymouth.enable=0 plymouth.enable=0 nopat
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Memory: 3986604K/4095612K available (12300K kernel code, 1399K rwdata, 3772K rodata, 2544K init, 1248K bss, 109008K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Kernel/User page tables isolation: enabled
[    0.000000] ftrace: allocating 35318 entries in 138 pages
[    0.001000] Hierarchical RCU implementation.
[    0.001000]  RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=2.
[    0.001000]  Tasks RCU enabled.
[    0.001000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.001000] Using NULL legacy PIC
[    0.001000] NR_IRQS: 4352, nr_irqs: 48, preallocated irqs: 0
[    0.001000] xen:events: Using FIFO-based ABI
[    0.001000] xen:events: Xen HVM callback vector for event delivery is enabled
[    0.001000]  Offload RCU callbacks from CPUs: .
[    0.001000] Console: colour dummy device 80x25
[    0.001000] console [hvc0] enabled
[    0.001000] tsc: Unable to calibrate against PIT
[    0.001000] tsc: No reference (HPET/PMTIMER) available
[    0.001000] tsc: Detected 2808.144 MHz processor
[    0.001000] Calibrating delay loop (skipped), value calculated using timer frequency.. 5616.28 BogoMIPS (lpj=2808144)
[    0.001000] pid_max: default: 32768 minimum: 301
[    0.001000] ACPI: Core revision 20170728
[    0.001000] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.001000] ACPI: setting ELCR to 0200 (from ffff)
[    0.001000] Security Framework initialized
[    0.001000] Yama: becoming mindful.
[    0.001000] AppArmor: AppArmor disabled by boot time parameter
[    0.001000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    0.001000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.001000] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.001000] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.001000] mce: CPU supports 2 MCE banks
[    0.001000] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.001000] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.001000] Spectre V2 : Mitigation: Full generic retpoline
[    0.001000] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.001000] Spectre V2 : Spectre v2 mitigation: Enabling Indirect Branch Prediction Barrier
[    0.001000] Spectre V2 : Enabling Restricted Speculation for firmware calls
[    0.001000] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.001000] Freeing SMP alternatives memory: 28K
[    0.001000] smpboot: Max logical packages: 1
[    0.001000] x2apic: IRQ remapping doesn't support X2APIC mode
[    0.001000] clocksource: xen: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.001000] installing Xen timer for CPU 0
[    0.001000] smpboot: CPU0: Intel(R) Core(TM) i7-6600U CPU @ 2.60GHz (family: 0x6, model: 0x4e, stepping: 0x3)
[    0.001000] cpu 0 spinlock event irq 5
[    0.001000] Performance Events: unsupported p6 CPU model 78 no PMU driver, software events only.
[    0.001000] Hierarchical SRCU implementation.
[    0.001000] NMI watchdog: Perf event create on CPU 0 failed with -2
[    0.001000] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.001147] smp: Bringing up secondary CPUs ...
[    0.001441] installing Xen timer for CPU 1
[    0.001552] x86: Booting SMP configuration:
[    0.001576] .... node  #0, CPUs:      #1
[    0.002167] cpu 1 spinlock event irq 11
[    0.002167] smp: Brought up 1 node, 2 CPUs
[    0.002167] smpboot: Total of 2 processors activated (11232.57 BogoMIPS)
[    0.002266] devtmpfs: initialized
[    0.002266] x86/mm: Memory block size: 128MB
[    0.003481] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.003481] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.003481] pinctrl core: initialized pinctrl subsystem
[    0.024036] RTC time: 165:165:165, date: 165/165/65
[    0.024899] NET: Registered protocol family 16
[    0.024926] xen:grant_table: Grant tables using version 1 layout
[    0.024978] Grant table initialized
[    0.025171] cpuidle: using governor menu
[    0.025190] ACPI: bus type PCI registered
[    0.026031] PCI: Fatal: No config space access function found
[    0.027439] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.027439] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.028085] ACPI: Added _OSI(Module Device)
[    0.028097] ACPI: Added _OSI(Processor Device)
[    0.028110] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.028124] ACPI: Added _OSI(Processor Aggregator Device)
[    0.028211] ACPI: SCI (ACPI GSI 9) not registered
[    0.033890] ACPI: Interpreter enabled
[    0.033905] ACPI: (supports S0)
[    0.033916] ACPI: Using platform specific model for interrupt routing
[    0.033940] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.033991] ACPI: GPE 0x02 active on init
[    0.034000] ACPI: Enabled 1 GPEs in block 00 to 0F
[    0.040496] acpi LNXCPU:02: Still not present
[    0.040522] xen:balloon: Initialising balloon driver
[    0.040522] acpi LNXCPU:03: Still not present
[    0.040522] acpi LNXCPU:04: Still not present
[    0.040522] acpi LNXCPU:05: Still not present
[    0.040522] acpi LNXCPU:06: Still not present
[    0.040522] acpi LNXCPU:07: Still not present
[    0.040522] acpi LNXCPU:08: Still not present
[    0.040522] acpi LNXCPU:09: Still not present
[    0.040522] acpi LNXCPU:0a: Still not present
[    0.040522] acpi LNXCPU:0b: Still not present
[    0.040522] acpi LNXCPU:0c: Still not present
[    0.040522] acpi LNXCPU:0d: Still not present
[    0.040522] acpi LNXCPU:0e: Still not present
[    0.040522] acpi LNXCPU:0f: Still not present
[    0.040522] acpi LNXCPU:10: Still not present
[    0.040522] acpi LNXCPU:11: Still not present
[    0.040522] acpi LNXCPU:12: Still not present
[    0.040522] acpi LNXCPU:13: Still not present
[    0.040522] acpi LNXCPU:14: Still not present
[    0.040522] acpi LNXCPU:15: Still not present
[    0.040522] acpi LNXCPU:16: Still not present
[    0.040522] acpi LNXCPU:17: Still not present
[    0.040522] acpi LNXCPU:18: Still not present
[    0.040522] acpi LNXCPU:1a: Still not present
[    0.040522] acpi LNXCPU:1b: Still not present
[    0.040522] acpi LNXCPU:1c: Still not present
[    0.040522] acpi LNXCPU:1d: Still not present
[    0.040522] acpi LNXCPU:1e: Still not present
[    0.040522] acpi LNXCPU:1f: Still not present
[    0.040522] acpi LNXCPU:20: Still not present
[    0.040522] acpi LNXCPU:22: Still not present
[    0.040522] acpi LNXCPU:23: Still not present
[    0.040522] acpi LNXCPU:24: Still not present
[    0.040522] acpi LNXCPU:25: Still not present
[    0.040522] acpi LNXCPU:26: Still not present
[    0.040522] acpi LNXCPU:27: Still not present
[    0.040522] acpi LNXCPU:28: Still not present
[    0.040522] acpi LNXCPU:29: Still not present
[    0.123019] random: fast init done
[    0.332029] vgaarb: loaded
[    0.332313] SCSI subsystem initialized
[    0.332505] ACPI: bus type USB registered
[    0.332544] usbcore: registered new interface driver usbfs
[    0.332577] usbcore: registered new interface driver hub
[    0.332648] usbcore: registered new device driver usb
[    0.333064] EDAC MC: Ver: 3.0.0
[    0.333198] dmi: Firmware registration failed.
[    0.333288] PCI: Using ACPI for IRQ routing
[    0.333303] PCI: System does not support PCI
[    0.333389] NetLabel: Initializing
[    0.333402] NetLabel:  domain hash size = 128
[    0.333418] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.333448] NetLabel:  unlabeled traffic allowed by default
[    0.333905] clocksource: Switched to clocksource xen
[    0.362889] VFS: Disk quotas dquot_6.6.0
[    0.362923] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.363820] pnp: PnP ACPI init
[    0.363892] pnp: PnP ACPI: found 0 devices
[    0.371477] NET: Registered protocol family 2
[    0.371703] TCP established hash table entries: 32768 (order: 6, 262144 bytes)
[    0.372167] TCP bind hash table entries: 32768 (order: 7, 524288 bytes)
[    0.373056] TCP: Hash tables configured (established 32768 bind 32768)
[    0.373384] UDP hash table entries: 2048 (order: 4, 65536 bytes)
[    0.373544] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes)
[    0.373760] NET: Registered protocol family 1
[    0.373814] Unpacking initramfs...
[    0.400840] Freeing initrd memory: 15628K
[    0.403307] audit: initializing netlink subsys (disabled)
[    0.405349] Initialise system trusted keyrings
[    0.405417] Key type blacklist registered
[    0.405529] audit: type=2000 audit(1545303477.007:1): state=initialized audit_enabled=0 res=1
[    0.407075] workingset: timestamp_bits=36 max_order=20 bucket_order=0
[    0.409119] zbud: loaded
[    0.880943] NET: Registered protocol family 38
[    0.881121] Key type asymmetric registered
[    0.881134] Asymmetric key parser 'x509' registered
[    0.881178] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    0.881288] io scheduler noop registered
[    0.881301] io scheduler deadline registered
[    0.881348] io scheduler cfq registered (default)
[    0.881364] io scheduler mq-deadline registered
[    0.881553] atomic64_test: passed for x86-64 platform with CX8 and with SSE
[    0.883242] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    0.885275] Non-volatile memory driver v1.3
[    0.885436] Linux agpgart interface v0.103
[    0.886095] libphy: Fixed MDIO Bus: probed
[    0.886213] usbcore: registered new interface driver usbserial
[    0.886274] usbcore: registered new interface driver usbserial_generic
[    0.886309] usbserial: USB Serial support registered for generic
[    0.886360] i8042: PNP: No PS/2 controller found.
[    0.886425] mousedev: PS/2 mouse device common for all mice
[    0.886590] device-mapper: uevent: version 1.0.3
[    0.886710] device-mapper: ioctl: 4.37.0-ioctl (2017-09-20) initialised: dm-devel@redhat.com
[    0.886860] dmi-sysfs: dmi entry is absent.
[    0.886892] hidraw: raw HID events driver (C) Jiri Kosina
[    0.887331] usbcore: registered new interface driver usbhid
[    0.887354] usbhid: USB HID core driver
[    0.887493] drop_monitor: Initializing network drop monitor service
[    0.887614] ip_tables: (C) 2000-2006 Netfilter Core Team
[    0.888341] Initializing XFRM netlink socket
[    0.888550] NET: Registered protocol family 10
[    0.892190] Segment Routing with IPv6
[    0.892226] mip6: Mobile IPv6
[    0.892238] NET: Registered protocol family 17
[    0.894295] RAS: Correctable Errors collector initialized.
[    0.894339] AVX2 version of gcm_enc/dec engaged.
[    0.894362] AES CTR mode by8 optimization enabled
[    0.909126] sched_clock: Marking stable (909007667, 0)->(90988672534745, -90987763527078)
[    0.909632] registered taskstats version 1
[    0.909664] Loading compiled-in X.509 certificates
[    0.909717] zswap: loaded using pool lzo/zbud
[    0.914760] Key type big_key registered
[    0.916829] Key type encrypted registered
[    0.918737] xenbus_probe_frontend: Device with no driver: device/vbd/51712
[    0.918757] xenbus_probe_frontend: Device with no driver: device/vbd/51728
[    0.918774] xenbus_probe_frontend: Device with no driver: device/vbd/51744
[    0.918791] xenbus_probe_frontend: Device with no driver: device/vbd/51760
[    0.918815]   Magic number: 1:252:3141
[    0.918868] hctosys: unable to open rtc device (rtc0)
[    0.927364] Freeing unused kernel memory: 2544K
[    1.440090] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x287a4defad7, max_idle_ns: 440795270835 ns
[    2.647022] random: crng init done
[    6.956185] Write protecting the kernel read-only data: 18432k
[    6.956696] Freeing unused kernel memory: 2024K
[    6.957270] Freeing unused kernel memory: 324K
[    6.957291] rodata_test: all tests were successful
Qubes initramfs script here:
[    6.963052] Invalid max_queues (4), will use default max: 2.
[    7.447022] blkfront: xvda: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled;
[    7.459092]  xvda: xvda1 xvda2 xvda3
[    7.508991] blkfront: xvdb: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled;
[    7.577789] blkfront: xvdc: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled;
[    7.582027] blkfront: xvdd: flush diskcache: enabled; persistent grants: enabled; indirect descriptors: enabled;
Waiting for /dev/xvda* devices...
Qubes: Doing R/W setup for TemplateVM...
[    7.632111]  xvdc: xvdc1
Setting up swapspace version 1, size = 1024 MiB (1073737728 bytes)
no label, UUID=4882d379-4701-4093-a623-e71603bb798a
Qubes: done.
[    7.656916] EXT4-fs (xvda3): mounted filesystem with ordered data mode. Opts: (null)
Waiting for /dev/xvdd device...
mount: /dev/xvdd is write-protected, mounting read-only
[    7.669831] EXT4-fs (xvdd): mounting ext3 file system using the ext4 subsystem
[    7.671999] EXT4-fs (xvdd): mounted filesystem with ordered data mode. Opts: (null)
switch_root: failed to mount moving /dev to /sysroot/dev: Invalid argument
switch_root: forcing unmount of /dev
switch_root: failed to mount moving /proc to /sysroot/proc: Invalid argument
switch_root: forcing unmount of /proc
switch_root: failed to mount moving /sys to /sysroot/sys: Invalid argument
switch_root: forcing unmount of /sys
switch_root: failed to mount moving /run to /sysroot/run: Invalid argument
switch_root: forcing unmount of /run
[    7.803631] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    7.803719] systemd[1]: Detected virtualization xen.
[    7.803741] systemd[1]: Detected architecture x86-64.

Welcome to Debian GNU/Linux 9 (stretch)!

[    7.807812] systemd[1]: No hostname configured.
[    7.807838] systemd[1]: Set hostname to <localhost>.
[    7.939916] systemd[1]: Listening on udev Control Socket.
[  OK  ] Listening on udev Control Socket.
[    7.940191] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started Dispatch Password Requests to Console Directory Watch.
[    7.940330] systemd[1]: Listening on udev Kernel Socket.
[  OK  ] Listening on udev Kernel Socket.
[    7.940456] systemd[1]: Listening on Journal Socket.
[  OK  ] Listening on Journal Socket.
[    7.940609] systemd[1]: Listening on Journal Audit Socket.
[  OK  ] Listening on Journal Audit Socket.
[  OK  ] Listening on LVM2 metadata daemon socket.
[  OK  ] Listening on Syslog Socket.
[  OK  ] Listening on Device-mapper event daemon FIFOs.
[  OK  ] Listening on /dev/initctl Compatibility Named Pipe.
[  OK  ] Set up automount Arbitrary Executab…rmats File System Automount Point.
[  OK  ] Created slice System Slice.
         Starting Load Kernel Modules...
         Mounting NFSD configuration filesystem...
         Starting Set the console keyboard layout...
         Mounting Debug File System...
[  OK  ] Created slice system-getty.slice.
         Mounting POSIX Message Queue File System...
         Starting Create list of required st…ce nodes for the current kernel...
[  OK  ] Created slice system-serial\x2dgetty.slice.
         Mounting Huge Pages File System...
[  OK  ] Listening on Journal Socket (/dev/log).
         Starting Monitoring of LVM2 mirrors…ng dmeventd or progress polling...
[  OK  ] Listening on fsck to fsckd communication Socket.
         Starting File System Check on Root Device...
[  OK  ] Listening on LVM2 poll daemon socket.
[  OK  ] Started Forward Password Requests to Wall Directory Watch.
[  OK  ] Reached target Encrypted Volumes.
         Mounting /proc/xen...
         Starting Journal Service...
[FAILED] Failed to listen on RPCbind Server Activation Socket.
See 'systemctl status rpcbind.socket' for details.
         Mounting RPC Pipe File System...
[  OK  ] Created slice User and Session Slice.
[  OK  ] Reached target Slices.
[  OK  ] Started Create list of required sta…vice nodes for the current kernel.
[  OK  ] Started File System Check Daemon to report status.
         Starting Create Static Device Nodes in /dev...
[  OK  ] Mounted Debug File System.
[  OK  ] Mounted POSIX Message Queue File System.
[  OK  ] Mounted Huge Pages File System.
[  OK  ] Started Journal Service.
[    8.003475] lp: driver loaded but no devices found
[    8.013958] ppdev: user-space parallel port driver
[  OK  ] Mounted /proc/xen.
[    8.027499] RPC: Registered named UNIX socket transport module.
[    8.027521] RPC: Registered udp transport module.
[    8.027535] RPC: Registered tcp transport module.
[    8.027549] RPC: Registered tcp NFSv4.1 backchannel transport module.
[  OK  ] Started LVM2 metadata daemon.
[  OK  ] Mounted RPC Pipe File System.
         Starting pNFS block layout mapping daemon...
[    8.032537] xen:xen_evtchn: Event-channel device installed
[  OK  ] Started File System Check on Root Device.
[  OK  ] Started pNFS block layout mapping daemon.
         Starting Remount Root and Kernel File Systems...
[    8.073299] EXT4-fs (xvda3): re-mounted. Opts: discard
[  OK  ] Started Remount Root and Kernel File Systems.
[    8.077344] u2mfn: loading out-of-tree module taints kernel.
         Starting udev Coldplug all Devices...
         Starting Flush Journal to Persistent Storage...
[    8.084482] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[  OK  ] Mounted NFSD configuration filesystem.
[    8.090817] systemd-journald[204]: Received request to flush runtime journal from PID 1
[  OK  ] Started Create Static Device Nodes in /dev.
         Starting udev Kernel Device Manager...
[  OK  ] Started Flush Journal to Persistent Storage.
[FAILED] Failed to start Load Kernel Modules.
See 'systemctl status systemd-modules-load.service' for details.
         Starting Apply Kernel Variables...
         Mounting Configuration File System...
         Starting Qubes DB agent...
[  OK  ] Mounted Configuration File System.
[  OK  ] Started udev Coldplug all Devices.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Qubes DB agent.
         Starting Init Qubes Services settings...
         Starting Load/Save Random Seed...
[  OK  ] Started Load/Save Random Seed.
[  OK  ] Started udev Kernel Device Manager.
[  OK  ] Started Init Qubes Services settings.
         Starting Initialize and mount /rw and /home...
         Starting Adjust root filesystem size...
[  OK  ] Started Adjust root filesystem size.
[    8.332215] input: PC Speaker as /devices/platform/pcspkr/input/input0
[    8.402646] EXT4-fs (xvdb): mounted filesystem with ordered data mode. Opts: discard
[    8.404878] RAPL PMU: API unit is 2^-32 Joules, 5 fixed counters, 655360 ms ovfl timer
[    8.404903] RAPL PMU: hw unit of domain pp0-core 2^-14 Joules
[    8.404920] RAPL PMU: hw unit of domain package 2^-14 Joules
[    8.404937] RAPL PMU: hw unit of domain dram 2^-14 Joules
[    8.404950] RAPL PMU: hw unit of domain pp1-gpu 2^-14 Joules
[    8.404967] RAPL PMU: hw unit of domain psys 2^-14 Joules
[  OK  ] Found device /dev/hvc0.
[    8.486320] Error: Driver 'pcspkr' is already registered, aborting...
[  OK  ] Started Initialize and mount /rw and /home.
[  OK  ] Found device /dev/xvdc1.
         Activating swap /dev/xvdc1...
[    8.548872] Adding 1048572k swap on /dev/xvdc1.  Priority:-2 extents:1 across:1048572k SSFS
[  OK  ] Activated swap /dev/xvdc1.
[  OK  ] Reached target Swap.
[    8.555515] intel_rapl: Found RAPL domain package
[    8.555538] intel_rapl: Found RAPL domain core
[    8.555554] intel_rapl: Found RAPL domain uncore
[    8.555570] intel_rapl: Found RAPL domain dram
[  OK  ] Started Set the console keyboard layout.
[  OK  ] Started Monitoring of LVM2 mirrors,…sing dmeventd or progress polling.
[  OK  ] Reached target Local File Systems (Pre).
[  OK  ] Reached target Local File Systems.
         Starting Preprocess NFS configuration...
         Starting Set console font and keymap...
         Starting Create Volatile Files and Directories...
         Starting Early Qubes VM settings...
         Starting Raise network interfaces...
[  OK  ] Started Set console font and keymap.
[  OK  ] Started Preprocess NFS configuration.
         Starting NFSv4 ID-name mapping service...
[  OK  ] Reached target NFS client services.
[  OK  ] Started Create Volatile Files and Directories.
[  OK  ] Reached target System Time Synchronized.
         Starting Update UTMP about System Boot/Shutdown...
[  OK  ] Started Entropy daemon using the HAVEGE algorithm.
[  OK  ] Started Early Qubes VM settings.
[  OK  ] Started NFSv4 ID-name mapping service.
[  OK  ] Started Update UTMP about System Boot/Shutdown.
[  OK  ] Reached target System Initialization.
[  OK  ] Started Daily apt download activities.
[  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[  OK  ] Started Periodically check for updates.
[  OK  ] Started CUPS Scheduler.
[  OK  ] Reached target Paths.
[  OK  ] Listening on D-Bus System Message Bus Socket.
[  OK  ] Started Update system time each 6h.
[  OK  ] Started Daily Cleanup of Temporary Directories.
[  OK  ] Started Daily apt upgrade and clean activities.
[  OK  ] Reached target Timers.
[  OK  ] Listening on Forward connection to updates proxy over Qubes RPC.
[  OK  ] Listening on CUPS Scheduler.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Basic System.
[  OK  ] Started D-Bus System Message Bus.
         Starting CUPS Scheduler...
         Starting Login Service...
         Starting Qubes base firewall settings...
         Starting Restore /etc/resolv.conf i…fore the ppp link was shut down...
         Starting Xen driver domain device daemon...
         Starting System Logging Service...
         Starting Qubes memory information reporter...
[  OK  ] Started CUPS Scheduler.
[  OK  ] Started Update time from ClockVM.
[  OK  ] Started Make remote CUPS printers available locally.
[  OK  ] Started Restore /etc/resolv.conf if…before the ppp link was shut down.
[  OK  ] Started Qubes memory information reporter.
         Starting Qubes GUI Agent...
[  OK  ] Started Qubes GUI Agent.
[  OK  ] Started Xen driver domain device daemon.
         Starting Qubes remote exec agent...
[  OK  ] Started System Logging Service.
[  OK  ] Started Login Service.
[   11.589762] nf_conntrack version 0.5.0 (2560 buckets, 10240 max)
[  OK  ] Started Qubes remote exec agent.
[  OK  ] Started Raise network interfaces.
[   11.981178] ip6_tables: (C) 2000-2006 Netfilter Core Team
[  OK  ] Started Qubes base firewall settings.
[  OK  ] Reached target Network.
         Starting NFS Mount Daemon...
         Starting /etc/rc.local Compatibility...
         Starting Qubes misc post-boot actions...
[  OK  ] Started /etc/rc.local Compatibility.
[  OK  ] Started NFS Mount Daemon.
         Starting NFS server and services...
[  OK  ] Started Qubes misc post-boot actions.
[   33.760176] svc: failed to register nfsdv3 RPC service (errno 111).
         Starting RealtimeKit Scheduling Policy Service...
[  OK  ] Started RealtimeKit Scheduling Policy Service.
         Starting Authorization Manager...
[  OK  ] Started Authorization Manager.
[**    ] A start job is running for NFS server and services (49s / no limit)[   57.824265] svc: failed to register nfsaclv3 RPC service (errno 111).
[FAILED] Failed to start NFS server and services.
See 'systemctl status nfs-server.service' for details.
         Stopping NFSv4 ID-name mapping service...
         Stopping NFS Mount Daemon...
[  OK  ] Reached target Remote File Systems (Pre).
[  OK  ] Reached target Remote File Systems.
         Starting Permit User Sessions...
[  OK  ] Stopped NFSv4 ID-name mapping service.
[  OK  ] Stopped NFS Mount Daemon.
[  OK  ] Started Permit User Sessions.
[  OK  ] Created slice User Slice of user.
[  OK  ] Started Getty on tty1.
         Starting User Manager for UID 1000...
[FAILED] Failed to start Session c3 of user user.
See 'systemctl status session-c3.scope' for details.
[FAILED] Failed to start Session c4 of user user.
See 'systemctl status session-c4.scope' for details.
[  OK  ] Started Session c1 of user user.
[  OK  ] Started Serial Getty on hvc0.
[  OK  ] Reached target Login Prompts.
[FAILED] Failed to start Session c2 of user user.
See 'systemctl status session-c2.scope' for details.
[  OK  ] Reached target Multi-User System.
         Starting Update UTMP about System Runlevel Changes...
[  OK  ] Started Update UTMP about System Runlevel Changes.
[  OK  ] Started User Manager for UID 1000.

Debian GNU/Linux 9 debian-9-mod1-nfs hvc0

debian-9-mod1-nfs login:

It took a very long time to go pass A start job is running for NFS server and services. Now everything works: XTerm, gnome-terminal, etc.

I believe this is still a bug, since the waiting time is incredibly long.

gasull commented 5 years ago

I fixed it running:

sudo update-rc.d -f nfs-kernel-server remove

on the template.

Before fixing it, the Terminal wouldn't open if the TemplateVM isn't already running. I would have to wait several minutes so it goes pass A start job is running for NFS server and services in the boot up before I can use any applications.

unman commented 5 years ago

Did you follow this advice on configuring the template post install?

In any case, I dont see this behaviour.

Are you reporting a failure in opening a terminal in Template or appVM?

gasull commented 5 years ago

I see. My bad. Thanks.

gasull commented 5 years ago

I want to add some information here in case someone runs into the same problem:

NFS server requires adding a new systemd configuration file (preferably on the TemplateVM so it's fixed for any AppVMs that enable the NFS server). And for Qubes specifically we need to unmask and start rpcbind before nfs-kernel-server. So, in the /rw/config/rc.local of the AppVM (not the TemplateVM) this needs to be added:

# See https://www.qubes-os.org/doc/templates/debian/#starting-services
# rpcbind is needed for nfs-kernel-server
# See https://discourse.osmc.tv/t/nfs-kernel-server-wont-start-on-boot/5936/8
systemctl unmask rpcbind
systemctl start rpcbind
systemctl unmask nfs-kernel-server
systemctl start nfs-kernel-server

QubesOS / qubes-issues