UnconnectedBedna / shrink-backup

A utility to backup SBC:s (like Raspberry pi) into minimal bootable img files
Other
48 stars 7 forks source link

Unable to run as cronjob #33

Closed MqlBql closed 5 months ago

MqlBql commented 6 months ago

Describe the bug Script works fine in CLI, but unable to make it work as cronjob

To Reproduce

sudo crontab -e
0 2 * * * backup -aytl /backup/pi.img

Expected behavior Was expecting it to work the same as CLI

Harware (please complete the following information):

Additional context First of all thank you very much for this wonderful script. This is just a small inconvenience. Asking here just in case this is a simple fix. Here is a log of a failed attempt at cronjob

2024-05-24 00:35:01 [INFO]  - Debugging requested, writing to log file /home/backup/shrink-backup.log
2024-05-24 00:35:01 [INFO]  - ext4 root filesystem detected
2024-05-24 00:35:01 [DEBUG] - FSTYPE=ext4
2024-05-24 00:35:01 [DEBUG] - LOCAL_DEV_PTUUID=28a6ec92 | LOCAL_DEV_PATH=/dev/mmcblk0
2024-05-24 00:35:01 [DEBUG] - PARTITION_TABLE=
2024-05-24 00:35:01 [DEBUG] - Update existing img file, UPDATE=false
2024-05-24 00:35:01 [DEBUG] - Requesting size from resize2fs, RESIZE2FS_RUN=true
2024-05-24 00:35:01 [DEBUG] - Prompt for user confirmation, PROMPTS=false
2024-05-24 00:35:01 [DEBUG] - Auto expansion, AUTOEXPAND=true
2024-05-24 00:35:01 [INFO]  - -a selected by user
2024-05-24 00:35:01 [DEBUG] - ADDED_SPACE=0
2024-05-24 00:35:01 [INFO]  - Executing make_img function
------------------------------------------------------------------------------
2024-05-24 00:35:01 [INFO]  - Running function: get_dev_variables
2024-05-24 00:35:01 [INFO]  - Separate boot partition detected
2024-05-24 00:35:01 [DEBUG] - LOCAL_DEV_BOOT_PATH=/dev/mmcblk0p1 | LOCAL_DEV_ROOT_PATH=/dev/mmcblk0p2
2024-05-24 00:35:01 [DEBUG] - LOCAL_ROOT_PARTN=
2024-05-24 00:35:01 [INFO]  - Calculating size for dd to cover bootsector in blocks (512B block size) and adding 256 blocks to overlap into root (only used in img creation)
2024-05-24 00:35:01 [DEBUG] - Running: fdisk -lo start /dev/mmcblk0 | tail -1
2024-05-24 00:35:01 [DEBUG] - LOCAL_ROOT_START= Blocks | LOCAL_BOOTSECTOR=-1 Blocks | LOCAL_DDBOOTSECTOR=255 Blocks
2024-05-24 00:35:01 [DEBUG] - LOCAL_ROOT_START=0 Bytes | LOCAL_BOOTSECTOR=-512 Bytes
2024-05-24 00:35:01 [DEBUG] - LOCAL_RESIZE2FS_MIN=0 Bytes
2024-05-24 00:35:01 [INFO]  - Setting TOTAL (space needed for files on root) to size calculated by resize2fs
2024-05-24 00:35:01 [DEBUG] - TOTAL=0 Bytes
2024-05-24 00:35:01 [INFO]  - Calculating .img file size by adding LOCAL_BOOTSECTOR to TOTAL (only used in img creation)
2024-05-24 00:35:01 [DEBUG] - TRUNCATE_TOTAL=-512 Bytes
2024-05-24 00:35:01 [INFO]  - Running function: get_shared_variables
2024-05-24 00:35:01 [DEBUG] - LOOP=
2024-05-24 00:35:01 [INFO]  - Separate boot partition detected
2024-05-24 00:35:01 [DEBUG] - Running: cat /etc/fstab | grep '/boot' | awk '{print $2}'
2024-05-24 00:35:01 [DEBUG] - BOOT_PATH=/boot | IMG_DEV_BOOT_PATH=p1 | IMG_DEV_ROOT_PATH=p2
2024-05-24 00:35:01 [INFO]  - -y selected by user. prompts are disabled
2024-05-24 00:35:07 [INFO]  - 6 seconds passed, user did not stop operation
------------------------------------------------------------------------------
2024-05-24 00:35:07 [WARNING] - Removing: /backup/RPI.img
2024-05-24 00:35:09 [INFO]  - Using dd to create bootsector
------------------------------------------------------------------------------
2024-05-24 00:35:09 [ERROR] - DD TO LOCAL_BOOTSECTOR FAILED:
255+0 records in
255+0 records out
130560 bytes (131 kB, 128 KiB) copied, 0.00577474 s, 22.6 MB/s
------------------------------------------------------------------------------
2024-05-24 00:35:09 [ERROR] - Cleanup function called with non zero exit code: exit 1
2024-05-24 00:35:09 [INFO]  - Elapsed time: 00.08
2024-05-24 00:35:09 [DEBUG] - Exiting script
UnconnectedBedna commented 6 months ago

Hello there and thank you for creating an issue informing me of this!

Just to clarify. If running the script manually it works? That is very important for me to know. If so, it should work, but I am no fan of cron (ie, I do not use it and have very limited knowledge), I use systemd timers in these cases... AFAIUI running cron as sudo is not recommended... Removing security checks on sudo passwd f ex... Not a great idea imho...

Reading the log file I can see it immediately fails to identify the partition table, that then has other consequences further down in the log.

It does not even recognize that there is a boot partition. It fails to get the sizes, so the dd is 128KiB, should be a couple of hundred mebibytes covering the entire boot partition and a bit more... Very strange...

So before we move forward, can you just confirm it works if you manually start the script?

MqlBql commented 6 months ago

Hello,

It works perfectly when using manually.

This is the only clue I could gather on why it fails with cron :

when you run things via cron you are operating in a different environment to when you run things at the command line, therefore your script must also use full path and file names.

I will try manually add root and boot path to see if it helps. Otherwise, don't worry to much about it, I'll just use systemd. Again, thank you for the script !

UnconnectedBedna commented 6 months ago

Well, yes, I just assumed you renamed the script to backup and put it somewhere in a $PATH location. But I feel like if THAT was actually the problem, it should fail to even start the script... I have implemented things making sure you would NOT have to rely on $PATH using basename & dirname in the script when setting variables containing those paths. This means you can both use the direct name (if it's inside a $PATH dir) and absolute path to the script, should not matter at all...

I feel pretty confident that a systemd timer would be great here, something like (I am just winging this here, edit to fit you):

$ sudo nano /etc/systemd/system/backup.service

[Unit]
Description=shrink-backup service
Wants=network.target
After=syslog.target network-online.target

[Service]
Type=simple
ExecStart=/bin/bash -c "/path/to/shrink-backup -aytl /path/to/img.img"

[Install]
WantedBy=multi-user.target
$ sudo nano /etc/systemd/system/backup.timer

[Unit]
Description=Schedule shrink-backup to run every Sunday at 18.00

[Timer]
Persistent=true
OnCalendar=Sun *-*-* 18:00:00

[Install]
WantedBy=timers.target
sudo systemctl daemon-reload
sudo systemctl enable --now backup.timer

Mind you though, that this will overwrite and create a new file every time, if you just want to keep it updated, use -U, or you could just add a variable like date and add to the filename so the new backup does not overwrite. But you probably already know this..

:slightly_smiling_face:

UnconnectedBedna commented 6 months ago

Try using the script in testing branch if you can not get it to work with the stable branch.

What is involved in this is something I actually think is a bug somewhere upstream, I even posted on the rpi forums but people probably thought it was an attention seeking thing and I got no responses, but it really isn't!

The variable for the loop boot partition for the img file (and root if you do not have a boot partition) FAILS UNLESS i put a sleep 1 before the lsblk operation is issued. I'm not joking, I just now had to add the sleep to the armbian version of the script otherwise it now also failed, has not been needed before. It just suddenly started to happen!

So if you have time, please check if the testing branch might work for you.

MqlBql commented 6 months ago

Testing branch does not work even manually. Here is the logs.

2024-05-24 19:30:43 [INFO]  - Debugging requested, writing to log file ./shrink-backup.log
2024-05-24 19:30:43 [INFO]  - Zoom speed NOT requested, setting SLEEPING=sleep 1 | ZOOM=false
2024-05-24 19:30:44 [INFO]  - -a selected by user, setting ADDED_SPACE to 0 (non-zero value)
2024-05-24 19:30:44 [DEBUG] - ADDED_SPACE=0
2024-05-24 19:30:44 [INFO]  - ext4 root filesystem detected
2024-05-24 19:30:44 [DEBUG] - FSTYPE=ext4
2024-05-24 19:30:44 [DEBUG] - LOCAL_DEV_PTUUID=28a6ec92 | LOCAL_DEV_PATH=/dev/mmcblk0
------------------------------------------------------------------------------
2024-05-24 19:30:44 [DEBUG] - PARTITION_TABLE=msdos
2024-05-24 19:30:44 [DEBUG] - UPDATE=false
2024-05-24 19:30:44 [DEBUG] - AUTORESIZE_RUN=true
2024-05-24 19:30:44 [DEBUG] - PROMPTS=false
2024-05-24 19:30:44 [DEBUG] - EXCLUDE_FILE=false
2024-05-24 19:30:44 [DEBUG] - AUTOEXPAND=true
2024-05-24 19:30:44 [DEBUG] - RSYNC_DELETE=--delete
2024-05-24 19:30:44 [DEBUG] - F2FS=false
------------------------------------------------------------------------------
2024-05-24 19:30:44 [INFO]  - -f NOT selected by user, using default exclude directories
2024-05-24 19:30:44 [INFO]  - Running function: make_img
------------------------------------------------------------------------------
2024-05-24 19:30:44 [INFO]  - Running function: get_dev_variables
2024-05-24 19:30:44 [INFO]  - Separate boot partition detected
2024-05-24 19:30:44 [DEBUG] - LOCAL_DEV_BOOT_PATH=/dev/mmcblk0p1 | LOCAL_DEV_ROOT_PATH=/dev/mmcblk0p2
2024-05-24 19:30:44 [DEBUG] - LOCAL_BOOT_UUID=5044-2089 | LOCAL_ROOT_UUID=cce434c1-4bcd-4c4d-ba03-f6179e1f1722 | LOCAL_ROOT_PARTUUID=28a6ec92-02
2024-05-24 19:30:44 [DEBUG] - BOOT_PATH=/boot
2024-05-24 19:30:44 [DEBUG] - LOCAL_ROOT_PARTN=2
2024-05-24 19:30:44 [INFO]  - Calculating size for dd to cover bootsector in blocks (512B block size) and adding 256 blocks to overlap into root (only used in img creation)
2024-05-24 19:30:44 [DEBUG] - Running: fdisk -lo start /dev/mmcblk0 | tail -1
2024-05-24 19:30:44 [DEBUG] - LOCAL_ROOT_START=264192 blocks | LOCAL_BOOTSECTOR=264191 blocks | LOCAL_DDBOOTSECTOR=264447 blocks
2024-05-24 19:30:44 [DEBUG] - LOCAL_ROOT_START=135266304 bytes | LOCAL_BOOTSECTOR=135265792 bytes
2024-05-24 19:30:44 [DEBUG] - BLOCKSIZE=4096 bytes
2024-05-24 19:30:44 [DEBUG] - LOCAL_AUTORESIZE_MIN=7009906688 bytes
2024-05-24 19:30:44 [INFO]  - Setting TOTAL (space needed for files on root) to size calculated by resize2fs
2024-05-24 19:30:44 [DEBUG] - TOTAL=7009906688 bytes
2024-05-24 19:30:44 [INFO]  - Calculating .img file size by adding LOCAL_BOOTSECTOR to TOTAL
2024-05-24 19:30:44 [DEBUG] - TRUNCATE_TOTAL=7145172480 bytes
2024-05-24 19:30:44 [INFO]  - -y selected by user. prompts are disabled
2024-05-24 19:30:50 [INFO]  - 6 seconds passed, user did not stop operation
------------------------------------------------------------------------------
2024-05-24 19:30:51 [INFO]  - Using dd to create bootsector
------------------------------------------------------------------------------
2024-05-24 19:30:58 [DEBUG] - Running: dd bs=512 count=264447 if=/dev/mmcblk0 of=/backup/RPi.img conv=noerror,sync status=progress
264447+0 records in
264447+0 records out
135396864 bytes (135 MB, 129 MiB) copied, 6.20591 s, 21.8 MB/s
------------------------------------------------------------------------------
2024-05-24 19:31:00 [INFO]  - Using truncate to resize img file to 6814MiB
2024-05-24 19:31:00 [DEBUG] - Running: truncate --size=7145172480 /backup/RPi.img
2024-05-24 19:31:01 [DEBUG] - Running function: do_loop
2024-05-24 19:31:01 [DEBUG] - LOOP=/dev/loop0
2024-05-24 19:31:02 [DEBUG] - Running: losetup -P /dev/loop0 /backup/RPi.img
2024-05-24 19:31:02 [DEBUG] - IS_LOOPED=true
2024-05-24 19:31:02 [INFO]  - Running function: set_img_variables
2024-05-24 19:31:02 [INFO]  - Separate boot partition detected
2024-05-24 19:31:03 [DEBUG] - IMG_DEV_BOOT_PATH= | IMG_DEV_ROOT_PATH=
2024-05-24 19:31:04 [INFO]  - Using sfdisk to remove root partition
2024-05-24 19:31:04 [DEBUG] - Running: sfdisk --delete -f /dev/loop0 2
2024-05-24 19:31:06 [INFO]  - Using parted to recreate root partition
2024-05-24 19:31:06 [DEBUG] - Running: parted -s -a none /dev/loop0 unit B mkpart primary ext4 135266304 100%
2024-05-24 19:31:09 [DEBUG] - LABEL= | UUID=cce434c1-4bcd-4c4d-ba03-f6179e1f1722
2024-05-24 19:31:09 [INFO]  - Using mkfs.ext4 to format root filesystem
------------------------------------------------------------------------------
2024-05-24 19:31:09 [DEBUG] - Running: mkfs.ext4 -U cce434c1-4bcd-4c4d-ba03-f6179e1f1722 -L  
mke2fs 1.47.0 (5-Feb-2023)
The file  does not exist and no size was specified.
------------------------------------------------------------------------------
2024-05-24 19:31:10 [INFO]  - Running function: do_e2fsck
2024-05-24 19:31:11 [DEBUG] - Running: e2fsck -p -f 
e2fsck: No such file or directory while trying to open 
Possibly non-existent device?
------------------------------------------------------------------------------
2024-05-24 19:31:12 [INFO]  - Running function: do_mount
2024-05-24 19:31:13 [INFO]  - Creating temp directory
2024-05-24 19:31:13 [DEBUG] - Running: mktemp -d -t backup-XXX
2024-05-24 19:31:13 [DEBUG] - TMP_DIR=/tmp/backup-Bl6
2024-05-24 19:31:15 [INFO]  - Mounting root partition from loop
2024-05-24 19:31:15 [DEBUG] - Running: mount  /tmp/backup-Bl6
------------------------------------------------------------------------------
2024-05-24 19:31:15 [ERROR] - ROOT MOUNT FAILED:
mount: /tmp/backup-Bl6: wrong fs type, bad option, bad superblock on , missing codepage or helper program, or other error.
       dmesg(1) may have more information after failed mount system call.
------------------------------------------------------------------------------
2024-05-24 19:31:15 [ERROR] - Cleanup function called with non zero exit code: exit 1
2024-05-24 19:31:15 [DEBUG] - Removing loop in cleanup function: losetup -d /dev/loop0
2024-05-24 19:31:15 [DEBUG] - Removing temp directory in cleanup function: rm -rf /tmp/backup-Bl6
2024-05-24 19:31:15 [INFO]  - Elapsed time: 00.32
2024-05-24 19:31:15 [DEBUG] - Exiting script
UnconnectedBedna commented 6 months ago

2024-05-24 19:31:03 [DEBUG] - IMG_DEV_BOOT_PATH= | IMG_DEV_ROOT_PATH=

See!!! I have NO IDEA, why that is happening!

I also see there is no label for the root fs, but that might just be the case on DietPi? Also please confirm your boot partition is mounted at /boot?

It fails right here on row 468 & 469

  if $(cat /etc/fstab | grep -q 'boot'); then
    debug 'INFO' 'Separate boot partition detected'

    # ext4
    if [ "$FSTYPE" == 'ext4' ] || [ "$FSTYPE" == 'f2fs' ]; then
      # I have no idea why, but if I do not put this sleep here, IMG_DEV_BOOT_PATH does not get set
      sleep 1
      IMG_DEV_BOOT_PATH=$(lsblk -o path,uuid "$LOOP" | grep "$LOCAL_BOOT_UUID" | awk '{print $1}')
      IMG_DEV_ROOT_PATH=$(lsblk -o path,uuid "$LOOP" | grep "$LOCAL_ROOT_UUID" | awk '{print $1}')
      debug 'DEBUG' "IMG_DEV_BOOT_PATH=$IMG_DEV_BOOT_PATH | IMG_DEV_ROOT_PATH=$IMG_DEV_ROOT_PATH"

When this started happening for me on rpiOS it was only the boot variable, but for you it's both, that's a new one...

What you could do, if you feel like giving me a huge helping hand here, is to: exchange row 467:

- sleep 1
+ pause 'Press [Enter] key to continue...'

Then run the script manually to make a new backup and when the script pauses, open another terminal and run following commands:

lsblk -o path,uuid /dev/loop0 | grep '5044-2089' | awk '{print $1}'
lsblk -o path,uuid /dev/loop0 | grep 'cce434c1-4bcd-4c4d-ba03-f6179e1f1722' | awk '{print $1}'

And see if they return antyhing, if they do, go back to the terminal that has the script paused, and "press any key".

Maybe a longer sleep is needed, again, I have no idea why this is happening. Maybe I need to inform the kernel of the changes or smthn, maybe it doesn't get updated immediately with the changes made. But:

2024-05-24 19:31:02 [DEBUG] - Running: losetup -P /dev/loop0 /backup/RPi.img

The -P is doing exactly that... :confused: I'm so confused...

I really hope you can help me test this theory with pausing longer for me...

UnconnectedBedna commented 6 months ago

Ok...

I installed DietPi on a rpi4b8gb. I only installed smbclient and python. Ran the script and failed with rsync, because rsync was not installed. xD Installed it using apt (no idea if that is correct, maybe I should have used the dietpi "package manager", but it worked).

Ran the script again, and I don't know what to tell you buddy, it worked immediately. I even forgot to disable the autoexpansion, so it detected the system as a "raspberry pi" (I should look into that) and used that method for autoexpansion.

Wrote the img to an sd-card, inserted it into my rpi and it booted, it ran the autoexpansion, rebooted, and then after loading I could log in and the sd-card was resized to use the full capacity.

So I don't know what to tell you, something on your system is different from what I got in a fresh install.

If you retry, and it still does not set the variables like I explained above, all you can do is try what I explained in the last post, and see what you get in the commands.

There really should not be an issue here, but if you can produce a workflow that fails, and you can help me identify what you have changed from a default install, we might be able to implement something, but as of now, I have nothing to go on.

$ uname -a
Linux DietPi 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr  3 17:24:16 BST 2023 aarch64 GNU/Linux
UnconnectedBedna commented 5 months ago

Well, with no response there is not much I can do, and this is something that does not happen on my freshly installed dietPI so this is either something upstream or something on your system not setup as "default" that makes the script not work, but I can't do anything without more info.

So this is not a bug I can do anything about on my side (I increased the sleep to 2) and therefore close this issue.