linuxmint / timeshift

System restore tool for Linux. Creates filesystem snapshots using rsync+hardlinks, or BTRFS snapshots. Supports scheduled snapshots, multiple backup levels, and exclude filters. Snapshots can be restored while system is running or from Live CD/USB.
1.53k stars 75 forks source link

timeshift hangs at mount -- Another instance of this application is running #290

Closed art-lucas closed 3 months ago

art-lucas commented 3 months ago
# lsblk
NAME          MAJ:MIN RM  SIZE RO TYPE  MOUNTPOINTS
zram0         251:0    0   16G  0 disk  [SWAP]
nvme2n1       259:0    0  7.3T  0 disk  
└─md0           9:0    0 14.6T  0 raid0 
  └─cryptdata 252:2    0 14.6T  0 crypt /home/linux/Library
                                        /backup
nvme1n1       259:1    0  7.3T  0 disk  
└─md0           9:0    0 14.6T  0 raid0 
  └─cryptdata 252:2    0 14.6T  0 crypt /home/linux/Library
                                        /backup
nvme0n1       259:2    0  3.6T  0 disk  
├─nvme0n1p1   259:3    0 1022M  0 part  /boot/efi
├─nvme0n1p2   259:4    0    4G  0 part  /recovery
├─nvme0n1p3   259:5    0  3.6T  0 part  
│ └─cryptroot 252:0    0  3.6T  0 crypt /home/linux/VMWare
│                                       /home
│                                       /
└─nvme0n1p4   259:6    0    4G  0 part  
  └─cryptswap 252:1    0    4G  0 crypt [SWAP]

The following issue happened before reinstalling the system from scratch -- for a different reason. I thought that perhaps the filesystem was corrupt or there was a misconfig due to the fact that I got rid of LVM in the previous install, so I didn't bother investigating it further.

Right now, the OS is newly installed. This is what's happening. Upon running a package install via apt, timeshift (via timeshift-autosnap-apt) thinks that another instance is running:

# apt install gir1.2-gtop-2.0
Reading package lists... Done
Building dependency tree... Done
Reading state information... Done
The following NEW packages will be installed:
  gir1.2-gtop-2.0
0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded.
Need to get 15.0 kB of archives.
After this operation, 69.6 kB of additional disk space will be used.
Get:1 http://apt.pop-os.org/ubuntu jammy/main amd64 gir1.2-gtop-2.0 amd64 2.40.0-2build3 [15.0 kB]
Fetched 15.0 kB in 6s (2,657 B/s)          
Rsyncing /boot into the filesystem before the call to timeshift.
Rsyncing /boot/efi into the filesystem before the call to timeshift.
Another instance of this application is running (PID=8353)
Unable to run timeshift-autosnap-apt! Please close Timeshift and try again. Script will now exit...
E: Problem executing scripts DPkg::Pre-Invoke '/usr/bin/timeshift-autosnap-apt'
E: Sub-process returned an error code

If I disable timeshift-autosnap-apt, packages can be installed, but no other snapshot can be created.

Another instance of timeshift was indeed running:

# ps ax|grep times
   8353 ?        SNs    0:00 timeshift --check --scripted
   8377 ?        DN     0:00 mount /dev/dm-0 /run/timeshift/8353/backup
# ll /dev/mapper/
crw------- 1 root root 10, 236 Mar 31 11:49 control
lrwxrwxrwx 1 root root       7 Mar 31 11:49 cryptdata -> ../dm-2
lrwxrwxrwx 1 root root       7 Mar 31 11:49 cryptroot -> ../dm-0
lrwxrwxrwx 1 root root       7 Mar 31 11:49 cryptswap -> ../dm-1

This tends to happen when running timeshift with --scripted, but not always. It always happens via script, i.e., crontab, timeshift scripted or check, etc.

mount cannot be killed, even with -9. It's probably an IO error?

# lsof -p 8377
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.portal file system /run/user/1000/doc
      Output information may be incomplete.
COMMAND  PID USER   FD   TYPE DEVICE SIZE/OFF   NODE NAME
mount   8377 root  cwd    DIR   0,31      334   3073 /root
mount   8377 root  rtd    DIR   0,31      204    256 /
mount   8377 root  txt    REG   0,31    47488 259284 /usr/bin/mount
mount   8377 root  mem    REG   0,29          259284 /usr/bin/mount (path dev=0,31)
mount   8377 root  mem    REG   0,29           18237 /usr/lib/locale/locale-archive (path dev=0,31)
mount   8377 root  mem    REG   0,29           34149 /usr/lib/x86_64-linux-gnu/libc.so.6 (path dev=0,31)
mount   8377 root  mem    REG   0,29           35220 /usr/lib/x86_64-linux-gnu/libpcre2-8.so.0.10.4 (path dev=0,31)
mount   8377 root  mem    REG   0,29          259679 /usr/lib/x86_64-linux-gnu/libblkid.so.1.1.0 (path dev=0,31)
mount   8377 root  mem    REG   0,29           35419 /usr/lib/x86_64-linux-gnu/libselinux.so.1 (path dev=0,31)
mount   8377 root  mem    REG   0,29          259725 /usr/lib/x86_64-linux-gnu/libmount.so.1.1.0 (path dev=0,31)
mount   8377 root  mem    REG   0,29           33618 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2 (path dev=0,31)
mount   8377 root    0r   CHR    1,3      0t0      5 /dev/null
mount   8377 root    1w  FIFO   0,14      0t0  70988 pipe
mount   8377 root    2w  FIFO   0,14      0t0  70989 pipe

This is what I see in the logs for subsequent timeshift runs:

/var/log/timeshift# cat 2024-03-31_13-31-10_list-snapshots.log
[13:31:10] Main: check_dependencies()
[13:31:10] Another instance of this application is running (PID=8353)
# lsof -p 8353
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.portal file system /run/user/1000/doc
      Output information may be incomplete.
COMMAND    PID USER   FD   TYPE DEVICE SIZE/OFF   NODE NAME
timeshift 8353 root  cwd    DIR   0,31      334   3073 /root
timeshift 8353 root  rtd    DIR   0,31      204    256 /
timeshift 8353 root  txt    REG   0,31   354536 333252 /usr/bin/timeshift
timeshift 8353 root  mem    REG   0,29          333252 /usr/bin/timeshift (path dev=0,31)
   ...
   ...
timeshift 8353 root  mem    REG   0,29           33618 /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2 (path dev=0,31)
timeshift 8353 root    0r  FIFO   0,14      0t0  70971 pipe
timeshift 8353 root    1u   REG   0,31       74 385037 /tmp/#385037 (deleted)
timeshift 8353 root    2u   REG   0,31       74 385037 /tmp/#385037 (deleted)
timeshift 8353 root    3w   REG   0,31     1979 385042 /var/log/timeshift/2024-03-31_13-00-01_backup.log
timeshift 8353 root    4r  FIFO   0,14      0t0  70988 pipe
timeshift 8353 root    6r  FIFO   0,14      0t0  70989 pipe

Corresponding timeshift log:

# cat /var/log/timeshift/2024-03-31_13-00-01_backup.log
[13:00:01] Main: check_dependencies()
[13:00:01] Main: add_default_exclude_entries()
[13:00:01] Main: add_default_exclude_entries(): exit
[13:00:01] update_partitions()
[13:00:01] Device: get_disk_space_using_df(): 7
[13:00:01] Device: get_mounted_filesystems_using_mtab(): 4
[13:00:01] Device: get_filesystems(): 10
[13:00:01] partition list updated
[13:00:01] detect_system_devices()
[13:00:01] Searching subvolume for system at path: /
[13:00:01] Found subvolume: @, on device: /dev/dm-0
[13:00:01] Found subvolume: @home, on device: /dev/dm-0
[13:00:01] Found subvolume: @vmware, on device: /dev/dm-0
[13:00:01] Found subvolume: @backup, on device: /dev/dm-2
[13:00:01] Found subvolume: @library, on device: /dev/dm-2
[13:00:01] Users: root linux
[13:00:01] Encrypted home users: 
[13:00:01] Encrypted home dirs:
[13:00:01] Encrypted private dirs:
[13:00:01] Main: load_app_config()
[13:00:01] Member not found in JSON object: snapshot_size
[13:00:01] Member not found in JSON object: snapshot_count
[13:00:01] IconManager: init()
[13:00:01] found images directory: /usr/share/timeshift/images
[13:00:01] Main(): ok
[13:00:01] AppConsole: parse_arguments()
[13:00:01] Main: initialize_repo()
[13:00:01] backup_uuid=20519552-7423-46b8-af4b-fbdcef6e1f50
[13:00:01] backup_parent_uuid=7e1b2b2a-d964-4a16-b3df-e6b40724a120
[13:00:01] Using system disk as snapshot device for creating snapshots in BTRFS mode
[13:00:01] SnapshotRepo: from_device(): BTRFS
[13:00:01] SnapshotRepo: init_from_device()
[13:00:01] 
[13:00:01] SnapshotRepo: unlock_and_mount_devices()
[13:00:01] device=/dev/dm-0
[13:00:01] SnapshotRepo: unlock_and_mount_device()
[13:00:01] device=/dev/dm-0
[13:00:01] Device: get_mounted_filesystems_using_mtab(): 4
[13:00:01] ------------------
[13:00:01] arg=20519552-7423-46b8-af4b-fbdcef6e1f50, device=/dev/dm-0
[13:00:01] /home/linux/VMWare
[13:00:01] /home
[13:00:01] /
[13:00:01] ------------------
[13:00:01] Device: get_mounted_filesystems_using_mtab(): 4

Then, it appears to hang there, at get_mounted_filesystems_using_mtab(), while the hour before, it went further:

   ...
   ...
[12:00:02] clean_logs()
[12:00:02] rm -rf '/tmp/noVTRr0J'
[12:00:02] cleanup_unmount_devices()
[12:00:02] Device: get_disk_space_using_df(): 8
[12:00:02] Device: get_mounted_filesystems_using_mtab(): 4
[12:00:02] Device: get_filesystems(): 10
[12:00:02] 
Found stale mount for device '/dev/dm-0' at path '/run/timeshift/5958/backup'
[12:00:02] Unmounted successfully

grep 5958 /var/log/timeshift/* shows:

# grep 5958 *
2024-03-31_12-00-01_backup.log:[12:00:01] Mounted '/dev/dm-0 (nvme0n1p3)' at '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:01] Searching subvolume for system at path: /run/timeshift/5958/backup/@
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs qgroup show --raw '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs qgroup show '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] root_path=/run/timeshift/5958/backup/@
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:[12:00:02] btrfs subvolume list '/run/timeshift/5958/backup'
2024-03-31_12-00-01_backup.log:[12:00:02] loading snapshots from '/run/timeshift/5958/backup/timeshift-btrfs/snapshots': 14 found
2024-03-31_12-00-01_backup.log:Found stale mount for device '/dev/dm-0' at path '/run/timeshift/5958/backup'

All new attempts at creating a snapshot fail with another instance is running.

No errors on the NVMe itself.

# smartctl -A /dev/nvme0n1
smartctl 7.2 2020-12-30 r5155 [x86_64-linux-6.8.0-76060800daily20240311-generic] (local build)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF SMART DATA SECTION ===
SMART/Health Information (NVMe Log 0x02)
Critical Warning:                   0x00
Temperature:                        42 Celsius
Available Spare:                    100%
Available Spare Threshold:          10%
Percentage Used:                    0%
Data Units Read:                    16,347,757 [8.37 TB]
Data Units Written:                 30,069,569 [15.3 TB]
Host Read Commands:                 46,381,175
Host Write Commands:                179,888,952
Controller Busy Time:               356
Power Cycles:                       85
Power On Hours:                     89
Unsafe Shutdowns:                   50
Media and Data Integrity Errors:    0
Error Information Log Entries:      0
Warning  Comp. Temperature Time:    1
Critical Comp. Temperature Time:    0

Nothing related to nvme0n1 in syslog, or anything interesting in syslog around that time either:

# grep "^Mar 31 12:00:0[1-9]" /var/log/syslog
Mar 31 12:00:01 pop-os CRON[5958]: (root) CMD (timeshift --check --scripted)
Mar 31 12:00:02 pop-os crontab[6028]: (root) LIST (root)
Mar 31 12:00:02 pop-os crontab[6029]: (root) LIST (root)
Mar 31 12:00:02 pop-os systemd[1]: run-timeshift-5958-backup.mount: Deactivated successfully.

I'm not sure this is related:

# grep "^Mar 31 13:[0-1][0-9]" /var/log/syslog
Mar 31 13:00:01 pop-os CRON[8353]: (root) CMD (timeshift --check --scripted)
Mar 31 13:00:42 pop-os kernel: [ 4314.168947] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 10-...D } 334397 jiffies s: 849 root: 0x1/.
Mar 31 13:00:42 pop-os kernel: [ 4314.168965] rcu: blocking rcu_node structures (internal RCU debug): l=1:0-15:0x400/.
Mar 31 13:00:42 pop-os kernel: [ 4314.168971] Sending NMI from CPU 28 to CPUs 10:
Mar 31 13:00:42 pop-os kernel: [ 4314.169046] NMI backtrace for cpu 10 skipped: idling at intel_idle+0x72/0xe0
Mar 31 13:01:39 pop-os systemd[2380]: Started Application launched by gnome-shell.
Mar 31 13:01:41 pop-os timeshift-gtk.desktop[8829]: Another instance of this application is running (PID=8353)
Mar 31 13:01:41 pop-os timeshift-gtk[8829]: gtk_icon_theme_load_icon_for_scale: assertion 'GTK_IS_ICON_THEME (icon_theme)' failed
Mar 31 13:01:41 pop-os timeshift-gtk[8829]: gee_abstract_collection_get_size: assertion 'self != NULL' failed
Mar 31 13:03:30 pop-os PackageKit: refresh-cache transaction /185_becbcddd from uid 1000 finished with success after 5605ms
Mar 31 13:03:31 pop-os gnome-shell[3043]: Unhandled promise rejection. To suppress this warning, add an error handler to your promise chain with .catch() or a try-catch block around your await expression. Stack trace of the failed promise:#012  _promisify/proto[asyncFunc]@resource:///org/gnome/gjs/modules/core/overrides/Gio.js:420:16#012  openExtensionPrefs@resource:///org/gnome/shell/ui/extensionSystem.js:241:26#012  openPrefs@resource:///org/gnome/shell/misc/extensionUtils.js:227:26#012  _initializeMenu/<@/home/linux/.local/share/gnome-shell/extensions/Vitals@CoreCoding.com/extension.js:154:28
Mar 31 13:03:36 pop-os PackageKit: get-packages transaction /186_accdddda from uid 1000 finished with success after 1056ms
Mar 31 13:03:36 pop-os PackageKit: get-updates transaction /187_beeaddad from uid 1000 finished with success after 315ms
Mar 31 13:03:42 pop-os kernel: [ 4494.388919] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 10-...D } 379453 jiffies s: 849 root: 0x1/.

Then:

# grep timeshift-gt /var/log/syslog
Mar 30 18:23:11 pop-os timeshift-gtk.desktop[8077]: First run mode (config file not found)
Mar 30 18:23:11 pop-os timeshift-gtk.desktop[8077]: Selected default snapshot type: BTRFS
Mar 30 18:23:11 pop-os timeshift-gtk.desktop[8077]: App config loaded: /etc/timeshift/timeshift.json
Mar 30 18:23:11 pop-os timeshift-gtk.desktop[8077]: Mounted '/dev/dm-0 (nvme0n1p3)' at '/run/timeshift/8077/backup'
Mar 30 18:23:11 pop-os timeshift-gtk.desktop[8077]: Selected default snapshot device: /dev/dm-0
Mar 30 18:23:27 pop-os timeshift-gtk.desktop[8077]: Added cron task: /etc/cron.d/timeshift-hourly
Mar 30 18:23:27 pop-os timeshift-gtk.desktop[8077]: Added cron task: /etc/cron.d/timeshift-boot
Mar 30 18:23:27 pop-os timeshift-gtk.desktop[8077]: App config saved: /etc/timeshift/timeshift.json
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Creating new backup...(BTRFS)
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Saving to device: /dev/dm-0, mounted at path: /run/timeshift/8077/backup
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Created directory: /run/timeshift/8077/backup/timeshift-btrfs/snapshots/2024-03-30_18-23-30
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Created subvolume snapshot: /run/timeshift/8077/backup/timeshift-btrfs/snapshots/2024-03-30_18-23-30/@
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Created subvolume snapshot: /run/timeshift/8077/backup/timeshift-btrfs/snapshots/2024-03-30_18-23-30/@home
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Created control file: /run/timeshift/8077/backup/timeshift-btrfs/snapshots/2024-03-30_18-23-30/info.json
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: BTRFS Snapshot saved successfully (0s)
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: Tagged snapshot '2024-03-30_18-23-30': ondemand
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: ------------------------------------------------------------------------------
Mar 30 18:23:30 pop-os timeshift-gtk.desktop[8077]: btrfs: Quotas are not enabled
Mar 30 18:23:39 pop-os timeshift-gtk.desktop[8077]: App config saved: /etc/timeshift/timeshift.json
Mar 30 21:26:59 pop-os timeshift-gtk.desktop[10705]: App config loaded: /etc/timeshift/timeshift.json
Mar 30 21:26:59 pop-os timeshift-gtk.desktop[10705]: Mounted '/dev/dm-0 (nvme1n1p3)' at '/run/timeshift/10705/backup'
Mar 30 21:26:59 pop-os timeshift-gtk.desktop[10705]: btrfs: Quotas are not enabled
Mar 30 21:27:20 pop-os timeshift-gtk.desktop[10705]: App config saved: /etc/timeshift/timeshift.json
Mar 30 21:27:40 pop-os timeshift-gtk.desktop[10705]: App config saved: /etc/timeshift/timeshift.json
Mar 30 21:28:17 pop-os timeshift-gtk.desktop[10705]: App config saved: /etc/timeshift/timeshift.json
Mar 30 21:28:24 pop-os timeshift-gtk.desktop[10705]: App config saved: /etc/timeshift/timeshift.json
Mar 31 10:20:21 pop-os timeshift-gtk.desktop[6300]: App config loaded: /etc/timeshift/timeshift.json
Mar 31 10:20:21 pop-os timeshift-gtk.desktop[6300]: Mounted '/dev/dm-0 (nvme0n1p3)' at '/run/timeshift/6300/backup'
Mar 31 10:20:21 pop-os timeshift-gtk.desktop[6300]: btrfs: Quotas are not enabled
Mar 31 10:20:48 pop-os timeshift-gtk.desktop[6300]: App config saved: /etc/timeshift/timeshift.json
Mar 31 10:20:58 pop-os timeshift-gtk.desktop[6300]: App config saved: /etc/timeshift/timeshift.json
Mar 31 10:21:02 pop-os timeshift-gtk.desktop[6508]: App config loaded: /etc/timeshift/timeshift.json
Mar 31 10:21:02 pop-os timeshift-gtk.desktop[6508]: Mounted '/dev/dm-0 (nvme0n1p3)' at '/run/timeshift/6508/backup'
Mar 31 10:21:02 pop-os timeshift-gtk.desktop[6508]: btrfs: Quotas are not enabled
Mar 31 10:21:07 pop-os timeshift-gtk.desktop[6508]: App config saved: /etc/timeshift/timeshift.json
Mar 31 10:21:09 pop-os timeshift-gtk.desktop[6508]: App config saved: /etc/timeshift/timeshift.json
Mar 31 13:01:41 pop-os timeshift-gtk.desktop[8829]: Another instance of this application is running (PID=8353)
Mar 31 13:01:41 pop-os timeshift-gtk[8829]: gtk_icon_theme_load_icon_for_scale: assertion 'GTK_IS_ICON_THEME (icon_theme)' failed
Mar 31 13:01:41 pop-os timeshift-gtk[8829]: gee_abstract_collection_get_size: assertion 'self != NULL' failed
# ll /run/timeshift/
drwxr-xr-x 2 root root 40 Mar 31 13:31 14761/
drwxr-xr-x 2 root root 40 Mar 31 14:00 18628/
drwxr-xr-x 3 root root 60 Mar 31 13:00 8353/ << This is the hung process
drwxr-xr-x 2 root root 40 Mar 31 13:00 8490/
drwxr-xr-x 2 root root 40 Mar 31 13:01 8829/
drwxr-xr-x 2 root root 40 Mar 31 13:02 9086/
# ll /run/timeshift/*
/run/timeshift/14761:
total 0

/run/timeshift/18628:
total 0

/run/timeshift/8353:
total 0
drwxr-xr-x 2 root root 40 Mar 31 13:00 backup/

/run/timeshift/8490:
total 0

/run/timeshift/8829:
total 0

/run/timeshift/9086:
total 0

# ll /run/timeshift/8353/backup/
total 0
# ps ax | egrep "14761|18628|8353|8490|8829|9086"
   8353 ?        SNs    0:00 timeshift --check --scripted
   8377 ?        DN     0:00 mount /dev/dm-0 /run/timeshift/8353/backup

The "weird" thing is there's no trace of these processes in the timeshift logs:

# egrep "14761|18628|8353|8490|8829|9086" *
2024-03-31_13-00-23_ondemand.log:[13:00:23] Another instance of this application is running (PID=8353)
2024-03-31_13-01-40_gui.log:[13:01:41] Another instance of this application is running (PID=8353)
2024-03-31_13-02-53_ondemand.log:[13:02:53] Another instance of this application is running (PID=8353)
2024-03-31_13-31-10_list-snapshots.log:[13:31:10] Another instance of this application is running (PID=8353)
2024-03-31_14-00-01_backup.log:[14:00:01] Another instance of this application is running (PID=8353)

Killing the running timeshift process and executing a timeshift commands aftwards hangs:

# kill 8353
# timeshift --list
[Warning] Deleted invalid lock

^C
# timeshift --list
[Warning] Deleted invalid lock

^C

The only way to take further snapshots is to issue a reboot, followed by a hard shutdown /restart (stay on the power button).

art-lucas commented 3 months ago

After some browsing, I see that /dev/dm-X entries are typically LVM devices. If that's the case (?), why does my system have them considering that I am not using LVM (see lsblk above)?

art-lucas commented 3 months ago

I know that PopOS creates a LVM group (data) under the 3rd partition, here nvme0n1p3 with only one logival volume (root), which I found useless and luks-formatted nvme0n1p3 directly. Could that be the reason?

art-lucas commented 3 months ago

After killing the above timeshift process and let it run for a while:

# ps ax | grep timeshift
   8377 ?        DN     0:00 mount /dev/dm-0 /run/timeshift/8353/backup
  34251 pts/0    DN     0:00 mount /dev/dm-0 /run/timeshift/34227/backup
  34295 pts/0    DN     0:00 mount /dev/dm-0 /run/timeshift/34271/backup
  36828 ?        SNs    0:00 timeshift --check --scripted
  36853 ?        DN     0:00 mount /dev/dm-0 /run/timeshift/36828/backup
# ll /run/timeshift/
drwxr-xr-x 2 root root 40 Mar 31 13:31 14761/
drwxr-xr-x 2 root root 40 Mar 31 14:00 18628/
drwxr-xr-x 2 root root 40 Mar 31 15:00 26799/
drwxr-xr-x 2 root root 40 Mar 31 15:43 34160/
drwxr-xr-x 3 root root 60 Mar 31 15:43 34227/
drwxr-xr-x 3 root root 60 Mar 31 15:43 34271/
drwxr-xr-x 3 root root 60 Mar 31 16:00 36828/
drwxr-xr-x 2 root root 40 Mar 31 17:00 43132/
drwxr-xr-x 3 root root 60 Mar 31 13:00 8353/
drwxr-xr-x 2 root root 40 Mar 31 13:00 8490/
drwxr-xr-x 2 root root 40 Mar 31 13:01 8829/
drwxr-xr-x 2 root root 40 Mar 31 13:02 9086/
# ll /run/timeshift/*
/run/timeshift/14761:
total 0

/run/timeshift/18628:
total 0

/run/timeshift/26799:
total 0

/run/timeshift/34160:
total 0

/run/timeshift/34227:
total 0
drwxr-xr-x 2 root root 40 Mar 31 15:43 backup/

/run/timeshift/34271:
total 0
drwxr-xr-x 2 root root 40 Mar 31 15:43 backup/

/run/timeshift/36828:
total 0
drwxr-xr-x 2 root root 40 Mar 31 16:00 backup/

/run/timeshift/43132:
total 0

/run/timeshift/8353:
total 0
drwxr-xr-x 2 root root 40 Mar 31 13:00 backup/

/run/timeshift/8490:
total 0

/run/timeshift/8829:
total 0

/run/timeshift/9086:
total 0
art-lucas commented 3 months ago

I ended up reinstalling the OS with the standard PopOS layout, i.e., with LVM group/lv @ /dev/data/root instead of luks-formatting nvme0n1p3 out of the box:

# lsblk
NAME            MAJ:MIN RM  SIZE RO TYPE  MOUNTPOINTS
   ...
   ...
nvme0n1         259:2    0  3.6T  0 disk  
├─nvme0n1p1     259:3    0 1022M  0 part  /boot/efi
├─nvme0n1p2     259:4    0    4G  0 part  /recovery
├─nvme0n1p3     259:5    0  3.6T  0 part  
│ └─cryptroot   252:0    0  3.6T  0 crypt 
│   └─data-root 252:1    0  3.6T  0 lvm   /home/linux/VMWare
│                                         /home
│                                         /
└─nvme0n1p4     259:6    0    4G  0 part  
  └─cryptswap   252:2    0    4G  0 crypt [SWAP]

So far, after extensively using btrfs & timeshift, I have not seen the issue yet.