'ssh-daemon' fails to start

DoneSubmitted by Leo Famulari.
Details
8 participants
  • Martin Castillo
  • Clément Lassieur
  • Christopher Lemmer Webber
  • Taegil Bae
  • Leo Famulari
  • Ludovic Courtès
  • Brant Gardner
  • maxim.cournoyer
Owner
unassigned
Severity
important
Merged with
L
L
Leo Famulari wrote on 29 Mar 2018 22:08
OpenSSH sshd killed by Shepherd 0.4.0
(address . bug-guix@gnu.org)
20180329200803.GA15842@jasmine.lan
Since the update to Shepherd 0.4.0, I've found that OpenSSH's sshd is
killed almost immediately after it starts with signal 15. I confirmed
the issue started with the Shepherd upgrade by bisecting our Git
history.

I can reproduce the issue from commit
b6beda1d6b9093a8493b5c3cde33ed522242c451 (gnu: Add botan.).

One interesting tidbit is that the PID file '/var/run/sshd.pid' is not
created anymore. And if I create an empty PID file by hand, it is
removed after trying to start the ssh-daemon service. Also, the sshd
user's home '/var/run/sshd' does not exist, and is similarly removed if
it does exist.

I ran the OpenSSH system test `make check-system TESTS=openssh` and it
failed when it could not find the PID file. It passed on another
non-GuixSD machine. The failing machine is relatively slow and lacks
KVM: a ThinkPad x200s.

After boot, trying to start the service again with `herd start
ssh-daemon` gives the same result.

I modified the sshd invocation to print some debug output ('-d -E
/tmp/sshd.log') and this is what it shows:

------
debug1: sshd version OpenSSH_7.6, OpenSSL 1.0.2o 27 Mar 2018
debug1: private host key #0: ssh-rsa SHA256:REDACTED
debug1: private host key #1: ssh-dss SHA256:REDACTED
debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:REDACTED
debug1: private host key #3: ssh-ed25519 SHA256:REDACTED
debug1: rexec_argv[0]='/gnu/store/az7vib8gk16fybhshh5xpkljmgxyrs4k-openssh-7.6p1/sbin/sshd'
debug1: rexec_argv[1]='-D'
debug1: rexec_argv[2]='-d'
debug1: rexec_argv[3]='-E'
debug1: rexec_argv[4]='/tmp/sshd.log'
debug1: rexec_argv[5]='-f'
debug1: rexec_argv[6]='/gnu/store/miy7xg5j4fg3mn04mcl27awmcl6s97ss-sshd_config'
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
Received signal 15; terminating.
------

My system configuration file, the shepherd log messages, and the OpenSSH
system test logs are attached. Any ideas?
Mar 29 15:47:32 localhost shepherd[1]: Service syslogd has been started.
Mar 29 15:47:33 localhost shepherd[1]: Service loopback has been started.
Mar 29 15:47:34 localhost shepherd[1]: Service virtual-terminal has been started.
Mar 29 15:47:35 localhost shepherd[1]: Service term-tty6 has been started.
Mar 29 15:47:35 localhost shepherd[1]: Service term-tty5 has been started.
Mar 29 15:47:36 localhost shepherd[1]: Service term-tty4 has been started.
Mar 29 15:47:38 localhost shepherd[1]: Service term-tty3 has been started.
Mar 29 15:47:39 localhost shepherd[1]: Service term-tty2 has been started.
Mar 29 15:47:41 localhost shepherd[1]: Service term-tty1 has been started.
Mar 29 15:47:43 localhost shepherd[1]: Service term-auto could not be started.
Mar 29 15:47:44 localhost shepherd[1]: Service console-font-tty1 has been started.
Mar 29 15:47:46 localhost shepherd[1]: Service console-font-tty2 has been started.
Mar 29 15:47:48 localhost shepherd[1]: Service console-font-tty3 has been started.
Mar 29 15:47:49 localhost shepherd[1]: Service console-font-tty4 has been started.
Mar 29 15:47:50 localhost shepherd[1]: Service console-font-tty5 has been started.
Mar 29 15:47:50 localhost shepherd[1]: Service console-font-tty6 has been started.
Mar 29 15:47:51 localhost shepherd[1]: Service dbus-system has been started.
Mar 29 15:47:51 localhost shepherd[1]: Service networking has been started.
Mar 29 15:47:52 localhost shepherd[1]: Service ntpd has been started.
Mar 29 15:47:56 localhost shepherd[1]: Service ssh-daemon could not be started.
Mar 29 15:47:59 localhost shepherd[1]: Service gpm has been started.
Mar 29 15:48:29 localhost vmunix: [ 5.486795] shepherd[1]: Service root has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.379651] shepherd[1]: starting services...
Mar 29 15:48:29 localhost vmunix: [ 7.381562] shepherd[1]: Service root-file-system has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.383337] shepherd[1]: Service user-file-systems has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.625406] shepherd[1]: Service file-system-/home has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.627645] shepherd[1]: Service file-system-/dev/pts has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.629909] shepherd[1]: Service file-system-/dev/shm has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.632089] shepherd[1]: Service file-system-/gnu/store has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.633924] shepherd[1]: Service file-systems has been started.
Mar 29 15:48:29 localhost vmunix: [ 7.731477] shepherd[1]: waiting for udevd...
Mar 29 15:48:29 localhost vmunix: [ 8.331344] shepherd[1]: Service udev has been started.
Mar 29 15:48:30 localhost vmunix: [ 8.446599] shepherd[1]: Service urandom-seed has been started.
Mar 29 15:48:30 localhost vmunix: [ 8.448462] shepherd[1]: Service user-processes has been started.
Mar 29 15:48:30 localhost vmunix: [ 8.450424] shepherd[1]: Service host-name has been started.
Mar 29 15:48:30 localhost vmunix: [ 8.546746] shepherd[1]: Service user-homes could not be started.
Mar 29 15:48:30 localhost vmunix: [ 9.554051] shepherd[1]: Service nscd has been started.
Mar 29 15:48:30 localhost vmunix: [ 9.606182] shepherd[1]: Service guix-daemon has been started.
Mar 29 15:49:21 localhost shepherd[1]: Respawning term-tty2.
Mar 29 15:49:21 localhost shepherd[1]: Service term-tty2 has been started.
Mar 29 15:49:28 localhost shepherd[1]: Respawning term-tty1.
Mar 29 15:49:28 localhost shepherd[1]: Service term-tty1 has been started.
;; This is an operating system configuration template ;; for a "bare bones" setup, with no X11 display server. (use-modules (gnu)) (use-service-modules networking dbus ssh sysctl) (use-package-modules certs curl ssh rsync tmux version-control vim) (operating-system (host-name "computer") (timezone "America/New_York") (locale "en_US.UTF-8") (kernel-arguments '(;; Console resolution "gfxpayload=1440x900x16,1440x900" ;; console cursor. stops the blinking but the colors are bad "vt.cur.default=0x520032" "consoleblank=120" "quiet")) ;; Assuming /dev/sdX is the target hard disk, and "my-root" is ;; the label of the target root file system. (bootloader (grub-configuration (target "/dev/sda") (terminal-outputs '(console)))) (file-systems (cons* (file-system (device "my-root") (title 'label) (mount-point "/") (type "ext4")) (file-system (device "home") (title 'label) (mount-point "/home") (type "ext4")) %base-file-systems)) ;; This is where user accounts are specified. The "root" ;; account is implicit, and is initially created with the ;; empty password. (users (cons (user-account (name "leo") (comment "") (group "users") ;; Adding the account to the "wheel" group ;; makes it a sudoer. Adding it to "audio" ;; and "video" allows the user to play sound ;; and access the webcam. (supplementary-groups '("wheel" "netdev" "audio")) (home-directory (string-append "/home/" name))) %base-user-accounts)) ;; Globally-installed packages. (packages (cons* curl git openssh mosh nss-certs rsync tmux vim %base-packages)) (services (cons* (dbus-service) (gpm-service) (service openssh-service-type (openssh-configuration (password-authentication? #f))) (ntp-service) (wicd-service) (modify-services %base-services (guix-service-type config => (guix-configuration (inherit config) (substitute-urls '("https://berlin.guixsd.org https://mirror.hydra.gnu.org"))))))))
Compiling Scheme modules...
Running 1 system tests...
The following derivation will be built:
/gnu/store/z4whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv
@ build-started /gnu/store/z4whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv - x86_64-linux /var/log/guix/drvs/z4//whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv.bz2
c[?7lSeaBIOS (version rel-1.11.0-0-g63451fca13-prebuilt.qemu-project.org)


iPXE (http://ipxe.org) 00:03.0 C980 PCI2.10 PnP PMM+0FF91300+0FEF1300 C980
Press Ctrl-B to configure iPXE (PCI 00:03.0)...


Booting from ROM..c[?7l. [ 0.000000] Linux version 4.15.13-gnu (nixbld@) (gcc version 7.3.0 (GCC)) #1 SMP 1
[ 0.000000] Command line: console=ttyS0 --root=/dev/vda1 --system=/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system --load=/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system/boot panic=1
[ 0.000000] KERNEL supported cpus:
[ 0.000000] Intel GenuineIntel
[ 0.000000] AMD AuthenticAMD
[ 0.000000] Centaur CentaurHauls
[ 0.000000] x86/fpu: x87 FPU will use FXSAVE
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000000ffddfff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000ffde000-0x000000000fffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[ 0.000000] NX (Execute Disable) protection: active
[ 0.000000] random: fast init done
[ 0.000000] SMBIOS 2.8 present.
[ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.11.0-0-g63451fca13-prebuilt.qemu-project.org 04/01/2014
[ 0.000000] e820: last_pfn = 0xffde max_arch_pfn = 0x400000000
[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
[ 0.000000] found SMP MP-table at [mem 0x000f5b60-0x000f5b6f] mapped at [ (ptrval)]
[ 0.000000] Scanning 1 areas for low memory corruption
[ 0.000000] RAMDISK: [mem 0x0f512000-0x0ffcffff]
[ 0.000000] ACPI: Early table checksum verification disabled
[ 0.000000] ACPI: RSDP 0x00000000000F5960 000014 (v00 BOCHS )
[ 0.000000] ACPI: RSDT 0x000000000FFE15FC 000030 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACP 0x000000000FFE1458 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
[ 0.000000] ACPI: DSDT 0x000000000FFE0040 001418 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACS 0x000000000FFE0000 000040
[ 0.000000] ACPI: APIC 0x000000000FFE154C 000078 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[ 0.000000] ACPI: HPET 0x000000000FFE15C4 000038 (v01 BOCHS BXPCHPET 00000001 BXPC 00000001)
[ 0.000000] No NUMA configuration found
[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000000ffddfff]
[ 0.000000] NODE_DATA(0) allocated [mem 0x0ffda000-0x0ffddfff]
[ 0.000000] tsc: Using PIT calibration value
[ 0.000000] Zone ranges:
[ 0.000000] DMA32 [mem 0x0000000000001000-0x000000000ffddfff]
[ 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-0x000000000009efff]
[ 0.000000] node 0: [mem 0x0000000000100000-0x000000000ffddfff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000000ffddfff]
[ 0.000000] Reserved but unavailable: 98 pages
[ 0.000000] ACPI: PM-Timer IO Port: 0x608
[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.000000] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.000000] Using ACPI (MADT) for SMP configuration information
[ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[ 0.000000] e820: [mem 0x10000000-0xfffbffff] available for PCI devices
[ 0.000000] Booting paravirtualized kernel on bare hardware
[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[ 0.000000] setup_percpu: NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:1 nr_node_ids:1
[ 0.000000] percpu: Embedded 45 pages/cpu @ (ptrval) s146072 r8192 d30056 u2097152
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 64359
[ 0.000000] Policy zone: DMA32
[ 0.000000] Kernel command line: console=ttyS0 --root=/dev/vda1 --system=/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system --load=/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system/boot panic=1
[ 0.000000] Memory: 223164K/261616K available (12300K kernel code, 1508K rwdata, 3840K rodata, 1760K init, 1164K bss, 38452K reserved, 0K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] ftrace: allocating 37456 entries in 147 pages
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=1.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[ 0.000000] NR_IRQS: 16640, nr_irqs: 256, preallocated irqs: 16
[ 0.000000] Console: colour VGA+ 80x25
[ 0.000000] console [ttyS0] enabled
[ 0.000000] ACPI: Core revision 20170831
[ 0.000000] ACPI: 1 ACPI AML tables successfully acquired and loaded
[ 0.000000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[ 0.008000] APIC: Switch to symmetric I/O mode setup
[ 0.020000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.040000] tsc: Fast TSC calibration using PIT
[ 0.044000] tsc: Detected 1862.112 MHz processor
[ 0.044000] Calibrating delay loop (skipped), value calculated using timer frequency.. 3724.22 BogoMIPS (lpj=7448448)
[ 0.044000] pid_max: default: 32768 minimum: 301
[ 0.044000] Security Framework initialized
[ 0.044000] Yama: becoming mindful.
[ 0.053236] AppArmor: AppArmor initialized
[ 0.059332] Dentry cache hash table entries: 32768 (order: 6, 262144 bytes)
[ 0.061386] Inode-cache hash table entries: 16384 (order: 5, 131072 bytes)
[ 0.064452] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
[ 0.066201] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
[ 0.098887] mce: CPU supports 10 MCE banks
[ 0.102074] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.103491] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.104170] Spectre V2 : Spectre mitigation: LFENCE not serializing, switching to generic retpoline
[ 0.106545] Spectre V2 : Mitigation: Full generic retpoline
[ 0.108109] Spectre V2 : Spectre v2 mitigation: Filling RSB on context switch
[ 0.817807] Freeing SMP alternatives memory: 28K
[ 0.864000] smpboot: CPU0: AMD QEMU Virtual CPU version 2.5+ (family: 0x6, model: 0x6, stepping: 0x3)
[ 0.873074] Performance Events: PMU not available due to virtualization, using software events only.
[ 0.876559] Hierarchical SRCU implementation.
[ 0.893597] NMI watchdog: Perf event create on CPU 0 failed with -2
[ 0.895131] NMI watchdog: Perf NMI watchdog permanently disabled
[ 0.901277] smp: Bringing up secondary CPUs ...
[ 0.902307] smp: Brought up 1 node, 1 CPU
[ 0.903445] smpboot: Max logical packages: 1
[ 0.904070] smpboot: Total of 1 processors activated (3724.22 BogoMIPS)
[ 0.932615] devtmpfs: initialized
[ 0.940082] x86/mm: Memory block size: 128MB
[ 0.947450] evm: security.selinux
[ 0.948000] evm: security.SMACK64
[ 0.948000] evm: security.SMACK64EXEC
[ 0.948000] evm: security.SMACK64TRANSMUTE
[ 0.948000] evm: security.SMACK64MMAP
[ 0.948000] evm: security.apparmor
[ 0.948000] evm: security.ima
[ 0.948839] evm: security.capability
[ 0.957213] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.960350] futex hash table entries: 256 (order: 2, 16384 bytes)
[ 0.967828] pinctrl core: initialized pinctrl subsystem
[ 0.976073] RTC time: 20:00:31, date: 03/29/18
[ 0.984579] NET: Registered protocol family 16
[ 0.990463] audit: initializing netlink subsys (disabled)
[ 0.996741] audit: type=2000 audit(1522353629.992:1): state=initialized audit_enabled=0 res=1
[ 1.005216] cpuidle: using governor ladder
[ 1.006745] cpuidle: using governor menu
[ 1.013354] ACPI: bus type PCI registered
[ 1.014768] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[ 1.023534] PCI: Using configuration type 1 for base access
[ 1.085592] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 1.099233] ACPI: Added _OSI(Module Device)
[ 1.100108] ACPI: Added _OSI(Processor Device)
[ 1.101286] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 1.102529] ACPI: Added _OSI(Processor Aggregator Device)
[ 1.145775] ACPI: Interpreter enabled
[ 1.148602] ACPI: (supports S0 S3 S4 S5)
[ 1.149762] ACPI: Using IOAPIC for interrupt routing
[ 1.152337] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 1.159380] ACPI: Enabled 2 GPEs in block 00 to 0F
[ 1.253283] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 1.255573] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[ 1.256543] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[ 1.260981] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[ 1.278069] acpiphp: Slot [3] registered
[ 1.279352] acpiphp: Slot [4] registered
[ 1.280287] acpiphp: Slot [5] registered
[ 1.281631] acpiphp: Slot [6] registered
[ 1.282983] acpiphp: Slot [7] registered
[ 1.284367] acpiphp: Slot [8] registered
[ 1.285764] acpiphp: Slot [9] registered
[ 1.287156] acpiphp: Slot [10] registered
[ 1.288368] acpiphp: Slot [11] registered
[ 1.289795] acpiphp: Slot [12] registered
[ 1.292375] acpiphp: Slot [13] registered
[ 1.293745] acpiphp: Slot [14] registered
[ 1.295116] acpiphp: Slot [15] registered
[ 1.296403] acpiphp: Slot [16] registered
[ 1.297771] acpiphp: Slot [17] registered
[ 1.299145] acpiphp: Slot [18] registered
[ 1.300370] acpiphp: Slot [19] registered
[ 1.301737] acpiphp: Slot [20] registered
[ 1.303094] acpiphp: Slot [21] registered
[ 1.304407] acpiphp: Slot [22] registered
[ 1.305784] acpiphp: Slot [23] registered
[ 1.308245] acpiphp: Slot [24] registered
[ 1.309614] acpiphp: Slot [25] registered
[ 1.311029] acpiphp: Slot [26] registered
[ 1.311661] acpiphp: Slot [27] registered
[ 1.312438] acpiphp: Slot [28] registered
[ 1.313040] acpiphp: Slot [29] registered
[ 1.313628] acpiphp: Slot [30] registered
[ 1.314215] acpiphp: Slot [31] registered
[ 1.315056] PCI host bridge to bus 0000:00
[ 1.315674] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
[ 1.316110] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
[ 1.316627] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[ 1.317171] pci_bus 0000:00: root bus resource [mem 0x10000000-0xfebfffff window]
[ 1.317711] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
[ 1.318509] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.342323] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
[ 1.344151] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
[ 1.345931] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
[ 1.348113] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
[ 1.354756] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
[ 1.356162] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
[ 1.491413] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[ 1.492368] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[ 1.494362] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[ 1.496000] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[ 1.496000] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[ 1.507649] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[ 1.508000] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[ 1.508000] pci 0000:00:02.0: vgaarb: bridge control possible
[ 1.508000] vgaarb: loaded
[ 1.513997] SCSI subsystem initialized
[ 1.517130] ACPI: bus type USB registered
[ 1.518474] usbcore: registered new interface driver usbfs
[ 1.519502] usbcore: registered new interface driver hub
[ 1.520242] usbcore: registered new device driver usb
[ 1.523103] EDAC MC: Ver: 3.0.0
[ 1.529480] PCI: Using ACPI for IRQ routing
[ 1.545043] NetLabel: Initializing
[ 1.545397] NetLabel: domain hash size = 128
[ 1.545746] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
[ 1.549527] NetLabel: unlabeled traffic allowed by default
[ 1.553776] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[ 1.554817] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 1.555416] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[ 1.564658] clocksource: Switched to clocksource hpet
[ 1.853027] VFS: Disk quotas dquot_6.6.0
[ 1.853871] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 1.863285] AppArmor: AppArmor Filesystem Enabled
[ 1.864157] pnp: PnP ACPI init
[ 1.878205] pnp: PnP ACPI: found 6 devices
[ 1.927881] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 1.932669] NET: Registered protocol family 2
[ 1.943514] TCP established hash table entries: 2048 (order: 2, 16384 bytes)
[ 1.944165] TCP bind hash table entries: 2048 (order: 3, 32768 bytes)
[ 1.944165] TCP: Hash tables configured (established 2048 bind 2048)
[ 1.948669] UDP hash table entries: 256 (order: 1, 8192 bytes)
[ 1.949486] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[ 1.953254] NET: Registered protocol family 1
[ 1.954338] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 1.954932] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 1.955645] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 1.956854] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[ 1.968936] Trying to unpack rootfs image as initramfs...
[ 3.798306] Freeing initrd memory: 11000K
[ 3.802929] Scanning for low memory corruption every 60 seconds
[ 3.815440] Initialise system trusted keyrings
[ 3.818763] workingset: timestamp_bits=40 max_order=16 bucket_order=0
[ 3.846004] zbud: loaded
[ 3.862888] Allocating IMA blacklist keyring.
[ 3.899156] Key type asymmetric registered
[ 3.899667] Asymmetric key parser 'x509' registered
[ 3.901802] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[ 3.903936] io scheduler noop registered
[ 3.904665] io scheduler deadline registered (default)
[ 3.906720] io scheduler cfq registered
[ 3.917369] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 3.922238] ACPI: Power Button [PWRF]
[ 3.931398] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[ 3.958457] 00:05: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 4.013121] Linux agpgart interface v0.103
[ 4.095282] brd: module loaded
[ 4.127041] loop: module loaded
[ 4.149868] scsi host0: ata_piix
[ 4.154499] scsi host1: ata_piix
[ 4.156069] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc100 irq 14
[ 4.156847] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc108 irq 15
[ 4.167823] libphy: Fixed MDIO Bus: probed
[ 4.168156] tun: Universal TUN/TAP device driver, 1.6
[ 4.170968] PPP generic driver version 2.4.2
[ 4.173117] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 4.173808] ehci-pci: EHCI PCI platform driver
[ 4.174631] ehci-platform: EHCI generic platform driver
[ 4.175286] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 4.175883] ohci-pci: OHCI PCI platform driver
[ 4.177008] ohci-platform: OHCI generic platform driver
[ 4.177680] uhci_hcd: USB Universal Host Controller Interface driver
[ 4.181524] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 4.188465] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 4.189322] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 4.194312] mousedev: PS/2 mouse device common for all mice
[ 4.201766] rtc_cmos 00:00: RTC can wake from S4
[ 4.206020] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 4.210802] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[ 4.212653] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram, hpet irqs
[ 4.213502] i2c /dev entries driver
[ 4.215174] device-mapper: uevent: version 1.0.3
[ 4.217866] device-mapper: ioctl: 4.37.0-ioctl (2017-09-20) initialised: dm-devel@redhat.com
[ 4.219362] ledtrig-cpu: registered to indicate activity on CPUs
[ 4.230168] NET: Registered protocol family 10
[ 4.245127] Segment Routing with IPv6
[ 4.246373] NET: Registered protocol family 17
[ 4.247375] Key type dns_resolver registered
[ 4.251796] sched_clock: Marking stable (4248154360, 0)->(4361042007, -112887647)
[ 4.259188] registered taskstats version 1
[ 4.259661] Loading compiled-in X.509 certificates
[ 4.262246] zswap: loaded using pool lzo/zbud
[ 4.285094] Key type big_key registered
[ 4.289432] Key type trusted registered
[ 4.293728] Key type encrypted registered
[ 4.294241] AppArmor: AppArmor sha1 policy hashing enabled
[ 4.295329] ima: No TPM chip found, activating TPM-bypass! (rc=-19)
[ 4.301130] evm: HMAC attrs: 0x1
[ 4.306850] Magic number: 10:245:44
[ 4.309171] rtc_cmos 00:00: setting system clock to 2018-03-29 20:00:34 UTC (1522353634)
[ 4.315004] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
[ 4.315523] EDD information not available.
[ 4.338845] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[ 4.342576] ata2.00: configured for MWDMA2
[ 4.362669] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
[ 4.389879] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[ 4.390735] cdrom: Uniform CD-ROM driver Revision: 3.20
[ 4.399275] sr 1:0:0:0: Attached scsi generic sg0 type 5
[ 4.474085] Freeing unused kernel memory: 1760K
[ 4.474622] Write protecting the kernel read-only data: 18432k
[ 4.481944] Freeing unused kernel memory: 2024K
[ 4.488199] Freeing unused kernel memory: 256K
GC Warning: pthread_getattr_np or pthread_attr_getstack failed for main thread
GC Warning: Couldn't read /proc/stat
[ 4.826412] tsc: Refined TSC clocksource calibration: 1849.226 MHz
[ 4.827283] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x354f9f4e667, max_idle_ns: 881590762287 ns
[ 5.861133] clocksource: Switched to clocksource tsc
Welcome, this is GNU's early boot Guile.
Use '--repl' for an initrd REPL.
loading kernel modules...
[ 6.068166] usbcore: registered new interface driver usb-storage
[ 6.114030] usbcore: registered new interface driver uas
[ 6.229953] hidraw: raw HID events driver (C) Jiri Kosina
[ 6.246509] usbcore: registered new interface driver usbhid
[ 6.247023] usbhid: USB HID core driver
[ 6.457581] isci: Intel(R) C600 SAS Controller Driver - version 1.2.0
[ 6.980292] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[ 7.459346] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
[ 7.939955] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[ 8.419789] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
[ 9.047289] vda: vda1 vda2
[ 9.199424] FS-Cache: Loaded
[ 9.234168] 9pnet: Installing 9P2000 support
[ 9.246603] 9p: Installing v9fs 9p2000 file system support
[ 9.248614] FS-Cache: Netfs '9p' registered for caching
[ 9.357039] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
loading '/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system/boot'...
making '/gnu/store/lli9bx5hq3hqb1d2vshm41sc2whxm36m-system' the current system...
setting up setuid programs in '/run/setuid-programs'...
populating /etc from /gnu/store/d1g43dj80wph83ag2zldiiz823gs4wz3-etc...
adding user 'root'...
adding group 'root'...
adding group 'wheel'...
adding group 'users'...
adding group 'nogroup'...
adding group 'tty'...
adding group 'dialout'...
adding group 'kmem'...
adding group 'input'...
adding group 'video'...
adding group 'audio'...
adding group 'netdev'...
adding group 'lp'...
adding group 'disk'...
adding group 'floppy'...
adding group 'cdrom'...
adding group 'tape'...
adding group 'kvm'...
adding group 'guixbuild'...
adding group 'sshd'...
usermod: no changes
adding user 'alice'...
[ 20.354756] clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
[ 20.361090] clocksource: 'hpet' wd_now: 7bf2c9db wd_last: 778761fc mask: ffffffff
[ 20.365593] clocksource: 'tsc' cs_now: 9bcfd4001 cs_last: 9848ecebb mask: ffffffffffffffff
[ 20.368620] tsc: Marking TSC unstable due to clocksource watchdog
[ 20.370720] TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
[ 20.373207] sched_clock: Marking unstable (20370599229, 13198)<-(20483512433, -112887647)
[ 20.397680] clocksource: Switched to clocksource hpet
adding user 'nobody'...
adding user 'guixbuilder01'...
adding user 'guixbuilder02'...
adding user 'guixbuilder03'...
adding user 'guixbuilder04'...
adding user 'guixbuilder05'...
adding user 'guixbuilder06'...
adding user 'guixbuilder07'...
adding user 'guixbuilder08'...
adding user 'guixbuilder09'...
adding user 'guixbuilder10'...
adding user 'sshd'...
registering public key '/gnu/store/xzz0xn80jp48fzy5xz4k8nmwwz1badgc-guix-0.14.0-9.bdf0c64/share/guix/hydra.gnu.org.pub'...
[ 28.866401] random: crng init done
ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519
[ 40.483832] shepherd[1]: Service root has been started.
[ 45.306274] shepherd[1]: starting services...
[ 45.347538] shepherd[1]: Service root-file-system has been started.
[ 45.387508] shepherd[1]: Service user-file-systems has been started.
[ 45.445802] shepherd[1]: Service file-system-/dev/pts has been started.
[ 45.493677] shepherd[1]: Service file-system-/dev/shm has been started.
[ 45.533174] shepherd[1]: Service file-systems has been started.
[ 45.791813] shepherd[1]: waiting for udevd...
[ 46.497694] shepherd[1]: waiting for udevd...
[ 46.797757] udevd[264]: starting version 3.2.4
[ 47.411495] udevd[264]: starting eudev-3.2.4
[ 47.471732] udevd[264]: no sender credentials received, message ignored
[ 49.356174] parport_pc 00:04: reported by Plug and Play ACPI
[ 49.393292] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
[ 49.431225] Floppy drive(s): fd0 is 2.88M AMI BIOS
[ 49.487746] FDC 0 is a S82078B
[ 49.743631] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
[ 50.091114] input: PC Speaker as /devices/platform/pcspkr/input/input3
[ 50.786448] Error: Driver 'pcspkr' is already registered, aborting...
[ 51.535618] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input4
[ 52.508577] kvm: Nested Virtualization enabled
[ 52.913484] ppdev: user-space parallel port driver
[ 53.089682] Error: Driver 'pcspkr' is already registered, aborting...
[ 53.289733] shepherd[1]: Service udev has been started.
[ 53.470334] shepherd[1]: Service urandom-seed has been started.
[ 53.509739] shepherd[1]: Service user-processes has been started.
[ 53.551190] shepherd[1]: Service host-name has been started.
[ 53.705528] shepherd[1]: Service user-homes could not be started.
nscd: 289 monitoring file `/etc/hosts` (1)
nscd: 289 monitoring directory `/etc` (2)
nscd: 289 monitoring file `/etc/resolv.conf` (3)
nscd: 289 monitoring directory `/etc` (2)
nscd: 289 monitoring file `/etc/services` (4)
nscd: 289 monitoring directory `/etc` (2)
[ 54.801392] shepherd[1]: Service nscd has been started.
[ 54.902220] shepherd[1]: Service guix-daemon has been started.
This is the GNU system. Welcome.
komputilo login: shepherd: Service ssh-daemon could not be started.
Backtrace:
4 (primitive-load "/gnu/store/gzysid4gy412hnd0jhj72c3c1zb?")
In ice-9/eval.scm:
619:8 3 (_ #f)
619:8 2 (_ #(#(#<directory (guile-user) 7ce140> #<test-run?>) #))
293:34 1 (_ #(#(#<directory (guile-user) 7ce140> #<test-run?>) #))
In unknown file:
0 (scm-error misc-error #f "~A ~S" ("file didn't show?" ?) ?)

ERROR: In procedure scm-error:
file didn't show up "/var/run/sshd.pid"
QEMU runs as PID 4
connected to QEMU's monitor
read QEMU monitor prompt
connected to guest REPL
%%%% Starting test ssh-daemon (Writing full log to "ssh-daemon.log")
marionette is ready
note: keeping build directory `/tmp/guix-build-openssh.drv-0'
builder for `/gnu/store/z4whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv' failed with exit code 1
@ build-failed /gnu/store/z4whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv - 1 builder for `/gnu/store/z4whl2ghvwwhyh323ihh13n1y8j6f6bq-openssh.drv' failed with exit code 1
TOTAL: 1
FAIL: /gnu/store/rs538fa2y5vqg76fcp1r5pyd6gcg29y0-openssh

Some deprecated features have been used. Set the environment
variable GUILE_WARN_DEPRECATED to "detailed" and rerun the
program to get more information. Set it to "no" to suppress
this message.
make: *** [Makefile:5232: check-system] Error 1
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAlq9R6AACgkQJkb6MLrK
fwjYhxAAspQ8Xkb3/m2SOEAQM9jRw1OwhshfiH8o0fwNywt4wEFV/xTTVwIG1PS0
/GoOPp7P9Yaf82mOX3BuuykFmAE+DLtP4Ee2rwLFA/vM7rMAkLaGjId7h/e/L+M4
7XBVT2esgCkKwD2hM5zWiMUWF+7YsoV4jRh9u0YZ28B8mmAxqTgArSsgl94Z+Y4l
Fh6WPt1ztTyRgn0P3GiWwdqNeHMNXeLwX2/jA7XtpGv0jin/dSkIX//dzC4cXqVB
3jB05GlgOdlYvMMijx/bGPf2RBhUtWya48fbPaCI+GCZHAZr/fR9weUF5lTFyjQ8
lpo3rehm1ED3D264ocnoTxMMktlJdNPmXoX2W9Lz3cQU6KuUNTSWTV6mmCxTbCaS
nQosqZvc8kLxdlY6lEO6Xs2E6y2v7qLTkuA+BZEv5zsOzSTMzGIN6XYODmdoFcv9
E9z5oFxHaUn+BnpfrfM0hCLIH8XbjVhRkmlJU2J4pkFLC7yiw0OglG+FwIq9vYgb
IOwxF2M2hcnSAuUgJjLh/vlGun2yXvb2SwcjGX7+a2Q8XL4Vp8rTTRXTYO0EwlR1
GMJl5TgJBq8iExTLJLtBybcKhO1cReIQq1YlXWjrao9ckqzZeyo/lacpyQibrcdU
0okRQAPdL1NnRyBoyu/9cqLdR6DrPExJxL/AEvMtaMWYlL4Jios=
=t4kS
-----END PGP SIGNATURE-----


L
L
Ludovic Courtès wrote on 6 Apr 2018 10:21
(name . Leo Famulari)(address . leo@famulari.name)(address . 30993@debbugs.gnu.org)
877epk3fuy.fsf@gnu.org
Hi Leo,

Leo Famulari <leo@famulari.name> skribis:

Toggle quote (14 lines)
> Since the update to Shepherd 0.4.0, I've found that OpenSSH's sshd is
> killed almost immediately after it starts with signal 15. I confirmed
> the issue started with the Shepherd upgrade by bisecting our Git
> history.
>
> I can reproduce the issue from commit
> b6beda1d6b9093a8493b5c3cde33ed522242c451 (gnu: Add botan.).
>
> One interesting tidbit is that the PID file '/var/run/sshd.pid' is not
> created anymore. And if I create an empty PID file by hand, it is
> removed after trying to start the ssh-daemon service. Also, the sshd
> user's home '/var/run/sshd' does not exist, and is similarly removed if
> it does exist.

Weird. On my laptop /var/run/sshd.pid exists and contains the right
PID. /var/run/sshd does not exist, though.

When I run the config you posted in ‘guix system vm’, ‘ssh-daemon’ is
correctly started and I see a correct ssh.pid and /var/run/sshd exists
as well.

Toggle quote (5 lines)
> I ran the OpenSSH system test `make check-system TESTS=openssh` and it
> failed when it could not find the PID file. It passed on another
> non-GuixSD machine. The failing machine is relatively slow and lacks
> KVM: a ThinkPad x200s.

FWIW on my x86_64 laptop, I’ve run it several times in a row (using
“guix build /gnu/store/…-openssh.drv --check”), and it always succeeds.

Toggle quote (24 lines)
> I modified the sshd invocation to print some debug output ('-d -E
> /tmp/sshd.log') and this is what it shows:
>
> ------
> debug1: sshd version OpenSSH_7.6, OpenSSL 1.0.2o 27 Mar 2018
> debug1: private host key #0: ssh-rsa SHA256:REDACTED
> debug1: private host key #1: ssh-dss SHA256:REDACTED
> debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:REDACTED
> debug1: private host key #3: ssh-ed25519 SHA256:REDACTED
> debug1: rexec_argv[0]='/gnu/store/az7vib8gk16fybhshh5xpkljmgxyrs4k-openssh-7.6p1/sbin/sshd'
> debug1: rexec_argv[1]='-D'
> debug1: rexec_argv[2]='-d'
> debug1: rexec_argv[3]='-E'
> debug1: rexec_argv[4]='/tmp/sshd.log'
> debug1: rexec_argv[5]='-f'
> debug1: rexec_argv[6]='/gnu/store/miy7xg5j4fg3mn04mcl27awmcl6s97ss-sshd_config'
> debug1: Set /proc/self/oom_score_adj from 0 to -1000
> debug1: Bind to port 22 on 0.0.0.0.
> Server listening on 0.0.0.0 port 22.
> debug1: Bind to port 22 on ::.
> Server listening on :: port 22.
> Received signal 15; terminating.
> ------

Hmm, where could that SIGTERM come from? ‘make-kill-destructor’ uses it
when a service is stopped, and otherwise it’s sent when we’re shutting
the system down. But here?…

Thanks,
Ludo’.
L
L
Leo Famulari wrote on 6 Apr 2018 14:41
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30993@debbugs.gnu.org)
20180406124101.GB1883@jasmine.lan
On Fri, Apr 06, 2018 at 10:21:09AM +0200, Ludovic Courtès wrote:
[...]
Toggle quote (10 lines)
> > Server listening on 0.0.0.0 port 22.
> > debug1: Bind to port 22 on ::.
> > Server listening on :: port 22.
> > Received signal 15; terminating.
> > ------
>
> Hmm, where could that SIGTERM come from? ‘make-kill-destructor’ uses it
> when a service is stopped, and otherwise it’s sent when we’re shutting
> the system down. But here?…

Indeed, that is the question. Does anyone have advice for debugging?

I still have this issue and so I'm continuing to use Shepherd 0.3.2.
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAlrHat0ACgkQJkb6MLrK
fwgNFg//X+diB7+Bg11URGH73/vda9Xpt9FSFqz6lo9fbnAj/Seli28MGZdYYaYt
GalvF62goVye0IT8UET7MAenHTatffaJt6wv5ejen5AdxbsH0tjFPJT+GqU5nNXo
09uAniGJOykbMZTejoGuC7Zr05zKubwH4R3mnctpEMs8i4Y2YrEasBJlUAkUZciu
mzqGLIIhcvSPrKujqLV9RgJeCi2zMwpEBV0KNSdUy0gmEODlDl/1ObcFrKY7Ykzh
6JiMygz52NKEoQtIre9VX2e+0LuVKMppWnrTI2NPhU56T8E+sJGm88Wo0Ntm2cWU
LZNPrT0EeFa91yYhuCLIlp5L0HtdCno8J3aJ1UqF8te5a3BswLE6FehdAJCEmTOt
rrNlEXPed8+aSYfuXxdxYKaP2IRrTEQB8d6bLzkvT6Lca0PvbqD9G1nCkBeXh8P4
I4eDpgLLHQ4lpZC/ivQFew8nEUQC1Rvtjzk+9RjRqvGy321FWplI7QsLOSY5grR+
DAz1+kouOCuGU0m6aA636+lsFf703FTRzP0mq3G6j9u2S48q9MX+mFWfltfGCEKe
mfl9HfWiT7PIDBJMjly7ILC1UkwPrBrISOQ93fdVS1IMifLuzKK3yIZ0zaltFQM5
vDZXSD3OcC4pF+LMGH+LKEhGZckOWYGH8WPXvcs0qka2NUf6Apo=
=b2IG
-----END PGP SIGNATURE-----


L
L
Ludovic Courtès wrote on 6 Apr 2018 16:32
control message for bug #30993
(address . control@debbugs.gnu.org)
87r2nsz9pi.fsf@gnu.org
severity 30993 important
L
L
Ludovic Courtès wrote on 6 Apr 2018 16:37
Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
(name . Leo Famulari)(address . leo@famulari.name)(address . 30993@debbugs.gnu.org)
87po3cz9i3.fsf@gnu.org
Leo Famulari <leo@famulari.name> skribis:

Toggle quote (16 lines)
> On Fri, Apr 06, 2018 at 10:21:09AM +0200, Ludovic Courtès wrote:
> [...]
>> > Server listening on 0.0.0.0 port 22.
>> > debug1: Bind to port 22 on ::.
>> > Server listening on :: port 22.
>> > Received signal 15; terminating.
>> > ------
>>
>> Hmm, where could that SIGTERM come from? ‘make-kill-destructor’ uses it
>> when a service is stopped, and otherwise it’s sent when we’re shutting
>> the system down. But here?…
>
> Indeed, that is the question. Does anyone have advice for debugging?
>
> I still have this issue and so I'm continuing to use Shepherd 0.3.2.

For you the bug is 100% reproducible with 0.4.0 and never happens with
0.3.2? Even in a ‘guix system vm’?

Ludo’.
M
M
Martin Castillo wrote on 1 May 2018 15:13
(address . bug-guix@gnu.org)
a61fd87e-8f57-bae7-7747-e4be02161a4d@uni-bremen.de
(resending because I forgot to CC the list)

On 06.04.2018 14:41, Leo Famulari wrote:
Toggle quote (9 lines)
>> Hmm, where could that SIGTERM come from? ‘make-kill-destructor’ uses it
>> when a service is stopped, and otherwise it’s sent when we’re shutting
>> the system down. But here?…
>
> Indeed, that is the question. Does anyone have advice for debugging?
>
> I still have this issue and so I'm continuing to use Shepherd 0.3.2.
>

Maybe one could somehow strace herd, or change the make-kill-destructor
to log every time it is being executed?

I'm not that fluent in guile so maybe someone else could do that?
L
L
Ludovic Courtès wrote on 1 May 2018 22:43
(name . Martin Castillo)(address . castilma@uni-bremen.de)(address . 30993@debbugs.gnu.org)
87r2mvnm29.fsf@gnu.org
Martin Castillo <castilma@uni-bremen.de> skribis:

Toggle quote (15 lines)
> (resending because I forgot to CC the list)
>
> On 06.04.2018 14:41, Leo Famulari wrote:
>>> Hmm, where could that SIGTERM come from? ‘make-kill-destructor’ uses it
>>> when a service is stopped, and otherwise it’s sent when we’re shutting
>>> the system down. But here?…
>>
>> Indeed, that is the question. Does anyone have advice for debugging?
>>
>> I still have this issue and so I'm continuing to use Shepherd 0.3.2.
>>
>
> Maybe one could somehow strace herd, or change the make-kill-destructor
> to log every time it is being executed?

‘herd status sshd’ displays the last time sshd was respawned, but the
info ‘herd’ receives actually includes the dates of all the respawns,
not just the last one. Is that what you’re asking for?

Thanks,
Ludo’.
M
M
Martin Castillo wrote on 3 May 2018 17:16
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30993@debbugs.gnu.org)
b1b51eb6-77f1-0b53-4f18-3a83fe7ef24c@uni-bremen.de
On 01.05.2018 22:43, Ludovic Courtès wrote:
Toggle quote (8 lines)
>> Maybe one could somehow strace herd, or change the make-kill-destructor
>> to log every time it is being executed?
>
> ‘herd status sshd’ displays the last time sshd was respawned, but the
> info ‘herd’ receives actually includes the dates of all the respawns,
> not just the last one. Is that what you’re asking for?
>

My idea was that maybe make-kill-destructor is being called from
somewhere else. If this is being
logged, one could rule that out.

Another wild idea would be sshd killing itself for some reason. stracing
sshd would tell us, if that's the case. How would one do that? Does
shepherd provide some debugging functions?

Or does linux provide a way to log all sent signals so one could find
the sending process?

Martin

--
GPG: 7FDE 7190 2F73 2C50 236E 403D CC13 48F1 E644 08EC
L
L
Leo Famulari wrote on 3 May 2018 18:38
(name . Martin Castillo)(address . castilma@uni-bremen.de)
20180503163808.GA1019@jasmine.lan
On Thu, May 03, 2018 at 05:16:32PM +0200, Martin Castillo wrote:
Toggle quote (22 lines)
>
>
> On 01.05.2018 22:43, Ludovic Courtès wrote:
> >> Maybe one could somehow strace herd, or change the make-kill-destructor
> >> to log every time it is being executed?
> >
> > ‘herd status sshd’ displays the last time sshd was respawned, but the
> > info ‘herd’ receives actually includes the dates of all the respawns,
> > not just the last one. Is that what you’re asking for?
> >
>
> My idea was that maybe make-kill-destructor is being called from
> somewhere else. If this is being
> logged, one could rule that out.
>
> Another wild idea would be sshd killing itself for some reason. stracing
> sshd would tell us, if that's the case. How would one do that? Does
> shepherd provide some debugging functions?
>
> Or does linux provide a way to log all sent signals so one could find
> the sending process?

I haven't had time to debug this yet, and Shepherd 0.3 still works.

Since nobody else can reproduce the bug, and since I expect OpenSSH to
be commonly used, I suspect some non-deterministic Guile mis-compilation
or filesystem corruption — the system in question is using ext4.
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAlrrOu0ACgkQJkb6MLrK
fwjwEw/9GWU0ObLtXCmd3jJ/JXagYqRmUnVaKvTlfohnlucPrliNzQ6z5Dx6E3He
ETjXbEQZ6U9ZGebIrSHunCNHialLW4gQ6cijnoAASIkGNb0gtA4rOr0pQHuxk9Do
c3x3IdW3kO8mzL1JQVo+ZBidYw50bccq0HcNMGIkLRDClZxkrK19AnMS5O9Jx3MI
4N0Vz5a0FZE3MwEDxycR6LA0X5DVVAv9QbiHPpzopFiTwfQLUDfnD8zbQhvIWmJX
nap6HPk5sg3Nyo5pOb9rbZUmEvwUwA5YFFqfmRS5g2ZZ6RdrE3zlC9zEEEO05UDv
wlAyRfalmpGw69XWarULwUn7DMnZ4/cO8TpAiEajOb/+rsP71oJ+8Qa1QQTyNCOG
G5FTUb2xodiw/kfY2x2HSf0Ct/IMbq4Qhnx6GfawxB7C1c8OFh3hiWN7j2hWR+Po
rnMZ7btY7E+dRh7iTo/+A5a+/vaRSPYoCS9aPUZzsxSTscrD6yzCaDA/mu9yIL/X
Dv2vC+V439PaqI8YSH3la6aWvlTWr4VqG5ADYtNtswUv9jJgPRYiagau6ZBYrlw2
sz2TT/GJUozWyIl1RcJTTqa8nNBeYgsx+DK9dG3K7qtODDgD/W+iOptkPug+8t0f
+RlvKTWqB2urmxpXes/Kb6fYaybL75JGhqEpdSD9BzSRrj1N0tE=
=/ead
-----END PGP SIGNATURE-----


M
M
Martin Castillo wrote on 4 May 2018 04:01
(name . Leo Famulari)(address . leo@famulari.name)
FB84BAEB-5F14-45C2-9BD6-8FF8CFA5BAD5@uni-bremen.de
Sorry, I forgot to mention that I have the same problem. But I had it already with shepherd 0.3.
L
L
Leo Famulari wrote on 6 May 2018 21:50
(name . Martin Castillo)(address . castilma@uni-bremen.de)
20180506195050.GD8038@jasmine.lan
On Fri, May 04, 2018 at 04:01:52AM +0200, Martin Castillo wrote:
Toggle quote (2 lines)
> Sorry, I forgot to mention that I have the same problem. But I had it already with shepherd 0.3.

Interesting. Did it ever work for you on that system?
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAlrvXJoACgkQJkb6MLrK
fwgTHg//SEB3jG8sKLmpiY4D+vUhlZpQFOg5fZI7QDq749/N2WgM/yg1ZIz9AptQ
gxixuZPTAyBGzOQTkB+BwGHwvhDBcMRuyqJ2bUDWstGcmvq2cBnvBOGLppG2wXsf
lcHnDo+5aCaZ5iFFkyuhOIfBb9dM7oMP6irpgGd1MCS5Yur/Tv8Wkd/l7CRV3SIX
cQrVKrsLtTI4BIiMoazDSiEzQ50k0L6d7KWsO7Reu8/4Qd/4bbeJeKcRkuL+MVRJ
6ccYLx81CurgDQcUGWV9Un9dIIkYTq2tuyO5PwoFIMpds6yQRLn2cx61FBggZdq/
ujL/Xs4cjN/H8+0eA6ZfjfLccVKUoeQqPyQkqow6ahvywyYlebBLiE6byNrsL9rh
0S1FErw2C4XheLJ+zvGowRGTrsNYBBsmAzu/ZXMOMYSbV6IRi4pRHfneQzjNs+tH
7UWihSW3yWoY1sf+4jIiFqzXvcGcxrwY5C5iAgb7FCMmUuvjn1D2Soomb2PBMmUa
+ksTAM0bmY+6QXGwNw+ql1F8hnR8Zl3ISntsRADBLAf87aqcY7//KAvHiqJZ4gYc
MaedC0px3tW8giQRbWxMnO66TUQq6S3SkdYRa2g+WNyqBXZDVH4DZe+i/LN2GodA
lzhYRQsTVKRyhph/kqt9mHZTE77sFyUw+A9OGppvpF9/UVd3sXs=
=SHOl
-----END PGP SIGNATURE-----


M
M
Martin Castillo wrote on 7 May 2018 21:10
bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
(name . Leo Famulari)(address . leo@famulari.name)
fb962e2b-2b18-7adc-ff6d-5fbb0a56c8b4@uni-bremen.de
On 06.05.2018 21:50, Leo Famulari wrote:
Toggle quote (6 lines)
> On Fri, May 04, 2018 at 04:01:52AM +0200, Martin Castillo wrote:
>> Sorry, I forgot to mention that I have the same problem. But I had it already with shepherd 0.3.
>
> Interesting. Did it ever work for you on that system?
>
> that system?
Do you mean shepherd 0.3? Yes. And once(or so) with shepherd 0.4.

I reported that here [0]. Some of the mentioned files needed small
changes for the current guix, but ssh works with all of them, strangely.

I attached my current configuration, where I need to start the daemon
manually (herd start ssh-daemon) after each boot.

Martin



;; This is an operating system configuration template ;; for a "desktop" setup without full-blown desktop ;; environments. ;; This is an operating system configuration template ;; for a "bare bones" setup, with no X11 display server. ;(use-modules (gnu)) (use-modules (gnu) (gnu system nss) (guix gexp)) (use-service-modules ssh) (use-service-modules base desktop xorg) (use-package-modules certs linux suckless wm) ;(use-package-modules admin) (define cyborg-quirk "Section \"InputClass\" Identifier \"Saitek Cyborg R.A.T.5 Mouse\" MatchIsPointer \"on\" MatchProduct \"Saitek Cyborg R.A.T.5 Mouse\" MatchVendor \"Saitek|SAITEK\" MatchDevicePath \"/dev/input/event*\" Option \"ButtonMapping\" \"1 2 3 4 5 6 7 2 9 4 5 12 0 0 0\" Option \"ZAxisMapping\" \"10 11\" # Option \"AutoReleaseButtons\" \"12 13 14 15\" EndSection ") (define xneo "Section \"InputClass\" Identifier \"keyboard-all\" Option \"XkbLayout\" \"neo\" MatchIsKeyboard \"on\" EndSection ") (define %my-xorg-conf (xorg-configuration-file #:extra-config (list cyborg-quirk xneo))) (define %my-startx (xorg-start-command #:configuration-file %my-xorg-conf)) (define %my-services ;; My very own list of services. (modify-services %desktop-services (guix-service-type config => (guix-configuration (inherit config) (extra-options '("-M4")) (substitute-urls (cons* "https://berlin.guixsd.org" "https://hydra.gnu.org" (guix-configuration-substitute-urls config))))) (openssh-service-type config => (openssh-configuration (inherit config) (x11-forwarding? (openssh-configuration-x11-forwarding? config)))) (slim-service-type config => (slim-configuration (inherit config) (startx %my-startx) (default-user "mcd"))))) (define (openssh-config-file config) "Return the sshd configuration file corresponding to CONFIG." (computed-file "sshd_config" #~(begin (use-modules (ice-9 match)) (call-with-output-file #$output (lambda (port) (display "# Generated by 'openssh-service'.\n" port) (format port "Port ~a\n" #$(number->string (openssh-configuration-port-number config))) (format port "PermitRootLogin ~a\n" #$(match (openssh-configuration-permit-root-login config) (#t "yes") (#f "no") ('without-password "without-password"))) (format port "PermitEmptyPasswords ~a\n" #$(if (openssh-configuration-allow-empty-passwords? config) "yes" "no")) (format port "PasswordAuthentication ~a\n" #$(if (openssh-configuration-password-authentication? config) "yes" "no")) (format port "PubkeyAuthentication ~a\n" #$(if (openssh-configuration-public-key-authentication? config) "yes" "no")) (format port "X11Forwarding ~a\n" #$(if (openssh-configuration-x11-forwarding? config) "yes" "no")) (format port "PidFile ~a\n" #$(openssh-configuration-pid-file config)) (format port "ChallengeResponseAuthentication ~a\n" #$(if (openssh-challenge-response-authentication? config) "yes" "no")) (format port "UsePAM ~a\n" #$(if (openssh-configuration-use-pam? config) "yes" "no")) (format port "PrintLastLog ~a\n" #$(if (openssh-configuration-print-last-log? config) "yes" "no")) ;; Add '/etc/authorized_keys.d/%u', which we populate. (format port "AuthorizedKeysFile \ .ssh/authorized_keys .ssh/authorized_keys2 /etc/ssh/authorized_keys.d/%u\n") (for-each (lambda (s) (format port "AcceptEnv ~a\n" s)) '#$(openssh-configuration-accepted-environment config)) ; (for-each ; (match-lambda ; ((name command) (format port "Subsystem\t~a\t~a\n" name command))) ; '#$(openssh-configuration-subsystems config)) #t))))) (define (my-openssh-shepherd-service config) "Return a <shepherd-service> for openssh with CONFIG." (define openssh-command #~(list (string-append #$(openssh-configuration-openssh config) "/sbin/sshd") "-D" "-f" #$(openssh-config-file config) "-d" "-E" "/var/log/sshd.debug")) (list (shepherd-service (documentation "OpenSSH server.") (requirement '(syslogd)) (provision '(ssh-daemon)) (start #~(make-forkexec-constructor #$openssh-command #:pid-file "/var/run/sshd.pid")) ; #:pid-file #$pid-file)) (stop #~(make-kill-destructor)) (auto-start? (openssh-auto-start? config))))) (operating-system (host-name "komputilo") (timezone "Europe/Berlin") (locale "de_DE.UTF-8") (hosts-file (plain-file "hosts" "127.0.0.1 localhost komputilo ::1 localhost komputilo 192.168.178.20 pi.fritz.box pi")) ;; Assuming /dev/sdX is the target hard disk, and "my-root" is ;; the label of the target root file system. (bootloader (bootloader-configuration (bootloader (bootloader (inherit grub-bootloader) (installer #~(const #t)))))) ; (bootloader (bootloader-configuration (bootloader grub-bootloader) ; (target "/dev/sda3") ;(menu-entries '((menu-entry ; (label "Grub Nixos") ; (multiboot "(hd0)") ; still unsupported ; ))) ; )) (file-systems (cons (file-system (device "guix-root") (title 'label) (mount-point "/") (type "ext4")) %base-file-systems)) ;; This is where user accounts are specified. The "root" ;; account is implicit, and is initially created with the ;; empty password. (users (cons (user-account (name "mcd") (comment "Martin Castillo") (group "users") ;; Adding the account to the "wheel" group ;; makes it a sudoer. Adding it to "audio" ;; and "video" allows the user to play sound ;; and access the webcam. (supplementary-groups '("wheel" ; "plugdev" ? für mtp? ist aber undefiniert "audio" "video" "netdev")) ;workmanager")) (home-directory "/home/mcd")) %base-user-accounts)) ;; Globally-installed packages. ;(packages (cons tcpdump %base-packages)) ;; Add a bunch of window managers; we can choose one at ;; the log-in screen with F1. (packages (cons* dmenu ;window managers nss-certs ;for HTTPS access kbd-neo %base-packages)) ;; Add services to the baseline: a DHCP client and ;; an SSH server. (services (cons* ;(dhcp-client-service) ; (gpm-service) ;mouse in vt (console-keymap-service (file-append kbd-neo "/share/keymaps/neo.map"));; ; (my-openssh-shepherd-service ; (openssh-configuration ; (accepted-environment '("COLORTERM")) ; (port-number 2222))) (service openssh-service-type (openssh-configuration (accepted-environment '("COLORTERM")) (port-number 2222))) (simple-service 'store-my-config etc-service-type `(("config.scm" ,(local-file (assoc-ref (current-source-location) 'filename))))) (xfce-desktop-service) %my-services)) ;; Use the "desktop" services, which include the X11 ;; log-in service, networking with Wicd, and more. ;(services %desktop-services) ;; Allow resolution of '.local' host names with mDNS. (name-service-switch %mdns-host-lookup-nss))
L
L
Ludovic Courtès wrote on 15 Jun 2018 11:07
control message for bug #30993
(address . control@debbugs.gnu.org)
87602kwh7e.fsf@gnu.org
tags 30993 unreproducible
L
L
Leo Famulari wrote on 18 Jul 2018 20:29
(no subject)
(address . control@debbugs.gnu.org)
20180718182910.GA23198@jasmine.lan
merge 32197 30993
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAltPhvYACgkQJkb6MLrK
fwjngw/8DIbj1gfhhtCZ9YsFe7hLJjYqSZyXF0FmCVhMiHW25bu/UxmuYsiFGe50
zTewIlZbzPKmACmU99y3w/NRWip7+P3qTemBw64ddHVCytZ9md9gjQhhQVg0oGzR
nyjNE/qtKFJnEegMhD/6wilgozp6D3SibETPnBB5qjfTxdZ9x2KdmPru5TT/NQpZ
+vTHESM0mUgWaSmrI56gGuiDZLL2h8wqkkEfdknl2t7Zuxq15Vshk7nMhwSZAxJ8
RSrvAXBEMU5Fa8MIox+gpO6xrLKHG+Ew2CvZKeTf6puJSNQwEN08UCc2ElZfPf3E
gbtHLKaISzlVb8iz+qChZ+b2YMaTkmgKY1M6Q4KvsSnomkhCw6NkC2U6E6wMes6t
cdAHakAnDdavOvNxYs8xeSowDVDE9pIhx7xBUp3DG6c3lK5IFgk0gDYnHVOoIgkG
n4YEgNXUNmKpnvKfdy9Tu/RSPqMNixejqGtapwNDkL7ysXdyBBzMKHizCjls7lxP
1xA+BaYgw5l0QrpvYmL9uUCyeJlJe3p2uNtZe1v/KuEuO4Un8XfnvPWbus4ba0Px
Ts8pgQZMbHKm4eCaokvxLEoqj4CB8mcT2MMQFOUcGx8yzn+JrD7ZR1jHKt69a3DX
5hUsACh7UEKU4O/tE3lK691sHcP1sYGnZ5adSIk5wpXBbk0UkJQ=
=Oq18
-----END PGP SIGNATURE-----


C
C
Clément Lassieur wrote on 19 Jul 2018 15:15
Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
87sh4f5ptn.fsf@lassieur.org
Heya,

Martin Castillo <castilma@uni-bremen.de> writes:

Toggle quote (15 lines)
> On 06.05.2018 21:50, Leo Famulari wrote:
>> On Fri, May 04, 2018 at 04:01:52AM +0200, Martin Castillo wrote:
>>> Sorry, I forgot to mention that I have the same problem. But I had it already with shepherd 0.3.
>>
>> Interesting. Did it ever work for you on that system?
>>
>> that system?
> Do you mean shepherd 0.3? Yes. And once(or so) with shepherd 0.4.
>
> I reported that here [0]. Some of the mentioned files needed small
> changes for the current guix, but ssh works with all of them, strangely.
>
> I attached my current configuration, where I need to start the daemon
> manually (herd start ssh-daemon) after each boot.

I don't think you're having the same bug. Martin can manually start the
daemon, whereas Leo can't. So Martin seems to have
has been pushed by Julien.

Martin, could you please test it? (You just need to 'guix pull' and try
again.) Leo, if you confirm my analysis, could you please unmerge the
bugs?

Thanks,
Clément
C
C
Clément Lassieur wrote on 19 Jul 2018 16:24
control message for bug #30993
(address . control@debbugs.gnu.org)
87pnzj5mms.fsf@lassieur.org
unmerge 30993
C
C
Clément Lassieur wrote on 19 Jul 2018 16:26
Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
87muun5mj0.fsf@lassieur.org
Clément Lassieur <clement@lassieur.org> writes:

Toggle quote (2 lines)
> Leo, if you confirm my analysis, could you please unmerge the bugs?

I did it, because Eric confirmed the fix.
Clément
L
L
Leo Famulari wrote on 19 Jul 2018 18:57
(name . Clément Lassieur)(address . clement@lassieur.org)
20180719165730.GA8867@jasmine.lan
On Thu, Jul 19, 2018 at 04:26:59PM +0200, Clément Lassieur wrote:
Toggle quote (6 lines)
> Clément Lassieur <clement@lassieur.org> writes:
>
> > Leo, if you confirm my analysis, could you please unmerge the bugs?
>
> I did it, because Eric confirmed the fix.

Thanks, sorry for the confusion!
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAltQwvcACgkQJkb6MLrK
fwhBexAAgwyIwR6u2bFrxqggaqEu4E+PV5yNkEnLYynx9Nh0rROvQNeDoqZQ+Oix
YKwOoPYPkY9eTHYbdvqEL1r8gGjUrSn/tBAlmGiuXTf9xVxkEmsBs1qYnKbAnTJ9
aWbCn3DtYxYkOi0hjCALb8FmPFiOcM0/7uFxfLNzwcTWq+R27AiTKAsUe3nf6zXW
+32yEm/7F3gcC73HaA3+EkqzmUYTAETqxqnkNz3ODMYMk7iBUmBpZ3LyHc6nWda0
L1SZF/uV8herR7xxo1q/sHyxwsAN51CBOprIyiKinafyZDohzqcKkjffnk9rm0TZ
h1IlwAWlseqZUJzIS3fCNRsmvQf1AklgZ6UafyWXxyjL6TIu0QDyV62MGwyIY69k
l9YSPb+n+7X/I28hDsLLzGIFoVoJzv6vLaeRECyCTG6gQ54V61yO6v1F4O2VEkBC
F2A4NN1bXQYhZnj7rPwjxmEkHNNrZRLbAoDBHE9hV9yvBA1RniTkXONupI9IV2O/
bkZitsF8N7A6jfoiqyEfCnMwegz743OAFuPc/bx1DvBFyJfwbjZ6VZexEcrbLf5T
AJ/aXUmiAyve0fM6zn1ykVNwlhvK6iTBv8QkjlNb9omtJ0X+6JINUBau/7WBm/7P
QVafNZpGuUyTObf1CLqiidQwu9/2VhuHaZhTLXYQRIVRX+JpnRw=
=OssZ
-----END PGP SIGNATURE-----


M
M
Martin Castillo wrote on 23 Jul 2018 19:08
a5d68301-2219-4e4a-0350-a906e4d4a379@uni-bremen.de
On 19.07.2018 15:15, Clément Lassieur wrote:
Toggle quote (9 lines)
> [...]
> Martin, could you please test it? (You just need to 'guix pull' and try
> again.) Leo, if you confirm my analysis, could you please unmerge the
> bugs?
>
> Thanks,
> Clément
>

It still does not work for me.

Attached are my guix version, dmesg|grep shepherd output, config.scm and
my qemu invocation (metal).

I run that system in qemu, but it is installed directly on my harddrive.

Martin

--
GPG: 7FDE 7190 2F73 2C50 236E 403D CC13 48F1 E644 08EC
;; This is an operating system configuration template ;; for a "desktop" setup without full-blown desktop ;; environments. ;; This is an operating system configuration template ;; for a "bare bones" setup, with no X11 display server. ;(use-modules (gnu)) (use-modules (gnu) (gnu system nss)) (use-service-modules ssh) (use-service-modules base desktop xorg) (use-package-modules certs linux suckless wm) ;(use-package-modules admin) (define cyborg-quirk "Section \"InputClass\" Identifier \"Saitek Cyborg R.A.T.5 Mouse\" MatchIsPointer \"on\" MatchProduct \"Saitek Cyborg R.A.T.5 Mouse\" MatchVendor \"Saitek|SAITEK\" MatchDevicePath \"/dev/input/event*\" Option \"ButtonMapping\" \"1 2 3 4 5 6 7 2 9 4 5 12 0 0 0\" Option \"ZAxisMapping\" \"10 11\" # Option \"AutoReleaseButtons\" \"12 13 14 15\" EndSection ") (define xneo "Section \"InputClass\" Identifier \"keyboard-all\" Option \"XkbLayout\" \"neo\" MatchIsKeyboard \"on\" EndSection ") (define %my-xorg-conf (xorg-configuration-file #:extra-config (list cyborg-quirk xneo))) (define %my-startx (xorg-start-command #:configuration-file %my-xorg-conf)) (define %my-services ;; My very own list of services. (modify-services %desktop-services (guix-service-type config => (guix-configuration (inherit config) (extra-options '("-M4")) (substitute-urls (cons* "https://berlin.guixsd.org" "https://hydra.gnu.org" (guix-configuration-substitute-urls config))))) (openssh-service-type config => (openssh-configuration (inherit config) (x11-forwarding? (openssh-configuration-x11-forwarding? config)))) (slim-service-type config => (slim-configuration (inherit config) (startx %my-startx) (default-user "mcd"))))) (operating-system (host-name "komputilo") (timezone "Europe/Berlin") (locale "de_DE.UTF-8") (hosts-file (plain-file "hosts" "127.0.0.1 localhost komputilo ::1 localhost komputilo 192.168.178.20 pi.fritz.box pi")) ;; Assuming /dev/sdX is the target hard disk, and "my-root" is ;; the label of the target root file system. (bootloader (bootloader-configuration (bootloader (bootloader (inherit grub-bootloader) (installer #~(const #t)))))) ; (bootloader (bootloader-configuration (bootloader grub-bootloader) ; (target "/dev/sda3") ;(menu-entries '((menu-entry ; (label "Grub Nixos") ; (multiboot "(hd0)") ; still unsupported ; ))) ; )) (file-systems (cons (file-system (device (file-system-label "guix-root")) (mount-point "/") (type "ext4")) %base-file-systems)) ;; This is where user accounts are specified. The "root" ;; account is implicit, and is initially created with the ;; empty password. (users (cons (user-account (name "mcd") (comment "Martin Castillo") (group "users") ;; Adding the account to the "wheel" group ;; makes it a sudoer. Adding it to "audio" ;; and "video" allows the user to play sound ;; and access the webcam. (supplementary-groups '("wheel" ; "plugdev" ? für mtp? ist aber undefiniert "audio" "video" "netdev")) ;workmanager")) (home-directory "/home/mcd")) %base-user-accounts)) ;; Globally-installed packages. ;(packages (cons tcpdump %base-packages)) ;; Add a bunch of window managers; we can choose one at ;; the log-in screen with F1. (packages (cons* dmenu ;window managers nss-certs ;for HTTPS access kbd-neo %base-packages)) ;; Add services to the baseline: a DHCP client and ;; an SSH server. (services (cons* ;(dhcp-client-service) ; (gpm-service) ;mouse in vt (console-keymap-service (file-append kbd-neo "/share/keymaps/neo.map"));; (service openssh-service-type (openssh-configuration (x11-forwarding? #t) (accepted-environment '("COLORTERM" "Foo")) (port-number 22))) (simple-service 'store-my-config etc-service-type `(("config.scm" ,(local-file (assoc-ref (current-source-location) 'filename))))) (xfce-desktop-service) %my-services)) ;; Use the "desktop" services, which include the X11 ;; log-in service, networking with Wicd, and more. ;(services %desktop-services) ;; Allow resolution of '.local' host names with mDNS. (name-service-switch %mdns-host-lookup-nss))
[ 11.764507] shepherd[1]: Service root has been started.
[ 14.719803] shepherd[1]: starting services...
[ 14.722728] shepherd[1]: Service root-file-system has been started.
[ 14.725482] shepherd[1]: Service user-file-systems has been started.
[ 14.729274] shepherd[1]: Service file-system-/dev/pts has been started.
[ 14.732863] shepherd[1]: Service file-system-/dev/shm has been started.
[ 14.736110] shepherd[1]: Service file-system-/gnu/store has been started.
[ 14.750763] shepherd[1]: Service file-system-/run/systemd has been started.
[ 14.757029] shepherd[1]: Service file-system-/run/user has been started.
[ 14.760723] shepherd[1]: Service file-system-/sys/fs/cgroup has been started.
[ 14.765708] shepherd[1]: Service file-system-/sys/fs/cgroup/elogind has been started.
[ 14.776834] shepherd[1]: Service file-system-/sys/fs/cgroup/cpuset has been started.
[ 14.790800] shepherd[1]: Service file-system-/sys/fs/cgroup/cpu has been started.
[ 14.795139] shepherd[1]: Service file-system-/sys/fs/cgroup/cpuacct has been started.
[ 14.810192] shepherd[1]: Service file-system-/sys/fs/cgroup/memory has been started.
[ 14.814319] shepherd[1]: Service file-system-/sys/fs/cgroup/devices has been started.
[ 14.827923] shepherd[1]: Service file-system-/sys/fs/cgroup/freezer has been started.
[ 14.834046] shepherd[1]: Service file-system-/sys/fs/cgroup/blkio has been started.
[ 14.838283] shepherd[1]: Service file-system-/sys/fs/cgroup/perf_event has been started.
[ 14.841524] shepherd[1]: Service file-systems has been started.
[ 14.966786] shepherd[1]: waiting for udevd...
[ 15.627793] shepherd[1]: Service udev has been started.
[ 15.679916] shepherd[1]: Service urandom-seed has been started.
[ 15.684068] shepherd[1]: Service user-processes has been started.
[ 15.688369] shepherd[1]: Service host-name has been started.
[ 15.719811] shepherd[1]: Service user-homes could not be started.
[ 16.737051] shepherd[1]: Service nscd has been started.
[ 16.780356] shepherd[1]: Service guix-daemon has been started.
guix (GNU Guix) 264967c883d32606c18b378f717c303e7490c942
Copyright (C) 2018 the Guix authors
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
# runs qemu as mcd but with read and write access to sda

mount |egrep -q 'sd(a|b)3' && echo guix-root is maybe mounted. Aborting. && exit

set -v
sudo sh -c 'exec sudo -u mcd -C 6 sh -c "
exec qemu-system-x86_64 -m 1800 -smp 2 -enable-kvm \
-net nic,model=virtio \
-net user,hostfwd=tcp::5560-:2222,hostfwd=tcp::5559-:22 \
-add-fd fd=5,set=2,opaque=rdwr:$(readlink -f /dev/disk/by-id/ata-Hitachi_HDT721010SLA360_STF6L7MS20ALEK) \
-drive file=/dev/fdset/2,index=0,media=disk" \
5<>/dev/disk/by-id/ata-Hitachi_HDT721010SLA360_STF6L7MS20ALEK '
Attachment: signature.asc
L
L
Ludovic Courtès wrote on 28 Aug 2018 11:47
(name . Leo Famulari)(address . leo@famulari.name)(address . 30993@debbugs.gnu.org)
874lfen7q7.fsf@gnu.org
Hi Leo,

Leo Famulari <leo@famulari.name> skribis:

Toggle quote (8 lines)
> Since the update to Shepherd 0.4.0, I've found that OpenSSH's sshd is
> killed almost immediately after it starts with signal 15. I confirmed
> the issue started with the Shepherd upgrade by bisecting our Git
> history.
>
> I can reproduce the issue from commit
> b6beda1d6b9093a8493b5c3cde33ed522242c451 (gnu: Add botan.).

I’m “happy” to say that I experienced this on a server—not having ssh
access to a remote server is fairly annoying, I definitely sympathize…

What I see is this:

Toggle snippet (15 lines)
Aug 6 07:56:40 localhost shepherd[1]: Service loopback has been started.

[...]

Aug 6 07:56:51 localhost sshd[606]: Server listening on 0.0.0.0 port 22.

[...]

Aug 6 07:57:05 localhost shepherd[1]: Service ssh-daemon could not be started.

[...]

Aug 6 07:57:46 localhost vmunix: [ 10.049791] random: ssh-keygen: uninitialized urandom read (32 bytes read)

(Note that the last message was pulled from /dev/kmsg by syslogd, but
it’s about an event that actually occurred before the first message.)

It waited for ~15 seconds, although ‘%pid-file-timeout’ in (shepherd
service) is only 5 seconds.

The SIGTERM you were seeing very likely comes from this bit:

Toggle snippet (9 lines)
(match (read-pid-file pid-file
#:max-delay pid-file-timeout)
(#f
(catch-system-error (kill pid SIGTERM))
#f)
((? integer? pid)
pid))

On another machine:

Toggle snippet (8 lines)
Aug 28 09:10:49 localhost sshd[435]: Server listening on 0.0.0.0 port 22.
Aug 28 09:10:49 localhost sshd[435]: Server listening on :: port 22.

[...]

Aug 28 09:10:50 localhost shepherd[1]: Service ssh-daemon has been started.

I wonder if this has to do with IPv6 (the failing case lacks the “Server
listening on ::” line), or if it’s just sshd occasionally taking a long
time to start.

Is it easily reproducible for you? Did you eventually gather more
details?

Thanks,
Ludo’.
L
L
Ludovic Courtès wrote on 7 Nov 2018 22:34
control message for bug #30993
(address . control@debbugs.gnu.org)
87r2fwshbc.fsf@gnu.org
merge 30993 33299
L
L
Ludovic Courtès wrote on 7 Nov 2018 22:36
Re: bug#33299: shepherd: Service ssh-daemon could not be started.
(name . swedebugia)(address . swedebugia@riseup.net)
87muqksh7i.fsf@gnu.org
Hello,

swedebugia <swedebugia@riseup.net> skribis:

Toggle quote (5 lines)
> This morning I started my GuixSD VM as usual.
>
> Openssh server was not running even though it was enabled and should
> have been respawned. Hmm.

This seems to be the same issue as described in
https://issues.guix.info/issue/30993 (I’ve now merged both).

It’s a serious problem…

Thanks for reporting it,
Ludo’.
T
T
Taegil Bae wrote on 17 Nov 2018 10:46
issue: ssh-daemon could not be started
(address . 30993@debbugs.gnu.org)
CA+k_ch+bxxA5Gm1_ZThn117quO31MfsQxU=UACXjbZOoLUDvvg@mail.gmail.com
Hi,

I have experienced this issue on a slow machine (Thinkpad T60). By
placing avahi-daemon after ssh-daemon, I fixed this issue. I added
ssh-daemon into the requirement of avahi-shepherd-service, and
reconfigured the system.

On the machine, openssh and dropbear both had this issue. I checked
that this trick works for the two ssh server. On another machine(Qemu
VM, faster), openssh only had the trouble. Through several
reconfiguring the system, it was fixed with the original
configuration. I think that it was because the reconfigurations
reordered the services.

Taegil
L
L
Ludovic Courtès wrote on 19 Nov 2018 22:22
(name . Taegil Bae)(address . esrevinu@gmail.com)(address . 30993@debbugs.gnu.org)
87efbgvk3o.fsf@gnu.org
Hello,

Taegil Bae <esrevinu@gmail.com> skribis:

Toggle quote (5 lines)
> I have experienced this issue on a slow machine (Thinkpad T60). By
> placing avahi-daemon after ssh-daemon, I fixed this issue. I added
> ssh-daemon into the requirement of avahi-shepherd-service, and
> reconfigured the system.

This is very surprising. Are you sure this is fully reproducible?
How would you explain this?

Thank you,
Ludo’.
T
T
Taegil Bae wrote on 20 Nov 2018 02:33
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30993@debbugs.gnu.org)
abf5965c-8cf9-fade-5539-30e054fc6c3d@gmail.com
Hello,

On 11/20/18 6:22 AM, Ludovic Courtès wrote:
Toggle quote (9 lines)
> Taegil Bae <esrevinu@gmail.com> skribis:
>
>> I have experienced this issue on a slow machine (Thinkpad T60). By
>> placing avahi-daemon after ssh-daemon, I fixed this issue. I added
>> ssh-daemon into the requirement of avahi-shepherd-service, and
>> reconfigured the system.
> This is very surprising. Are you sure this is fully reproducible?
> How would you explain this?

At least in my machine it seems reproducible. I just reproduced that:
reconfigured the system without my modification of avahi-daemon, checked
ssh-daemon not started, reconfigured the system again with the
modification, and then checked ssh-daemon started.

I am not a professional. But I guess that avahi-daemon manipulates
network things such as the host name, and ssh-daemon waits for that to
be completed. Look at this failing case:

Nov 20 09:37:57 localhost avahi-daemon[344]: Found user 'avahi' (UID
985) and group 'avahi' (GID 973).
Nov 20 09:37:59 localhost avahi-daemon[344]: Successfully dropped root
privileges.
Nov 20 09:38:00 localhost avahi-daemon[344]: avahi-daemon 0.7 starting up.
Nov 20 09:38:18 localhost shepherd[1]: Service avahi-daemon has been
started.
Nov 20 09:38:01 localhost avahi-daemon[344]: WARNING: No NSS support for
mDNS detected, consider installing nss-mdns!
Nov 20 09:38:05 localhost avahi-daemon[344]: Successfully called chroot().
Nov 20 09:38:12 localhost avahi-daemon[344]: Successfully dropped
remaining capabilities.
Nov 20 09:38:32 localhost shepherd[1]: Service ssh-daemon could not be
started.
Nov 20 09:38:15 localhost avahi-daemon[344]: Loading service file
/services/sftp-ssh.service.
Nov 20 09:38:17 localhost avahi-daemon[344]: Loading service file
/services/ssh.service.
Nov 20 09:38:19 localhost avahi-daemon[344]: Network interface
enumeration completed.
Nov 20 09:38:22 localhost avahi-daemon[344]: Server startup complete.
Host name is gravity.local. Local service cookie is 4157419020.
Nov 20 09:38:29 localhost avahi-daemon[344]: Service "gravity"
(/services/ssh.service) successfully established.
Nov 20 09:38:32 localhost avahi-daemon[344]: Service "gravity"
(/services/sftp-ssh.service) successfully established.
Nov 20 09:38:36 localhost avahi-daemon[344]: write() failed while
writing return value to pipe: Broken pipe
Nov 20 09:39:12 localhost avahi-daemon[344]: Joining mDNS multicast
group on interface wls3.IPv6 with address fe80::4c7d:9233:7845:eb88.
Nov 20 09:39:12 localhost avahi-daemon[344]: New relevant interface
wls3.IPv6 for mDNS.
Nov 20 09:39:12 localhost avahi-daemon[344]: Registering new address
record for fe80::4c7d:9233:7845:eb88 on wls3.*.
Nov 20 09:39:12 localhost avahi-daemon[344]: Joining mDNS multicast
group on interface wls3.IPv4 with address 192.168.42.242.
Nov 20 09:39:12 localhost avahi-daemon[344]: New relevant interface
wls3.IPv4 for mDNS.
Nov 20 09:39:12 localhost avahi-daemon[344]: Registering new address
record for 192.168.42.242 on wls3.IPv4.

Regards,

Taegil
L
L
Ludovic Courtès wrote on 9 Mar 2019 19:35
control message for bug #30993
(address . control@debbugs.gnu.org)
87tvgb520i.fsf@gnu.org
merge 30993 34580
L
L
Ludovic Courtès wrote on 14 May 2019 15:33
Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
(name . Leo Famulari)(address . leo@famulari.name)(address . 30993@debbugs.gnu.org)
878sv9yxbs.fsf@gnu.org
Hi Leo,

Leo Famulari <leo@famulari.name> skribis:

Toggle quote (6 lines)
> One interesting tidbit is that the PID file '/var/run/sshd.pid' is not
> created anymore. And if I create an empty PID file by hand, it is
> removed after trying to start the ssh-daemon service. Also, the sshd
> user's home '/var/run/sshd' does not exist, and is similarly removed if
> it does exist.

There are reasons to believe that this issue is fixed by the Shepherd 0.6.1:


Could you check somehow if the bug shows up again?

Thanks,
Ludo’.
L
L
Leo Famulari wrote on 14 May 2019 20:21
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30993-done@debbugs.gnu.org)
20190514182106.GA1446@jasmine.lan
On Tue, May 14, 2019 at 03:33:59PM +0200, Ludovic Courtès wrote:
Toggle quote (6 lines)
> There are reasons to believe that this issue is fixed by the Shepherd 0.6.1:
>
> https://issues.guix.info/issue/35550
>
> Could you check somehow if the bug shows up again?

The bug disappeared for me a couple of reboots after reinstalling the
Guix System on my affected machine. That reinstallation provided
Shepherd 0.5, although 0.5 was also tested unsuccessfully before
reinstalling.

The issue does not manifest for me with Shepherd 0.6, 0.6.1 or Guix 1.0.

So... I think the bug was probably some kind of race condition or TOCTOU
problem that went away with a less fragmented or full filesystem (I was
really pushing the limits in that regard).

It's great that Shepherd 0.6.1 improved the PID file handling, assuming
that was the culprit.

I am closing this bug, but we can reopen it later if necessary.
-----BEGIN PGP SIGNATURE-----

iQIzBAABCAAdFiEEsFFZSPHn08G5gDigJkb6MLrKfwgFAlzbBw8ACgkQJkb6MLrK
fwh/ZA//fOH/6fpiWBWCtFFv8lUD0lOdJqnndPGaFfrYIihuW2XnHpLT8q/bKgv5
fJlUPkhzKWyWw3zOeXBagrUE9yG0mjWlez0lf+ygV1Bhk0BckbfQonKHW+B6LK3w
Pz3C/N6dLifofdmUpXD7JD4JiqoERtjf47LMImm3SF1b0VrcHjPVJVmVnb0GlJXA
kWJw84FW48cysxFhyHtuU54QNUdzfJKIvFA8YN/DizDJMcS/gGcftujNy7xNQW5e
RnAA2p0PiTpAFL7NWutoT4GRlhUttqVjgDEpiP8vSsVN56ttAnkGHj/91gDJ1HcR
NWl8HneDXeIuidw16JocYmCWxdPTuLBKAnfCz29Jzf3h192NQDsKU1BZHPSi1Q3w
84Clq/aHd0qXexb0nkB2IJSg5KHhPI0UMmteLMmSI8vk9680a8hcEpI6o7QQrpWB
TzU0JKmDXgk7EfpDSuR4zaAme8xEoR0+kEvUQvN29nTMK6Ix5BWSezxIumZZd4EG
8GAqktLwbnnRo3CqYMdNaLHFhu+FZ1tXs0Biqse0c8STkS2GmZ+3PrS/G0rdsw3y
HimdJgcLaXJlbIipf19h2jMfNIn6VTohoWkbyaGXIGvIF0w9KQUZvdRSviagQeEE
LilZATvUuhtZUBccYpAzH/cpzeAzNJivp52+xG3Y7qBULN1hMi4=
=2YjU
-----END PGP SIGNATURE-----


Closed
B
B
Brant Gardner wrote on 20 Sep 2019 18:19
Archived problem report bug#34580 (Service ssh-daemon could no t be started)
(address . control@debbugs.gnu.org)
1ee347ea-f340-4d61-8bfb-53a58139aa2d@www.fastmail.com
unarchive 34580

--
Brant Gardner
Attachment: file
L
L
Ludovic Courtès wrote on 26 Sep 2019 22:28
control message for bug #30993
(address . control@debbugs.gnu.org)
87r242ls3n.fsf@gnu.org
merge 30993 37309
quit
L
L
Ludovic Courtès wrote on 26 Sep 2019 22:29
(address . control@debbugs.gnu.org)
87pnjmls36.fsf@gnu.org
retitle 30993 'ssh-daemon' fails to start
quit
M
M
maxim.cournoyer wrote on 18 Aug 2020 06:08
(address . control@debbugs.gnu.org)
87wo1wppdk.fsf@hurd.i-did-not-set--mail-host-address--so-tickle-me
tags 30993 fixed
close 30993
quit
C
C
Christopher Lemmer Webber wrote on 27 Nov 2020 23:57
unarchive 37309
(address . control@debbugs.gnu.org)
87y2imjtm0.fsf@dustycloud.org
unarchive 37309
?
Your comment

This issue is archived.

To comment on this conversation send email to 30993@debbugs.gnu.org