DVR Engine doesn't restart

Help and support for HDHomeRun DVR and HDHomeRun software for Windows 10, Mac, Android, XBox, etc.
jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

DVR Engine doesn't restart

Post by jdcuartero » Tue Jun 25, 2019 2:13 am

I am having some issues with the DVR Engine ...

I have a Synology NAS with a power off and power on setup schedule. When the NAS powers on ... the DVR Engine seems not to be restarted because it shows a DVR Failure.

If if go to the Package Center the HDHomeRunDVR Manager iis running.

If I go to the UI ... and I stop and restart the DVR Engine ... then the DVR starts working again.

I have thought creating an script in order to stop and restart the DVR automatically once the NAS is power on.

Where is the DVR Engine exactly located? I have changed the Record path to a different location /volume1/Grabaciones instead than /volume1/HDHomeRunDVR

I have thought is using this script could work:

cd /volume1/HDHomeRunDVR
./hdhomerun_record stop
./hdhomerun_record start

or should I use ...

cd /volume1/Grabaciones
./hdhomerun_record stop
./hdhomerun_record start

Is someone else having this issue?

dknife
Posts: 26
Joined: Wed May 18, 2016 8:00 am

Re: DVR Engine doesn't restart

Post by dknife » Tue Jun 25, 2019 6:30 am

Are you using demonrik's Synology SPK?

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Tue Jun 25, 2019 6:38 am

Yes, I am using the demonrik's Synology SPK. The last one HDHomeRunDVR-0.7.0.spk

With the previous one, the 0.6.9 spk, I didn't notice that. I think it was working ok.

I don't know if it is possible to downgrade to 0.6.9 and test again in order to see if only happens with the 0.7.0.

Best regards,

jasonl
Silicondust
Posts: 14067
Joined: Sun Oct 28, 2007 9:23 pm

Re: DVR Engine doesn't restart

Post by jasonl » Tue Jun 25, 2019 12:29 pm

The spk starts the DVR automatically. You should not create a script to do that, you'll need to investigate why it's not starting correctly. Have you gone through the Error running the engine with a previously created shared folder section of viewtopic.php?p=309570#p309570 ?

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Tue Jun 25, 2019 2:00 pm

I have been checking and all the permissions are ok for the "http" group (read and write) and the "Restrict access to administrators only" is not selected.

I have disabled the DTV from the VideoStation app ... so tomorrow I'll see if the DVR Engine starts automatically when the NAS boots up.

I didn't change anything else from the NAS since the 0.6.9 spk.

Thanks

demonrik
Posts: 1116
Joined: Mon May 04, 2015 10:03 am
Device ID: 10736454, 1073A35A, 1075C377

Re: DVR Engine doesn't restart

Post by demonrik » Tue Jun 25, 2019 7:44 pm

When you say
jdcuartero wrote:
Tue Jun 25, 2019 2:13 am
the DVR Engine seems not to be restarted because it shows a DVR Failure.
What do you mean?
If I go to the UI ... and I stop and restart the DVR Engine ... then the DVR starts working again.
So the UI showed the DVR was running?
And RecordPath looks right?
I have thought creating an script in order to stop and restart the DVR automatically once the NAS is power on.
Already part of the spk

If not auto-starting it could be another issue preventing the NAS finishing the startup and getting to the DVR start
On start the included script writes to /tmp/hdhr_arch_choice
Check the timestamp is close to your reboot, or delete before restart and you should see another one.

If script works you should see a new/updated log file in your recordpath..
To test, stop the engine via UI.. Delete the log files through the NAS file manager, and restart... Should see brand new log file.
If not and u got an updated /tmp/hdhr_arch_choice we have a problem on the NAS that needs more investigation
If u do... Then whats in the log.

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Wed Jun 26, 2019 1:42 am

This morning the NAS boots up.

At the Synology Package Center ... the HDHomeRun spk is running.

But when I am trying to play the channel it shows ... "Unable to play the channel. DVR Failure".

Image

When I am going to the UI ... it looks it is working OK, because I can see the hardware and the software.

Image

And I can also see the log files ... but the log file is from today ... before the NAS shutted down.

Image

But if I am going to the recordings window... it shows 0 recordings ... but there should be 3 recordings on it.

Image

At the setup window ...

Image

So ... I am going to the Dashboard window and ... I push the "stop" button and then the "play" button. After doing this ... I am able to play the channels without DVR Failure. The log file is updated and I can see the recordings at the UI web page

Image

Image

Image

[Image

So I don't know exactly what is going on. :cry:

One thing I have just seen. The time from the DVR Manager is about 2 hours earlier than the NAS setup time.

Another thing I also have seen... the first pictures (when the DVR shows the failure) were taken this morning at 8am but the UI shows they were taken at 00:58am. This is the time when the NAS it is scheduled to power off (at 3:00am). Once the DVR is stopped and restarted ... the next pictures are showing the correct time (6am) because I manually restarted the DVR Engine at 8am. So it seems the DVR has not been started when the NAS boots up.

The time zone in the NAS is set up to Brussels (this means GMT+1:00) and it shows the correct time and data according to my country (Spain). Now the NAS is showing 11:54 am.

While if I look at the HDHomeRunDVR Manager settings ... I can see the data timezone is set to Brussels ...

php version = 7.2.13
php.ini file = /volume1/@appstore/PHP7.2/misc/php-fpm.ini
php.ini date.timezone = Europe/Brussels
date_default_timezone_get() = Europe/Brussels"

And at the bottom of the UI it shows "HDHomeRun RECORD running | 20190626-09:54:12 Status: Resource: nbk=0 dmk=173"

This means there is a couple of hours of difference.

Thank you demonrik for your help.

As you recommend ... I have stopped the DVR Engine ... then I deleted all the log files using the Synology File Station explorer. Then I restarted the engine (pushing the play button). And a new log file was generated at the record path. Everything works again. So the DVR Engine starts OK. I can see the recordings at the UI and I can play the channels.

If I open the log file ... I can see the following data (I only have deleted the Device ID using ***):

HDHomeRun RECORD 20190621 Linux 5A4FC90F-5FA5-42E9-CF4C-2AE02C8478F8
20190626-10:19:06 System: file limit = 4096
20190626-10:19:06 Recording: RecordPath[0] = '/volume1/Grabaciones/'
20190626-10:19:06 Recording: RecordPath /volume1/Grabaciones/ = btrfs
20190626-10:19:06 System: LocalIP: 192.168.2.100 255.255.255.0
20190626-10:19:06 System: website port = 59090
20190626-10:19:06 Recorded: RecordPath '/volume1/Grabaciones/' (btrfs)
20190626-10:19:06 Status: Resource: nbk=0 dmk=153
20190626-10:19:06 Status: ticks = 16614781
20190626-10:19:06 Recorded: directory /volume1/Grabaciones/ with 3 subdirs and 0 recordings
20190626-10:19:06 Recording: sending discover using local ip 192.168.2.100
20190626-10:19:06 Recorded: directory /volume1/Grabaciones/Señoras del (h)ampa/ with 0 subdirs and 1 recordings
20190626-10:19:06 Recorded: directory /volume1/Grabaciones/Cuarto milenio/ with 0 subdirs and 1 recordings
20190626-10:19:06 Recorded: directory /volume1/Grabaciones/Zapeando/ with 0 subdirs and 1 recordings
20190626-10:19:06 Recording: sending discover using local ip 192.168.2.100
20190626-10:19:07 Recording: discover response from 5A4FC90F-5FA5-42E9-CF4C-2AE02C8478F8 http://192.168.2.100:59090
20190626-10:19:07 Recording: discover response from ******** http://192.168.2.63:80
20190626-10:19:07 Recorded: recorded sync to record-api.hdhomerun.com
20190626-10:19:07 Recording: event download from record-api.hdhomerun.com
20190626-10:19:07 Recording: ******** lineup request success (found 33 channels)
20190626-10:19:08 System: server time = Wed Jun 26 10:19:08 2019 (correction of 0s)
20190626-10:19:08 Recorded: recorded sync success
20190626-10:19:08 System: server time = Wed Jun 26 10:19:08 2019 (correction of 0s)
20190626-10:19:08 Recording: event download success
20190626-10:19:08 Recording: disk space available = 3975GB
20190626-10:19:08 Recording: current time = Wed Jun 26 10:19:08 2019 (correction of 0s)
20190626-10:19:08 Recording: no timer events planned

The server time is still incorrect. It shows 2 hours less than the NAS time (The NAS time is the correct one).

This is the setup time at the NAS:

Image

I don't know if this can be the problem because of the DVR Engine doesn't restart properly when the NAS wakes up.
Last edited by jdcuartero on Thu Jun 27, 2019 4:39 am, edited 3 times in total.

demonrik
Posts: 1116
Joined: Mon May 04, 2015 10:03 am
Device ID: 10736454, 1073A35A, 1075C377

Re: DVR Engine doesn't restart

Post by demonrik » Wed Jun 26, 2019 7:01 am

Thanks for all the info
jdcuartero wrote:
Wed Jun 26, 2019 1:42 am
This morning the NAS boots up.
Do you shutdown the NAS every night?
When I am going to the UI ... it looks it is working OK, because I can see the hardware and the software.
....
And I can also see the log files ... but the log file is from today ... before the NAS shutted down.
strange...
Discover finds everything, but log shows the engine isn't running
Status bar also shows engine is running... Unlike discover this is local and gotten from the DVR binary
So ... I am going to the Dashboard window and ... I push the "stop" button and then the "play" button. After doing this ... I am able to play the channels without DVR Failure. The log file is updated and I can see the recordings at the UI web page
This is the bit that confuses me.
i have seen issues in the past with a bad ARM binary causing permissions issues on start.. But when that happens it just fails to start or it's running as root and the UI can't stop the engine
the fact you can stop it means it is executing and is executing as the http user on your system.
from log window it would seem that the engine stops at ~1am UTC and then resumes once you do the restart at 6am UTC
any ideas when the NAS actually restarted?
So I don't know exactly what is going on. :cry:
Will figure it out - but isn't straight forward.
One thing I have just seen. The time from the DVR Manager is about 2 hours earlier than the NAS.
The log is always in UTC time - I don't adjust it in the UI so you can cut and paste it to emails, etc.. And if I modified it, SD might get confused ;)
Rest of UI should be showing everything in right time
To be clear - you have the time all set up correctly - is not the issue ;)
As you recommend ... I have stopped the DVR Engine ... then I deleted all the log files using the Synology File Station explorer. Then I restarted the engine (pushing the play button). And a new log file was generated at the record path. Everything works again. So the DVR Engine starts OK. I can see the recordings at the UI and I can play the channels.
I meant restart the NAS..
Would be curious to see if it even creates the log file.

What about the /tmp/hdhr_arch_choice file?

If you provide a Device ID maybe SD can provide some insights on their end.. It looks like the engine fires up.. but it doesn't have permissions to the folder.. Could be it thinks it's full.

To me it's like something just isn't quite ready at start up.. but by the time you log in and restart it's all ok.
It could be something really simple... e.g. if for some reason NAS doesn't shutdown the filesystem cleanly and needs to scrub on boot, the scrub could mean the filesystem isn't ready by the time the engine starts.. It looks ready, but as far as engine is concerned it's full or no access. And with no ability to put logs to somewhere meaningful (cough - please please add this feature SD - cough) we can't debug beyond getting the engine up and running (and it says it is - the discover says it is - and the viewer says it is).
@jasonl can check and ensure they're seeing the engine communicate with servers and maybe see if my suspicion is correct.
As to the solution - we need to figure out the real problem first :(

I wonder if it's something to do with btrfs.. It shouldn't be.. but you never know.

I think I'll put something into the startup script in the SPK to 'check' the recordpath and log findings ahead of engine start. but that won't help you right now. Busy today, so earliest I'll get to this is Friday :(

Anyway...
One more thing to try..

Change the recordpath to /tmp
Don't record anything - just set the record path.. stop the engine.. and restart the NAS.
If it comes up all good and you get a log file with the boot info on the dashboard then we know the SPK, NAS, etc.. is all good.. it's definitely something on the recordpath
Immediately change the recordpath and restart engine once you verify so you don't fill /tmp which is really small.

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Wed Jun 26, 2019 7:11 am

Thank you demonrik. I will try to change the record path and restart the NAS once I come back to home this afternoon. I will keep you updated.

jasonl
Silicondust
Posts: 14067
Joined: Sun Oct 28, 2007 9:23 pm

Re: DVR Engine doesn't restart

Post by jasonl » Wed Jun 26, 2019 11:20 am

The DVR is starting and has server communications, it can't write to the recording directory. I'm thinking you might be on to something about the NAS being shut down uncleanly and still in the middle of a filesystem check when the DVR starts, so maybe the permissions aren't right?

demonrik
Posts: 1116
Joined: Mon May 04, 2015 10:03 am
Device ID: 10736454, 1073A35A, 1075C377

Re: DVR Engine doesn't restart

Post by demonrik » Wed Jun 26, 2019 3:05 pm

jasonl wrote:
Wed Jun 26, 2019 11:20 am
The DVR is starting and has server communications, it can't write to the recording directory. I'm thinking you might be on to something about the NAS being shut down uncleanly and still in the middle of a filesystem check when the DVR starts, so maybe the permissions aren't right?
kind of backs it up.
If the system is scheduling a shutdown and something doesn't close so the filesystem is still open.. I wonder if BTRFS is storing the journal and then writing that on next boot and that scrub is just taking a while.
the problem is trying to debug this since by the time OP logs in, it seems to have cleared and thus a restart of the engine fixes.

@jdcuartero - are there any storage notifications on the system after reset to indicate a scrub?

Also it may be worth going back to previous engine version via older SPK and see if you have same issue.. Just to make sure nothing was introduced in the engine which is causing the scrub (assuming that's the issue here).

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Wed Jun 26, 2019 4:10 pm

Thank you to Jason and Demonrik for your help.

I have changed the record path to the tmp folder. Then I restarted the NAS, with the same result. The engine it is not running after the NAS restarts.

One curious thing is ... it is not enough by clicking the "play" button at the UI. I have to click the "stop" button and then the "play" button in the dashboard in order the engine can start.

I also removed the 0.7.0 spk and I installed some old versions.

In the past I have no problems with the version 0.6.8 and version 0.6.9. So I installed both versions. But today I have the same result with both versions ... the engine it is not starting after the NAS boots up.

One thing I remember ... the problem started after the HDHomeRun Record was updated some days ago to version 20190621. I can remember that some days ago I have the 0.6.9 spk running ok and I saw a message at my.hdhomerun.com showing that the HDHomeRun Record can be updated. So I updated the HDHomeRun Record through my.hdhomerun.com.

Maybe something has been corrupted during the update?

jasonl
Silicondust
Posts: 14067
Joined: Sun Oct 28, 2007 9:23 pm

Re: DVR Engine doesn't restart

Post by jasonl » Wed Jun 26, 2019 5:09 pm

I don't believe it is correct to say the DVR isn't starting. It is starting, it just can't write to the recording location when it starts.

What method are you using to shut down the NAS?

jdcuartero
Posts: 11
Joined: Tue Jun 25, 2019 1:58 am
Device ID: 1250FE42

Re: DVR Engine doesn't restart

Post by jdcuartero » Wed Jun 26, 2019 5:16 pm

There is an "Energy program" at the control panel. So I scheduled to shut down the NAS at 3:00am and the boot up is scheduled at 9:00am

But if I restart manually trough the DSM the result is the same.

In both cases I receive the DVR Failure.

jasonl
Silicondust
Posts: 14067
Joined: Sun Oct 28, 2007 9:23 pm

Re: DVR Engine doesn't restart

Post by jasonl » Wed Jun 26, 2019 5:50 pm

The DVR failure message indicates the DVR is running, but can't access the recording location. If the DVR wasn't running, you couldn't get a DVR failure error because the error is generated by the DVR.

@demonrik I'm not super familiar with the packaging system on the Synology. Is there any kind of option at the package level to tell the system to not try to start the package until after the filesystem is fully mounted and ready for use? Otherwise I don't know what could be done besides having either the startup script or the DVR itself check to see if the RecordPath is writable and if not sleeping for a while until it is, similar to what the DVR does on Mac to wait for USB drives to be mounted. I haven't seen this before on other Linux systems so I'm not sure what Synology is doing differently that's causing it.

Post Reply