Profile with Propagate Deletion works manually, but deletes everything when running from schedule.

Comments

• gchen

  November 2014

  I couldn't reproduce the issue.  Basically I replicated everything you had, including the exclude patterns you used, and I also synced my iTunes directory.

  
  

  I also double checked the code -- both update and backup modes follow the same code path with respect to setting include/exclude patterns, so it is very strange that the results would differ.

  
  

  Can you show me this line in your log?  what is the total bytes?

  
  

  12:35:02    Uploaded 0 files; total 110006689 bytes, skipped 110006689 bytes, sent 0/0 bytes

  
  
• DaVig

  November 2014

  Ok, thanks, will do.

  
  

  1) I re-started it, let it do a full re-sync.  All good.

  2) "Stopped" it, modified a couple files, tweaked the schedule so that it would run again, "Started" it.  All good - the updates went up, no deletes.

  3) "Stopped" it again, added an additional test exclude, tweaked the schedule so it would run again, "Started" it. All good - no changes (0 files).

  4) "Stopped" it again, removed the test exclude, tweaked the schedule so it would run again, "Started" it. All good - no changes (0 files).

  
  

  5) "Stopped" it again, tweaked the schedule to it's normal time late tonight.  Will leave it and wait for the results since the above seems to indicate I may just be crazy even though the deletions I swear have happened on multiple occasions before :)

  
  

  Thanks!

  -DV

  
  
• DaVig

  November 2014 edited November 2014

  Hi gchen,

  
  

  Here's are the results of runs occurring after the ones in the prior post:

  
  

  6) Regular run at 11pm on 11/4.  I left the Acrosync app open in the foreground, with the screen blank/locked.  All good still.  

  23:00:01    rsync command: rsync --server --modify-window=2 --out-format=%n --links --recursive --delete-during -tude. .

  music-share/iTunes/

  23:00:02    Add pattern: - /.acrosync/

  23:00:02    Add pattern: - .DS_Store

  23:00:02    Add pattern: - /Album*Artwork

  23:00:02    Add pattern: - /Album*Artwork/***

  ... [a bunch more Add patterns)

  23:00:11    Uploaded 0 files; total 37144733796 bytes, skipped 37144733796 bytes, sent 0/0 bytes

  
  

  7) Regular run at 11pm on 11/5.  With the Acrosync app hidden, but running green in menu bar.  Everything deleted!

  09:17:35    Acrosync for Mac 1.4 build 411 initialized

  23:00:07    Performing a full backup of /Users/[user]/Music/iTunes

  23:01:36    Deleted iTunes Media/Music/Zac Brown Band/Uncaged/11 Last But Not Least.m4a remotely

  ... [~8K more deletes]

  23:01:36    Deleted iTunes Media/Music remotely

  23:01:36    Deleted iTunes Media remotely

  23:01:36    Deleted sentinel remotely

  23:01:36    Deleted iTunes Library.xml remotely

  23:01:36    Deleted iTunes Library.itl remotely

  23:01:36    Deleted iTunes Library Genius.itdb remotely

  23:01:36    Deleted iTunes Library Extras.itdb remotely

  
  

  So fortunately (or unfortunately?) I'm not crazy - at least related to this.  Perhaps the deletions are in some way caused by the fact it is running in the "background" or it's just random. I changed nothing in the profile between runs 6 & 7. System log points to sandboxing:

    11/5/14 11:00:07.771 PM sandboxd[284]: ([286]) Acrosync(286) deny file-read-data /Users/[user]/Music/iTunes

  
  

  From the night before I just see a vague reference about failed validation at that time - not sure if related to Acrosync since things worked for that run:

    11/4/14 11:00:05.678 PM usernoted[227]: Failed to validate application at (null) -67071

  
  

  
  

  A few other interesting things about the Acrosync log:

  a) The initialize line at 09:17:35 - I rebooted the machine around then for some other reason (messes with my test case a bit).

  b) There's no rsync command or Add patterns after the second line in log.

  c) There's no final line at all showing file/byte counts, the log just ends after the last Deleted line.

   

  
  

  Perhaps something related to the system reboot, Acrosync initializing, and sandboxing?  Let me know your thoughts.

  
  

  Thanks!

  -DVig

  
  
• gchen

  November 2014

  Such a nasty bug!

  
  

  What happened here was that somehow the security bookmark used to access the source directory failed after the reboot, so Acrosync saw an empty directory and forced the server to remove everything.  It should have at least thrown out an error and then given up.

  
  

  I'll submit a fix as soon as possible.  The workaround in the mean time is to disable the 'Propagate Deletions' option.  
• gchen

  November 2014

  found the root cause.  When profiles are started on startup, the security bookmarks are not used to access the directory.  That is why you saw the denial message in the system log.

  
  

  Hope you didn't lose any files due to this bug.  I'll submit a fix later today.
• DaVig

  November 2014

  Great!  Glad you were able to track it down. Also glad for the random reboot since it turned out to be part of the root cause - so much for my well-thought-out test case, lol.
  
  No files lost - everything is backed up elsewhere and this is just to refresh the media server.
  
  I'll keep an eye out for the update. Thanks.
  
  Cheers,
  -DV
  
• gchen

  November 2014

  Despite some earlier issue with App Store, the build went through and version 1.5 is now waiting for review.  Let's see how long the review takes this time (if I remember correctly, the last two times it took one day).
• gchen

  November 2014

  Version 1.5 is now available in the Mac App Store.

  
  

  To verify the fix, you can run the following command in a terminal:

  
  
  
  
  
  
  

  open acrosync://launchedAtLogin

  This is the same command to automatically start Acrosync at login.

  
  
• DaVig

  November 2014

  Hi,

  
  

  Downloaded and have been testing for a few days.  Seems to be working great after restarts now.  Thanks!

  
  

  Cheers,

  -Dan