Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

Bug#906767: Setup command is not working in SystemdD

93 views
Skip to first unread message

eHenry Berg

unread,
Aug 20, 2018, 4:20:03 PM8/20/18
to
Package: dphys-swapfile
Version: 20100506-4

Hardware: Raspberry Pi 2.
I use Debian release "sid".

My KInfocenter shows:
KDE Plasma Verson: 5.13.2
KDE Frameworks Version: 5.47.0
Qt Version: 5.11.1
Kernel Version: 4.17.0-2-armmp
OS Type: 32-bit

# grep -i swap /boot/config-4.17.0-2-armmp
CONFIG_SWAP=y
CONFIG_MEMCG_SWAP=y
# CONFIG_MEMCG_SWAP_ENABLED is not set
CONFIG_ARCH_USE_BUILTIN_BSWAP=y
CONFIG_FRONTSWAP=y
CONFIG_ZSWAP=y
CONFIG_MTD_SWAP=m
CONFIG_NFS_SWAP=y
CONFIG_SUNRPC_SWAP=y
CONFIG_RING_BUFFER_ALLOW_SWAP=y
# CONFIG_TRACER_SNAPSHOT_PER_CPU_SWAP is not set

I made a guide for 32-bit and 64-bit for Debian for Raspberry Pi here:
https://github.com/evasjo/DebianSbcRaspberry

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.

Test1:
# journalctl
Aug 19 15:24:35 irena systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 19 15:24:36 irena dphys-swapfile[403]: want /var/swap=1024MByte
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.
# systemctl status swap.target
��� swap.target - Swap
Loaded: loaded (/lib/systemd/system/swap.target; static; vendor
preset: enabled)
Active: active since Fri 2018-06-22 11:11:50 UTC; 1 months 27 days ago
Docs: man:systemd.special(7)
Warning: Journal has been rotated since unit was started. Log output
is incomplete or unavailable.
# 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 Sun 2018-08-19 15:24:36
UTC; 1h 45min ago
Docs: man:dphys-swapfile(8)
Process: 403 ExecStart=/sbin/dphys-swapfile setup (code=exited,
status=1/FAILURE)
Main PID: 403 (code=exited, status=1/FAILURE)
Aug 19 15:24:35 irena systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 19 15:24:36 irena dphys-swapfile[403]: want /var/swap=1024MByte
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.
# cat /proc/swaps
Filename Type Size Used Priority
#
Swap is not working!

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.

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"

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 do not know why "ExecStart=/sbin/dphys-swapfile setup" is not
working in SystemD for me.

// Evald

Axel Beckert

unread,
Aug 20, 2018, 6:30:03 PM8/20/18
to
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.

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.

> 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?)

> 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?

> 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.

> 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.

> 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.

Other questions:

* Did this happen directly after the initial installation or after an
upgrade?

* Did you change the wanted size of the swapfile recently, i.e. since
the last reboot but before the (suspected) upgrade?

* Can you reproduce this issue if you do a fresh installation?

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

eHenry Berg

unread,
Aug 21, 2018, 3:40:04 PM8/21/18
to
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).

eHenry Berg

unread,
Aug 22, 2018, 4:40:04 PM8/22/18
to
Test5: // How many times do "dphys-swapfile setup" run
# nano -w /usr/local/bin/swapsetup.cmd
#!/bin/bash
if output=$("/sbin/dphys-swapfile" "setup"); then
printf 'SwapSetupTrue «%s»\n' "$output"
logger SwapSetupLogTrue $output
else
printf 'SwapSetupFailed «%s»\n' "$output"
logger SwapSetupLogFailed $output
fi
exit $output

# chmod +x /usr/local/bin/swapsetup.cmd
# nano -w /lib/systemd/system/dphys-swapfile.service
ExecStart=/usr/local/bin/swapsetup.cmd // Old:
ExecStart=/sbin/dphys-swapfile setup

Restart

# journalctl|grep SwapSetup
Aug 22 19:08:21 irena swapsetup.cmd[391]: SwapSetupFailed ?want
/var/swap=1024MByte?
Aug 22 19:08:21 irena root[425]: SwapSetupLogFailed want /var/swap=1024MByte
# journalctl|grep -i swap
Aug 22 19:08:14 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 22 19:08:14 irena kernel: zswap: loaded using pool lzo/zbud
Aug 22 19:08:14 irena systemd[1]: Reached target Swap.
Aug 22 19:08:20 irena systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 22 19:08:21 irena swapsetup.cmd[391]: SwapSetupFailed ?want
/var/swap=1024MByte?
Aug 22 19:08:21 irena root[425]: SwapSetupLogFailed want /var/swap=1024MByte
Aug 22 19:08:21 irena swapsetup.cmd[391]:
/usr/local/bin/swapsetup.cmd: line 9: exit: want: numeric argument
required
Aug 22 19:08:21 irena systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Aug 22 19:08:21 irena systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
Aug 22 19:08:21 irena systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
# journalctl|grep -i dphys-swapfile
Aug 22 19:08:20 irena systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 22 19:08:21 irena systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Aug 22 19:08:21 irena systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
Aug 22 19:08:21 irena systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
#

Test5 answer: "dphys-swapfile setup" run only one time (I also tested
if /etc/init.d/dphys-swapfile still run, the answer is no)

# cat /proc/swaps
Filename Type Size Used Priority
# ls -l /var/swap
-rw------- 1 root root 1073741824 Aug 15 20:13 /var/swap
# /sbin/dphys-swapfile swapon
# cat /proc/swaps
Filename Type Size Used Priority
/var/swap file 1048572 256 -2
#

I have not got "dphys-swapfile setup" exit code. It seems that it give
a question mark.
"dphys-swapfile setup" exit with false code altought "dphys-swapfile
setup" seems to went okay for me, because I can run
"/sbin/dphys-swapfile swapon" successfully.
I will see if I can get the exit code from the 64-bit environment tomorrow.

// Evald

Davide Prina

unread,
Aug 23, 2018, 4:00:03 AM8/23/18
to
Package: dphys-swapfile
Version: 20100506-4

Dear Maintainer,

upgrade dphys-swapfile to version 20100506-4 fail

* What led up to the situation?

upgrading my testing system

* What exactly did you do (or not do) that was effective (or
ineffective)?

----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<
# apt update; apt -u upgrade
[...]
Configurazione di dphys-swapfile (20100506-4)...
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.
invoke-rc.d: initscript dphys-swapfile, action "restart" failed.
● dphys-swapfile.service - dphys-swapfile - set up, mount/unmount, and
delete a swap file
Loaded: loaded (/lib/systemd/system/dphys-swapfile.service;
disabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Thu 2018-08-23 08:14:40
CEST; 14ms ago
Docs: man:dphys-swapfile(8)
Process: 23017 ExecStart=/sbin/dphys-swapfile setup (code=exited,
status=1/FAILURE)
Main PID: 23017 (code=exited, status=1/FAILURE)

ago 23 08:14:40 davide systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
ago 23 08:14:40 davide dphys-swapfile[23017]: computing size,
ago 23 08:14:40 davide systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=1/FAILURE
ago 23 08:14:40 davide systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
ago 23 08:14:40 davide systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
dpkg: errore nell'elaborare il pacchetto dphys-swapfile (--configure):
installed dphys-swapfile package post-installation script subprocess
returned error exit status 1
[...]
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<



I have try

----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<
# LANG=C apt -f install
[...]
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
1 not fully installed or removed.
After this operation, 0 B of additional disk space will be used.
Setting up dphys-swapfile (20100506-4) ...
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.
invoke-rc.d: initscript dphys-swapfile, action "restart" failed.
* dphys-swapfile.service - dphys-swapfile - set up, mount/unmount, and
delete a swap file
Loaded: loaded (/lib/systemd/system/dphys-swapfile.service;
disabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Thu 2018-08-23 09:31:34
CEST; 9ms ago
Docs: man:dphys-swapfile(8)
Process: 11090 ExecStart=/sbin/dphys-swapfile setup (code=exited,
status=1/FAILURE)
Main PID: 11090 (code=exited, status=1/FAILURE)

Aug 23 09:31:34 davide systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 23 09:31:34 davide dphys-swapfile[11090]: computing size,
Aug 23 09:31:34 davide systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=1/FAILURE
Aug 23 09:31:34 davide systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
Aug 23 09:31:34 davide systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
dpkg: error processing package dphys-swapfile (--configure):
installed dphys-swapfile package post-installation script subprocess
returned error exit status 1
Errors were encountered while processing:
dphys-swapfile
E: Sub-process /usr/bin/dpkg returned an error code (1)
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<



----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<
# LANG=C journalctl -xe
[...]
Aug 23 09:34:58 davide systemd[1]: Reloading.
Aug 23 09:34:59 davide systemd[1]: Reloading.
Aug 23 09:34:59 davide 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 23 09:34:59 davide dphys-swapfile[26518]: computing size,
Aug 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=1/FAILURE
Aug 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
Aug 23 09:34:59 davide 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.
Aug 23 09:35:03 davide su[27010]: (to debian-security-support) davide on
none
Aug 23 09:35:03 davide su[27010]: pam_unix(su:session): session opened
for user debian-security-support by (uid=0)
Aug 23 09:35:03 davide su[27010]: pam_systemd(su:session): Cannot create
session: Already running in a session or user slice
Aug 23 09:35:03 davide su[27010]: pam_unix(su:session): session closed
for user debian-security-support
Aug 23 09:35:03 davide su[27221]: (to debian-security-support) davide on
none
Aug 23 09:35:03 davide su[27221]: pam_unix(su:session): session opened
for user debian-security-support by (uid=0)
Aug 23 09:35:03 davide su[27221]: pam_systemd(su:session): Cannot create
session: Already running in a session or user slice
Aug 23 09:35:03 davide su[27221]: pam_unix(su:session): session closed
for user debian-security-support
Aug 23 09:35:03 davide su[27619]: (to debian-security-support) davide on
none
Aug 23 09:35:03 davide su[27619]: pam_unix(su:session): session opened
for user debian-security-support by (uid=0)
Aug 23 09:35:03 davide su[27619]: pam_systemd(su:session): Cannot create
session: Already running in a session or user slice
Aug 23 09:35:04 davide su[27619]: pam_unix(su:session): session closed
for user debian-security-support
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<


I execute the command more times and each time I have the pam_unix
messages. These are very strange... or not?


----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<
# 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;
disabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Thu 2018-08-23 09:34:59
CEST; 7min ago
Docs: man:dphys-swapfile(8)
Process: 26518 ExecStart=/sbin/dphys-swapfile setup (code=exited,
status=1/FAILURE)
Main PID: 26518 (code=exited, status=1/FAILURE)

ago 23 09:34:59 davide systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
ago 23 09:34:59 davide dphys-swapfile[26518]: computing size,
ago 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=1/FAILURE
ago 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
ago 23 09:34:59 davide systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
davide:~#
davide:~#
davide:~# LANG=C 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;
disabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Thu 2018-08-23 09:34:59
CEST; 8min ago
Docs: man:dphys-swapfile(8)
Process: 26518 ExecStart=/sbin/dphys-swapfile setup (code=exited,
status=1/FAILURE)
Main PID: 26518 (code=exited, status=1/FAILURE)

Aug 23 09:34:59 davide systemd[1]: Starting dphys-swapfile - set up,
mount/unmount, and delete a swap file...
Aug 23 09:34:59 davide dphys-swapfile[26518]: computing size,
Aug 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Main process
exited, code=exited, status=1/FAILURE
Aug 23 09:34:59 davide systemd[1]: dphys-swapfile.service: Failed with
result 'exit-code'.
Aug 23 09:34:59 davide systemd[1]: Failed to start dphys-swapfile - set
up, mount/unmount, and delete a swap file.
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<

I try to execute the following command:
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<
# dphys-swapfile swapoff
# dphys-swapfile setup
computing size, # dphys-swapfile swapon
#
----8<----8<----8<----8<----8<----8<----8<----8<----8<----8<

and you can see that all work

Let me know if you need more info and how I can give to you.

Ciao
Davide

-- System Information:
Debian Release: buster/sid
APT prefers testing
APT policy: (500, 'testing'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 4.17.14-dp-20180816 (SMP w/4 CPU cores; PREEMPT)
Locale: LANG=it_IT.utf8, LC_CTYPE=it_IT.utf8 (charmap=UTF-8),
LANGUAGE=it_IT.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages dphys-swapfile depends on:
ii dc 1.07.1-2+b1
ii lsb-base 9.20170808

dphys-swapfile recommends no packages.

dphys-swapfile suggests no packages.

-- no debconf information
0 new messages