[mythtv-users] HELP! Really odd stuff with old deleted recordings and find_orphans.py

Stephen Worthington stephen_agent at jsw.gen.nz
Mon Oct 29 07:25:17 UTC 2018


On Sun, 28 Oct 2018 23:11:32 -0400, you wrote:

>On 10/28/18, Mark Perkins <perkins1724 at hotmail.com> wrote:
>>
>>
>> On 29 October 2018 11:53:47 am Tom Dexter <digitalaudiorock at gmail.com>
>> wrote:
>>
>>> Wow...I desperately need help here. I don't get what's going on. A
>>> little background:
>>>
>>> I had to replace the drive in my backend. I restored the OS etc from
>>> clonzilla backups, and restored a current backup of the database...all
>>> went just fine. I was also able to recover the recordings I cared
>>> about from the old drives. As far as the others where I had an entry
>>> listed in the recordings and no actual file, I deleted those in
>>> mythweb, and everything seemed fine.
>>>
>>> Today I noticed a ton of these in the mythbackend log:
>>>
>>> 2018-10-28 08:28:46.756113 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 2225 MB for 1071 at
>>> 2018-10-21T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>> 2018-10-28 08:28:46.756175 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 1839 MB for 1071 at
>>> 2018-10-19T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>> 2018-10-28 08:28:46.756225 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 1964 MB for 1071 at
>>> 2018-10-18T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>> 2018-10-28 08:28:46.756274 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 1824 MB for 1071 at
>>> 2018-10-17T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>> 2018-10-28 08:28:46.756325 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 2017 MB for 1071 at
>>> 2018-10-16T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>> 2018-10-28 08:28:46.756374 N [21736/21763] Expire autoexpire.cpp:637
>>> (SendDeleteMessages) - Expiring 1813 MB for 1071 at
>>> 2018-10-15T22:30:00Z => "ABC
>>> World News Tonight With David Muir"
>>>
>>> ...as well as ones like these;
>>>
>>> 2018-10-28 08:28:46.771847 E [21736/21736] CoreContext
>>> programinfo.cpp:2608 (GetPlaybackURL) -
>>> ProgramInfo(1071_20181021223000.ts): GetPlaybackURL: '1
>>> 071_20181021223000.ts' should be local, but it can not be found.
>>> 2018-10-28 08:28:46.771943 E [21736/21736] CoreContext
>>> mainserver.cpp:3069 (DoHandleDeleteRecording) - MainServer: ERROR when
>>> trying to delete file: G
>>> etPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/mythback/1071_20181021223000.ts.
>>> File doesn't exist.  Database metadata will not be removed.
>>> 2018-10-28 08:28:46.801380 E [21736/21736] CoreContext
>>> programinfo.cpp:2608 (GetPlaybackURL) -
>>> ProgramInfo(1071_20181019223000.ts): GetPlaybackURL: '1
>>> 071_20181019223000.ts' should be local, but it can not be found.
>>> 2018-10-28 08:28:46.801476 E [21736/21736] CoreContext
>>> mainserver.cpp:3069 (DoHandleDeleteRecording) - MainServer: ERROR when
>>> trying to delete file: G
>>> etPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/mythback/1071_20181019223000.ts.
>>> File doesn't exist.  Database metadata will not be removed.
>>> 2018-10-28 08:28:46.825473 E [21736/21736] CoreContext
>>> programinfo.cpp:2608 (GetPlaybackURL) -
>>> ProgramInfo(1071_20181018223000.ts): GetPlaybackURL: '1
>>> 071_20181018223000.ts' should be local, but it can not be found.
>>>
>>> Those are ALL from recordings I deleted...they do NOT show in the
>>> recordings screen...and I have no idea where they're coming from.
>>> Totally lost. The find_orphans.py script sees these as
>>> well...*everything* I've deleted in mythweb:
>>>
>>> ./find_orphans.py
>>> Recordings with missing files
>>>  mythback: A Cat's Attic: Yusuf/Cat Stevens
>>>       1131_20180810023000.ts
>>>  mythback: ABC World News Tonight
>>>       1071_20180930223000.ts
>>>  mythback: ABC World News Tonight
>>>       1071_20181014223000.ts
>>>  mythback: ABC World News Tonight
>>>       1071_20180923223000.ts
>>>  mythback: ABC World News Tonight With David Muir
>>>       1071_20181021223000.ts
>>>  mythback: ABC World News Tonight With David Muir
>>>       1071_20180727223000.ts
>>> ...etc...
>>>
>>>           Count:          87
>>> Other files
>>>  mythback: /video/recordings/1021_20181025000000.ts.png.EB6667
>>>                      845.1KB
>>>  mythback: /video/recordings/1021_20181025000000.ts.png.Lf6756
>>>                      221.6KB
>>> ...etc...
>>>
>>>
>>>           Total:       4.1MB
>>> Please select from the following
>>> 1. Delete orphaned recording entries
>>> 2. Delete other files
>>> 3. Refresh list
>>>
>>> Again, I have no idea where they're coming from and worse yet, if I
>>> try to use option 1 to delete those I get this:
>>>
>>> Are you sure you want to continue?
>>>> yes
>>> Traceback (most recent call last):
>>>  File "./find_orphans.py", line 230, in <module>
>>>    main()
>>>  File "./find_orphans.py", line 214, in main
>>>    opt[1](opt[2])
>>>  File "./find_orphans.py", line 129, in delete_recs
>>>    rec.delete(True, True)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/dataheap.py", line
>>> 375, in delete
>>>    return self.getProgram().delete(force, rerecord)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/dataheap.py", line
>>> 387, in getProgram
>>>    return Program.fromRecorded(self)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/mythproto.py", line
>>> 946, in fromRecorded
>>>    return be.getRecording(rec.chanid, rec.starttime)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/mythproto.py", line
>>> 647, in getRecording
>>>    return Program(res[1:], db=self.db)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/mythproto.py", line
>>> 875, in __init__
>>>    DictData.__init__(self, raw)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/altdict.py", line 148,
>>> in __init__
>>>    data = self._process(data)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/altdict.py", line 164,
>>> in _process
>>>    data[i] = self._trans[self._field_type[i]](v)
>>>  File "/usr/lib/python2.7/site-packages/MythTV/altdict.py", line 104,
>>> in <lambda>
>>>    lambda x: datetime.fromtimestamp(x, datetime.UTCTZ())\
>>>  File "/usr/lib/python2.7/site-packages/MythTV/utility/dt.py", line
>>> 304, in fromtimestamp
>>>    obj = super(datetime, cls).fromtimestamp(float(timestamp), tz)
>>> ValueError: timestamp out of range for platform time_t
>>>
>>> Any help would be appreciated. I've never had an issue with deleting
>>> anything in mythweb for sure. I just looked an it appears these all
>>> still have rows in the recorded table. That shouldn't be the case
>>> correct?
>>>
>>> What on earth could be going on there?
>>>
>>> Tom
>>> _______________________________________________
>>> mythtv-users mailing list
>>> mythtv-users at mythtv.org
>>> http://lists.mythtv.org/mailman/listinfo/mythtv-users
>>> http://wiki.mythtv.org/Mailing_List_etiquette
>>> MythTV Forums: https://forum.mythtv.org
>> My understanding is that is expected behaviour. find_orphans.py just asks
>> mythtv to do the delete. mythtv won't delete the metadata unless it can
>> find the file.
>>
>> IIRC just go to FE recordings screen, change group filter to "Deleted",
>> select All Programmes, menu, add this group to playlist, menu, playlist
>> options, delete. Will get some sort of 'are you really REALLY sure' type
>> message, I don't recall wording.
>>
>>
>
>Thanks! Looks like this might have gotten things straightened out. I'm
>still a little confused as to your first paragraph, as the whole point
>of that option #1 in find_orphans.py is to delete programs with
>missing files. What you're saying seems to imply that that would never
>work(?). I had originally deleted the programs in mythweb anyway.
>
>That aside, I tried what you explained about deleting items in the
>Deleted group using a playlist. There were 84 entries in the Deleted
>group. For some reason when I added that to the playlist it only
>wanted to add 74 of them...not sure why. I deleted the other 10 one at
>a time. Each one warned me that the file was missing too.
>
>Very confusing behavior...I'm still a little confused on all that.
>I've had cases where there were missing files form tuner failures and
>don't recall ever having things stuck out there like I had here. Maybe
>that's because I've always just deleted those from the recordings
>screen.
>
>Thanks again!
>Tom

This is how I understand MythTV currently does things.

When you delete something from MythTV, it is not actually deleted, but
instead is queued to be deleted later.  The "later" depends on your
settings.  With the default settings, I believe it takes up to 20
minutes before it will actually be deleted ("expired" in terms of what
log message you will see).  Some available options will never actually
do the delete until there is no spare space for a recording.  Until
the "deleted" recordings get "expired", they can be undeleted.  To see
the "deleted" recordings, you change the group filter to "Deleted".
From the "Deleted" group, if you then delete something, it will be
"expired" immediately - it will really be deleted.

The other half of your problem is that things on the "Deleted" queue
will not be deleted if there is a problem with them.  So if an error
happens when a normal "expire" operation is done on them, they are not
actually deleted and remain queued for deletion.  And at some later
time there will be another attempt to "expire" them, and that will
fail again.  In your case, the fact that there are no recording files
for the recording causes the normal "expire" attempts to fail.
However, when you manually select things from the "Deleted" group to
be deleted again, that causes a real deletion to happen immediately,
which does not fail if the recording file is not present.

The way find_orphans.py works, if you tell it to delete all recordings
where there is no recording file, it will tell MythTV to do exactly
that.  However, where there are many recordings to be deleted, that
results in a queue of recordings that MythTV will "expire" in order,
and it takes its time doing it.  So if you run find_orphans.py again,
you often find that things you have told it to delete are still there.
But if you wait long enough, the "expire" queue will get processed
completely and everything will be gone.  It works the same way when
you delete lots of things from the Deleted group - if you exit from
the Deleted group and go back into it, you may well see some of the
things you have just deleted are still there.  But if you give it long
enough, they will eventually disappear.  Unless mythbackend gets shut
down, especially if a bad shut down like a power failure occurs - I
think the expire queue is held in RAM only, so does not survive a shut
down.


More information about the mythtv-users mailing list