Recycle not working on backups previously of APFS SSD

[DavidHertzberg]

As many of you know, I follow the 20th Century practice of backing up onto one of 3 portable HDDs formatted with HFS+, one of which I rotate each week—after 7 preceding days of use—into a bank safe deposit box.  Each Saturday, when I rotate the next of my portable HDDs back into use, I Recycle its associated Media Set—first with a "sacrificial" script and then with a "real" script that backs up 3 drives and a Favorite folder.   My MacBook Pro's SSD—formatted with APFS since 2 April—is the first one backed up in the "real" Recycle script on Saturdays, and the only one backed up in the Saturday "sacrificial" script.  After that SSD (the only drive on my MacBook Pro) was reformatted with APFS on 2 April 2019, I got:

• 6 April 2019 "Media Set White"—which had been backed up on 16 March starting with HFS+ SSD: OK on both "sacrificial" and "real" scripts
• 13 April 2019 "Media Set Blue"—which had been backed up on 23 March starting with HFS+ SSD: "sacrificial" script was stopped after many  "!Error reading snapshot record at ...", Rebuild from portable HDD, OK on "real script
• 20 April 2019 "Media Set Red"—which had been backed up on 5 April starting with HFS+ SSD : OK on both "sacrificial" and "real" scripts
• 27 April 2019 "Media Set White": "sacrificial" script was stopped 16 minutes after "!Error reading snapshot record at 61653107172u", Rebuild from portable HDD, OK on "real script
• 4 May 2019 "Media Set Blue": "sacrificial" script failed with "!Can't reset Backup Set Media Set Blue, error -1,102 (drive missing/unavailable)", "real" script showed No Media Action—stopped, Rebuild from portable HDD, OK on "real" script
• 11 May 2019 "Media Set Red": "sacrificial" script failed with "!Can't reset Backup Set Media Set Red, error -1,102 (drive missing/unavailable)",  Rebuild from deleted Media Set Red on portable HDD, OK on "real" script

I also run "sacrificial" scripts, which use the No Files rule, before the No Media Action "real" scripts I run to backup my MBP the other 6 days of the week.  There have been no problems with these No Media Action "sacrificial" or "real" scripts.

I wasn't having any of the above  Recycle problems with my portable HDDs up through 30 March, while the SSD on my MBP was still formatted with HFS+ .

P.S.: Slightly cut down so the part through the itemized list could fit in the Problem Statement, I have turned the contents of this into Support Case #67777.

Edited May 13, 2019 by DavidHertzberg
P.S. to say I have turned this into a Support Case

[DavidHertzberg]

Quote

Retrospect Agent Reply can be found below. 

Agent Response: 
The issue is this specific error: 
!Backup Set member "1-Media Set Red": error -1,102 (drive missing/unavailable) 
!Can't reset Backup Set Media Set Red, error -1,102 (drive missing/unavailable) 
It looks like Retrospect could not find this media during a recycle backup attempt. 
Do you know the status of the media when this error was reported? 
Retrospect version 16.1 has been released, please update to the latest version.

To which I replied [start-end underscored words changed to underlined words, which the Forums allow but the Support Case software doesn't]:

"G-DRIVE Red", which is a USB2 portable HDD, was—and still is—cabled to my Mac Pro "backup server". Note that, as soon as the "sacrificial" script terminated on 11 May with the -1102 error. the "real" script began to run. It proceeded several minutes after logging "Finished scanning backup set data files" before I stopped it, which I did because the Summary was showing that the run was methodically examining the existing files in "Media Set Red"—despite all 3 schedules for the script specifying Recycle. Then, after I did a Rebuild of "Media Set Red"—which I stopped after the log said "Adding to 29.9 GB of backup set data, starting at file index 51", I'm pretty sure I Finder-deleted file "1-Media Set Red" on "G-DRIVE Red" and Removed/reAdded "Media Set Red"—which doesn't show in the log. After that a Repeat Never schedule of the same "real" script to "Media Set Red" ran OK.

Note that the same sequence of script runs the previous Saturday 4 May to "Media Set Blue", with its member on "G-DRIVE Blue", got pretty much the same results. The only differences are that I manually-scheduled a run of the "real" script I created after stopping the automatically-scheduled run, and stopped that run after it logged "!Cannot find parent directory for file Scalloped-Frame-V-2.png in backup 4/13/19 4:06:29 AM"—which certainly implies that it wasn't doing a Recycle, and that I let the subsequent Rebuild for the existing "1-Media Set Blue" run over an hour to completion.

I alternate portable HDDs weekly between 2 USB-A-to-USB-Mini cables attached to different built-in ports on the back of my Mac Pro "backup server". Note also that these 3 portable HDDs always work fine for the rest of the week's No Media Action scheduled runs. So, despite my not having attended Hogwarts, I think there's a bug in Retrospect Mac 16.0 for Recycle.

I will now proceed to upgrade to Retrospect Mac 16.1 for both Engine-Console and Client.

[DavidHertzberg]

As you can see from the color-named progression ("three cheers for the Red, White, and Blue") of my Media Sets in the OP, this morning I was scheduled to do my Saturday Recycle backup to "Media Set White"—whose "1-Media Set White" Member is on portable HDD "G-DRIVE White".  Since the Retrospect Agent Reply in the post directly above this evinces a certain skepticism about whether my portable HDDs have been properly cabled to my Mac Pro "backup server" when I switched them, after I had yesterday un-cabled "G-DRIVE Red" (to take it to my bank safe deposit box) and cabled "G-DRIVE White"  I ran a  "sacrificial" script with No Media Action backing up my MacBook Pro's SSD to "1-Media Set White".  This ran OK in 4 minutes. I then scheduled a repeat of the same "sacrificial" script to run 5 minutes before the "sacrificial" script with Recycle backing up to "1-Media Set White" early this morning.

All three scripts ran OK in succession early this morning backing up to "1-Media Set White" : the No Media Action "sacrificial" script backing up my MBP ,  followed by the Recycle "sacrificial" script backing up my MBP, followed by the Recycle "real" script backing up my 4 drives—starting with my MBP's SSD—and a Favorite Folder.  I have to admit I was disappointed with missing the opportunity to demonstrate my bug-proving prowess to Retrospect Tech Support.

I can think of only 3 possibilities for why the Saturday scripts ran OK this morning:

1. My "G-DRIVE"'s cables had previously been jiggled loose by me or my cleaning lady on previous Fridays, but not yesterday.  This seems unlikely, because I'm pretty careful and because my cleaning lady only comes on alternate Fridays.
2. One of my two "backup server" USB3 cables, which are swapped into use every Friday morning, is defective.  This seems unlikely, both because the OP shows failures on four successive Saturdays and because the same two cables worked fine connecting "G-DRIVE"' portable HDDs on Sundays through Fridays.
3. On Friday morning I upgraded to Retrospect Mac 16.1 from 16.0.  Whoever wrote the Retrospect Agent Reply in the post directly above this made that upgrade suggestion; maybe he/she knew knew something about an undocumented bug fix involving Recycle and APFS.

I'll test again next Saturday morning.

 

 

[DavidHertzberg]

I originally posted this on 25 May (as shown in the right-most column of the thread listing), but it was deleted by Retrospect Inc.—evidently sometime after 6 June 2019 03:35 when I copied it as an Additional Note to Support Case #67777—because they considered a final paragraph I've now omitted to be overly critical of Retrospect Inc. engineers.  This happens, as I warned you in the third paragraph here!

Both the Recycle backup scripts—the "sacrificial" one and the "real" one—ran OK early 25 May morning to "Media Set Blue". Of the possibilities discussed here up-thread:

1. I simply pushed the USB3 cable firmly into "G-DRIVE Blue" late 24 May morning; I didn't take special precautions. This wasn't the week for my cleaning lady, but last week—when the scripts also all ran successfully—was.
2. The USB3 cable I used was the same one that was used when I had problems two Saturdays ago.
3. I had upgraded my "backup server" to Retrospect Mac 16.1.0 before last Saturday's run, and I upgraded it to 16.1.1 on Thursday.

So possibility 3 is the winner. The Retrospect Inc. engineers must have fixed the Recycle bug in 16.1.0, even though there's no mention of that in the cumulative Release Notes. I can't believe they released 16.0 without having tested Recycle for APFS-built Media Sets; I too would be ashamed!

[DavidHertzberg]

After I downloaded Retrospect Mac 16.1.2.102, both the Recycle backup scripts—the "sacrificial" one and the "real" one—started to run OK early 1 June morning to "Media Set Red".  However, after the "sacrificial" script ran OK, two things happened while the "real" script was running:

• The backup of my MacBook Pro "client" failed after 1.5 hours with -559 (network connection timeout).  The script continued with my local drives.
• After the script backed up and compared my late friend's local "Macintosh HD" and backed up my local "Macintosh HD SSD", it failed with -116 (volume doesn't exist) when I gently (I thought) picked up "G-DRIVE Blue" to look at its bottom masking-tape label one minute into the compare.

 

[DavidHertzberg]

I stopped the "sacrificial" script early 8 June morning after 19 minutes when it issued  "!Error reading snapshot record ...", which it shouldn't have been doing because the script specified Recycle.  I did a Rebuild of "Media Set White" from portable HDD "G-DRIVE White" , and the "real script started to run OK—until it failed with a -519 (network communication failed) error after 4 minutes when I absent-mindedly shut down my MacBook Pro "client" preparatory to going back to bed.