Hello Guest, if you are reading this it means you have not registered yet. Please take a second, Click here to register, and in a few simple steps you will be able to enjoy our community and use our OpenViX support section.
Page 10 of 19 FirstFirst ... 89101112 ... LastLast
Results 136 to 150 of 273

Thread: Vix 5.1.006. Time wrong

  1. #136
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by ccs View Post
    .... 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.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  2. #137
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by fat-tony View Post
    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.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  3. #138
    Joe_90's Avatar
    Title
    Moderator
    Join Date
    Mar 2014
    Location
    Wicklow, Ireland
    Posts
    4,100
    Thanks
    1,265
    Thanked 1,115 Times in 879 Posts
    Quote Originally Posted by birdman View Post
    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.
    GB Quad Plus, Mut@nt HD51, AX HD61, 80cm dish and Supreme Dark motor. Sony STR-DN 1060, Sony UHP-H1 Bluray, Odroid N2+ (CoreElec), Monitor Audio Bronze 5.1 speakers

  4. #139
    Joe_90's Avatar
    Title
    Moderator
    Join Date
    Mar 2014
    Location
    Wicklow, Ireland
    Posts
    4,100
    Thanks
    1,265
    Thanked 1,115 Times in 879 Posts
    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
    GB Quad Plus, Mut@nt HD51, AX HD61, 80cm dish and Supreme Dark motor. Sony STR-DN 1060, Sony UHP-H1 Bluray, Odroid N2+ (CoreElec), Monitor Audio Bronze 5.1 speakers

  5. #140
    SpaceRat's Avatar
    Title
    Senior Member
    Join Date
    Apr 2015
    Posts
    206
    Thanks
    25
    Thanked 79 Times in 52 Posts
    Quote Originally Posted by fat-tony View Post
    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.


    Quote Originally Posted by fat-tony View Post
    (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.


    Quote Originally Posted by fat-tony View Post
    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.
    Receiver/TV:
    • Vu+ Duo² 4*S2+2*C / 1.8TB HDD / OpenATV 6.1@Samsung 50" Plasma
    • AX Quadbox 2400 / 2*S2/2*C / 930GB HDD / OpenATV 6.1@Samsung 32" LCD
    • Vu+ Solo² / 465GB HDD / OpenATV 6.1
    • Vu+ Solo² / 230GB HDD / OpenATV 6.1
    • DVBSky S2-Twin-Tuner PCIe@Samsung SyncMaster T240HD (PC)
    Pay TV: Redlight Mega, Brazzers TV Europe, XXL, HD-, Sky
    Internet: Unitymedia 1play 100 / Cisco EPC3212 + Linksys WRT1900ACS + Fritz!Box 7390 / IPv4 (UM) + IPv6 (HE)

  6. #141
    SpaceRat's Avatar
    Title
    Senior Member
    Join Date
    Apr 2015
    Posts
    206
    Thanks
    25
    Thanked 79 Times in 52 Posts
    Quote Originally Posted by fat-tony View Post
    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
    fake-hwclock is a 1:1 rip from Raspbian, the Debian distro for Raspberry Pis
    Receiver/TV:
    • Vu+ Duo² 4*S2+2*C / 1.8TB HDD / OpenATV 6.1@Samsung 50" Plasma
    • AX Quadbox 2400 / 2*S2/2*C / 930GB HDD / OpenATV 6.1@Samsung 32" LCD
    • Vu+ Solo² / 465GB HDD / OpenATV 6.1
    • Vu+ Solo² / 230GB HDD / OpenATV 6.1
    • DVBSky S2-Twin-Tuner PCIe@Samsung SyncMaster T240HD (PC)
    Pay TV: Redlight Mega, Brazzers TV Europe, XXL, HD-, Sky
    Internet: Unitymedia 1play 100 / Cisco EPC3212 + Linksys WRT1900ACS + Fritz!Box 7390 / IPv4 (UM) + IPv6 (HE)

  7. #142
    Joe_90's Avatar
    Title
    Moderator
    Join Date
    Mar 2014
    Location
    Wicklow, Ireland
    Posts
    4,100
    Thanks
    1,265
    Thanked 1,115 Times in 879 Posts
    Quote Originally Posted by SpaceRat View Post
    It does, the pre-requisites for it just haven't been installed inside the image previously. I changed that yesterday.
    I was referring to the ntpdate binary - not ntpdate-sync



    Quote Originally Posted by SpaceRat View Post
    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.
    My box is set to use NTP time, but if there is no time available (for whatever reason) at boot, then E2 seems to use transponder time for the initial clock setting, then it reverts to NTP at the specified intervals (default 30 mins) after that.


    Quote Originally Posted by SpaceRat View Post
    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.
    I think (I'm pretty sure!) that you are correct. It's the major change which has happened in the past month or so. The old E2 ntpdate synchronisation always worked in my setup. Now it's been commented out and the ntpdate-sync script is failing as it seems to be starting too early as you say. However, I still have the situation where I'm getting a double forward of time. Is E2 still running an ntpdate call somewhere? I thought it had been suppressed?
    GB Quad Plus, Mut@nt HD51, AX HD61, 80cm dish and Supreme Dark motor. Sony STR-DN 1060, Sony UHP-H1 Bluray, Odroid N2+ (CoreElec), Monitor Audio Bronze 5.1 speakers

  8. #143
    Joe_90's Avatar
    Title
    Moderator
    Join Date
    Mar 2014
    Location
    Wicklow, Ireland
    Posts
    4,100
    Thanks
    1,265
    Thanked 1,115 Times in 879 Posts
    Quote Originally Posted by SpaceRat View Post
    fake-hwclock is a 1:1 rip from Raspbian, the Debian distro for Raspberry Pis
    Ok - but it does not seem to me to be best practice to name scripts and settings files exactly the same. I run several Raspberry Pis and I had asked in the past for the devs here on Vix to introduce the fake hwclock mechanism as I hated the 1/1/1970 filenames on the debug logs!
    Now I'm not so sure it's such a good ideas but maybe we'll get there in the end!

    I'll run a dev build for my HD51 later today and incorporate your changes and re-test, thanks.
    GB Quad Plus, Mut@nt HD51, AX HD61, 80cm dish and Supreme Dark motor. Sony STR-DN 1060, Sony UHP-H1 Bluray, Odroid N2+ (CoreElec), Monitor Audio Bronze 5.1 speakers

  9. #144
    SpaceRat's Avatar
    Title
    Senior Member
    Join Date
    Apr 2015
    Posts
    206
    Thanks
    25
    Thanked 79 Times in 52 Posts
    Quote Originally Posted by fat-tony View Post
    I was referring to the ntpdate binary - not ntpdate-sync
    You have to see the whole package though


    Quote Originally Posted by fat-tony View Post
    The old E2 ntpdate synchronisation always worked in my setup. Now it's been commented out and the ntpdate-sync script is failing as it seems to be starting too early as you say.
    That part is only about getting the ntpdate-sync from where it was before (As a workaround in enigma2.sh) to where it belongs to (System boot).
    Workarounds are always bad, because in the end they kick you into the ass ... previously, the very same (double time jump) was possible, just on fast networks rather than slow ones ...
    As soon as we have a good value for the amount of retries, it will work cleanly for all, networks coming up slowly, "mediumly" and fastly ...

    Quote Originally Posted by fat-tony View Post
    However, I still have the situation where I'm getting a double forward of time. Is E2 still running an ntpdate call somewhere?
    Yes.
    If you set it to use NTP, is simply periodically calls ntpdate-sync ...
    Receiver/TV:
    • Vu+ Duo² 4*S2+2*C / 1.8TB HDD / OpenATV 6.1@Samsung 50" Plasma
    • AX Quadbox 2400 / 2*S2/2*C / 930GB HDD / OpenATV 6.1@Samsung 32" LCD
    • Vu+ Solo² / 465GB HDD / OpenATV 6.1
    • Vu+ Solo² / 230GB HDD / OpenATV 6.1
    • DVBSky S2-Twin-Tuner PCIe@Samsung SyncMaster T240HD (PC)
    Pay TV: Redlight Mega, Brazzers TV Europe, XXL, HD-, Sky
    Internet: Unitymedia 1play 100 / Cisco EPC3212 + Linksys WRT1900ACS + Fritz!Box 7390 / IPv4 (UM) + IPv6 (HE)

  10. The Following User Says Thank You to SpaceRat For This Useful Post:

    Joe_90 (20-01-18)

  11. #145
    dsayers's Avatar
    Title
    ViX Beta Tester
    Join Date
    Mar 2016
    Posts
    1,752
    Thanks
    472
    Thanked 606 Times in 432 Posts
    Hi im not sure if this is releated I have EPG xml files downloading on boot and just had an issue with enigma2 taking agies to load. I created a debug log with Talnet, this is the part I noticed


    Code:
    Traceback (most recent call last):
      File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 310, in addCallbacks
        
      File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 653, in _runCallbacks
        
      File "/usr/lib/python2.7/site-packages/twisted/internet/base.py", line 441, in _continueFiring
        
      File "/usr/lib/python2.7/site-packages/twisted/internet/base.py", line 671, in disconnectAll
        
    --- <exception caught here> ---
      File "/usr/lib/python2.7/site-packages/twisted/python/log.py", line 103, in callWithLogger
        
      File "/usr/lib/python2.7/site-packages/twisted/python/log.py", line 86, in callWithContext
        
      File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 122, in callWithContext
        
      File "/usr/lib/python2.7/site-packages/twisted/python/context.py", line 85, in callWithContext
        
      File "/usr/lib/python2.7/site-packages/twisted/internet/unix.py", line 420, in connectionLost
        
    exceptions.OSError: [Errno 2] No such file or directory: '/tmp/hotplug.socket'
    I deleted the prestart sh and enigma2 booted fine

    Is this related to time issues or completely different? If a different issues apologies.

    Edit after another resart I still get the same issue. Ill re flash and start a new thread if needed.
    Last edited by dsayers; 20-01-18 at 17:21.

  12. #146
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by SpaceRat View Post
    It does, the pre-requisites for it just haven't been installed inside the image previously. I changed that yesterday.
    No, ntpdate doesn't have any locking. ntpdate-sync does (optionally), but that's just a front-end script. you can still run ntpdate by hand twice at the same time.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  13. #147
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by fat-tony View Post
    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.
    So it's not actually detracted as a means of setting the time initially. Although many system would have an RTC and hence just use NTP.

    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.
    Correct. As far as I can tell fake-hwclock was installed just so that a (almost) valid time could always be set at start-up. But this was only ever needed for services which required network access (e.g. ssl certificates for VPN) and hence in all situations where it was needed a synchronous ntpdate-sync would have been better, and simpler to implement.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  14. #148
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by SpaceRat View Post
    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.
    Which is arguably a bug, as ntpdate-sync will have been run as the network interface is brought up, so it doesn't need to be run as enigma2 starts (transponder time does, though, as they may be no netwo0rk) - just the "run every 30mins from now" bit is needed.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  15. #149
    birdman's Avatar
    Title
    Moderator
    Join Date
    Sep 2014
    Location
    Hitchin, UK
    Posts
    7,769
    Thanks
    235
    Thanked 1,656 Times in 1,305 Posts
    Quote Originally Posted by fat-tony View Post
    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
    It is confusing (it confused me). I wouldn't do it, but I didn't write the code. Once someone has written it it would be a potential maintenance probelm to change it just for one distro.
    MiracleBox Prem Twin HD - 2@DVB-T2 + Xtrend et8000 - 5(incl. 2 different USBs)@DVB-T2[terrestrial - UK Freeview HD, Sandy Heath] - LAN/USB-stick/HDD

  16. #150
    Joe_90's Avatar
    Title
    Moderator
    Join Date
    Mar 2014
    Location
    Wicklow, Ireland
    Posts
    4,100
    Thanks
    1,265
    Thanked 1,115 Times in 879 Posts
    Thanks @birdman. It did confuse me, but I thought it was maybe a "style" thing. I'm an old-school programmer from the time before object-oriented languages. I haven't programmed since the early 80's as my job description changed over time. I realise that the coding was lifted for various distributions unchanged and that it would be a maintenance issue - just thought it was sloppy as I was always taught to use "meaningful data names". Anyway - enough of that!

    I cleaned up my build system and pulled from the OE 4.2 branch and built my HD51 image as a clean OpenVix 5.2.000 dev. I flashed it clean (no restores) and set up the box to use NTP from the default "pool.ntp.org" and shut it down at 02:18 this morning (21/01). I booted at about 10:45 this morning.


    Code:
    <    23.121> [Volume] setValue 50
    <    23.158> [eDVBVolumecontrol] Setvolume: raw: 100 100, -1db: 0 0
    <    23.163> [eDVBVolumecontrol] Setvolume: raw: 50 50, -1db: 32 32
    <    23.184> [Skin] processing screen Scart:
    <    23.191> [Skin] processing screen AutoVideoModeLabel:
    <    23.194> [LogManager] Trim Poll Started
    <    23.212> [LogManager] Trash Poll Started
    <    23.212> [NetworkTime] Updating
    <    23.212> [Console] command: /usr/bin/ntpdate-sync                  <------------------------------------------- ntpdate-sync kicked off
    <    23.212> [eConsoleAppContainer] Starting /bin/sh
    <    23.214> [eDVBFrontend] close frontend 1
    <    23.214> [eDVBFrontend] sendTone allowed only in feSatellite (2)
    <    23.222> [Navigation] playing 1:0:16:451:3E9:2174:EEEE0000:0:0:0:
    <    23.279> [eDVBServicePlay] timeshift
    <    23.279> [eDVBServicePlay] timeshift
    <    23.280> [eDVBServicePlay] timeshift
    <    23.281> [eDVBServicePlay] timeshift
    <    23.281> [eDVBServicePlay] timeshift
    <    23.281> [eDVBServicePlay] timeshift
    <    23.282> [Notifications] RemovePopup, id = ZapError
    <    23.297> [eDVBResourceManager] allocate channel.. 03e9:2174
    <    23.297> [eDVBFrontend] opening frontend 1
    <    23.306> [eDVBFrontend] (1)tune
    <    23.306> [eDVBFrontend] tune setting type to 2 from 0
    <    23.306> [eDVBChannel] OURSTATE: tuning
    <    23.306> [eDVBServicePMTHandler] allocate Channel: res 0
    <    23.306> [eDVBCIInterfaces] addPMTHandler 1:0:16:451:3E9:2174:EEEE0000:0:0:0:
    <    23.306> [eDVBChannel] getDemux cap=00
    <    23.306> [eDVBResourceManager] allocate demux cap=00
    <    23.306> [eDVBResourceManager] allocating demux adapter=0, demux=0, source=-1 fesource=1
    <    23.306> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.311> [eHdmiCEC] received message 00 8E 00
    <    23.312> [Console] finished: ('/sbin/ip', '/sbin/ip', '-o', 'addr', 'show', 'dev', 'eth0')
    <    23.321> [Console] command: route -n | grep eth0
    <    23.321> [eConsoleAppContainer] Starting /bin/sh
    <    23.324> [Console] finished: ('/sbin/ip', '/sbin/ip', '-o', 'addr', 'show', 'dev', 'wlan0')
    <    23.325> [Console] command: route -n | grep wlan0
    <    23.325> [eConsoleAppContainer] Starting /bin/sh
    <    23.329> [Task] job Components.Task.Job name=LogManager #tasks=1 completed with [] in None
    <    23.330> [eDVBFrontend] startTuneTimeout 5000
    <    23.331> [eDVBFrontend] setVoltage 0
    <    23.332> [eDVBFrontend] setFrontend 1
    <    23.332> [eDVBFrontend] setting frontend 1
    <    23.333> [eDVBFrontend] (1)fe event: status 0, inversion off, m_tuning 1
    <    23.335> [LogManager] probing folders
    <    23.347> [LogManager] found following log's: ['/home/root/logs']
    <    23.347> [LogManager] looking in: /home/root/logs
    <    23.348> [LogManager] /home/root/logs: bytesToRemove -10463154
    <    23.350> [Task] job Components.Task.Job name=LogManager #tasks=1 completed with [] in None
    <    23.359> [Console] finished: route -n | grep eth0
    <    23.367> [Console] finished: route -n | grep wlan0
    <    23.367> 0.0.0.0
    <    23.367> 192.168
    <    23.369> [Network] read configured interface: {'lo': {'dhcp': False}, 'wlan0': {'dhcp': True}, 'eth0': {'dhcp': True}}
    <    23.370> [Network] self.ifaces after loading: {'wlan0': {'preup': '\tpre-up wpa_supplicant -iwlan0 -c/etc/wpa_supplicant.wlan0.conf -B -dd -Dnl80211 || true\n', 'predown': '\tpre-down wpa_cli -iwlan0 terminate || true\n', 'ip': [192, 168, 0, 126], 'up': True, 'mac': '00:e0:4c:0d:39:8e', 'dhcp': True, 'bcast': [192, 168, 0, 255], 'netmask': [255, 255, 255, 0], 'gateway': [192, 168, 0, 1]}, 'eth0': {'preup': False, 'predown': False, 'ip': [0, 0, 0, 0], 'up': False, 'mac': '00:6c:fd:ff:51:6b', 'dhcp': True, 'netmask': [0, 0, 0, 0], 'gateway': [0, 0, 0, 0]}}
    <    23.377> SerienRecorder plugin not found
    <    23.377> EPG Refresh Plugin not found
    <    23.379> [OpenWebif] no plugins to load
    <    23.380> [OpenWebif] started on 80
    <    23.381> [Avahi] Not running yet, cannot register type _http._tcp.
    
    <    23.706> [eDVBFrontend] (1)fe event: status 1f, inversion off, m_tuning 2
    <    23.706> [eDVBChannel] OURSTATE: ok
    <    23.706> [eDVBLocalTimerHandler] channel 0xf60b50 running
    <    23.706> [eEPGCache] channel 0xf60b50 running
    <    23.706> [eDVBChannel] getDemux cap=00
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.706> [eDVBResourceManager] stop release channel timer
    <    23.706> [eDVBChannel] getDemux cap=01
    <    23.706> [eDVBResourceManager] allocate demux cap=01
    <    23.706> [eEPGCache] next update in 2 sec
    <    23.706> [eDVBResourceManager] allocating shared demux adapter=0, demux=0, source=1
    <    23.706> [eDVBServicePMTHandler] ok ... now we start!!
    <    23.706> [eDVBServicePlay] eventNewProgramInfo timeshift_enabled=0 timeshift_active=0
    <    23.706> [eDVBServicePlay] have 1 video stream(s) (0451), and 1 audio stream(s) (04b5), and the pcr pid is 1ffe, and the text pid is 0519
    <    23.706> [eDVBChannel] getDemux cap=01
    <    23.713> [eTSMPEGDecoder] decoder state: play, vpid=0451, apid=04b5
    <    23.713> [eDVBPCR0] DMX_SET_PES_FILTER pid=0x1ffe ok
    <    23.713> [eDVBPCR0] DEMUX_START ok
    <    23.713> [eDVBAudio0] DMX_SET_PES_FILTER pid=0x04b5 ok
    <    23.713> [eDVBAudio0] DEMUX_START ok
    <    23.713> [eDVBAudio0] AUDIO_SET_BYPASS bypass=1 ok
    <    23.713> [eDVBAudio0] AUDIO_PAUSE ok
    <    23.713> [eDVBAudio0] AUDIO_PLAY ok
    <    23.719> [eDVBVideo] Video Device: /dev/dvb/adapter0/video0
    <    23.719> [eDVBVideo] demux device: /dev/dvb/adapter0/demux0
    <    23.719> [eDVBVideo0] VIDEO_SET_STREAMTYPE 1 - ok
    <    23.719> [eDVBVideo0] DMX_SET_PES_FILTER pid=0x0451 ok
    <    23.719> [eDVBVideo0] DEMUX_START ok
    <    23.719> [eDVBVideo0] VIDEO_FREEZE ok
    <    23.719> [eDVBVideo0] VIDEO_PLAY ok
    <    23.725> [eDVBText0] DMX_SET_PES_FILTER pid=0x0519 ok
    <    23.725> [eDVBText0] DEMUX_START ok
    <    23.727> [eDVBVideo0] VIDEO_SLOWMOTION 0 ok
    <    23.727> [eDVBVideo0] VIDEO_FAST_FORWARD 0 ok
    <    23.727> [eDVBVideo0] VIDEO_CONTINUE ok
    <    23.728> [eDVBAudio0] AUDIO_CONTINUE ok
    <    23.728> [eDVBAudio0] AUDIO_CHANNEL_SELECT 0 ok
    <    23.728> [eDVBTeletextParser] Starting!
    <    23.728> [eDVBTeletextParser] disable teletext subtitles page ffffffffffffffff (und)
    <    23.728> [eDVBPESReader] Created. Opening demux
    <    23.728> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.728> [eDVBTeletextParser] created teletext subtitle PES reader!
    <    23.728> [eDVBPESReader] Created. Opening demux
    <    23.728> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.728> [eDVBTeletextParser] starting PES reader on pid=0519
    <    23.728> [eDVBPESReader] DMX_SET_PES_FILTER pid=0519
    <    23.741> [eDVBCAService] new service 1:0:16:451:3E9:2174:EEEE0000:0:0:0:
    <    23.741> [eDVBCAService] add demux 0 to slot 0 service 1:0:16:451:3E9:2174:EEEE0000:0:0:0:
    <    23.741> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.741> [eDVBSectionReader] DMX_SET_FILTER pid=0
    <    23.742> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.742> [eDVBSectionReader] DMX_SET_FILTER pid=18
    <    23.743> [Notifications] RemovePopup, id = ZapError
    <    23.744> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.744> [eDVBSectionReader] DMX_SET_FILTER pid=0
    <    23.826> [eDVBServicePMTHandler] PATready
    <    23.826> [eDVBServicePMTHandler] use pmtpid 0771 for service_id 0451
    <    23.826> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.826> [eDVBSectionReader] DMX_SET_FILTER pid=1905
    <    23.827> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.827> [eDVBSectionReader] DMX_SET_FILTER pid=0
    <    23.828> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.828> [eDVBSectionReader] DMX_SET_FILTER pid=4352
    <    23.828> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.828> [eDVBSectionReader] DMX_SET_FILTER pid=17
    <    23.915> [eDVBServicePlay] eventNewProgramInfo timeshift_enabled=0 timeshift_active=0
    <    23.916> [eDVBServicePlay] have 1 video stream(s) (0451), and 1 audio stream(s) (04b5), and the pcr pid is 1ffe, and the text pid is 0519
    <    23.916> [eTSMPEGDecoder] decoder state: play, vpid=0451, apid=04b5
    <    23.927> [eDVBCIInterfaces] gotPMT
    <    23.928> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.928> [eDVBSectionReader] DMX_SET_FILTER pid=1905
    <    23.929> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    23.929> [eDVBSectionReader] DMX_SET_FILTER pid=1901
    <    23.976> [eDVBServicePMTHandler] sdt update done!
    <    24.069> [eDVBServicePlay] timeshift
    <    24.069> [eDVBDemux] open demux /dev/dvb/adapter0/demux0
    <    24.069> [eDVBSectionReader] DMX_SET_FILTER pid=18
    <    24.604> [eDVBVideo0] VIDEO_GET_EVENT FRAME_RATE_CHANGED 25000 fps
    <    24.604> [eDVBVideo0] VIDEO_GET_EVENT SIZE_CHANGED 528x576 aspect 3
    <    24.610> [eDVBVideo0] VIDEO_GET_EVENT PROGRESSIVE_CHANGED 0
    <    25.069> [eDVBServicePlay] timeshift
    <    25.112> [VideoHardware] setting aspect: 16:9
    <    25.112> [VideoHardware] setting wss: auto
    <    25.112> [VideoHardware] setting policy: panscan
    <    25.112> [VideoHardware] setting policy2: letterbox
    <    25.715> [eEPGCache] start caching events(1516501135)
    <    25.715> [eDVBSectionReader] DMX_SET_FILTER pid=3842
    <    25.716> [eDVBSectionReader] DMX_SET_FILTER pid=3003
    <    25.716> [eDVBSectionReader] DMX_SET_FILTER pid=18
    <    25.717> [eDVBSectionReader] DMX_SET_FILTER pid=18
    <    25.717> [eDVBSectionReader] DMX_SET_FILTER pid=18
    <    25.717> [eDVBSectionReader] DMX_SET_FILTER pid=700
    <    25.717> [eDVBSectionReader] DMX_SET_FILTER pid=700
    <    25.718> [eDVBSectionReader] DMX_SET_FILTER pid=5000
    <    25.718> [eDVBSectionReader] DMX_SET_FILTER pid=5000
    <    25.718> [eDVBSectionReader] DMX_SET_FILTER pid=57
    <    32.718> [eEPGCache] abort non avail virgin nownext reading
    <    32.719> [eEPGCache] abort non avail virgin schedule reading
    <    32.719> [eEPGCache] abort non avail netmed schedule reading
    <    32.720> [eEPGCache] abort non avail netmed schedule other reading
    <    32.720> [eEPGCache] abort non avail FreeSat schedule_other reading
    <    32.720> [eEPGCache] abort non avail viasat reading
    <    32.751> [eEPGCache] nownext finished(1516501142)
    <    32.771> [Task] job Components.Task.Job name=SoftcamCheck #tasks=1 completed with [] in None
    <    33.200> [eHdmiCEC] received message 84 00 00 00
    <    33.512> [eHdmiCEC] received message 87 08 00 46
    <    33.738> [eHdmiCEC] received message A0 08 00 46 00 04 00 01
    <    33.963> [eHdmiCEC] received message A0 08 00 46 00 08 00 00
    <    35.420> [eEPGCache] schedule finished(1516501145)
    <    37.492> [eEPGCache] schedule other finished(1516501147)
    <    37.493> [eEPGCache] stop caching events(1516501147)
    <    37.493> [eEPGCache] next update in 60 min
    <    58.989> [eInputDeviceInit] 1 8b 1
    <    58.990> [InfoBarGenerics] KEY: 139 MENU
    <    58.990> [ActionMap] InfobarMenuActions mainMenu
    <    58.994> [Skin] processing screen Menu:
    <    59.007> [Skin] processing screen MenuSummary:
    <    59.391> [eInputDeviceInit] 2 8b 1
    <    59.392> [InfoBarGenerics] KEY: 139 MENU
    <    59.407> [eInputDeviceInit] 0 8b 1
    <    59.407> [InfoBarGenerics] KEY: 139 MENU
    <    80.839> [Console] command: ('sdparm', 'sdparm', '--flexible', '--readonly', '--command=stop', '/dev/sda')
    <    80.839> [eConsoleAppContainer] Starting sdparm
    <    81.407> [Console] finished: ('sdparm', 'sdparm', '--flexible', '--readonly', '--command=stop', '/dev/sda')
    <   104.600> [Console] finished: /usr/bin/ntpdate-sync
    <   104.600> [NetworkTime] setting E2 time: 1516531589.55                <-------------------------------  10:46:29 21/01/2018       81 seconds have elapsed
    <   128.648> [eInputDeviceInit] 1 ae 1
    <   128.649> [InfoBarGenerics] KEY: 174 EXIT
    The log shows ntpdate-sync being kicked off at 23.212 seconds and returning some 81 seconds later and the system time of 10:46:29 being set. Subsequent updates of ntpdate-sync (at 30 minute intervals) return within about 6 seconds.

    However, the syslog (messages) shows a slightly different story:


    Code:
    Jan 21 02:18:46 mutant51 user.info kernel: [   12.586151] wlan0: authenticated
    Jan 21 02:18:46 mutant51 user.info kernel: [   12.590497] wlan0: associate with f4:f2:6d:9b:fd:5a (try 1/3)
    Jan 21 02:18:46 mutant51 user.info kernel: [   12.599991] wlan0: RX AssocResp from f4:f2:6d:9b:fd:5a (capab=0x431 status=0 aid=2)
    Jan 21 02:18:46 mutant51 user.info kernel: [   12.650585] wlan0: associated
    Jan 21 02:18:46 mutant51 user.info kernel: [   12.653640] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    Jan 21 02:18:46 mutant51 daemon.info avahi-daemon[2071]: Found user 'avahi' (UID 999) and group 'avahi' (GID 999).
    Jan 21 02:18:46 mutant51 daemon.info avahi-daemon[2071]: Successfully dropped root privileges.
    Jan 21 02:18:46 mutant51 daemon.info avahi-daemon[2071]: avahi-daemon 0.6.32 starting up.
    Jan 21 02:18:46 mutant51 daemon.err avahi-daemon[2071]: dbus_bus_get_private(): Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory
    Jan 21 02:18:46 mutant51 daemon.warn avahi-daemon[2071]: WARNING: Failed to contact D-Bus daemon.
    Jan 21 02:18:46 mutant51 daemon.info avahi-daemon[2071]: avahi-daemon 0.6.32 exiting.
    Jan 21 02:18:53 mutant51 daemon.crit automount[2039]: key "logs" not found in map source(s).
    Jan 21 10:45:59 mutant51 daemon.notice ntpdate[2171]: step time server 193.1.31.66 offset 30374.856716 sec  <---------------------------- this update not shown in debug log
    Jan 21 10:45:59 mutant51 daemon.notice stb-hwclock: Current system time has been written into FP pseudo RTC.
    Jan 21 10:46:29 mutant51 daemon.notice ntpdate[2200]: adjust time server 193.1.31.66 offset -0.000560 sec      <---------------------------------  this matches the entry shown in debug log
    Jan 21 10:46:29 mutant51 daemon.notice stb-hwclock: Current system time has been written into FP pseudo RTC.
    Jan 21 11:16:35 mutant51 daemon.notice ntpdate[3460]: adjust time server 193.1.31.66 offset -0.011561 sec
    Jan 21 11:16:35 mutant51 daemon.notice stb-hwclock: Current system time has been written into FP pseudo RTC.
    There is an ntpdate update shown at 10:45:59 which is some 30 seconds before the update shown in the debug log. It would appear to me that ntpdate is being fired twice at least during the boot phase.
    Either way, the asynchronous nature of establishing the time is messing with the evaluation of things like ABM and CrossEPG timer checks which happen at about 16 - 18 seconds into the debug log which is some 5 seconds before ntpdate-sync is being run. The log filename is using the stored fake-hwclock time.

    I agree with you that somehow the clock setting needs to be synchronous and that checks for ABM and recording timers need to wait until the time is established.
    GB Quad Plus, Mut@nt HD51, AX HD61, 80cm dish and Supreme Dark motor. Sony STR-DN 1060, Sony UHP-H1 Bluray, Odroid N2+ (CoreElec), Monitor Audio Bronze 5.1 speakers

Page 10 of 19 FirstFirst ... 89101112 ... LastLast

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •  
This website uses cookies
We use cookies to store session information to facilitate remembering your login information, to allow you to save website preferences, to personalise content and ads, to provide social media features and to analyse our traffic. We also share information about your use of our site with our social media, advertising and analytics partners.