Vix 5.1.006. Time wrong

[birdman]

If the initial ntpdate-sync fails (or takes long), E2 will start with the fake-hwclock time, just like you said.
That's absolutely no problem at all though, as it will later do some own time sync (Either DVB or NTP) anyways and previously E2 sometimes even started on 1970-01-01 and had no problem with it.

The only problem is that currently two sync can happen at the very same time.

Which appears to be what is happening. And that is a bug.
The simple fix is to ensure that the first ntpdate is run synchronously. Then concurrent ntpdate syncs will not occur, and services will start with the correct time set and the enigma2 log will have a sensible time-stamp in its name(unless ntp isn't working because of network connectivity failure, in which case ntpdate-sync isn't going to do anything and this whole discussion becomes moot).

 

[birdman]

EDIT - I've noticed that the ntpdate updates are not being logged in "messages" for some reason (so I can't tell which NTP server is being used). The E2 log is reporting ntpdate-sync at the 30 minute intervals as follows:

I'm not sure that they are meant to be.
Hence the debug version of my script which does log when it runs - except the the initial calls are before syslogd start up, so they don't get logged either, which is why I added the log file in /var/tmp.

 

[birdman]

This may be a WiFi - specific issue.

Probably. But it's related to timings at start-up. And running the ntpdate in the background loses all control of timing.

 

[Joe_90]

I'm not sure that they are meant to be.
Hence the debug version of my script which does log when it runs - except the the initial calls are before syslogd start up, so they don't get logged either, which is why I added the log file in /var/tmp.

The ntpdate updates were being logged in syslog (messages) up to several days ago - that is what I pasted onto the posts to show the double updates. Now I don't see anything logged in syslog in regard to ntpdate. There are just the entries in the normal debug log showing ntpdate-sync being run every 30 minutes and updating the system clock.

Since I've uncommented the second line in /etc/default/fake-hwclock so that it now reads

# Uncomment to set clock even if saved value appears to be in the past
FORCE=force

what is happening is that the file /etc/fake-hwclock.data is no longer being updated on shutdown and the system now boots with the epoch start date of 1/1/1970 which means that the system now forces a time update from the transponder if the initial ntpdate-sync doesn't work for any reason. So, normal service (of a sort) has been resumed in that the system clock is set correctly and then ntpdate-sync works at 30 minute intervals thereafter and further transponder syncs are disabled.

Now, the way I interpreted the wording in the first line of /etc/default/fake-hwclock was that removing the comment in the second line "Force=force" would force the update of /etc/fake-hwclock.data on each shutdown. Instead, what appears to happen is that there are no further updates to /etc/fake-hwclock.data, no further usage of stored time data and the system reverts to the old method of starting from epoch zero. Is this the intended behaviour, SpaceRat?

 

[birdman]

Since I've uncommented the second line in /etc/default/fake-hwclock so that it now reads

# Uncomment to set clock even if saved value appears to be in the past
FORCE=force

There's a bug in that config fie....
Having read the script that uses it that line should be:

FORCE=true

The current setting mean that the script aborts, being unable to find a command "force", hence the lack of any update to /etc/fake-hwclock.data.

 

[ccs]

..... isn't FORCE simply a parameter passed onto fake-hwclock. eg fake-hwclock load FORCE

fake-hwclock [ command ] [ force ]

edit:

Just moved onto 5.1.012, so can now see /bin/fake-hwclock

...
FORCE=false
if [ "$2"x = "force"x ] ; then
FORCE=true
fi
...

 

[ccs]

... fake-hwclock load FORCE should read fake-hwclock load force

 

[Joe_90]

So the setting is correct - "force", not "true". However, setting "force" seems to stop the process using the saved time at all, either on boot or on shutdown on my Mutant HD51, so maybe there is another issue?

 

[ccs]

.... I'm not so sure anymore, Birdman refers to a script which uses /etc/default/fake-hwclock, /bin/fake-hwclock doesn't.

 

[SpaceRat]

So the setting is correct - "force", not "true". However, setting "force" seems to stop the process using the saved time at all, either on boot or on shutdown on my Mutant HD51, so maybe there is another issue?

The Mutant HD51 is one of the boxes that appears to have no or no Linux access to the FP-RTC.

The proc entry always reports "0" and by setting "force" you are enforcing setting the box to that value ... which is exactly the reason why you need a special parameter to also restore bad times from RTC.

 

[Joe_90]

@SpaceRat - I recall seeing "0" reports on FP-RTC accesses on my HD51 as you say.

Here is an example:

<   940.143> [eDVBLocalTimerHandler] no transponder tuned... or no TDT/TOT avail .. try to use RTC :)
<   940.143> [eDVBLocalTimerHandler]    getRTC returned time=0. RTC problem?

What do you mean by this, please - "which is exactly the reason why you need a special parameter to also restore bad times from RTC" ?

 

[SpaceRat]

What do you mean by this, please - "which is exactly the reason why you need a special parameter to also restore bad times from RTC" ?

It's the reason why "FORCE" exists:
As I said, the FP-RTC can not be behind the fake-hwclock, only ahead.

You simply can't flash the image before it was built and you can not boot the box before the previous shutdown ... impossible, that's why the script simply doesn't do that ... unless you set the FORCE option.

 

[Joe_90]

Ok - I think I see

However, on my HD51 I have had several instances where the time has advanced due to the ntpdate-sync running twice on Vix. This seems to be a Vix feature/bug due to the lock file not being created. Then, because of timing issues on WiFi (or some other reason), the clock is not being set correctly on startup and I end up continually running a future date which messes up my PowerTimers and recording timers and EPG etc. The only way for me to resolve this at the moment is to use the "force" parameter which is forcing the system to use the start of the epoch and messes with the filename of the Vix debug log.

Before any these changes were made my HD51 was running fine on NTP setting by WiFi and the debug logs had proper current dated filenames. I think if the double start of ntpdate-sync was eliminated it would remove the "future date" issue, but there is obviously some other difference as to how my box is setting NTP date and time now versus how it was doing it in the past. I think the significant difference is that previously enigma.sh was running ntpdate directly at system start. That has been removed now and ntpdate-sync is doing it instead but I think it's happening too early in the boot sequence in my particular case. I know that @birdman posted an amended script (and I have used it) but it doesn't seem to work for me.

 

[birdman]

The Mutant HD51 is one of the boxes that appears to have no or no Linux access to the FP-RTC.

Both of my boxes (an Xtrend et800 and a Miraclebox MBtwin) also have a /proc/stb/fp/rtc that always return 0.

The proc entry always reports "0" and by setting "force" you are enforcing setting the box to that value ... which is exactly the reason why you need a special parameter to also restore bad times from RTC.

You can try to set any value you wish on these systems (including the current time) and that rtc device file will still return 0. Setting "force" makes no difference to that.
This is why fake-hwclock writes the current (== latest) time to a file, precisely because there is no valid RTC n the system.

But since, by definition, that restores an incorrect time at boot up, then any system that is able to use NTP should do so before any other processes are started.

This would mean that if enigma2 is used to set time internally using NTP then it could skip the immediate one (just set up the every 30min ones) as it would know that the NTP time has just been set, if it is settable at all.

 

[birdman]

It's the reason why "FORCE" exists:
As I said, the FP-RTC can not be behind the fake-hwclock, only ahead.

You simply can't flash the image before it was built and you can not boot the box before the previous shutdown ... impossible, that's why the script simply doesn't do that ... unless you set the FORCE option.

The FORCE setting is only used to force a load at start-up. It isn't used when saving any clock value.

 

[birdman]

.... I'm not so sure anymore, Birdman refers to a script which uses /etc/default/fake-hwclock, /bin/fake-hwclock doesn't.

My fault. That was wrong.
It's actually used by the init script in /etc/init.d.

 

[birdman]

However, on my HD51 I have had several instances where the time has advanced due to the ntpdate-sync running twice on Vix. This seems to be a Vix feature/bug due to the lock file not being created.

The lock file has never been created. And it shouldn't need a lock file either (ntpdate itself should probably be locking, but that is a separate issue).
It's a trivial matter to run the first ntpdate in the foreground so that the system services are started with the correct time if it is available. Then the issue goes away.

 

[Joe_90]

The lock file has never been created. And it shouldn't need a lock file either (ntpdate itself should probably be locking, but that is a separate issue).
It's a trivial matter to run the first ntpdate in the foreground so that the system services are started with the correct time if it is available. Then the issue goes away.

ntpdate is a deprecated time setting facility in linux (it's not been changed in years). It's normally only used once at system start-up in linux systems and then ntpd is used to maintain the system clock accurately if needed. Using ntpdate to poll a single server (in my case) is probably not very reliable. ntpd is better because one normally provides a list of time servers with a preferred option so that it can poll several and then work out which is accurate. Once the system time settles down servers are polled less frequently. I'm fairly sure that ntpdate does not use any locking mechanism to prevent it being run multiple times.

However, for E2 systems, ntpdate is probably "good enough" and the fact that it is scheduled to run at 30 minute (or greater) intervals is probably ok. What you're saying about ensuring it is run at an appropriate time (when network interfaces are actually up) is correct and we should ensure that it happens before the various timer checks (or log naming) are done. If ntpdate fails to get a response at boot time, then the system should use the transponder time instead. If it fails on one of the 30 minute checks, then just carry on with the existing time.

In the two days since I've changed /etc/default/fake-hwclock to "force", I have not had any problem with time setting. The system starts at zero, ntpdate seems to start too early and returns nothing which means the clock check decides to use the transponder time in preference at boot. Then ntpdate runs at 30 minute intervals and updates the time. The debug log file is dated 1/1/1970.

So, after having a year of correctly dated log files and no issues with time keeping by NTP on my HD51, I am now in a situation where I can either have the time randomly setting at startup to any time in the future with log files dated as of the previous shutdown time OR I can have the time running reasonably stable with log files dated 1/1/1970 all by either commenting out or enabling the "force" parameter in /etc/default/fake-hwclock.

 

[Joe_90]

As an aside - is it usual to have a script in /etc/init.d, a parameter file in /etc/default and another script in /bin all with the exact same name - e.g. "fake-hwclock"? It seems confusing to me. Just asking

 

[SpaceRat]

I'm fairly sure that ntpdate does not use any locking mechanism to prevent it being run multiple times.

It does, the pre-requisites for it just haven't been installed inside the image previously. I changed that yesterday.

(when network interfaces are actually up)

I have also added a 500ms sleep between checks if the network is up.
This should help if the network is slow to come up.
If this alone doesn't solve the problem of ntpdate-sync failing on slow interfaces, we can increase the retry counter too.

which means the clock check decides to use the transponder time in preference at boot.

The clock check decices nothing, you decide:
If you set E2 to use DVB time, it will sync time using DVB right after start and continue to sync the clock with DVB at run-time, no matter what the time was set to before by fake-hwclock, restoring the FP-RTC or ntpdate.
If you set E2 to use NTP time, it will sync time using NTP right after start and continue to sync the clock with NTP at run-time, no matter what the time was set to before by fake-hwclock, restoring the FP-RTC or ntpdate.

The only problem I can see on your setup is that there is a timing issue: ntpdate-sync from boot (if-up) runs at the very same time as E2s own first NTP sync and thus does a double forward.
As soon as OpenViX builds with latest git changes, this issue will be gone, as ntpdate-sync will no longer allow concurrent runs.
For the second issue (on-boot-ntpdate-sync failing on slow networks), only tests, e.g. by you, can show if 0.5s wait time between 5 retries is enough, if not, we will increase retries.