Mass File Deletion when Moving Recordings

[sagetvuser489]

I'm a pretty enthusiastic SageTV user, having the software running in one form or another for over a decade. I offer my thanks to the entire community of supporters of this software, everyone from Narflex to the most recent committer, for their efforts to keep this incredibly useful software alive.

Because this software is so useful I'd like to get your help with an issue where SageTV conducted a mass-deletion of about half of all the recordings I had on a test server. The recording purge event happened immediately after I moved several recordings between my TV storage directories using the "advanced_video_file_recovery=true" method. I'd like the community's advice on how to prevent the purge event from happening in the first place and to understand how I may have caused it. If any project contributors read this, I'd also be interested if you'd recommend filing an issue on GitHub, or if this is just user error.

While my description of this problem includes an overview of my work-around to it, I don't really consider that setting some of my TV recording directories as read-only is a viable option in the long-term. SageTV expects to be able to create, delete and modify all TV recording directories (and it usually does a fine job of it) so if there is another work-around to this issue in 9.2.2 I'm all ears. For now, I've designated a specific TV recording directory as read-only and am using "seeker/video_storage" size limits to fool SageTV into thinking it should not ever record there. I move recordings that SageTV shouldn't be deleting (keep-all favorites, etc) to the read-only share, and leave recordings that SageTV should be manipulating on the read-write share.

Steps for Replication

1. Install SageTV V9.2.2.268 (JVM version=11.0.9.1) on Ubuntu Desktop 20.04.1, set multiple TV storage folders and allow system to accumulate recordings
   a. TV storage folders are specified as: seeker/video_storage=/var/media/tv,1000000,1;/media/01/media01/tv,944000000000,1;/media/01/media01/tv2,200000000000,2;
   b. Yes, the Linux default recording directory has a customized size limit because I don't want SageTV using local storage. Refer to https://forums.sagetv.com/forums/showthread.php?t=49015.
   c. The directories '/media/01/media01/tv' and '/media/01/media01/tv2' represent NFS mounts on remote storage. Mount '/media/01/media01/tv' is read-only, to prevent this 'recordings purge' issue. Mount '/media/01/media01/tv2' is read-write, and as you will see has it's recordings purged. Both mounts use the same underlying virtual disk.
2. Before making any changes use a SageTV client to examine the 'Current Recordings' view and note how many recordings there are. I observed the number of recordings to be 839.
3. Stop the SageTV server
4. Follow Opus4's instructions under "The Advanced Method" for moving most TV recordings from '/media/01/media01/tv2' to the read-only '/media/01/media01/tv'. Reference https://forums.sagetv.com/forums/showthread.php?t=30697. [edit: fixed URL from original posting] I used a command something like "mv -v /media/01/media01/tv2/*.ts /media/01/media01/tv/" and "mv -v /var/media/tv/*.ts /media/01/media01/tv/" to transfer the recordings.
5. Once the file move is complete, re-start the SageTV software ensuring that "advanced_video_file_recovery=true"
6. As SageTV starts, observe that the recovery kicks off (alphabetically by file name?) and that some files are identified as being recovered [Log indicates "Found matching media file for recovery of ..."]. I noticed that this list includes about 492 files which represent a mix of files that I had moved and some that I hadn't. From my sagetv_1.txt log.
   
   

   	Sat 1/9 1:38:43.618 [main@1218025c] Checking encoder key:190004967
   	Sat 1/9 1:38:43.618 [main@1218025c] EncoderMap1={}
   	Sat 1/9 1:38:43.618 [main@1218025c] devices detected=[]
   	Sat 1/9 1:38:43.618 [main@1218025c] EncoderMap={pipe-01 on encode.computer.local:9000=pipe-01 on encode.computer.local:9000}
   	Sat 1/9 1:38:43.618 [main@1218025c] Splash: SageTV Core is initializing...
   	Sat 1/9 1:38:43.633 [main@1218025c] Checking video directories for new files
   	Sat 1/9 1:38:43.645 [main@1218025c] Found matching media file for recovery of /media/01/media01/tv/AlienCovenant-4164747-0.ts to be MediaFile[id=4490943 A[4164747,4157766,"Alien: Covenant",14988@0106.20:00,140,T] mask=TV host=encode encodedBy=pipe-01 on encode.computer.local:9000 Great-H.264 format=MPEG2-TS 0:00:00 0 kbps [] /var/media/tv/AlienCovenant-4164747-0.ts, Seg0[Wed 1/6 20:00:00.002-Wed 1/6 22:20:00.001]]
   	Sat 1/9 1:38:43.653 [main@1218025c] Using internal format detector first for: /media/01/media01/tv/AlienCovenant-4164747-0.ts
   	Sat 1/9 1:38:43.660 [main@1218025c] File Format Parsed-2a /media/01/media01/tv/AlienCovenant-4164747-0.ts=MPEG2-TS 2:19:55 0 kbps [#0 Audio[AAC 48000 Hz 2 channels  MAIN idx=0 id=0101 at=ADTS-MPEG4]]
   	Sat 1/9 1:38:43.664 [main@1218025c] File Format Parsed-2b /media/01/media01/tv/AlienCovenant-4164747-0.ts=MPEG2-TS 2:19:55 0 kbps [#0 Audio[AAC 48000 Hz 2 channels  MAIN idx=0 id=0101 at=ADTS-MPEG4]{AiringDuration=8400000, Description=Bound for a remote planet on the far side of the galaxy, members (Katherine Waterston, Billy Crudup) of the colony ship Covenant discover what they think to be an uncharted paradise. While there, they meet David (Michael Fassbender), the synthetic survivor of the doomed Prometheus expedition. The mysterious world soon turns dark and dangerous when a hostile alien life-form forces the crew into a deadly fight for survival., ExternalID=MV8260190000, ShowcardID=12343481, ExtendedRatings=Adult Language,Adult Situations,Graphic Violence,Nudity, ForcedUnique=true, Rated=R, Film Editor=Pietro Scalia, AiringTime=1609992000000, Actor=Michael Fassbender;Katherine Waterston;Billy Crudup;Danny McBride;Demi?n Bichir;Carmen Ejogo;Jussie Smollett;Callie Hernandez;Amy Seimetz;Nathaniel Dean;Alexander England;Uli Latukefu;Tess Haubrich;Benjamin Rigby, CC=true, Misc=**+;Chilling;Frightening;Gripping;Suspenseful;Future;Discovery;Mystery;Quest;Adventure;Space traveler;Colonist;Robot;Alien;Spaceship;Alien planet;Space;Alien life-forms;Cyborgs;Space exploration;Space Travel, Director=Ridley Scott, Costume Designer=Janty Yates, Title=Alien: Covenant, Production Design=Chris Seagers, Casting=Carmen Cuba, Year=2017, Producer=Ridley Scott;Mark Huffam;Michael Schaefer;David Giler;Walter Hill, Music=Jed Kurzel, Cinematographer=Dariusz Wolski, ParentalRating=TVM, Genre=Movie;Science fiction;Horror;Thriller, RunningTime=7320000, Writer=John Logan;Dante Harper}]
   	Sat 1/9 1:38:43.664 [main@1218025c] Using external format detector because we only detected audio on the internal format...
   	Sat 1/9 1:38:43.664 [main@1218025c] Now using external format detector for: /media/01/media01/tv/AlienCovenant-4164747-0.ts
   	Sat 1/9 1:38:43.683 [main@1218025c] File Format Parsed /media/01/media01/tv/AlienCovenant-4164747-0.ts=MPEG2-TS 0:00:00 0 kbps [{AiringDuration=8400000, Description=Bound for a remote planet on the far side of the galaxy, members (Katherine Waterston, Billy Crudup) of the colony ship Covenant discover what they think to be an uncharted paradise. While there, they meet David (Michael Fassbender), the synthetic survivor of the doomed Prometheus expedition. The mysterious world soon turns dark and dangerous when a hostile alien life-form forces the crew into a deadly fight for survival., ExternalID=MV8260190000, ShowcardID=12343481, ExtendedRatings=Adult Language,Adult Situations,Graphic Violence,Nudity, ForcedUnique=true, Rated=R, Film Editor=Pietro Scalia, AiringTime=1609992000000, Actor=Michael Fassbender;Katherine Waterston;Billy Crudup;Danny McBride;Demi?n Bichir;Carmen Ejogo;Jussie Smollett;Callie Hernandez;Amy Seimetz;Nathaniel Dean;Alexander England;Uli Latukefu;Tess Haubrich;Benjamin Rigby, CC=true, Misc=**+;Chilling;Frightening;Gripping;Suspenseful;Future;Discovery;Mystery;Quest;Adventure;Space traveler;Colonist;Robot;Alien;Spaceship;Alien planet;Space;Alien life-forms;Cyborgs;Space exploration;Space Travel, Director=Ridley Scott, Costume Designer=Janty Yates, Title=Alien: Covenant, Production Design=Chris Seagers, Casting=Carmen Cuba, Year=2017, Producer=Ridley Scott;Mark Huffam;Michael Schaefer;David Giler;Walter Hill, Music=Jed Kurzel, Cinematographer=Dariusz Wolski, ParentalRating=TVM, Genre=Movie;Science fiction;Horror;Thriller, RunningTime=7320000, Writer=John Logan;Dante Harper}]

7. Using a SageTV client, examine the 'Current Recordings' view and note how many recordings there are. I observed the number of recordings to be 400.
8. Continue looking through the logs. Observe that a few seconds after the recovery messages that the Seeker appears to wake up and start purging recordings. It states that it is "Verifying existence of all TV media files in database fixDurs=true avoidArchive=false". In this first phase it deletes 7 recordings. It proceeds to a second phase "Verifying existence of all TV media files in database fixDurs=false avoidArchive=true", where it calls Seeker.destroyFile 470 times.
   a. PHASE 1
   

   	Sat 1/9 1:38:48.127 [Seeker@2920168] Verifying existence of all TV media files in database fixDurs=true avoidArchive=false
   	Sat 1/9 1:38:48.130 [FSManager@30f62434] FSManager is running...
   	Sat 1/9 1:38:48.131 [Carny@72ce24f0] Carny got a Std job of null
   	Sat 1/9 1:38:48.134 [MsgMgrSocket@3b27f9b7] Spawned thread for MsgManger server socket listening...
   	Sat 1/9 1:38:48.136 [SageTV@38affcd3] Splash: Waiting for SageTV to finish initialization...
   	Sat 1/9 1:38:48.138 [EPG@66955283] Increased ArrayList pool to size=1
   	Sat 1/9 1:38:48.144 [EPG@66955283] sage.epg.sd.SDRipper@65a2f4fe needs an update in 0:00:00
   	Sat 1/9 1:38:48.144 [EPG@66955283] EPG needs an update in 0 minutes
   	Sat 1/9 1:38:48.147 [EPG@66955283] EPG attempting to expand ....
   	Sat 1/9 1:38:48.152 [EPG@66955283] expand called on ... at Sat 1/9 1:38:48.151 expandedUntil=Sat 1/9 0:07:27.232 scannedUntil=Sat 8/16 23:12:55.807
   	Sat 1/9 1:38:48.155 [EPG@66955283] EPG Expanding ... at Sat 1/9 1:38:48.155
   	Sat 1/9 1:38:48.181 [Scheduler@318bea10] Scheduler.updateSchedule() called  manual=[ManualRecord[A[254026,227562,"Thor: Ragnarok",34240@0802.17:15,165,T] time=Sun 8/2 17:15:00.000 dur=2:45:00], ManualRecord[A[571860,567890,"Solo: A Star Wars Story",18510@0816.20:00,180,T] time=Sun 8/16 20:00:00.000 dur=3:00:00], ManualRecord[A[4084907,4081766,"Annihilation",14988@0104.12:00,140,T] time=Mon 1/4 12:00:00.000 dur=2:20:00], ManualRecord[A[4164747,4157766,"Alien: Covenant",14988@0106.20:00,140,T] time=Wed 1/6 20:00:00.000 dur=2:20:00]] schedules={pipe-01 on encode.computer.local:9000=[Sched=[] MustSee=[]]} scheduleRandSize=0
   	Sat 1/9 1:38:48.287 [Carny@72ce24f0] CARNY building airing maps...
   	Sat 1/9 1:38:48.340 [Scheduler@318bea10] # Airs=1465
   	Sat 1/9 1:38:48.365 [Seeker@2920168] MediaFile failing verify testFile=/var/media/tv/Today-S2021E01-4017851-0.ts isFile=false len=0 isTV=true isRecording=false
   	Sat 1/9 1:38:48.365 [Seeker@2920168] Removing MediaFile because it failed verification:MediaFile[id=4399270 A[4017851,4009335,"Today",21213@0101.07:00,120,T] mask=TV host=encode encodedBy=pipe-01 on encode.computer.local:9000 Great-H.264 format=MPEG2-TS 0:00:00 0 kbps [] /var/media/tv/Today-S2021E01-4017851-0.ts, Seg0[Fri 1/1 7:00:00.002-Fri 1/1 9:00:00.001]]
   	Sat 1/9 1:38:48.365 [Seeker@2920168] Seeker.destroyFile called for: MediaFile[id=4399270 A[4017851,4009335,"Today",21213@0101.07:00,120,T] mask=TV host=encode encodedBy=pipe-01 on encode.computer.local:9000 Great-H.264 format=MPEG2-TS 0:00:00 0 kbps [] /var/media/tv/Today-S2021E01-4017851-0.ts, Seg0[Fri 1/1 7:00:00.002-Fri 1/1 9:00:00.001]]
   	Sat 1/9 1:38:48.365 [Seeker@2920168] Deleted media segment file /var/media/tv/Today-S2021E01-4017851-0.ts dtime=0 len=0

   b. PHASE 2
   

   	Sat 1/9 1:38:48.867 [Seeker@2920168] Checking video directories for new files
   	Sat 1/9 1:38:48.887 [Scheduler@318bea10] Scheduler.updateSchedule() called  manual=... scheduleRandSize=0
   	Sat 1/9 1:38:48.892 [Seeker@2920168] Diskspace checking is running
   	Sat 1/9 1:38:48.892 [Seeker@2920168] Verifying existence of all TV media files in database fixDurs=false avoidArchive=true
   	Sat 1/9 1:38:48.894 [AsyncPropSaver@5166ce5] Done writing out the data to the properties file
   	Sat 1/9 1:38:48.921 [LibraryImporter@2f7aec0a] Increased Thread pool to size=6
   	Sat 1/9 1:38:48.921 [LibraryImporter@2f7aec0a] Checking video directories for new files
   	Sat 1/9 1:38:48.925 [Scheduler@318bea10] # Airs=1465
   	Sat 1/9 1:38:48.927 [Seeker@2920168] Seeker waiting for 153722840444494 mins.
   	Sat 1/9 1:38:48.931 [Seeker@2920168] Seeker awoken
   	Sat 1/9 1:38:48.932 [Seeker@2920168] MemStats: Used=236MB Total=598MB Max=1342MB
   	Sat 1/9 1:38:48.932 [Seeker@2920168] Seeker adding new Encoder: pipe-01 on encode.computer.local:9000
   	Sat 1/9 1:38:48.936 [Seeker@2920168] Checking video directories for new files
   	Sat 1/9 1:38:48.936 [Seeker@2920168] Diskspace checking is running
   	Sat 1/9 1:38:48.936 [Seeker@2920168] Verifying existence of all TV media files in database fixDurs=false avoidArchive=true
   	Sat 1/9 1:38:48.945 [Seeker@2920168] Seeker waiting for 153722840444494 mins.
   	Sat 1/9 1:38:49.117 [Scheduler@318bea10] MUST SEE FINAL-pipe-01 on encode.computer.local:9000-...
   	Sat 1/9 1:38:49.118 [Scheduler@318bea10] Evaluating Potentials
   	Sat 1/9 1:38:49.118 [Scheduler@318bea10] COMPLETE SCHEDULE-----**&^%&*-------COMPLETE SCHEDULE
   	Sat 1/9 1:38:49.118 [Scheduler@318bea10] pipe-01 on encode.computer.local:9000
   	Sat 1/9 1:38:49.119 [Scheduler@318bea10] [...]
   	Sat 1/9 1:38:49.119 [Scheduler@318bea10] Total Schedule eval time=248 msec
   	Sat 1/9 1:38:49.119 [Seeker@2920168] Seeker awoken
   	Sat 1/9 1:38:49.120 [Seeker@2920168] MemStats: Used=218MB Total=598MB Max=1342MB
   	Sat 1/9 1:38:49.121 [Seeker@2920168] MARK 1 currRecord=null enc=pipe-01 on encode.computer.local:9000 clients=[] ir=false
   	Sat 1/9 1:38:49.122 [Seeker@2920168] Seeker in AUTOMATIC mode nextRecord=A[4214627,4205824,"NBC Nightly News With Lester Holt",21213@0109.02:06,30,T] nextTTA=1630880
   	Sat 1/9 1:38:49.122 [Seeker@2920168] newRecord=null
   	Sat 1/9 1:38:49.122 [Seeker@2920168] NOTHING TO RECORD FOR NOW...
   	Sat 1/9 1:38:49.122 [Seeker@2920168] Seeker waiting for -26836418 mins.
   	Sat 1/9 1:38:49.122 [Scheduler@318bea10] Scheduler starting wait...
   	Sat 1/9 1:38:49.123 [Seeker@2920168] Seeker awoken
   	Sat 1/9 1:38:49.123 [Seeker@2920168] MemStats: Used=219MB Total=598MB Max=1342MB
   	Sat 1/9 1:38:49.124 [Seeker@2920168] MARK 1 currRecord=null enc=pipe-01 on encode.computer.local:9000 clients=[] ir=false
   	Sat 1/9 1:38:49.124 [Seeker@2920168] Seeker in AUTOMATIC mode nextRecord=A[4214627,4205824,"NBC Nightly News With Lester Holt",21213@0109.02:06,30,T] nextTTA=1630876
   	Sat 1/9 1:38:49.124 [Seeker@2920168] newRecord=null
   	Sat 1/9 1:38:49.124 [Seeker@2920168] NOTHING TO RECORD FOR NOW...
   	Sat 1/9 1:38:49.124 [Seeker@2920168] Checking video directories for new files
   	Sat 1/9 1:38:49.124 [Seeker@2920168] Diskspace checking is running
   	Sat 1/9 1:38:49.124 [Seeker@2920168] Verifying existence of all TV media files in database fixDurs=false avoidArchive=true
   	Sat 1/9 1:38:49.131 [Seeker@2920168] Enforcing keep at most limits for the files...
   	Sat 1/9 1:38:49.132 [Seeker@2920168] DONE enforcing keep at most limits for the files.
   	Sat 1/9 1:38:49.132 [Seeker@2920168] Seeker clearing unwanted and partial files...
   	Sat 1/9 1:38:49.133 [Seeker@2920168] Seeker.destroyFile called for: MediaFile[id=2620510 A[2346458,2331051,"Saturday Night Live",21213@0919.22:00,60,T] mask=TV host=encode encodedBy=pipe-01 on encode.computer.local:9000 Great-H.264 format=MPEG2-TS 0:00:00 0 kbps [] /media/01/media01/tv/SaturdayNightLive-JanetJackson-2346458-0.ts, Seg0[Sat 9/19 22:00:00.007-Sat 9/19 22:00:00.007]]

9. Stop the SageTV service to prevent further file deletions.
10. While the service is stopped, examine Sage.properties and observe that the "linux/delete_queue=" property has a comically long list of files scheduled for deletion. Realize that the only reason why all of these files were not successfully deleted was that SageTV was eventually shut off and that the '/media/01/media01/tv' NFS mount, where most recordings were moved INTO, is set as read-only. This may be why the logs are spammed with "Failed renaming file to move into delete queue" and "Progressive deletion failed for" messages.
11. While the service is stopped, modify Sage.properties such that there are zero items on the "linux/delete_queue=" (just delete the value of this property) This prevents part of the recordings purge from being carried out. Unfortunately, I may have already lost some of the recordings that were resident in the read-write TV recordings directory.
12. From the backup I took just prior to moving recordings, I replace Wiz.bin and Wiz.bak in the SageTV folder. I did this in the hopes that any database records would be recovered, and if the files were still there, would be re-imported.
13. Start the SageTV service. (Note that "advanced_video_file_recovery=true" is still set)
14. Wait a minute or two to allow SageTV to finish processing records.
15. Using a SageTV client, examine the 'Current Recordings' view and note how many recordings there are. I observed the number of recordings to be 839. It appears the missing 439 records have re-appeared?
16. Examine the SageTV logs to understand what might have happened. Observe that the log statement "MediaFile RECOVERY Added" appears 439 times, and this appears to be SageTV recovering the recordings
    a.
    

    	Sat 1/9 1:48:35.932 [main@1218025c] Using internal format detector first for: /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts
    	Sat 1/9 1:48:35.934 [main@1218025c] File Format Parsed-2a /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts=MPEG2-TS 0:14:57 0 kbps [#0 Audio[AAC 48000 Hz 2 channels  MAIN idx=0 id=0101 at=ADTS-MPEG4]]
    	Sat 1/9 1:48:35.938 [main@1218025c] File Format Parsed-2b /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts=MPEG2-TS 0:14:57 0 kbps [#0 Audio[AAC 48000 Hz 2 channels  MAIN idx=0 id=0101 at=ADTS-MPEG4]{AiringDuration=900000, CC=true, Description=Dr. Weird's giant mechanical Rabbot wreaks havoc on a New Jersey city., OriginalAirDate=978206400000, ExternalID=EP4662930001, Title=Aqua Teen Hunger Force, EpisodeName=Rabbot, EpisodeNumber=1, ForcedUnique=true, AiringTime=1609332300000, ParentalRating=TVM, Genre=Comedy;Fantasy;Animated, RunningTime=720000, Voice=Carey Means;Dana Snyder;Dave Willis, SeasonNumber=1}]
    	Sat 1/9 1:48:35.938 [main@1218025c] Using external format detector because we only detected audio on the internal format...
    	Sat 1/9 1:48:35.938 [main@1218025c] Now using external format detector for: /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts
    	Sat 1/9 1:48:35.945 [main@1218025c] File Format Parsed /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts=MPEG2-TS 0:00:00 0 kbps [{AiringDuration=900000, CC=true, Description=Dr. Weird's giant mechanical Rabbot wreaks havoc on a New Jersey city., OriginalAirDate=978206400000, ExternalID=EP4662930001, Title=Aqua Teen Hunger Force, EpisodeName=Rabbot, EpisodeNumber=1, ForcedUnique=true, AiringTime=1609332300000, ParentalRating=TVM, Genre=Comedy;Fantasy;Animated, RunningTime=720000, Voice=Carey Means;Dana Snyder;Dave Willis, SeasonNumber=1}]
    	Sat 1/9 1:48:35.947 [main@1218025c] Added:MediaFile[id=4563798 A[4129647,4129393,"Aqua Teen Hunger Force",18151@1230.04:45,15,T] mask=TV host=encode encodedBy= format=MPEG2-TS 0:00:00 0 kbps [{AiringDuration=900000, CC=true, Description=Dr. Weird's giant mechanical Rabbot wreaks havoc on a New Jersey city., OriginalAirDate=978206400000, ExternalID=EP4662930001, Title=Aqua Teen Hunger Force, EpisodeName=Rabbot, EpisodeNumber=1, ForcedUnique=true, AiringTime=1609332300000, ParentalRating=TVM, Genre=Comedy;Fantasy;Animated, RunningTime=720000, Voice=Carey Means;Dana Snyder;Dave Willis, SeasonNumber=1}] /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts, Seg0[Wed 12/30 4:45:02.467-Wed 12/30 5:00:00.003]]
    	Sat 1/9 1:48:35.947 [main@1218025c] MediaFile RECOVERY Added MediaFile[id=4563798 A[4129647,4129393,"Aqua Teen Hunger Force",18151@1230.04:45,15,T] mask=TV host=encode encodedBy= format=MPEG2-TS 0:00:00 0 kbps [{AiringDuration=900000, CC=true, Description=Dr. Weird's giant mechanical Rabbot wreaks havoc on a New Jersey city., OriginalAirDate=978206400000, ExternalID=EP4662930001, Title=Aqua Teen Hunger Force, EpisodeName=Rabbot, EpisodeNumber=1, ForcedUnique=true, AiringTime=1609332300000, ParentalRating=TVM, Genre=Comedy;Fantasy;Animated, RunningTime=720000, Voice=Carey Means;Dana Snyder;Dave Willis, SeasonNumber=1}] /media/01/media01/tv/AquaTeenHungerForce-S01E01-Rabbot-4129647-0.ts, Seg0[Wed 12/30 4:45:02.467-Wed 12/30 5:00:00.003]]

17. Once everything is smoke tested, shut off SageTV server and set "advanced_video_file_recovery=false" to prevent future unecessary processing

One last thing to mention just in case it is relevant. All recordings in this test server are HEVC and AAC in an MPEG-TS container. As a result, you'll see SageTV logs saying "Using external format detector because we only detected audio on the internal format". I don't think this is related to why SageTV decides to purge the recordings, but that is why I'm consulting you all for help. As a side note, I'm watching jvl711's MediaFormatParserPlugin project with interest and would also be interested in hearing folks' experience with it.

Full logs, Wiz database and other files available on request via Private Message.

Thanks for any comments or suggestions

[trk2]

Originally Posted by sagetvuser489

[*]Follow Opus4's instructions under "The Advanced Method" for moving most TV recordings from '/media/01/media01/tv2' to the read-only '/media/01/media01/tv'. Reference https://forums.sagetv.com/forums/showthread.php?t=49015.

This is an incorrect link. I'd like to help you but I don't use linux or have ever used "advanced_video_file_recovery=true". I was curious about the process and interestingly a forum search for "advanced_video_file_recovery=true" or similar iterations yields no results. I'm sure one of the linux guys will have some suggestions. That was a well written post.

[sagetvuser489]

Thanks for reaching out trk2!

You are absolutely right, I referenced the wrong post when talking about Opus4's instructions about the Advanced Method of moving recordings. The right posting URL is actually: https://forums.sagetv.com/forums/showthread.php?t=30697. When you check this posting out, the procedure you are looking to read is mentioned under "The Advanced Method (for SageTV version 6.3.9 and later)"

I've edited my original post to correct this error.

[Tiki]

I don’t know for sure what’s happening, but here is a theory.

When you setup the new instance of Sage, did you copy over your wiz.bin before doing the advanced file recovery?

If not, when Sage scanned the recordings, it may not have recognized them as Favorites or Manual recordings. Therefore it may have treated them like intelligent recordings. Depending on other settings, these can be deleted by Sage to make room if more space is needed.

Here is an alternate theory:

You said these were all HEVC format recordings. I’m not sure how you made these since Sage doesn’t normally handle HEVC (although steps have been made recently to start adding support for this). It’s possible that when Sage scanned the files, it’s format detector didn’t recognize them as valid video files, so it assumed they were corrupt and deleted them. Someone who is familiar with the Sage code would need to look to see if this is a real possibility.

[sagetvuser489]

Hi Tiki - thanks for your advice!

When I originally set up this test install of SageTV on Ubuntu I started with a blank Wiz.bin because I had no recordings. Since then, I chose to move recordings around among the three pre-existing recording directories that SageTV knew about.

Yes, before I moved the recordings around from folder to folder I stored off a backup copy of my Wiz.bin. While I was moving the recordings between recording directories (after step 4), I did not re-install SageTV.

On your "manual recordings" theory, I used the SageTV placeshifter to examine the markings on each recording (i.e. what I got after step 17). The ones that I would expect to be marked as favorites are actually marked as favorites. Same with manual recordings. Still, the Wiz.bin I am looking at is after I replaced it with a backup (in step 12), so you might still be right. I'll have to examine what the "broken" Wiz.bin looks like (that was overwritten in step 12), but that will take a bit more testing to replicate.

Correct - SageTV has only just begun to support HEVC and the setup required to get them into the system is more involved than anything I'd done previously. Now that hardware encoders for HEVC are widely available, I'm eager to make use of them and take advantage of the storage savings. It turns out that if you are using OpenDCT (https://forums.sagetv.com/forums/showthread.php?t=62774) as a network encoder, SageTV will accept the files as long as you are using it's RawSageTVConsumerImpl and what you provide it is a MPEG-TS container containing some stream it can parse.

Your theory about SageTV thinking that the recordings are invalid somehow was my first thought too. After all, the seeker logs seem to call them "Seeker clearing unwanted and partial files...". However, when I looked at the actual Seeker code I didn't see any code path that would have deleted files just because the didn't have an identifiable video stream.

There were 7 files ("phase 1" in step 8) for which destroyFile was called while the Seeker was "Verifying existence of all TV media files in database fixDurs=true avoidArchive=false". Now that I've taken a closer look at each one of these deletions, I see that all 7 of them were actually moved from '/var/media/tv/' to '/media/01/media01/tv', as in the case of the log line "MediaFile failing verify testFile=/var/media/tv/Today-S2021E01-4017851-0.ts isFile=false len=0 isTV=true isRecording=false" To my mind these 7 deletions should have been identified as moved files as SageTV was starting in step 6, but they were instead recognized as files that were missing and should be deleted.

I'm left wondering if there is some kind of race condition between whatever is running the advanced file recovery process and the Seeker, which at SageTV boot time is trying to validate that all the recordings are where they should be. If the advanced file recovery thread was running, but hadn't finished correcting file location metadata for each recording before the Seeker comes in and starts deleting recordings it can't find that might explain why only part of the database is deleted.

I am no expert in the SageTV code though, so like you I could really use the advice of someone who knows the code better than I do. I could also use advice on a test that could confirm\refute the race condition theory.

[davidk21770]

I have been having a similar problem under Windows where sage is deleting files from a media folder -- one that it should not be managing. I can easily recover these files since this is an NAS and I can move/rename the #recycle/TVRecordings/...delete files and the associated .my, .edl, etc. files to another folder where I am hoping that they stay (a recordings folder that is mostly empty).

At one point in time, I was using the NAS as a sage recordings folder but had issues with speed with overlapping recordings (probably since fixed, but I haven't added it back). I've quadruple checked that it's still not a recording directory and it is not.

This is an OLD system that was migrated from XP and is now running 8.1 -- but reconfiguring all of the little things that I had to do to make it work with my ancient HD PVR/cable box/USB-UIRT and 2 silicon dust dual recorders (now doing OTA) has kept me from a reinstall. I've tried to upgrade to x64 but have been unsuccessful. As I said, complex old system.

Does anyone have any suggestions?