350 replies to this topic

[teo1966]

nog wat logs word steeds vreemder

• 2022/09/08 17:29:40 216D2937 c (ecm) dvbapiau (0100@00006A/5C00/5225/64:BC860FB95C9A5BE3FF92B7EB9C62EE15): found (374 ms) by Canal_Digitaal - NPO1 HD (cwc OK)
• 2022/09/08 17:29:51 216D2937 c (ecm) dvbapiau (0100@00006A/5C00/5225/64:54C77DCD108E731DE4E8A1D00B7D059A): found (732 ms) by Canal_Digitaal - NPO1 HD (cwc OK)
• 2022/09/08 17:30:00 216D2937 c (ecm) dvbapiau (0100@00006A/5C00/5225/64:D2EBB4FBD90C8A8B2DDDE623332A046A): found (461 ms) by Canal_Digitaal - NPO1 HD (cwc OK)
• 2022/09/08 17:28:43 216D2937 c (dvbapi) *** WARNING: BAD TIME AFFECTING WHOLE OSCAM ECM HANDLING ****
• 2022/09/08 17:28:44 216D2937 c (ecm) dvbapiau (0100@00006A/5C00/5225/64:429F99EE12E5B865DD163E93A0AB54F2): found (481 ms) by Canal_Digitaal - NPO1 HD (cwc OK)
• 2022/09/08 17:28:54 216D2937 c (ecm) dvbapiau (0100@00006A/5C00/5225/64:C13293286AC4EC87401BFB2F26021FDC): found (742 ms) by Canal_Digitaal - NPO1 HD (cwc OK)

Sep  8 09:30:09 revo4k daemon.notice ntpdate[28659]: step time server 167.248.49.102 offset 1.007193 sec
Sep  8 10:30:00 revo4k cron.info crond[1381]: USER root pid 29394 cmd /usr/bin/ntpdate-sync silent
Sep  8 10:30:08 revo4k daemon.notice ntpdate[29399]: step time server 83.137.149.135 offset 1.001864 sec
Sep  8 11:30:00 revo4k cron.info crond[1381]: USER root pid 30186 cmd /usr/bin/ntpdate-sync silent
Sep  8 11:30:09 revo4k daemon.notice ntpdate[30191]: step time server 94.198.159.16 offset 1.006139 sec
Sep  8 12:30:00 revo4k cron.info crond[1381]: USER root pid 30994 cmd /usr/bin/ntpdate-sync silent
Sep  8 12:29:04 revo4k daemon.notice ntpdate[30999]: step time server 94.198.159.16 offset -62.995223 sec
Sep  8 12:30:00 revo4k cron.info crond[1381]: USER root pid 31011 cmd /usr/bin/ntpdate-sync silent
Sep  8 12:30:09 revo4k daemon.notice ntpdate[31016]: adjust time server 94.198.159.16 offset -0.000190 sec
Sep  8 13:30:00 revo4k cron.info crond[1381]: USER root pid 31748 cmd /usr/bin/ntpdate-sync silent
Sep  8 13:29:01 revo4k daemon.notice ntpdate[31753]: step time server 78.142.193.131 offset -67.994264 sec
Sep  8 13:30:00 revo4k cron.info crond[1381]: USER root pid 31767 cmd /usr/bin/ntpdate-sync silent
Sep  8 13:30:00 revo4k daemon.err ntpdate[31772]: 78.142.193.131 rate limit response from server.
Sep  8 13:30:09 revo4k daemon.notice ntpdate[31772]: adjust time server 217.91.44.17 offset -0.000670 sec
Sep  8 14:30:00 revo4k cron.info crond[1381]: USER root pid 32498 cmd /usr/bin/ntpdate-sync silent
Sep  8 14:28:54 revo4k daemon.notice ntpdate[32503]: step time server 80.87.128.222 offset -72.994451 sec
Sep  8 14:30:00 revo4k cron.info crond[1381]: USER root pid 32517 cmd /usr/bin/ntpdate-sync silent
Sep  8 14:30:09 revo4k daemon.notice ntpdate[32522]: adjust time server 80.87.128.222 offset 0.000208 sec
Sep  8 15:30:00 revo4k cron.info crond[1381]: USER root pid 796 cmd /usr/bin/ntpdate-sync silent
Sep  8 15:28:49 revo4k daemon.notice ntpdate[801]: step time server 51.15.20.83 offset -77.998641 sec
Sep  8 15:30:00 revo4k cron.info crond[1381]: USER root pid 824 cmd /usr/bin/ntpdate-sync silent
Sep  8 15:30:09 revo4k daemon.notice ntpdate[829]: adjust time server 213.136.0.252 offset 0.003893 sec
Sep  8 16:30:00 revo4k cron.info crond[1381]: USER root pid 1617 cmd /usr/bin/ntpdate-sync silent
Sep  8 16:28:45 revo4k daemon.notice ntpdate[1622]: step time server 185.224.145.68 offset -81.998135 sec
Sep  8 16:30:00 revo4k cron.info crond[1381]: USER root pid 1638 cmd /usr/bin/ntpdate-sync silent
Sep  8 16:30:09 revo4k daemon.notice ntpdate[1643]: adjust time server 185.224.145.68 offset 0.000832 sec
Sep  8 17:30:00 revo4k cron.info crond[1381]: USER root pid 2360 cmd /usr/bin/ntpdate-sync silent
Sep  8 17:28:39 revo4k daemon.notice ntpdate[2365]: step time server 213.154.236.182 offset -86.993652 sec
Sep  8 17:30:00 revo4k cron.info crond[1381]: USER root pid 2384 cmd /usr/bin/ntpdate-sync silent
Sep  8 17:30:08 revo4k daemon.notice ntpdate[2389]: adjust time server 213.154.236.182 offset 0.000284 sec

 

[littlesat]

Ntp zal dit soort sprongen in tijd niet horen te maken..:: maak ook ergens als het runt moet het blijven runnen in de achtergrond. Waarom gebeurt dit eigenlijk als one shot elk half uur…. Als het contant in de achtergrond rund bepaald het zelf een Ping tijd afhankelijk van de afwijking…. En regelt het geleidelijk bij.

Edited by littlesat, 8 September 2022 - 17:41.

[WanWizard]

NTP zal dat wel doen, als er in de tussentijd iets is gebeurd dat de tijd heeft verzet. Dan wordt terecht de boel door NTP gecorrigeerd.

 

NTP doet een update op het moment dat de netwerk interface op komt, en daarna eens per uur via een cron job. Als de correctie klein is, gebeurt dat direct, anders in stapjes ("adjkust time" vs "step time" in de log).

 

Het is in ieder geval geen hardware issue, als de RTC zou afwijken dat zo de klok geleidelijk moeten afwijken, en dat is niet het geval, als je bv kijkt naar de correcties in de log van voor 12:30.

 

Dus wat is er gebeurd tussen 11:30 en 12:30 dat de tijd een minuut terug heeft gezet? Stond de box toen getuned (aan, opname, stream), en op welke zender?

[teo1966]

stond aan op npo1

tv staat uit

tijd synchronatie staat op    internet (NTP)

hele dag aan gehad er was niemand thuis

Edited by teo1966, 8 September 2022 - 18:01.

[littlesat]

Weet je heel zeker dat je geen plug-in geïnstalleerd hebt ivm tijds synchronisatie.

[teo1966]

heb als extra cacheflush met de standaard instellingen en oscam en cccam

 

 1_0_1_5225_C99_3_EB0000_0_0_0_20220908193511.jpg   69KB   5 downloads

Edited by teo1966, 8 September 2022 - 18:36.

[Tech]

Cacheflush?. Wat is dat dan weer voor onzin?

[teo1966]

installeer ik eigenlijk standaard vanaf het begin ivm de oudere ontvangers met weinig geheugen

[Tech]

Nog nooit gebruikt/ van gehoord, ik heb een behoorlijke stapel e2 boxen gehad maar heb die plugin (welke zelf ook ruimte in beslag zal nemen) nog nooit gebruikt of nodig gehad.

 

Maar of die plugin ervoor zorgt dat je nu de time problemen hebt of van invloed kan zijn, weet ik niet.

[WanWizard]

Linux kan dat prima zelf, dus zelfs op een box met weinig geheugen lijkt me dit geen toegevoegde waarde hebben.

 

Er zijn wat mij betreft maar twee opties:

• iets zorgt er voor dat elk uur de linux klok ergens een minuut stil staat
• iets zorgt er voor dat elk uur de tijd met min 60 seconden wordt bijgesteld

stond aan op npo1

 

Ook voor 12:30 vandaag? Want toen begon de ellende pas volgens je log.

[40H3X]

Maak een backup en dan OpenPLi opnieuw installeren zonder backup en OSCam uit de feed. Ben benieuwd wat er dan gebeurd? Ik kan je ook een OSCam met clockfix geven, maar daar krijg je mijns inzien mogelijk weer andere problemen voor terug.

[teo1966]

Maak een backup en dan OpenPLi opnieuw installeren zonder backup en OSCam uit de feed. Ben benieuwd wat er dan gebeurd? Ik kan je ook een OSCam met clockfix geven, maar daar krijg je mijns inzien mogelijk weer andere problemen voor terug.

geef maar eens een oscam met clockfix om te testen zal vrijdag of zaterdag eens opnieuw installeren

[WanWizard]

Nog even voor de duidelijkheid: die "clockfix" fixt geen klok, en dus niet je probleem. Sterker nog, je probleem zal er groter mee worden.

 

Wat de "fix" doet is bij het opstarten van Oscam de tijd intern opslaan en bijhouden, en zodra Oscam merkt dat de linux klok af wijkt, de tijd van de box weer terug zetten op wat Oscam denkt dat de goede tijd is. En die is altijd fout.

 

Daarmee heb je die foutmelding weggewerkt, maar loopt je box steeds meer uit de pas, werkt zowel NTP als transpondertijd niet meer, en ga je op den duur opname en EPG problemen krijgen omdat de boel te ver uit de pas loopt.

 

Oorzaak is al vele malen gemeld aan Oscam, met oplossing (synthetic time gebruiken intern ipv realtime zodat intern 60 seconden altijd precies 60 seconden duurt, ongeacht wat de linux klok doet), maar tot op heden alleen maar dovemansoren.

 

edit:

 

Om het duidelijk te maken:

eindtijd = systemtijd + 60
while (eindtijd > systemtijd)
{
    print "."
    sleep 1
}

Onder normale omstandigheden print dit dus 60 puntjes, 1 per seconde.

 

Wat denk je dat er gebeurt als je terwijl dit loopt de systeemtijd aan past? Meer of minder puntjes dus, afhankelijk van of de aanpassing plus of min was.
En daar zeurt Oscam over, omdat er hardcoded vaste wachtlussen in de code zitten die op bovenstaand principe zijn gebaseerd.

Edited by WanWizard, 8 September 2022 - 20:53.

[40H3X]

@teo1966 krijg je morgen, let wel @WanWizard heeft duidelijk uiteen gezet, wat deze “clock fix” ons inziens met zich meebrengt.

[scriptmelvin †]

Kan dit gerelateerd zijn? Dit is met de box in standby, hij is om 12:45 aangezet, daarna geen meldingen meer.

 

# grep 'ntpdate.*step' /var/log/messages
Sep  8 03:30:08 vuuno4kse daemon.notice ntpdate[23141]: step time server 158.101.221.122 offset +0.973444 sec
Sep  8 04:30:09 vuuno4kse daemon.notice ntpdate[26815]: step time server 94.228.220.14 offset +0.861581 sec
Sep  8 05:30:08 vuuno4kse daemon.notice ntpdate[30646]: step time server 83.137.149.135 offset +1.033771 sec
Sep  8 07:30:08 vuuno4kse daemon.notice ntpdate[5858]: step time server 213.154.236.182 offset +1.675413 sec
Sep  8 08:30:09 vuuno4kse daemon.notice ntpdate[9564]: step time server 83.137.149.135 offset +1.697831 sec
Sep  8 09:30:11 vuuno4kse daemon.notice ntpdate[13412]: step time server 94.198.159.11 offset +1.701088 sec
Sep  8 10:30:08 vuuno4kse daemon.notice ntpdate[17315]: step time server 83.137.149.135 offset +1.698499 sec
Sep  8 11:30:08 vuuno4kse daemon.notice ntpdate[21608]: step time server 83.98.155.30 offset +1.487538 sec
Sep  8 12:30:11 vuuno4kse daemon.notice ntpdate[25430]: step time server 83.98.155.30 offset +1.694220 sec

[teo1966]

thanks ik wil wel wat links en rechts wat testen heb nu cachflush eraf gegooid

[WanWizard]

Kan dit gerelateerd zijn? Dit is met de box in standby, hij is om 12:45 aangezet, daarna geen meldingen meer.

 

# grep 'ntpdate.*step' /var/log/messages

 

NTP doet een "step time" als de tijd meer dan 0.5 seconden af wijkt, bij minder een directe "adjust".

[scriptmelvin †]

NTP doet een "step time" als de tijd meer dan 0.5 seconden af wijkt, bij minder een directe "adjust".

Ja dat weet ik. Maar waarom gebeurt dat alleen in standby? En kan het gerelateerd zijn aan @teo1966 z'n issue?

[WanWizard]

Zou ook gewoon toeval kunnen zijn. Ik heb hier even gekeken (6 boxen all-sorts), en er zit geen enkele logica in.

[pasquenel]

NTP story heeft mijns inziens niets te maken met "CD kaart kan nog maar twee zenders tegelijk decoderen".

De problemen zijn begonnen tijdens de periode dat TVV / CD hun website hebben aangepast met de belofte dat er geen impact voor de gebruiker zou zijn ....

Dit is zo sinds ~eind juni / begin juli.

Daarvoor heb ik deze problemen niet ervaren.

 

Al vele dingen uitgetest maar tot nu toe nog niet dichter bij een oplossing gekomen.

 

Voor zover ik kan lezen of verschillende forums zijn er 2 gebruikers die geen problemen hebben.

Als dat klopt ligt daar de oplossing.