[mythtv-users] Mythbackend suddenly deleting everything marked for deletion including unwatched

Sat Feb 1 04:19:05 UTC 2014

Hoi Stephen,

Saturday, February 1, 2014, 4:58:43 AM, you wrote:

> On 1/31/14, 10:52 PM, Hika van den Hoven wrote:
>> Hoi Mark,
>>
>> Saturday, February 1, 2014, 4:39:58 AM, you wrote:
>>
>>
>>
>>>> On 1 Feb 2014, at 1:58 pm, "Hika van den Hoven" <hikavdh at gmail.com> wrote:
>>>>
>>>> Hoi R.G.,
>>>>
>>>> Saturday, February 1, 2014, 4:15:06 AM, you wrote:
>>>>
>>>>> Were the actual files deleted or only the entries in the database? These
>>>>> two manifestations point to entirely different problems.
>>>>> If the first, I would suspect the hard drive or controller, possibly caused
>>>>> by a power surge. Thge second could also be caused by a power surge, and
>>>>> possibly could be fixed by optimize-db.
>>>>> But I am guessing here.
>>>>> Geoff
>>>>> Psvthis *should* come out as bottom boosted, if the setting does what it
>>>>> sasys. New toy, my apologies if wrong.
>>>>> G
>>>>> Sent with AquaMail for Android
>>>>> http://www.aqua-mail.com
>>>>
>>>>> On January 31, 2014 10:03:05 PM Hika van den Hoven <hikavdh at gmail.com> wrote:
>>>>>> Hoi Discussion,
>>>>>>
>>>>>>  Some two hours ago I had the weirdest thing.
>>>>>>  I was watching a recording and when it finished it sprang as usual
>>>>>>  back to the list (unwatched recordings) and I saw some recordings
>>>>>>  marked as unfindable. If had that before and restarting the viewer
>>>>>>  solved it. But not this time. All recording not marked to keep where
>>>>>>  gone, including a few unwatched and the one I had just watched.
>>>>>>  When I realised what had happend I took the backend and the volume
>>>>>>  offline. I'm now running an undelete with ext4magic on everything
>>>>>>  recorded the last month, which seems to go fine. I only had first to
>>>>>>  create space to store the files. The deleted files are some 180 Gb
>>>>>>  and what I,m now undeleting is something in between a quarter and a
>>>>>>  half of that, but I probably only want to restore the unwatched
>>>>>>  ones.
>>>>>>
>>>>>>  Anybody an idea how this happened and how to restore the recordings
>>>>>>  to the database. I could restore the database to last night, but
>>>>>>  that leaves today out.
>>>>>>
>>>>>> --
>>>>>> Tot Mails,
>>>>>> Hika                          mailto:hikavdh at gmail.com
>>>>>> Mijn Mailadres is gewijzigd. Zie hierboven!
>>>>>>
>>>>>> "Zonder hoop kun je niet leven
>>>>>> Zonder leven is er geen hoop
>>>>>> Het eeuwige dilemma
>>>>>> Zeker als je hoop moet vernietigen om te kunnen overleven!"
>>>>>>
>>>>>> De lerende Mens
>>>>>>
>>>>>> _______________________________________________
>>>>>> mythtv-users mailing list
>>>>>> mythtv-users at mythtv.org
>>>>>> http://www.mythtv.org/mailman/listinfo/mythtv-users
>>>>
>>>>> _______________________________________________
>>>>> mythtv-users mailing list
>>>>> mythtv-users at mythtv.org
>>>>> http://www.mythtv.org/mailman/listinfo/mythtv-users
>>>>
>>>> They where physically deleted. To me it seems like it suddenly decided
>>>> it needed much more space. To me it sounds like it got some wrong
>>>> input about either needed space or available space.  Luckily it
>>>> stopped at recordings marked to keep. The deleted recordings I hadn't
>>>> yet watched are maybe 3, 5 at the most.
>>>> I will look into the logs, but haven't had time. I first had to
>>>> secure the volume and undelete what I can.
>>>> I'm thinking of restoring last nights backup in parallel and copying
>>>> the relevant records.
>>>>
>>> +1 to seeing what hints are in the logs. Would hate to restore the
>>> backup from 24hrs ago for it to just do exactly the same thing 24hrs later.
>>> I would also secure any recent backups and run a new backup ASAP
>>> just to try and keep options available, don't want your best backup
>>> to get overwritten by a junk one if your system is set to only keep a couple.
>>> _______________________________________________
>>> mythtv-users mailing list
>>> mythtv-users at mythtv.org
>>> http://www.mythtv.org/mailman/listinfo/mythtv-users
>>
>> My backups and the backupscript are on the data volume. What is the
>> naming of the backupfiles? Among the deleted files there are 18 files
>> like "mythconverge_backup-####.pl". where #### is a sequential number.
>> I'll undelete them to be sure and I'll move the backupfiles for the
>> future elsewhere with the ldap, tdb etc. backups.
>> For now the undelete is just past halfway and when that finishes I go
>> to bed! I was about to, when it happened.
>>
>> Tot mails,
>>   Hika                            mailto:hikavdh at gmail.com
>>
>> "Zonder hoop kun je niet leven
>> Zonder leven is er geen hoop
>> Het eeuwige dilemma
>> Zeker als je hoop moet vernietigen om te kunnen overleven!"
>>
>> De lerende Mens
>> --
>>
>> _______________________________________________
>>
> I'll plead guilty to doing the same, but I have scripts that copy off
> said data to a different storage unit.
> Just in case the volume dies, then I still have a backup.

> As I recall, backups are named by date/time group. Hence, the latest
> date/time on a 24 hour scale is the latest.

> I'll not go into my own undelete history, we'll suffice it to learn how
> it works out for you.
> My previous, unintentionally configured version didn't fare so well.
> Later versions fared far better, by design and understanding of the
> backup method.

> _______________________________________________
> mythtv-users mailing list
> mythtv-users at mythtv.org
> http://www.mythtv.org/mailman/listinfo/mythtv-users

Ok the log part when it went wrong:

2014-02-01 00:21:06.659851 N [4582/4582] CoreContext autoexpire.cpp:264 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0 GB w/freq: 15 min
2014-02-01 00:21:06.932926 N [4582/4582] CoreContext autoexpire.cpp:264 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 6.0 GB w/freq: 15 min
2014-02-01 00:22:18.035699 I [4582/18519] ProcessRequest mainserver.cpp:1395 (HandleAnnounce) - MainServer::ANN Monitor
2014-02-01 00:22:18.035713 I [4582/18519] ProcessRequest mainserver.cpp:1397 (HandleAnnounce) - adding: pc-Myth as a client (events: 0)
2014-02-01 00:22:18.037227 I [4582/18519] ProcessRequest mainserver.cpp:1395 (HandleAnnounce) - MainServer::ANN Monitor
2014-02-01 00:22:18.037239 I [4582/18519] ProcessRequest mainserver.cpp:1397 (HandleAnnounce) - adding: pc-Myth as a client (events: 1)
2014-02-01 00:22:36.937312 N [4582/4844] Expire autoexpire.cpp:641 (SendDeleteMessages) - Expiring 0 MB for 1 at 2014-01-31T23:21:06Z => "Pauw & Witteman"
2014-02-01 00:22:36.937383 N [4582/4844] Expire autoexpire.cpp:641 (SendDeleteMessages) - Expiring 9 MB for 1 at 2014-01-31T23:21:07Z => "Pauw & Witteman"
2014-02-01 00:23:21.703251 I [4582/4843] HouseKeeping housekeeper.cpp:221 (RunHouseKeeping) - Running housekeeping thread
2014-02-01 00:24:30.760948 E [4582/9611] Socket mainserver.cpp:5740 (connectionClosed) - Slave backend: pc-Myth no longer connected
2014-02-01 00:24:30.762352 I [4582/4841] Scheduler scheduler.cpp:2129 (HandleReschedule) - Reschedule requested for PLACE SlaveDisconnected
2014-02-01 00:24:30.783102 I [4582/4841] Scheduler mythdbcon.cpp:409 (PurgeIdleConnections) - New DB connection, total: 13
2014-02-01 00:24:30.809337 I [4582/4841] Scheduler scheduler.cpp:2242 (HandleReschedule) - Scheduled 22 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
2014-02-01 00:27:02.482963 I [4582/18519] ProcessRequest mainserver.cpp:1395 (HandleAnnounce) - MainServer::ANN Monitor
2014-02-01 00:27:02.482976 I [4582/18519] ProcessRequest mainserver.cpp:1397 (HandleAnnounce) - adding: tzcheck as a client (events: 0)
2014-02-01 00:27:04.032495 I [4582/18519] ProcessRequest mainserver.cpp:1445 (HandleAnnounce) - adding: pc-Myth as a slave backend server
2014-02-01 00:27:04.033184 I [4582/4841] Scheduler scheduler.cpp:2129 (HandleReschedule) - Reschedule requested for PLACE SlaveConnected
2014-02-01 00:27:04.069020 I [4582/4841] Scheduler scheduler.cpp:2242 (HandleReschedule) - Scheduled 22 items in 0.0 = 0.00 match + 0.00 check + 0.01 place
2014-02-01 00:27:10.048127 N [4582/7296] Update autoexpire.cpp:264 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 34359738372.0 GB w/freq: 3 min
2014-02-01 00:28:26.707281 I [4582/4843] HouseKeeping housekeeper.cpp:221 (RunHouseKeeping) - Running housekeeping thread
2014-02-01 00:32:36.057366 N [4582/4844] Expire autoexpire.cpp:264 (CalcParams) - AutoExpire: CalcParams(): Max required Free Space: 34359738372.0 GB w/freq: 3 min
2014-02-01 00:32:36.520675 N [4582/4844] Expire autoexpire.cpp:641 (SendDeleteMessages) - Expiring 1942 MB for 1 at 2013-12-11T20:25:00Z => "Case Sensitive"
2014-02-01 00:32:36.520721 N [4582/4844] Expire autoexpire.cpp:641 (SendDeleteMessages) - Expiring 1310 MB for 4 at 2013-12-12T13:35:00Z => "New tricks"
2014-02-01 00:32:36.520752 N [4582/4844] Expire autoexpire.cpp:641 (SendDeleteMessages) - Expiring 2025 MB for 2 at 2013-12-12T20:10:00Z => Zembla

As you can see the 'Max required Free Space' suddenly changed from 6.0
Gb as I had set it to 34359738372.0 GB which is astronomical and
probably the max allowed value in the database. Why?...
It took about an hour to delete all it's allowed and with this setting
it will keep deleting everything set to autoexpire.
I'm now into mythtv-setup to try to correct it

Tot mails,
  Hika                            mailto:hikavdh at gmail.com

"Zonder hoop kun je niet leven
Zonder leven is er geen hoop
Het eeuwige dilemma
Zeker als je hoop moet vernietigen om te kunnen overleven!"

De lerende Mens
--