Hello!
Sorry, I think I've sent this initially during Spring break and it didn't get
anyone's attention. ☺
I'd still like to hear your opinions.
I have a service in a form of a python script to copy OS profile to a
LUKS-encrypted external drive on service stop and
restore from it back on service start. (If anyone is interested, this
btrfs-progs
test: https://gist.github.com/ettavolt/b9e94c36a483f6045339c33fd90ce2e8 - might
give an idea of the flow)
The service (backup-ask-rbr.service in the logs I'll attach below) is hooked to
device connection via udev by adding
SYSTEMD_WANTS device property.
However, there is a race condition when I unplug the drive (e.g. to come with a
laptop to a meeting).
1. disk-by-<…>.device is stopped (because unplugged).
2. systemd-cryptsetup@<…>.service is stopped, because it
BindsTo=disk-by-<…>.device.
2.1. Fails, because drive is still mounted.
3. Service is stopped, because it BindsTo=<…>.mount, and that has stop
propagated from blockdev@dev-mapper-<…>.target.
3.1. Fails, because IO can not go to device.
4. <…>.mount is unmounted.
4.1. Succeeds.
Note, that /dev/mapper/<name> is still there.
Now, when I plug the drive back, systemd tries to activate the main service
(due to SYSTEMD_WANTS). Service
BindsTo=<…>.mount, so systemd goes to activate the mount. Mount sees
/dev/mapper/<name>, doesn't activate systemd-
cryptsetup@<…>.service, fails. Consequently, the main service fails to start
too.
BTW, /dev/sdc seems to be occupied, so the drive gets /dev/sdd (but that's not
a problem for cryptsetup&mounts per se).
Things can get up properly on replug if I manually issue cryptsetup close <…>
before plugging.
I've solved this race by adding overrides to <…>.mount and
blockdev@dev-mapper-<…>.target so that the former
BindsTo=blockdev@dev-mapper-<…>.target and the latter
BindsTo=systemd-cryptsetup@<…>.service. With that, things are
properly ordered on unplug:
1. disk-by-<…>.device is stopped (because unplugged).
2. Stop propagates through systemd-cryptsetup@<…>.service,
blockdev@dev-mapper-<…>.target, <…>.mount to the main
service.
2.1. Fails to properly stop because of IO failure.
3. <…>.mount successfully unmounts (nothing tries IO).
4. systemd-cryptsetup@<…>.service successfully closes, because unmounted.
And units get up without manual interaction on plug.
What do you think about making systemd-fstab-generator to write
BindsTo=blockdev@<…>.target instead of just Requires=,
and also somehow make sure that systemd-cryptsetup@<…>.service is BoundBy
blockdev@dev-mapper-<…>.target?
Attached are statuses of device, crypt, mount, and service units after various
actions, the units themselves (without
overrides), and journal excerpts after unplugging (with and without overrides).
Thanks
● dev-sdc.device - PSSD_T7
Follows: unit currently follows state of
sys-devices-pci0000:00-0000:00:0d.0-usb3-3\x2d1-3\x2d1:1.0-host4-target4:0:0-4:0:0:0-block-sdc.device
Loaded: loaded
Active: active (plugged) since Fri 2023-04-07 11:32:57 EDT; 11s ago
Device:
/sys/devices/pci0000:00/0000:00:0d.0/usb3/3-1/3-1:1.0/host4/target4:0:0/4:0:0:0/block/sdc
Apr 07 11:32:57 ptits-lt systemd[1]: Condition check resulted in PSSD_T7 being
skipped.
● [email protected] - Cryptography Setup for rbrssd
Loaded: loaded (/etc/crypttab; generated)
Active: active (exited) since Fri 2023-04-07 11:32:59 EDT; 9s ago
Docs: man:crypttab(5)
man:systemd-cryptsetup-generator(8)
man:[email protected](8)
Process: 2753 ExecStart=/usr/lib/systemd/systemd-cryptsetup attach rbrssd
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b - luks,discard,nofail
(code=exited, status=0/SUCCESS)
Main PID: 2753 (code=exited, status=0/SUCCESS)
CPU: 7.486s
Apr 07 11:32:57 ptits-lt systemd[1]: Starting Cryptography Setup for rbrssd...
Apr 07 11:32:57 ptits-lt systemd-cryptsetup[2753]: Set cipher aes, mode
xts-plain64, key size 512 bits for device
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b.
Apr 07 11:32:59 ptits-lt systemd[1]: Finished Cryptography Setup for rbrssd.
● run-rbrssd.mount - /run/rbrssd
Loaded: loaded (/etc/fstab; generated)
Active: active (mounted) since Fri 2023-04-07 11:32:59 EDT; 9s ago
Where: /run/rbrssd
What: /dev/mapper/rbrssd
Docs: man:fstab(5)
man:systemd-fstab-generator(8)
Tasks: 0 (limit: 76832)
Memory: 872.0K
CPU: 4ms
CGroup: /system.slice/run-rbrssd.mount
Apr 07 11:32:59 ptits-lt systemd[1]: Mounting /run/rbrssd...
Apr 07 11:32:59 ptits-lt systemd[1]: Mounted /run/rbrssd.
● backup-ask-rbr.service - Sync ask-rbr with external drive on start and stop.
Loaded: loaded (/etc/systemd/system/backup-ask-rbr.service; static)
Active: active (exited) since Fri 2023-04-07 11:32:59 EDT; 9s ago
Process: 2953 ExecStart=/run/rbrssd/snapshot.py start (code=exited,
status=0/SUCCESS)
Main PID: 2953 (code=exited, status=0/SUCCESS)
CPU: 19ms
Apr 07 11:32:59 ptits-lt systemd[1]: Starting Sync ask-rbr with external drive
on start and stop....
Apr 07 11:32:59 ptits-lt systemd[1]: Finished Sync ask-rbr with external drive
on start and stop..
023-04-07T11:31:30.306557-0400 ptits-lt kernel: usb 3-1: USB disconnect, device
number 2
2023-04-07T11:31:30.390563-0400 ptits-lt systemd[1]: Stopping Sync ask-rbr with
external drive on start and stop....
2023-04-07T11:31:30.392608-0400 ptits-lt systemd[1]: Stopping Cryptography
Setup for rbrssd...
2023-04-07T11:31:30.398536-0400 ptits-lt systemd-cryptsetup[2528]: Underlying
device for crypt device rbrssd disappeared.
2023-04-07T11:31:30.398699-0400 ptits-lt systemd-cryptsetup[2528]: Device
rbrssd is still in use.
2023-04-07T11:31:30.398703-0400 ptits-lt systemd-cryptsetup[2528]: Failed to
deactivate: Device or resource busy
2023-04-07T11:31:30.399122-0400 ptits-lt systemd[1]:
[email protected]: Control process exited, code=exited,
status=1/FAILURE
2023-04-07T11:31:30.399327-0400 ptits-lt systemd[1]:
[email protected]: Failed with result 'exit-code'.
2023-04-07T11:31:30.413224-0400 ptits-lt kernel: sd 4:0:0:0: [sdc]
Synchronizing SCSI cache
2023-04-07T11:31:30.430151-0400 ptits-lt systemd[1]: Stopped Cryptography Setup
for rbrssd.
2023-04-07T11:31:30.433205-0400 ptits-lt snapshot.py[2529]: Create a readonly
snapshot of '/home/ask-rbr' in '/home/.ask-rbr-snapshots/@2023-04-07T11'
2023-04-07T11:31:30.437904-0400 ptits-lt snapshot.py[2531]: At subvol
/home/.ask-rbr-snapshots/@2023-04-07T11
2023-04-07T11:31:30.500056-0400 ptits-lt snapshot.py[2532]: ERROR: creating
snapshot ask-arch-profile/@2023-04-06T13 -> @2023-04-07T11 failed: Input/output
error
2023-04-07T11:31:30.500292-0400 ptits-lt snapshot.py[2532]: At snapshot
@2023-04-07T11
2023-04-07T11:31:30.501630-0400 ptits-lt snapshot.py[2527]: Traceback (most
recent call last):
2023-04-07T11:31:30.501630-0400 ptits-lt snapshot.py[2527]: File
"/run/rbrssd/snapshot.py", line 51, in <module>
2023-04-07T11:31:30.501890-0400 ptits-lt snapshot.py[2527]: run([
2023-04-07T11:31:30.501890-0400 ptits-lt snapshot.py[2527]: File
"/usr/lib/python3.10/subprocess.py", line 526, in run
2023-04-07T11:31:30.501991-0400 ptits-lt snapshot.py[2527]: raise
CalledProcessError(retcode, process.args,
2023-04-07T11:31:30.502028-0400 ptits-lt snapshot.py[2527]:
subprocess.CalledProcessError: Command '['sh', '-c', 'btrfs send -p
/home/.ask-rbr-snapshots/@2023-04-06T13 /home/.ask-rbr-snapshots/@2023-04-07T11
| btrfs receive />
2023-04-07T11:31:30.503208-0400 ptits-lt kernel: BTRFS error (device dm-2:
state A): Transaction aborted (error -5)
2023-04-07T11:31:30.503243-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state A) in add_to_free_space_tree:1056: errno=-5 IO failure
2023-04-07T11:31:30.503910-0400 ptits-lt kernel: BTRFS info (device dm-2: state
EA): forced readonly
2023-04-07T11:31:30.505669-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in do_free_extent_accounting:2854: errno=-5 IO failure
2023-04-07T11:31:30.505733-0400 ptits-lt kernel: BTRFS error (device dm-2:
state EA): failed to run delayed ref for logical 22544384 num_bytes 16384 type
176 action 2 ref_mod 1: -5
2023-04-07T11:31:30.505789-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in btrfs_run_delayed_refs:2151: errno=-5 IO failure
2023-04-07T11:31:30.505849-0400 ptits-lt kernel: BTRFS warning (device dm-2:
state EA): Skipping commit of aborted transaction.
2023-04-07T11:31:30.505907-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in cleanup_transaction:1984: errno=-5 IO failure
2023-04-07T11:31:30.509774-0400 ptits-lt systemd[1]: backup-ask-rbr.service:
Control process exited, code=exited, status=1/FAILURE
2023-04-07T11:31:30.509996-0400 ptits-lt systemd[1]: backup-ask-rbr.service:
Failed with result 'exit-code'.
2023-04-07T11:31:30.546788-0400 ptits-lt systemd[1]: Stopped Sync ask-rbr with
external drive on start and stop..
2023-04-07T11:31:30.567031-0400 ptits-lt systemd[1]: Unmounting /run/rbrssd...
2023-04-07T11:31:30.573148-0400 ptits-lt kernel: sd 4:0:0:0: [sdc] Synchronize
Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
2023-04-07T11:31:30.574020-0400 ptits-lt systemd[1]: run-rbrssd.mount:
Deactivated successfully.
2023-04-07T11:31:30.614847-0400 ptits-lt dbus-daemon[636]: [system] Activating
via systemd: service name='org.freedesktop.Avahi'
unit='dbus-org.freedesktop.Avahi.service' requested by ':1.101' (uid=124
pid=2541 comm="/usr/lib>
2023-04-07T11:31:30.633533-0400 ptits-lt systemd[1]: Unmounted /run/rbrssd.
2023-04-07T11:31:30.634122-0400 ptits-lt systemd[1]: Stopped target Block
Device Preparation for /dev/mapper/rbrssd.
2023-04-07T11:31:30.634164-0400 ptits-lt systemd[1]:
[email protected]: Deactivated successfully.
2023-04-07T11:31:30.634440-0400 ptits-lt dbus-daemon[636]: [system] Activation
via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit
dbus-org.freedesktop.Avahi.service not found.
2023-04-07T11:31:30.663356-0400 ptits-lt systemd[1]: Stopped File System Check
on /dev/mapper/rbrssd.
2023-04-07T11:44:56.089744-0400 ptits-lt kernel: usb 3-1: USB disconnect,
device number 4
2023-04-07T11:44:56.150535-0400 ptits-lt systemd[1]: Stopping Sync ask-rbr with
external drive on start and stop....
2023-04-07T11:44:56.173076-0400 ptits-lt kernel: sd 4:0:0:0: [sdc]
Synchronizing SCSI cache
2023-04-07T11:44:56.197018-0400 ptits-lt snapshot.py[4430]: Create a readonly
snapshot of '/home/ask-rbr' in '/home/.ask-rbr-snapshots/@2023-04-07T11:44'
2023-04-07T11:44:56.200681-0400 ptits-lt snapshot.py[4432]: At subvol
/home/.ask-rbr-snapshots/@2023-04-07T11:44
2023-04-07T11:44:56.266632-0400 ptits-lt snapshot.py[4433]: ERROR: creating
snapshot ask-arch-profile/@2023-04-06T13 -> @2023-04-07T11:44 failed:
Input/output error
2023-04-07T11:44:56.266632-0400 ptits-lt snapshot.py[4433]: At snapshot
@2023-04-07T11:44
2023-04-07T11:44:56.267337-0400 ptits-lt snapshot.py[4429]: Traceback (most
recent call last):
2023-04-07T11:44:56.267337-0400 ptits-lt snapshot.py[4429]: File
"/run/rbrssd/snapshot.py", line 51, in <module>
2023-04-07T11:44:56.267527-0400 ptits-lt snapshot.py[4429]: run([
2023-04-07T11:44:56.267527-0400 ptits-lt snapshot.py[4429]: File
"/usr/lib/python3.10/subprocess.py", line 526, in run
2023-04-07T11:44:56.267581-0400 ptits-lt snapshot.py[4429]: raise
CalledProcessError(retcode, process.args,
2023-04-07T11:44:56.267602-0400 ptits-lt snapshot.py[4429]:
subprocess.CalledProcessError: Command '['sh', '-c', 'btrfs send -p
/home/.ask-rbr-snapshots/@2023-04-06T13
/home/.ask-rbr-snapshots/@2023-04-07T11:44 | btrfs receiv>
2023-04-07T11:44:56.269811-0400 ptits-lt kernel: BTRFS error (device dm-2:
state A): Transaction aborted (error -5)
2023-04-07T11:44:56.269854-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state A) in add_to_free_space_tree:1056: errno=-5 IO failure
2023-04-07T11:44:56.269898-0400 ptits-lt kernel: BTRFS info (device dm-2: state
EA): forced readonly
2023-04-07T11:44:56.269969-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in do_free_extent_accounting:2854: errno=-5 IO failure
2023-04-07T11:44:56.269999-0400 ptits-lt kernel: BTRFS error (device dm-2:
state EA): failed to run delayed ref for logical 22544384 num_bytes 16384 type
176 action 2 ref_mod 1: -5
2023-04-07T11:44:56.270106-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in btrfs_run_delayed_refs:2151: errno=-5 IO failure
2023-04-07T11:44:56.270135-0400 ptits-lt kernel: BTRFS warning (device dm-2:
state EA): Skipping commit of aborted transaction.
2023-04-07T11:44:56.270181-0400 ptits-lt kernel: BTRFS: error (device dm-2:
state EA) in cleanup_transaction:1984: errno=-5 IO failure
2023-04-07T11:44:56.270801-0400 ptits-lt systemd[1]: backup-ask-rbr.service:
Control process exited, code=exited, status=1/FAILURE
2023-04-07T11:44:56.271030-0400 ptits-lt systemd[1]: backup-ask-rbr.service:
Failed with result 'exit-code'.
2023-04-07T11:44:56.306751-0400 ptits-lt systemd[1]: Stopped Sync ask-rbr with
external drive on start and stop..
2023-04-07T11:44:56.340586-0400 ptits-lt systemd[1]: Unmounting /run/rbrssd...
2023-04-07T11:44:56.346501-0400 ptits-lt systemd[1]: run-rbrssd.mount:
Deactivated successfully.
2023-04-07T11:44:56.363219-0400 ptits-lt kernel: sd 4:0:0:0: [sdc] Synchronize
Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
2023-04-07T11:44:56.399918-0400 ptits-lt systemd[1]: Unmounted /run/rbrssd.
2023-04-07T11:44:56.400225-0400 ptits-lt systemd[1]: Stopped target Block
Device Preparation for /dev/mapper/rbrssd.
2023-04-07T11:44:56.400870-0400 ptits-lt systemd[1]: Stopping Cryptography
Setup for rbrssd...
2023-04-07T11:44:56.400885-0400 ptits-lt systemd[1]:
[email protected]: Deactivated successfully.
2023-04-07T11:44:56.403841-0400 ptits-lt systemd-cryptsetup[4449]: Underlying
device for crypt device rbrssd disappeared.
2023-04-07T11:44:56.406383-0400 ptits-lt kernel: dm-2: detected capacity change
from 976740400 to 0
2023-04-07T11:44:56.409930-0400 ptits-lt dbus-daemon[636]: [system] Activating
via systemd: service name='org.freedesktop.Avahi'
unit='dbus-org.freedesktop.Avahi.service' requested by ':1.136' (uid=124
pid=4443 comm="/usr/lib>
2023-04-07T11:44:56.446906-0400 ptits-lt systemd[1]: Stopped File System Check
on /dev/mapper/rbrssd.
2023-04-07T11:44:56.448415-0400 ptits-lt dbus-daemon[636]: [system] Activation
via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit
dbus-org.freedesktop.Avahi.service not found.
2023-04-07T11:44:56.453115-0400 ptits-lt systemd[1]:
[email protected]: Deactivated successfully.
2023-04-07T11:44:56.493245-0400 ptits-lt systemd[1]: Stopped Cryptography Setup
for rbrssd.
● dev-sdc.device - PSSD_T7
Follows: unit currently follows state of
sys-devices-pci0000:00-0000:00:0d.0-usb3-3\x2d1-3\x2d1:1.0-host4-target4:0:0-4:0:0:0-block-sdc.device
Loaded: loaded
Active: active (plugged) since Fri 2023-04-07 11:31:16 EDT; 9s ago
Device:
/sys/devices/pci0000:00/0000:00:0d.0/usb3/3-1/3-1:1.0/host4/target4:0:0/4:0:0:0/block/sdc
● [email protected] - Cryptography Setup for rbrssd
Loaded: loaded (/etc/crypttab; generated)
Active: active (exited) since Fri 2023-04-07 11:31:19 EDT; 7s ago
Docs: man:crypttab(5)
man:systemd-cryptsetup-generator(8)
man:[email protected](8)
Process: 2301 ExecStart=/usr/lib/systemd/systemd-cryptsetup attach rbrssd
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b - luks,discard,nofail
(code=exited, status=0/SUCCESS)
Main PID: 2301 (code=exited, status=0/SUCCESS)
CPU: 7.474s
Apr 07 11:31:16 ptits-lt systemd[1]: Starting Cryptography Setup for rbrssd...
Apr 07 11:31:16 ptits-lt systemd-cryptsetup[2301]: Set cipher aes, mode
xts-plain64, key size 512 bits for device
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b.
Apr 07 11:31:19 ptits-lt systemd[1]: Finished Cryptography Setup for rbrssd.
● run-rbrssd.mount - /run/rbrssd
Loaded: loaded (/etc/fstab; generated)
Active: active (mounted) since Fri 2023-04-07 11:31:19 EDT; 7s ago
Where: /run/rbrssd
What: /dev/mapper/rbrssd
Docs: man:fstab(5)
man:systemd-fstab-generator(8)
Tasks: 0 (limit: 76832)
Memory: 868.0K
CPU: 3ms
CGroup: /system.slice/run-rbrssd.mount
Apr 07 11:31:19 ptits-lt systemd[1]: Mounting /run/rbrssd...
Apr 07 11:31:19 ptits-lt systemd[1]: Mounted /run/rbrssd.
● backup-ask-rbr.service - Sync ask-rbr with external drive on start and stop.
Loaded: loaded (/etc/systemd/system/backup-ask-rbr.service; static)
Active: active (exited) since Fri 2023-04-07 11:31:19 EDT; 7s ago
Process: 2501 ExecStart=/run/rbrssd/snapshot.py start (code=exited,
status=0/SUCCESS)
Main PID: 2501 (code=exited, status=0/SUCCESS)
CPU: 20ms
Apr 07 11:31:19 ptits-lt systemd[1]: Starting Sync ask-rbr with external drive
on start and stop....
Apr 07 11:31:19 ptits-lt systemd[1]: Finished Sync ask-rbr with external drive
on start and stop..
○ dev-sdc.device - /dev/sdc
Loaded: loaded
Active: inactive (dead)
× [email protected] - Cryptography Setup for rbrssd
Loaded: loaded (/etc/crypttab; generated)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:31:30 EDT; 27s
ago
Duration: 11.342s
Docs: man:crypttab(5)
man:systemd-cryptsetup-generator(8)
man:[email protected](8)
Process: 2301 ExecStart=/usr/lib/systemd/systemd-cryptsetup attach rbrssd
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b - luks,discard,nofail
(code=exited, status=0/SUCCESS)
Process: 2528 ExecStop=/usr/lib/systemd/systemd-cryptsetup detach rbrssd
(code=exited, status=1/FAILURE)
Main PID: 2301 (code=exited, status=0/SUCCESS)
CPU: 6ms
Apr 07 11:31:16 ptits-lt systemd[1]: Starting Cryptography Setup for rbrssd...
Apr 07 11:31:16 ptits-lt systemd-cryptsetup[2301]: Set cipher aes, mode
xts-plain64, key size 512 bits for device
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b.
Apr 07 11:31:19 ptits-lt systemd[1]: Finished Cryptography Setup for rbrssd.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopping Cryptography Setup for rbrssd...
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Underlying device for crypt
device rbrssd disappeared.
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Device rbrssd is still in
use.
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Failed to deactivate: Device
or resource busy
Apr 07 11:31:30 ptits-lt systemd[1]: [email protected]: Control
process exited, code=exited, status=1/FAILURE
Apr 07 11:31:30 ptits-lt systemd[1]: [email protected]: Failed
with result 'exit-code'.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopped Cryptography Setup for rbrssd.
× run-rbrssd.mount - /run/rbrssd
Loaded: loaded (/etc/fstab; generated)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:31:45 EDT; 12s
ago
Duration: 11.386s
Where: /run/rbrssd
What: /dev/mapper/rbrssd
Docs: man:fstab(5)
man:systemd-fstab-generator(8)
CPU: 1ms
Apr 07 11:31:45 ptits-lt systemd[1]: Mounting /run/rbrssd...
Apr 07 11:31:45 ptits-lt mount[2591]: mount: /run/rbrssd: can't read superblock
on /dev/mapper/rbrssd.
Apr 07 11:31:45 ptits-lt mount[2591]: dmesg(1) may have more information
after failed mount system call.
Apr 07 11:31:45 ptits-lt systemd[1]: run-rbrssd.mount: Mount process exited,
code=exited, status=32/n/a
Apr 07 11:31:45 ptits-lt systemd[1]: run-rbrssd.mount: Failed with result
'exit-code'.
Apr 07 11:31:45 ptits-lt systemd[1]: Failed to mount /run/rbrssd.
× backup-ask-rbr.service - Sync ask-rbr with external drive on start and stop.
Loaded: loaded (/etc/systemd/system/backup-ask-rbr.service; static)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:31:30 EDT; 27s
ago
Duration: 11.130s
Process: 2501 ExecStart=/run/rbrssd/snapshot.py start (code=exited,
status=0/SUCCESS)
Process: 2527 ExecStop=/run/rbrssd/snapshot.py stop (code=exited,
status=1/FAILURE)
Main PID: 2501 (code=exited, status=0/SUCCESS)
CPU: 46ms
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: File "/run/rbrssd/snapshot.py",
line 51, in <module>
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: run([
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: File
"/usr/lib/python3.10/subprocess.py", line 526, in run
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: raise
CalledProcessError(retcode, process.args,
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: subprocess.CalledProcessError:
Command '['sh', '-c', 'btrfs send -p /home/.ask-rbr-snapshots/@2023-04-06T13
/home/.ask-rbr-snapshots/@2023-04-07T11 | btrfs receive
/run/rbrssd/ask-arch-profile']' returned non-zero exit status 1.
Apr 07 11:31:30 ptits-lt systemd[1]: backup-ask-rbr.service: Control process
exited, code=exited, status=1/FAILURE
Apr 07 11:31:30 ptits-lt systemd[1]: backup-ask-rbr.service: Failed with result
'exit-code'.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopped Sync ask-rbr with external drive
on start and stop..
Apr 07 11:31:45 ptits-lt systemd[1]: Dependency failed for Sync ask-rbr with
external drive on start and stop..
Apr 07 11:31:45 ptits-lt systemd[1]: backup-ask-rbr.service: Job
backup-ask-rbr.service/start failed with result 'dependency'.
# Automatically generated by systemd-cryptsetup-generator
[Unit]
Description=Cryptography Setup for %I
Documentation=man:crypttab(5) man:systemd-cryptsetup-generator(8) man:[email protected](8)
SourcePath=/etc/crypttab
DefaultDependencies=no
IgnoreOnIsolate=true
After=cryptsetup-pre.target systemd-udevd-kernel.socket
Before=blockdev@dev-mapper-%i.target
Wants=blockdev@dev-mapper-%i.target
Conflicts=umount.target
BindsTo=dev-disk-by\x2duuid-000db593\x2d5c9b\x2d492e\x2db100\x2d3596d955701b.device
After=dev-disk-by\x2duuid-000db593\x2d5c9b\x2d492e\x2db100\x2d3596d955701b.device
Before=umount.target
[Service]
Type=oneshot
RemainAfterExit=yes
TimeoutSec=0
KeyringMode=shared
OOMScoreAdjust=500
ExecStart=/usr/lib/systemd/systemd-cryptsetup attach 'rbrssd' '/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b' '-' 'luks,discard,nofail'
ExecStop=/usr/lib/systemd/systemd-cryptsetup detach 'rbrssd'
# SPDX-License-Identifier: LGPL-2.1-or-later
#
# This file is part of systemd.
#
# systemd is free software; you can redistribute it and/or modify it
# under the terms of the GNU Lesser General Public License as published by
# the Free Software Foundation; either version 2.1 of the License, or
# (at your option) any later version.
[Unit]
Description=Block Device Preparation for %f
Documentation=man:systemd.special(7)
StopWhenUnneeded=yes
# Automatically generated by systemd-fstab-generator
[Unit]
Documentation=man:fstab(5) man:systemd-fstab-generator(8)
SourcePath=/etc/fstab
[email protected]
[email protected]
[email protected]
[Mount]
What=/dev/mapper/rbrssd
Where=/run/rbrssd
Type=btrfs
Options=rw,noatime,nosuid,nofail
[Unit]
Description=Sync ask-rbr with external drive on start and stop.
BindsTo=run-rbrssd.mount
After=run-rbrssd.mount
[Service]
Type=oneshot
RemainAfterExit=yes
#ExecStop=/run/rbrssd/snapshot.py backup
ExecStart=/run/rbrssd/snapshot.py start
ExecStop=/run/rbrssd/snapshot.py stop
○ dev-sdc.device - /dev/sdc
Loaded: loaded
Active: inactive (dead)
× [email protected] - Cryptography Setup for rbrssd
Loaded: loaded (/etc/crypttab; generated)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:31:30 EDT; 5s
ago
Duration: 11.342s
Docs: man:crypttab(5)
man:systemd-cryptsetup-generator(8)
man:[email protected](8)
Process: 2301 ExecStart=/usr/lib/systemd/systemd-cryptsetup attach rbrssd
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b - luks,discard,nofail
(code=exited, status=0/SUCCESS)
Process: 2528 ExecStop=/usr/lib/systemd/systemd-cryptsetup detach rbrssd
(code=exited, status=1/FAILURE)
Main PID: 2301 (code=exited, status=0/SUCCESS)
CPU: 6ms
Apr 07 11:31:16 ptits-lt systemd[1]: Starting Cryptography Setup for rbrssd...
Apr 07 11:31:16 ptits-lt systemd-cryptsetup[2301]: Set cipher aes, mode
xts-plain64, key size 512 bits for device
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b.
Apr 07 11:31:19 ptits-lt systemd[1]: Finished Cryptography Setup for rbrssd.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopping Cryptography Setup for rbrssd...
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Underlying device for crypt
device rbrssd disappeared.
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Device rbrssd is still in
use.
Apr 07 11:31:30 ptits-lt systemd-cryptsetup[2528]: Failed to deactivate: Device
or resource busy
Apr 07 11:31:30 ptits-lt systemd[1]: [email protected]: Control
process exited, code=exited, status=1/FAILURE
Apr 07 11:31:30 ptits-lt systemd[1]: [email protected]: Failed
with result 'exit-code'.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopped Cryptography Setup for rbrssd.
○ run-rbrssd.mount - /run/rbrssd
Loaded: loaded (/etc/fstab; generated)
Active: inactive (dead) since Fri 2023-04-07 11:31:30 EDT; 4s ago
Duration: 11.386s
Where: /run/rbrssd
What: /dev/mapper/rbrssd
Docs: man:fstab(5)
man:systemd-fstab-generator(8)
CPU: 8ms
Apr 07 11:31:19 ptits-lt systemd[1]: Mounting /run/rbrssd...
Apr 07 11:31:19 ptits-lt systemd[1]: Mounted /run/rbrssd.
Apr 07 11:31:30 ptits-lt systemd[1]: Unmounting /run/rbrssd...
Apr 07 11:31:30 ptits-lt systemd[1]: run-rbrssd.mount: Deactivated successfully.
Apr 07 11:31:30 ptits-lt systemd[1]: Unmounted /run/rbrssd.
× backup-ask-rbr.service - Sync ask-rbr with external drive on start and stop.
Loaded: loaded (/etc/systemd/system/backup-ask-rbr.service; static)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:31:30 EDT; 5s
ago
Duration: 11.130s
Process: 2501 ExecStart=/run/rbrssd/snapshot.py start (code=exited,
status=0/SUCCESS)
Process: 2527 ExecStop=/run/rbrssd/snapshot.py stop (code=exited,
status=1/FAILURE)
Main PID: 2501 (code=exited, status=0/SUCCESS)
CPU: 46ms
Apr 07 11:31:30 ptits-lt snapshot.py[2532]: At snapshot @2023-04-07T11
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: Traceback (most recent call last):
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: File "/run/rbrssd/snapshot.py",
line 51, in <module>
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: run([
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: File
"/usr/lib/python3.10/subprocess.py", line 526, in run
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: raise
CalledProcessError(retcode, process.args,
Apr 07 11:31:30 ptits-lt snapshot.py[2527]: subprocess.CalledProcessError:
Command '['sh', '-c', 'btrfs send -p /home/.ask-rbr-snapshots/@2023-04-06T13
/home/.ask-rbr-snapshots/@2023-04-07T11 | btrfs receive
/run/rbrssd/ask-arch-profile']' returned non-zero exit status 1.
Apr 07 11:31:30 ptits-lt systemd[1]: backup-ask-rbr.service: Control process
exited, code=exited, status=1/FAILURE
Apr 07 11:31:30 ptits-lt systemd[1]: backup-ask-rbr.service: Failed with result
'exit-code'.
Apr 07 11:31:30 ptits-lt systemd[1]: Stopped Sync ask-rbr with external drive
on start and stop..
○ dev-sdc.device - /dev/sdc
Loaded: loaded
Active: inactive (dead)
Apr 07 11:32:57 ptits-lt systemd[1]: Condition check resulted in PSSD_T7 being
skipped.
○ [email protected] - Cryptography Setup for rbrssd
Loaded: loaded (/etc/crypttab; generated)
Active: inactive (dead) since Fri 2023-04-07 11:44:56 EDT; 2s ago
Duration: 11min 56.980s
Docs: man:crypttab(5)
man:systemd-cryptsetup-generator(8)
man:[email protected](8)
Process: 4449 ExecStop=/usr/lib/systemd/systemd-cryptsetup detach rbrssd
(code=exited, status=0/SUCCESS)
Main PID: 2753 (code=exited, status=0/SUCCESS)
CPU: 4ms
Apr 07 11:32:57 ptits-lt systemd[1]: Starting Cryptography Setup for rbrssd...
Apr 07 11:32:57 ptits-lt systemd-cryptsetup[2753]: Set cipher aes, mode
xts-plain64, key size 512 bits for device
/dev/disk/by-uuid/000db593-5c9b-492e-b100-3596d955701b.
Apr 07 11:32:59 ptits-lt systemd[1]: Finished Cryptography Setup for rbrssd.
Apr 07 11:44:56 ptits-lt systemd[1]: Stopping Cryptography Setup for rbrssd...
Apr 07 11:44:56 ptits-lt systemd-cryptsetup[4449]: Underlying device for crypt
device rbrssd disappeared.
Apr 07 11:44:56 ptits-lt systemd[1]: [email protected]:
Deactivated successfully.
Apr 07 11:44:56 ptits-lt systemd[1]: Stopped Cryptography Setup for rbrssd.
○ run-rbrssd.mount - /run/rbrssd
Loaded: loaded (/etc/fstab; generated)
Drop-In: /etc/systemd/system/run-rbrssd.mount.d
└─override.conf
Active: inactive (dead) since Fri 2023-04-07 11:44:56 EDT; 2s ago
Duration: 11min 56.820s
Where: /run/rbrssd
What: /dev/mapper/rbrssd
Docs: man:fstab(5)
man:systemd-fstab-generator(8)
CPU: 8ms
Apr 07 11:32:59 ptits-lt systemd[1]: Mounting /run/rbrssd...
Apr 07 11:32:59 ptits-lt systemd[1]: Mounted /run/rbrssd.
Apr 07 11:44:56 ptits-lt systemd[1]: Unmounting /run/rbrssd...
Apr 07 11:44:56 ptits-lt systemd[1]: run-rbrssd.mount: Deactivated successfully.
Apr 07 11:44:56 ptits-lt systemd[1]: Unmounted /run/rbrssd.
× backup-ask-rbr.service - Sync ask-rbr with external drive on start and stop.
Loaded: loaded (/etc/systemd/system/backup-ask-rbr.service; static)
Active: failed (Result: exit-code) since Fri 2023-04-07 11:44:56 EDT; 2s
ago
Duration: 11min 56.583s
Process: 4429 ExecStop=/run/rbrssd/snapshot.py stop (code=exited,
status=1/FAILURE)
Main PID: 2953 (code=exited, status=0/SUCCESS)
CPU: 50ms
Apr 07 11:44:56 ptits-lt snapshot.py[4433]: At snapshot @2023-04-07T11:44
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: Traceback (most recent call last):
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: File "/run/rbrssd/snapshot.py",
line 51, in <module>
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: run([
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: File
"/usr/lib/python3.10/subprocess.py", line 526, in run
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: raise
CalledProcessError(retcode, process.args,
Apr 07 11:44:56 ptits-lt snapshot.py[4429]: subprocess.CalledProcessError:
Command '['sh', '-c', 'btrfs send -p /home/.ask-rbr-snapshots/@2023-04-06T13
/home/.ask-rbr-snapshots/@2023-04-07T11:44 | btrfs receive
/run/rbrssd/ask-arch-profile']' returned non-zero exit status 1.
Apr 07 11:44:56 ptits-lt systemd[1]: backup-ask-rbr.service: Control process
exited, code=exited, status=1/FAILURE
Apr 07 11:44:56 ptits-lt systemd[1]: backup-ask-rbr.service: Failed with result
'exit-code'.
Apr 07 11:44:56 ptits-lt systemd[1]: Stopped Sync ask-rbr with external drive
on start and stop..
