anacron jobs starts too soon after udev triggered backup

[Istvan Gyorsok]

backintime-gnome/common 1.0.34-0.1 (ubuntu)

When creating an udev triggered, encrypted local backup to a USB attached disk from the gnome gui, the anacrontab line created fires the backintime backup job immediately after udev triggers anacron, which seems to be too early.
Jun 22 10:39:22 uh552 backintime (isti): INFO: Lock
Jun 22 10:39:22 uh552 backintime (isti): ERROR: A titkosított mappa konfigurációja nem található
Jun 22 10:39:22 uh552 backintime (isti): INFO: Unlock

For some reason, encfs can't find it's config. The syslog roughly translated: "Cannot find encrypted folder config".

If I just add a minute delay to the anacron_line, everything works fine. A few seconds would probably suffice, but it seems only minutes can be specified for anacron.

Non-encrypted backup does not seem to need this delay.

[Germar (germar)]

Thanks for the patch. I didn't add the 1min delay because I think it's confusing for people who test the udev/anacron schedule. They might think it doesn't work and fiddle around during the minute.

Anyways, it turns out anacron wasn't the best choice. I'll have to rewrite the part of anacron by my self because anacron does always mark a job as done for the day even if BIT failed.

[Germar (germar)]

Found an easy solution for this by letting BackInTime wait 30sec for snapshot folder come available even if notifications are disabled. Please try out attached patch with 'sudo patch /usr/share/backintime/common/snapshots.py < snapshots.patch'

[Mauro (mauromol)]

Hi Germar,
with 1.1.2 I still get this problem. As sson as I plug in the device, the BIT tray icon appears saying it can't find the folder and suggests to wait 30 seconds. But it doesn't start automatically then, I must manually start the backup process from the GUI...

Any idea?

[Germar (germar)]

Hi Mauro,

Could you please attach your syslog starting from first udev messages about the new connection?

Regards,
Germar

[Mauro (mauromol)]

Here is is:

Feb 4 22:19:00 hppb kernel: [ 7615.521927] usb 3-3: new high-speed USB device number 8 using xhci_hcd
Feb 4 22:19:00 hppb kernel: [ 7615.541705] usb 3-3: New USB device found, idVendor=1bcf, idProduct=0c31
Feb 4 22:19:00 hppb kernel: [ 7615.541709] usb 3-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 4 22:19:00 hppb kernel: [ 7615.541711] usb 3-3: Product: USB to Serial-ATA bridge
Feb 4 22:19:00 hppb kernel: [ 7615.541713] usb 3-3: Manufacturer: Sunplus Innovation Technology
Feb 4 22:19:00 hppb kernel: [ 7615.541714] usb 3-3: SerialNumber: FDC0FD10EA00000FD0FCAF55667939
Feb 4 22:19:00 hppb kernel: [ 7615.543532] usbip-host 3-3:1.0: 3-3 is not in match_busid table... skip!
Feb 4 22:19:00 hppb kernel: [ 7615.543550] usb-storage 3-3:1.0: USB Mass Storage device detected
Feb 4 22:19:00 hppb kernel: [ 7615.543607] scsi7 : usb-storage 3-3:1.0
Feb 4 22:19:00 hppb mtp-probe: checking bus 3, device 8: "/sys/devices/pci0000:00/0000:00:14.0/usb3/3-3"
Feb 4 22:19:00 hppb mtp-probe: bus: 3, device: 8 was not an MTP device
Feb 4 22:19:00 hppb laptop-mode: Laptop mode
Feb 4 22:19:00 hppb laptop-mode: enabled, not active
Feb 4 22:19:00 hppb laptop-mode: Laptop mode
Feb 4 22:19:00 hppb laptop-mode: enabled, not active
Feb 4 22:19:01 hppb kernel: [ 7616.548233] scsi 7:0:0:0: Direct-Access WDC WD10 EADS-11M2B1 0200 PQ: 0 ANSI: 4
Feb 4 22:19:01 hppb kernel: [ 7616.548469] sd 7:0:0:0: Attached scsi generic sg2 type 0
Feb 4 22:19:01 hppb kernel: [ 7616.549535] sd 7:0:0:0: [sdb] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
Feb 4 22:19:01 hppb kernel: [ 7616.556319] sd 7:0:0:0: [sdb] Write Protect is off
Feb 4 22:19:01 hppb kernel: [ 7616.556323] sd 7:0:0:0: [sdb] Mode Sense: 38 00 00 00
Feb 4 22:19:01 hppb kernel: [ 7616.563195] sd 7:0:0:0: [sdb] No Caching mode page found
Feb 4 22:19:01 hppb kernel: [ 7616.563209] sd 7:0:0:0: [sdb] Assuming drive cache: write through
Feb 4 22:19:01 hppb kernel: [ 7616.577746] sd 7:0:0:0: [sdb] No Caching mode page found
Feb 4 22:19:01 hppb kernel: [ 7616.577760] sd 7:0:0:0: [sdb] Assuming drive cache: write through
Feb 4 22:19:01 hppb kernel: [ 7616.640281] sdb: sdb1 sdb2
Feb 4 22:19:01 hppb kernel: [ 7616.655220] sd 7:0:0:0: [sdb] No Caching mode page found
Feb 4 22:19:01 hppb kernel: [ 7616.655225] sd 7:0:0:0: [sdb] Assuming drive cache: write through
Feb 4 22:19:01 hppb kernel: [ 7616.655228] sd 7:0:0:0: [sdb] Attached SCSI disk
Feb 4 22:19:01 hppb kernel: [ 7617.025578] btrfs: device label WDC-Green devid 1 transid 832 /dev/sdb1
Feb 4 22:19:01 hppb kernel: [ 7617.026076] btrfs: device label WDC-Green devid 2 transid 832 /dev/sdb2
Feb 4 22:19:01 hppb kernel: [ 7617.049763] btrfs: device label WDC-Green devid 1 transid 832 /dev/sdb1
Feb 4 22:19:01 hppb kernel: [ 7617.050255] btrfs: device label WDC-Green devid 2 transid 832 /dev/sdb2
Feb 4 22:19:01 hppb anacron[7182]: Anacron 2.3 started on 2015-02-04
Feb 4 22:19:01 hppb anacron[7183]: Anacron 2.3 started on 2015-02-04
Feb 4 22:19:01 hppb anacron[7183]: Job `1_Profilo_principale' locked by another anacron - skipping
Feb 4 22:19:01 hppb anacron[7182]: Will run job `1_Profilo_principale' in 0 m...

[Germar (germar)]

First of all you still use the old method with anacron. Starting with 1.1.0 I included anacrons function into BIT and start BIT directly from udev (anacron is not used anymore). Please open Settingsdialog and press OK for both root and user mauro. BIT will automatically install the new udev rules.

The notification 'Can't find snapshot folder' will be shown as soon as BIT start to take a new snapshot but couldn't find the folder. Then it will wait for 30sec (or to be correct it waits 30x 1sec and retry) for the snapshot folder. If that failed it will write the error message to syslog and exit.

Does your drive auto-mount correctly? How log does it take? Would it help to increase the timeout? Please try attached patch with 'sudo patch /usr/share/backintime/common/snapshots.py < timeout.diff'

Sure, it would be great to start the new snapshot as soon as the device is mounted. But Udev doesn't provide that information and there is no other way to get this to work on every DE.

[Germar (germar)]

Sorry, forgot to attach the patch

[Mauro (mauromol)]

This evening I will try to update my profiles, thank you! By the way, shouldn't this kind of update a good candidate for automatic execution on BIT deb package update? Or at least on first BIT start, when it detects the profile is still using the old anacron rules...

I will also try your patch and let you know. By the way, regarding the automatic mounting, it's something I should investigate further. In theory, I have auto-mounting enabled for all already known devices in KDE settings, however the drive I have my backups into, which has a BTRFS filesystem, seems not to mount automatically. Anyway, if I mount it manually within 30 seconds BIT should work well, am I correct?

[Germar (germar)]

package updates only run as root. This must be done as your own user. On first start would've been an option. But if someone wouldn't start BIT after upgrade this wouldn't help. So I needed to make it work even with the old rule which was no big deal. And as this was not critical I made this update with the normal Settings.

Yes. If you mount it during this 30sec BIT should be fine.

[Mauro (mauromol)]

After I updated my scheduled tasks, BIT behaviour seems to be more polite: I don't get a notification about the fact that the target backup folder is missing as soon as I connect the drive, while the backup starts after some seconds if I mount the partition.
Anyway, what is strange is that I now have 3 backup profiles (two as my normal user, one as root) and they have just started all of them at the same time!! Since the target folders are all on the same device (a traditional hard disk), I don't think this is optimal... Is this the supposed behaviour? I can't remember this happening before, but it could have been just a coincidence.

[Mauro (mauromol)]

There's also a small glitch. If I open the BIT main window while the two profiles for my normal user are running, I can see the correct progress information for each of these running profiles in the status bar. But if I hold the mouse cursor over the two BIT icons in the system tray, both of them show the progress of the first of these two profiles (the main profile) i.e. they both show the file being copied by the first running profile.