On 21/08/2018, Axel Beckert <a...@debian.org> wrote: > Control: retitle -1 dphys-swapfile: "setup" subcommand failure under > systemd > Control: tag -1 + moreinfo > > Hi eHenry, > > eHenry Berg wrote: >> My 32-bit (armhf) worked with dphys-swapfile in version 20100506-3. >> My 64-bit (arm64) works with dphys-swapfile in version 20100506-3. >> >> Swap is not working after upgrde of my 32-bit (armhf) dphys-swapfile >> to version 20100506-4. > > Hrm, I assume that both systems are running systemd.
Yes! > > I've tested that package before uploading on Sid/arm64 with systemd, > Sid/armhf with sysvinit and Raspbian/stretch with systemd. So the > variant where you ran into issues wasn't in my test cases. But then > again, I suspect this is no general issue but related to the specific > environment. The main question is: What part of the environment did > trigger the issue and was it triggered erroneously. apt-get update // went normal 2018-08-15 18:27:40 apt-get dist-update // went normal 2018-08-15 18:59:34 change of kernel from 4.17.0-1-armmp to 4.17.0-2-armmp Reboot dphys-swapfile error, I became without swap, I recreated the swapfile but it did not help. No problem before with swap if you disregard that I have to create the swapfile with dd because of f2fs. # tail /var/log/apt/history.log Start-Date: 2018-08-12 07:31:47 Commandline: apt-get dist-upgrade Install: libio-stringy-perl:armhf (2.111-2, automatic) Upgrade: libfile-mimeinfo-perl:armhf (0.28-1, 0.29-1) End-Date: 2018-08-12 07:32:27 --> Here is the breakpoint: 2018-08-12 07:31:47 Ok, 2018-08-15 18:59:34 not Ok. Start-Date: 2018-08-15 18:27:40 Commandline: apt-get upgrade Upgrade: libpam0g:armhf (1.1.8-3.7, 1.1.8-3.8), fdisk:armhf (2.32-0.4, 2.32.1-0.1), libgcc-7-dev:armhf (7.3.0-27, 7.3.0-28), perl-base:armhf (5.26.2-6, 5.26.2-7), init:armhf (1.51, 1.52), init-system-helpers:armhf (1.51, 1.52), libdrm-freedreno1:armhf (2.4.92-1, 2.4.93-1), libgroupsock8:armhf (2018.07.07-1, 2018.08.05-1), libfdisk1:armhf (2.32-0.4, 2.32.1-0.1), libdrm-nouveau2:armhf (2.4.92-1, 2.4.93-1), linux-libc-dev:armhf (4.17.8-1, 4.17.14-1), dphys-swapfile:armhf (20100506-3, 20100506-4), libpam-modules:armhf (1.1.8-3.7, 1.1.8-3.8), tasksel-data:armhf (3.44, 3.45), libegl1-mesa-dev:armhf (18.1.5-1, 18.1.6-1), libssh-4:armhf (0.8.0-1, 0.8.1-1), libegl-mesa0:armhf (18.1.5-1, 18.1.6-1), libobjc4:armhf (8.2.0-3, 8.2.0-4), cpp-7:armhf (7.3.0-27, 7.3.0-28), cpp-8:armhf (8.2.0-3, 8.2.0-4), libglapi-mesa:armhf (18.1.5-1, 18.1.6-1), libmount1:armhf (2.32-0.4, 2.32.1-0.1), python-gi:armhf (3.28.2-1+b1, 3.28.3-1), gcc-8-base:armhf (8.2.0-3, 8.2.0-4), libdrm-exynos1:armhf (2.4.92-1, 2.4.93-1), libbz2-1.0:armhf (1.0.6-8.1, 1.0.6-9), binutils:armhf (2.31.1-2, 2.31.1-4), libarchive13:armhf (3.2.2-4.1, 3.2.2-4.2), perl-modules-5.26:armhf (5.26.2-6, 5.26.2-7), libgettextpo0:armhf (0.19.8.1-6+b1, 0.19.8.1-7), lmodern:armhf (2.004.5-3, 2.004.5-4), console-setup-linux:armhf (1.184, 1.185), util-linux:armhf (2.32-0.4, 2.32.1-0.1), gcc-7-base:armhf (7.3.0-27, 7.3.0-28), libharfbuzz-icu0:armhf (1.8.4-1, 1.8.7-1), libdrm-etnaviv1:armhf (2.4.92-1, 2.4.93-1), libcilkrts5:armhf (7.3.0-27, 7.3.0-28), console-setup:armhf (1.184, 1.185), libasan4:armhf (7.3.0-27, 7.3.0-28), libasan5:armhf (8.2.0-3, 8.2.0-4), libpam-runtime:armhf (1.1.8-3.7, 1.1.8-3.8), binutils-arm-linux-gnueabihf:armhf (2.31.1-2, 2.31.1-4), libisl19:armhf (0.20-1, 0.20-2), perl-doc:armhf (5.26.2-6, 5.26.2-7), libgbm1:armhf (18.1.5-1, 18.1.6-1), libgcc1:armhf (1:8.2.0-3, 1:8.2.0-4), python3-twisted:armhf (18.4.0-2, 18.7.0-2), mount:armhf (2.32-0.4, 2.32.1-0.1), libperl5.26:armhf (5.26.2-6, 5.26.2-7), libdrm-amdgpu1:armhf (2.4.92-1, 2.4.93-1), libgcc-8-dev:armhf (8.2.0-3, 8.2.0-4), python3-twisted-bin:armhf (18.4.0-2, 18.7.0-2), libblkid1:armhf (2.32-0.4, 2.32.1-0.1), libdrm-tegra0:armhf (2.4.92-1, 2.4.93-1), libubsan0:armhf (7.3.0-27, 7.3.0-28), libubsan1:armhf (8.2.0-3, 8.2.0-4), g++-8:armhf (8.2.0-3, 8.2.0-4), libdrm-omap1:armhf (2.4.92-1, 2.4.93-1), libuuid1:armhf (2.32-0.4, 2.32.1-0.1), gcc-7:armhf (7.3.0-27, 7.3.0-28), gcc-8:armhf (8.2.0-3, 8.2.0-4), libbasicusageenvironment1:armhf (2018.07.07-1, 2018.08.05-1), libgles2-mesa-dev:armhf (18.1.5-1, 18.1.6-1), libprotobuf-c1:armhf (1.2.1-2, 1.3.1-1), libdrm2:armhf (2.4.92-1, 2.4.93-1), libgomp1:armhf (8.2.0-3, 8.2.0-4), libsmartcols1:armhf (2.32-0.4, 2.32.1-0.1), libssh-gcrypt-4:armhf (0.8.0-1, 0.8.1-1), libpam-modules-bin:armhf (1.1.8-3.7, 1.1.8-3.8), libgl1-mesa-dri:armhf (18.1.5-1, 18.1.6-1), bzip2:armhf (1.0.6-8.1, 1.0.6-9), keyboard-configuration:armhf (1.184, 1.185), bsdutils:armhf (1:2.32-0.4, 1:2.32.1-0.1), binutils-common:armhf (2.31.1-2, 2.31.1-4), libgl1-mesa-glx:armhf (18.1.5-1, 18.1.6-1), tasksel:armhf (3.44, 3.45), findutils:armhf (4.6.0+git+20171230-2, 4.6.0+git+20180808-2), python3-gi:armhf (3.28.2-1+b1, 3.28.3-1), fonts-lmodern:armhf (2.004.5-3, 2.004.5-4), libbinutils:armhf (2.31.1-2, 2.31.1-4), perl:armhf (5.26.2-6, 5.26.2-7), liblivemedia62:armhf (2018.07.07-1, 2018.08.05-1), libp11-kit0:armhf (0.23.12-2, 0.23.13-2), libdrm-radeon1:armhf (2.4.92-1, 2.4.93-1), mesa-vdpau-drivers:armhf (18.1.5-1, 18.1.6-1), libatomic1:armhf (8.2.0-3, 8.2.0-4), libharfbuzz0b:armhf (1.8.4-1, 1.8.7-1), libcc1-0:armhf (8.2.0-3, 8.2.0-4), gettext-base:armhf (0.19.8.1-6+b1, 0.19.8.1-7), gettext:armhf (0.19.8.1-6+b1, 0.19.8.1-7), libstdc++6:armhf (8.2.0-3, 8.2.0-4), libdrm-dev:armhf (2.4.92-1, 2.4.93-1), libstdc++-8-dev:armhf (8.2.0-3, 8.2.0-4), libusageenvironment3:armhf (2018.07.07-1, 2018.08.05-1), mesa-va-drivers:armhf (18.1.5-1, 18.1.6-1), libglx-mesa0:armhf (18.1.5-1, 18.1.6-1), libdrm-common:armhf (2.4.92-1, 2.4.93-1) End-Date: 2018-08-15 18:56:07 Start-Date: 2018-08-15 18:59:34 Commandline: apt-get dist-upgrade Install: libgles1:armhf (1.1.0-1, automatic), linux-image-4.17.0-2-armmp:armhf (4.17.14-1, automatic) Upgrade: libegl1:armhf (1.0.0+git20180308-4, 1.1.0-1), libgl1:armhf (1.0.0+git20180308-4, 1.1.0-1), libopengl0:armhf (1.0.0+git20180308-4, 1.1.0-1), libgles2:armhf (1.0.0+git20180308-4, 1.1.0-1), linux-image-armmp:armhf (4.17+95, 4.17+96), libglvnd-dev:armhf (1.0.0+git20180308-4, 1.1.0-1), libglx0:armhf (1.0.0+git20180308-4, 1.1.0-1), libglvnd-core-dev:armhf (1.0.0+git20180308-4, 1.1.0-1), libglvnd0:armhf (1.0.0+git20180308-4, 1.1.0-1) End-Date: 2018-08-15 19:03:53 > >> Warning: Journal has been rotated since unit was started. Log output >> is incomplete or unavailable. > > Any chance that you can reproduce this case and check journalctl > before the log is rotated away? (Or can you dig up the rotated away > log or look up what happened in /var/log/syslog?) # less /var/log/syslog Aug 19 15:24:36 irena systemd[1]: Starting lircd(8) initialization helper tool... Aug 19 15:24:36 irena kernel: [ 10.654078] usb 1-1.2.1: New USB device found, idVendor=413c, idProduct=2107, bcdDevice= 1.15 Aug 19 15:24:36 irena kernel: [ 10.663345] usb 1-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Aug 19 15:24:36 irena kernel: [ 10.671214] usb 1-1.2.1: Product: Dell USB Entry Keyboard Aug 19 15:24:36 irena kernel: [ 10.679540] usb 1-1.2.1: Manufacturer: Dell Aug 19 15:24:36 irena kernel: [ 10.845770] usb 1-1.2.2: new low-speed USB device number 6 using dwc2 Aug 19 15:24:36 irena systemd[1]: Started Regular background program processing daemon. Aug 19 15:24:36 irena kernel: [ 10.958491] usb 1-1.2.2: New USB device found, idVendor=413c, idProduct=3012, bcdDevice=43.01 Aug 19 15:24:36 irena kernel: [ 10.966377] usb 1-1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Aug 19 15:24:36 irena kernel: [ 10.974243] usb 1-1.2.2: Product: Dell USB Optical Mouse Aug 19 15:24:36 irena kernel: [ 10.979844] random: crng init done Aug 19 15:24:36 irena kernel: [ 10.982014] usb 1-1.2.2: Manufacturer: Dell Aug 19 15:24:36 irena kernel: [ 11.077753] usb 1-1.2.3: new high-speed USB device number 7 using dwc2 Aug 19 15:24:36 irena systemd[1]: Starting Modem Manager... Aug 19 15:24:36 irena kernel: [ 11.191304] usb 1-1.2.3: New USB device found, idVendor=05dc, idProduct=a838, bcdDevice=11.00 Aug 19 15:24:36 irena kernel: [ 11.199493] usb 1-1.2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 19 15:24:36 irena systemd[1]: Starting Login Service... Aug 19 15:24:36 irena kernel: [ 11.207450] usb 1-1.2.3: Product: USB Flash Drive Aug 19 15:24:36 irena kernel: [ 11.215319] usb 1-1.2.3: Manufacturer: Lexar Aug 19 15:24:36 irena kernel: [ 11.223196] usb 1-1.2.3: SerialNumber: AA1A6T9ON1E4YA87 Aug 19 15:24:36 irena kernel: [ 12.177006] vc4_hdmi 3f902000.hdmi: ASoC: Failed to create component debugfs directory Aug 19 15:24:36 irena cron[387]: (CRON) INFO (pidfile fd = 3) Aug 19 15:24:36 irena kernel: [ 12.182383] vc4_hdmi 3f902000.hdmi: vc4-hdmi-hifi <-> 3f902000.hdmi mapping ok Aug 19 15:24:36 irena kernel: [ 12.197960] vc4_hdmi 3f902000.hdmi: ASoC: no DMI vendor name! Aug 19 15:24:36 irena systemd[1]: Started D-Bus System Message Bus. Aug 19 15:24:36 irena cron[387]: (CRON) INFO (Running @reboot jobs) Aug 19 15:24:36 irena systemd[1]: Starting Disk Manager... Aug 19 15:24:36 irena systemd[1]: Started CUPS Scheduler. Aug 19 15:24:36 irena systemd[1]: Started irqbalance daemon. Aug 19 15:24:36 irena systemd[1]: Started Forward LIRC button presses as uinput events. Aug 19 15:24:36 irena systemd[1]: Starting Avahi mDNS/DNS-SD Stack... Aug 19 15:24:36 irena systemd[1]: Starting Network Manager... Aug 19 15:24:36 irena systemd[1]: Starting System Logging Service... Aug 19 15:24:36 irena systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Aug 19 15:24:36 irena kernel: [ 12.199473] vc4-drm soc:gpu: bound 3f902000.hdmi (ops vc4_hdmi_ops [vc4]) Aug 19 15:24:36 irena systemd[1]: Starting Restore /etc/resolv.conf if the system crashed before the ppp link was shut down... Aug 19 15:24:36 irena kernel: [ 12.214313] vc4-drm soc:gpu: bound 3f806000.vec (ops vc4_vec_ops [vc4]) Aug 19 15:24:36 irena kernel: [ 12.222513] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4]) Aug 19 15:24:36 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 19 15:24:36 irena kernel: [ 12.223132] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4]) Aug 19 15:24:36 irena kernel: [ 12.238637] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4]) Aug 19 15:24:36 irena kernel: [ 12.239011] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4]) Aug 19 15:24:36 irena kernel: [ 12.281743] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4]) Aug 19 15:24:36 irena kernel: [ 12.281797] checking generic (3e887000 373800) vs hw (0 ffffffff) Aug 19 15:24:36 irena systemd[1]: Starting WPA supplicant... Aug 19 15:24:36 irena kernel: [ 12.281803] fb: switching to vc4drmfb from simple Aug 19 15:24:36 irena kernel: [ 12.305001] Console: switching to colour dummy device 80x30 Aug 19 15:24:36 irena kernel: [ 12.308006] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0 Aug 19 15:24:36 irena systemd[1]: Started Raise network interfaces. Aug 19 15:24:36 irena kernel: [ 12.308065] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013). Aug 19 15:24:36 irena kernel: [ 12.308091] [drm] Driver supports precise vblank timestamp query. Aug 19 15:24:36 irena kernel: [ 12.383078] Console: switching to colour frame buffer device 240x67 Aug 19 15:24:36 irena systemd[1]: Started Save/Restore Sound Card State. Aug 19 15:24:36 irena kernel: [ 12.459502] vc4-drm soc:gpu: fb0: frame buffer device Aug 19 15:24:36 irena kernel: [ 13.949916] bcm2835-rng 3f104000.rng: hwrng registered Aug 19 15:24:36 irena kernel: [ 13.957903] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer Aug 19 15:24:36 irena kernel: [ 14.905892] hidraw: raw HID events driver (C) Jiri Kosina Aug 19 15:24:36 irena systemd[1]: Started Restore /etc/resolv.conf if the system crashed before the ppp link was shut down. Aug 19 15:24:36 irena kernel: [ 14.940200] SCSI subsystem initialized Aug 19 15:24:36 irena kernel: [ 14.968411] usb-storage 1-1.2.3:1.0: USB Mass Storage device detected Aug 19 15:24:36 irena kernel: [ 14.985971] scsi host0: usb-storage 1-1.2.3:1.0 Aug 19 15:24:36 irena kernel: [ 14.987694] usbcore: registered new interface driver usb-storage Aug 19 15:24:36 irena systemd[1]: Reached target Sound Card. Aug 19 15:24:36 irena kernel: [ 15.008492] usbcore: registered new interface driver uas Aug 19 15:24:36 irena kernel: [ 15.011044] smsc95xx: unknown parameter 'macaddr' ignored Aug 19 15:24:36 irena kernel: [ 15.012026] smsc95xx v1.0.6 Aug 19 15:24:36 irena kernel: [ 15.062324] usbcore: registered new interface driver usbhid Aug 19 15:24:36 irena kernel: [ 15.062334] usbhid: USB HID core driver Aug 19 15:24:36 irena irexec[401]: do_connect: could not connect to socket Aug 19 15:24:36 irena kernel: [ 15.088601] input: Dell Dell USB Entry Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.1/1-1.2.1:1.0/0003:413C:2107.0001/input/input0 Aug 19 15:24:36 irena kernel: [ 15.107352] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:2d:26:98 Aug 19 15:24:36 irena kernel: [ 15.108292] usbcore: registered new interface driver smsc95xx Aug 19 15:24:36 irena kernel: [ 15.153369] smsc95xx 1-1.1:1.0 enxb827eb2d2698: renamed from eth0 Aug 19 15:24:36 irena kernel: [ 15.155668] hid-generic 0003:413C:2107.0001: input,hidraw0: USB HID v1.10 Keyboard [Dell Dell USB Entry Keyboard] on usb-3f980000.usb-1.2.1/input0 Aug 19 15:24:36 irena kernel: [ 15.172480] input: Dell Dell USB Optical Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.2/1-1.2.2:1.0/0003:413C:3012.0002/input/input1 Aug 19 15:24:36 irena kernel: [ 15.186260] hid-generic 0003:413C:3012.0002: input,hidraw1: USB HID v1.11 Mouse [Dell Dell USB Optical Mouse] on usb-3f980000.usb-1.2.2/input0 Aug 19 15:24:36 irena irexec[401]: connect: No such file or directory Aug 19 15:24:36 irena kernel: [ 15.424694] EXT4-fs (mmcblk0p2): mounting ext2 file system using the ext4 subsystem Aug 19 15:24:36 irena kernel: [ 15.449652] EXT4-fs (mmcblk0p2): warning: mounting unchecked fs, running e2fsck is recommended Aug 19 15:24:36 irena kernel: [ 15.680615] EXT4-fs (mmcblk0p2): mounted filesystem without journal. Opts: (null) Aug 19 15:24:36 irena kernel: [ 16.283959] scsi 0:0:0:0: Direct-Access Lexar USB Flash Drive 1100 PQ: 0 ANSI: 6 Aug 19 15:24:36 irena ModemManager[390]: <info> ModemManager (version 1.7.990) starting in system bus... Aug 19 15:24:36 irena kernel: [ 16.373784] scsi 0:0:0:0: Attached scsi generic sg0 type 0 Aug 19 15:24:36 irena kernel: [ 16.407141] sd 0:0:0:0: [sda] 250068992 512-byte logical blocks: (128 GB/119 GiB) Aug 19 15:24:36 irena kernel: [ 16.424834] sd 0:0:0:0: [sda] Write Protect is off Aug 19 15:24:36 irena kernel: [ 16.437938] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 Aug 19 15:24:36 irena lircd-0.10.0[397]: Info: lircd-uinput: Opening log, level: Info Aug 19 15:24:36 irena lircd-uinput[397]: lircd-0.10.0[397]: Info: lircd-uinput: Opening log, level: Info Aug 19 15:24:36 irena kernel: [ 16.438999] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Aug 19 15:24:36 irena kernel: [ 16.461741] sda: sda1 Aug 19 15:24:36 irena kernel: [ 16.482101] sd 0:0:0:0: [sda] Attached SCSI removable disk Aug 19 15:24:36 irena lircd-uinput[397]: lircd-0.10.0[397]: Info: Reading data from /var/run/lirc/lircd, writing to /dev/uinput Aug 19 15:24:36 irena kernel: [ 17.435604] F2FS-fs (sda1): Mounted with checkpoint version = 1db2 Aug 19 15:24:36 irena kernel: [ 17.926254] audit: type=1400 audit(1534692274.691:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=355 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 17.943745] audit: type=1400 audit(1534692274.691:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/ntpd" pid=354 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 17.959414] audit: type=1400 audit(1534692274.691:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=356 comm="apparmor_parser" Aug 19 15:24:36 irena lircd-uinput[397]: lircd-0.10.0[397]: Cannot stat socket path /var/run/lirc/lircd: No such file or directory Aug 19 15:24:36 irena kernel: [ 17.973725] audit: type=1400 audit(1534692274.691:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=356 comm="apparmor_parser" Aug 19 15:24:36 irena lircd-uinput[397]: lircd-0.10.0[397]: Error: Cannot setup input file descriptor. Aug 19 15:24:36 irena kernel: [ 17.987458] audit: type=1400 audit(1534692274.691:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=356 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 18.001147] audit: type=1400 audit(1534692274.707:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/haveged" pid=357 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 18.015158] audit: type=1400 audit(1534692274.723:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/cups/backend/cups-pdf" pid=353 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 18.029578] audit: type=1400 audit(1534692274.723:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cupsd" pid=353 comm="apparmor_parser" Aug 19 15:24:36 irena kernel: [ 18.044342] audit: type=1400 audit(1534692274.723:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cupsd//third_party" pid=353 comm="apparmor_parser" Aug 19 15:24:36 irena lircd-0.10.0[397]: Info: Reading data from /var/run/lirc/lircd, writing to /dev/uinput Aug 19 15:24:36 irena lircd-0.10.0[397]: Cannot stat socket path /var/run/lirc/lircd: No such file or directory Aug 19 15:24:36 irena lircd-0.10.0[397]: Error: Cannot setup input file descriptor. Aug 19 15:24:36 irena avahi-daemon[398]: Found user 'avahi' (UID 113) and group 'avahi' (GID 121). Aug 19 15:24:36 irena avahi-daemon[398]: Successfully dropped root privileges. Aug 19 15:24:36 irena avahi-daemon[398]: avahi-daemon 0.7 starting up. Aug 19 15:24:36 irena udisksd[394]: udisks daemon version 2.7.6 starting Aug 19 15:24:36 irena rsyslogd: environment variable TZ is not set, auto correcting this to TZ=/etc/localtime [v8.37.0 try http://www.rsyslog.com/e/2442 ] Aug 19 15:24:36 irena rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.37.0] Aug 19 15:24:36 irena rsyslogd: [origin software="rsyslogd" swVersion="8.37.0" x-pid="400" x-info="http://www.rsyslog.com";] start Aug 19 15:24:36 irena dphys-swapfile[403]: want /var/swap=1024MByte Aug 19 15:24:36 irena systemd[1]: Started System Logging Service. Aug 19 15:24:36 irena systemd[1]: lircd-uinput.service: Main process exited, code=exited, status=1/FAILURE Aug 19 15:24:36 irena avahi-daemon[398]: Successfully called chroot(). Aug 19 15:24:36 irena avahi-daemon[398]: Successfully dropped remaining capabilities. Aug 19 15:24:36 irena systemd[1]: lircd-uinput.service: Failed with result 'exit-code'. Aug 19 15:24:36 irena systemd[1]: irexec.service: Main process exited, code=exited, status=1/FAILURE Aug 19 15:24:36 irena systemd[1]: irexec.service: Failed with result 'exit-code'. Aug 19 15:24:36 irena systemd[1]: dphys-swapfile.service: Main process exited, code=exited, status=1/FAILURE Aug 19 15:24:36 irena systemd[1]: dphys-swapfile.service: Failed with result 'exit-code'. Aug 19 15:24:36 irena systemd[1]: Failed to start dphys-swapfile - set up, mount/unmount, and delete a swap file. Aug 19 15:24:36 irena avahi-daemon[398]: No service file found in /etc/avahi/services. Aug 19 15:24:36 irena avahi-daemon[398]: Network interface enumeration completed. Aug 19 15:24:36 irena avahi-daemon[398]: Server startup complete. Host name is irena.local. Local service cookie is 1280021019. Aug 19 15:24:36 irena dbus-daemon[393]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.4' (uid=0 pid=390 comm="/usr/sbin/ModemManager --filter-policy=strict ") Aug 19 15:24:36 irena systemd[1]: Started Login Service. Aug 19 15:24:36 irena systemd[1]: Started Avahi mDNS/DNS-SD Stack. Aug 19 15:24:36 irena systemd[1]: Starting Authorization Manager... Aug 19 15:24:36 irena systemd[1]: Started Make remote CUPS printers available locally. Aug 19 15:24:36 irena systemd[1]: Started WPA supplicant. Aug 19 15:24:36 irena wpa_supplicant[404]: Successfully initialized wpa_supplicant Aug 19 15:24:37 irena polkitd[434]: started daemon version 0.105 using authority implementation `local' version `0.105' Aug 19 15:24:37 irena dbus-daemon[393]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Aug 19 15:24:37 irena systemd[1]: Started Authorization Manager. Aug 19 15:24:37 irena accounts-daemon[383]: started daemon version 0.6.45 Aug 19 15:24:37 irena systemd[1]: Started Accounts Service. Aug 19 15:24:37 irena udisksd[394]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory Aug 19 15:24:37 irena NetworkManager[399]: <info> [1534692277.5396] NetworkManager (version 1.12.2) is starting... (for the first time) Aug 19 15:24:37 irena NetworkManager[399]: <info> [1534692277.5406] Read config: /etc/NetworkManager/NetworkManager.conf (lib: no-mac-addr-change.conf) Aug 19 15:24:37 irena timidity[384]: Starting TiMidity++ ALSA midi emulation: timidity. Aug 19 15:24:37 irena systemd[1]: Started LSB: start and stop timidity. Aug 19 15:24:37 irena NetworkManager[399]: <info> [1534692277.6518] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager" Aug 19 15:24:37 irena systemd[1]: Started Network Manager. Aug 19 15:24:37 irena udisksd[394]: Failed to load the 'mdraid' libblockdev plugin Aug 19 15:24:37 irena NetworkManager[399]: <info> [1534692277.6929] manager[0x1e44000]: monitoring kernel firmware directory '/lib/firmware'. > >> Process: 403 ExecStart=/sbin/dphys-swapfile setup (code=exited, >> status=1/FAILURE) >> Main PID: 403 (code=exited, status=1/FAILURE) > > I can imagine that this happens (correctly) under the following > circumstances: > > * A different size of the swapfile is requested and the system is > swapping enough so that "swapoff" fails. Since "setup" calls > "swapoff" first, if "swapoff" fails, "setup" will fail accordingly. > > * There's not enough diskspace anymore to create the swapfile. (But > this case should actually be fixed 20100506-4.) > > Was any of this the case on your system when the error happened? No. Different size: I have to create the swapfile with dd at the initial installation otherwise I get holes. After the first installation I have not touched swap. Test1b: (calls "swapoff" first, does it work?): # nano -w /lib/systemd/system/dphys-swapfile.service ExecStart=/sbin/dphys-swapfile swapoff // New ExecStart=/sbin/dphys-swapfile setup ExecStart=/sbin/dphys-swapfile swapon Reboot Result: # cat /proc/swaps Filename Type Size Used Priority # # systemctl status dphys-swapfile.service ��� dphys-swapfile.service - dphys-swapfile - set up, mount/unmount, and delete a swap file Loaded: loaded (/lib/systemd/system/dphys-swapfile.service; enabled; vendor preset: enabled) Active: failed (Result: exit-code) since Tue 2018-08-21 17:06:38 UTC; 6min ago Docs: man:dphys-swapfile(8) Process: 416 ExecStart=/sbin/dphys-swapfile setup (code=exited, status=1/FAILURE) Process: 389 ExecStart=/sbin/dphys-swapfile swapoff (code=exited, status=0/SUCCESS) Main PID: 416 (code=exited, status=1/FAILURE) Aug 21 17:06:37 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 21 17:06:38 irena dphys-swapfile[416]: want /var/swap=1024MByte Aug 21 17:06:38 irena systemd[1]: dphys-swapfile.service: Main process exited, code=exited, status=1/FAILURE Aug 21 17:06:38 irena systemd[1]: dphys-swapfile.service: Failed with result 'exit-code'. Aug 21 17:06:38 irena systemd[1]: Failed to start dphys-swapfile - set up, mount/unmount, and delete a swap file. # Test1c: (what happen without setup): # nano -w /lib/systemd/system/dphys-swapfile.service ExecStart=/sbin/dphys-swapfile swapon // Only row of ExecStart ("ExecStart=/sbin/dphys-swapfile setup" erased) Reboot Result: # cat /proc/swaps Filename Type Size Used Priority /var/swap file 1048572 4352 -2 # # journalctl|grep -i swap Jun 22 11:11:50 irena kernel: Kernel command line: bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 dma.dmachans=0x7f35 bcm2709.boardrev=0xa01041 bcm2709.serial=0xfc2d2698 bcm2709.uart_clock=48000000 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 smsc95xx.macaddr=B8:27:EB:2D:26:98 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=tty0 console=${serial} root=/dev/mmcblk0p3 rootfstype=f2fs elevator=deadline fsck.repair=yes rootwait cma=416M Aug 21 17:24:19 irena kernel: zswap: loaded using pool lzo/zbud Aug 21 17:24:26 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 21 17:24:30 irena kernel: Adding 1048572k swap on /var/swap. Priority:-2 extents:3 across:50157532k SSFS Aug 21 17:24:30 irena systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file. # # systemctl status dphys-swapfile.service ��� dphys-swapfile.service - dphys-swapfile - set up, mount/unmount, and delete a swap file Loaded: loaded (/lib/systemd/system/dphys-swapfile.service; enabled; vendor preset: enabled) Active: active (exited) since Tue 2018-08-21 17:24:30 UTC; 10min ago Docs: man:dphys-swapfile(8) Process: 404 ExecStart=/sbin/dphys-swapfile swapon (code=exited, status=0/SUCCESS) Main PID: 404 (code=exited, status=0/SUCCESS) Aug 21 17:24:26 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 21 17:24:30 irena systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file. # How can it work without setup!!!??? Enough diskspace: My 32-bit system card is from year 2016: Kingston 64GB microSDXC UHS-I speed class 3 (U3) 90R/80W I have only the system on this card. (My data is on a Usb memory.) I do not know if "Trim and Checkpoint of Nand" have any implications. I have have 1GB memory and 1GB swap file on F2FS partition, which is needed for KDE on Raspberry 2 och 3. I use default swappiness. I trust F2FS to take care that swap is using all of my free space on the sd card i.e. for a longer life of sd card. No problem at all so far with the combination "F2FS + sd card". # df -h Filesystem Size Used Avail Use% Mounted on udev 245M 0 245M 0% /dev tmpfs 93M 4.2M 89M 5% /run /dev/mmcblk0p3 58G 13G 45G 23% / tmpfs 463M 18M 445M 4% /dev/shm tmpfs 5.0M 4.0K 5.0M 1% /run/lock tmpfs 463M 0 463M 0% /sys/fs/cgroup /dev/mmcblk0p2 248M 100M 136M 43% /boot /dev/sda1 120G 31G 90G 26% /evsj tmpfs 93M 12K 93M 1% /run/user/1000 # > >> Test2: >> # systemctl start dphys-swapfile.service >> Job for dphys-swapfile.service failed because the control process >> exited with error code. >> See "systemctl status dphys-swapfile.service" and "journalctl -xe" for >> details. >> # systemctl status dphys-swapfile.service // Same error message as >> above >> # cat /proc/swaps >> Filename Type Size Used >> Priority >> # >> Swap is not working! // I tried also to erase row >> "ExecStart=/sbin/dphys-swapfile swapon" in dphys-swapfile.service, but >> same error message as above. > > Can you post the "journalctl -xe" output from this test. That might > contain a hint to the real cause. Restart # cat /proc/swaps Filename Type Size Used Priority # # journalctl|grep -i swap Aug 21 17:46:22 irena kernel: Kernel command line: bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 dma.dmachans=0x7f35 bcm2709.boardrev=0xa01041 bcm2709.serial=0xfc2d2698 bcm2709.uart_clock=48000000 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 smsc95xx.macaddr=B8:27:EB:2D:26:98 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=tty0 console=${serial} root=/dev/mmcblk0p3 rootfstype=f2fs elevator=deadline fsck.repair=yes rootwait cma=416M Aug 21 17:46:22 irena kernel: zswap: loaded using pool lzo/zbud Aug 21 17:46:28 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 21 17:46:29 irena dphys-swapfile[388]: want /var/swap=1024MByte Aug 21 17:46:29 irena systemd[1]: dphys-swapfile.service: Main process exited, code=exited, status=1/FAILURE Aug 21 17:46:29 irena systemd[1]: dphys-swapfile.service: Failed with result 'exit-code'. Aug 21 17:46:29 irena systemd[1]: Failed to start dphys-swapfile - set up, mount/unmount, and delete a swap file. # # systemctl start dphys-swapfile.service # journalctl -xef Aug 21 17:57:24 irena kernel: alloc_contig_range: [20300, 21300) PFNs busy Aug 21 17:57:24 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... -- Subject: Unit dphys-swapfile.service has begun start-up -- Defined-By: systemd -- Support: https://www.debian.org/support -- -- Unit dphys-swapfile.service has begun starting up. Aug 21 17:57:24 irena dphys-swapfile[1039]: want /var/swap=1024MByte Aug 21 17:57:24 irena systemd[1]: dphys-swapfile.service: Main process exited, code=exited, status=1/FAILURE Aug 21 17:57:24 irena systemd[1]: dphys-swapfile.service: Failed with result 'exit-code'. Aug 21 17:57:24 irena systemd[1]: Failed to start dphys-swapfile - set up, mount/unmount, and delete a swap file. -- Subject: Unit dphys-swapfile.service has failed -- Defined-By: systemd -- Support: https://www.debian.org/support -- -- Unit dphys-swapfile.service has failed. -- -- The result is RESULT. ^C > >> Test3: >> # /sbin/dphys-swapfile setup >> want /var/swap=1024MByte >> # /sbin/dphys-swapfile swapon >> # cat /proc/swaps >> Filename Type Size Used >> Priority >> /var/swap file 1048572 256 >> -2 >> # >> Swap works! // Swap works even without command "/sbin/dphys-swapfile >> setup" > > Interesting. Any idea how long "/sbin/dphys-swapfile setup" ran? > According to systemd.service(5), "when Type=oneshot is used, […] the > timeout is disabled by default", so it shouldn't be any timeout issue. > But maybe I've missed another type of timeout. # cat /proc/swaps Filename Type Size Used Priority # root@irena:/home/evald# /sbin/dphys-swapfile setup want /var/swap=1024MByteroot@irena:/home/evald# // maybe 1/10 of a second or max 1 second // I can enter the command several times with the same reply "want /var/swap=1024MByte" # cat /proc/swaps Filename Type Size Used Priority # # /sbin/dphys-swapfile swapon // At least a few seconds # cat /proc/swaps Filename Type Size Used Priority /var/swap file 1048572 0 -2 # Test3b: Restart # cat /proc/swaps Filename Type Size Used Priority # # journalctl|grep -i swap Aug 21 18:23:33 irena kernel: Kernel command line: bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 dma.dmachans=0x7f35 bcm2709.boardrev=0xa01041 bcm2709.serial=0xfc2d2698 bcm2709.uart_clock=48000000 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 smsc95xx.macaddr=B8:27:EB:2D:26:98 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=tty0 console=${serial} root=/dev/mmcblk0p3 rootfstype=f2fs elevator=deadline fsck.repair=yes rootwait cma=416M Aug 21 18:23:33 irena kernel: zswap: loaded using pool lzo/zbud Aug 21 18:23:39 irena systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file... Aug 21 18:23:39 irena dphys-swapfile[385]: want /var/swap=1024MByte Aug 21 18:23:40 irena systemd[1]: dphys-swapfile.service: Main process exited, code=exited, status=1/FAILURE Aug 21 18:23:40 irena systemd[1]: dphys-swapfile.service: Failed with result 'exit-code'. Aug 21 18:23:40 irena systemd[1]: Failed to start dphys-swapfile - set up, mount/unmount, and delete a swap file. # # /sbin/dphys-swapfile swapon # cat /proc/swaps Filename Type Size Used Priority /var/swap file 1048572 0 -2 # Swap works even without command "/sbin/dphys-swapfile setup" i.e. it works with only "/sbin/dphys-swapfile swapon", how can it work with only swapon!!!??? > >> Test4: >> Solution: >> # nano -w /lib/systemd/system/dphys-swapfile.service >> ExecStart=-/sbin/dphys-swapfile setup // Old: >> ExecStart=/sbin/dphys-swapfile setup >> Restart computer! >> Swap works! > > I wouldn't call this a solution since it just ignores the exit code > which likely means that an error happened and should be fixed. Yes, you are right. > > Other questions: > > * Did this happen directly after the initial installation or after an > upgrade? See specification above "tail /var/log/apt/history.log" > > * Did you change the wanted size of the swapfile recently, i.e. since > the last reboot but before the (suspected) upgrade? No. I recreated the swapfile after I got error and was without swap. > > * Can you reproduce this issue if you do a fresh installation? I have 2 environments, the 32-bit and 64-bit. I can do a totally new installation of my 32-bit, but it will take some time. I should like to take this as the last test option. When we run out of option with 32-bit environment, we can test 64-bit environment. If we upgrade 64-bit we cannot compare how it was before. However, we have an analogy now between SystemD "Test1c" and CLI (command line interface) "Test3b". How can it work without "/sbin/dphys-swapfile setup" in both Test1c and Test3b? I made "journalctl|grep -i swap" on a few places if it help. Should I test with kernel 4.17.0-1-armmp which I had when it was working? Has ZSWAP anthing to do with it, but it should be same as before. Has filesystem F2FS any part, but it is same as before. Do you want to me to test anything in my 64-bit environment for comparement? The 64-bit is working and is not updated (history.log last upgraded 2018-04-13 18:16:47). > > Regards, Axel > -- > ,''`. | Axel Beckert <a...@debian.org>, https://people.debian.org/~abe/ > : :' : | Debian Developer, ftp.ch.debian.org Admin > `. `' | 4096R: 2517 B724 C5F6 CA99 5329 6E61 2FF9 CD59 6126 16B5 > `- | 1024D: F067 EA27 26B9 C3FC 1486 202E C09E 1D89 9593 0EDE >
