os.time qui perd la boule à minuit

[jjacques68]

Bonjour à tous,

 

Je remarque que très souvent la fonction os.time() manque de stabilité.

J'ai une scène qui tourne H24 et qui utilise os.time().

J'ai plusieurs fois par semaine cette scène qui bug à exactement minuit (rien dans le code de cette scène ne peut la faire planter à minuit...)

 

alors du coup j'ai créé une autre petite scène pour observer le os.time() :

--[[
%% autostart
%% properties
%% events
%% globals
--]]

local last = os.time()

function loop()
  --1. test la différence d'une boucle à l'autre, si plus d'une seconde alors debug
  if os.time() - last > 1 then print("error : "..(os.time() - last).." s") end
  
  --2. affiche os.time de 23:59:40 à 00:00:20
  if os.date("%H:%M:%S") >= "23:59:40" or os.date("%H:%M:%S") <= "00:00:20" then    
    print(os.time())
  end
  
  --affecte la nouvelle valeur à la variable
  last = os.time()
  
  --bouclage toutes les 1 seconde
  setTimeout(loop, 1000)
end

loop()

cette scène à 2 rôles :

1- si plus d'une seconde d'écart entre 2 boucles on affiche dans le debug la différence de temps

2- affiche chaque seconde le os.time() entre 23:59:40 et 00:00:20.

 

J'ai fais tourner cette scène hier soir de 22h à ce matin 6h...

voilà le résultat pour le premier rôle :

[DEBUG] 23:44:49: error : 2 s
[DEBUG] 23:44:51: error : 2 s
[DEBUG] 23:45:06: error : 2 s
[DEBUG] 00:31:02: error : 10 s
[DEBUG] 02:16:19: error : 2 s
[DEBUG] 02:16:22: error : 2 s
[DEBUG] 02:16:30: error : 2 s
[DEBUG] 02:16:34: error : 2 s
[DEBUG] 04:13:31: error : 2 s
[DEBUG] 04:13:48: error : 2 s
[DEBUG] 06:11:02: error : 2 s
[DEBUG] 06:11:04: error : 2 s
[DEBUG] 06:11:11: error : 2 s
[DEBUG] 06:11:16: error : 2 s
[DEBUG] 06:11:23: error : 2 s
[DEBUG] 06:11:26: error : 2 s

on voit que c'est qu'il y a des trucs étrange entre 23h44 et 6h11 (heure à laquelle j'ai arrêté le script)

 

et voici le résultat pour le second rôle :

[DEBUG] 23:59:40: 1500242380
[DEBUG] 23:59:41: 1500242381
[DEBUG] 23:59:42: 1500242382
[DEBUG] 23:59:43: 1500242383
[DEBUG] 23:59:44: 1500242384
[DEBUG] 23:59:45: 1500242385
[DEBUG] 23:59:46: 1500242386
[DEBUG] 23:59:47: 1500242387
[DEBUG] 23:59:48: 1500242388
[DEBUG] 23:59:49: 1500242389
[DEBUG] 23:59:50: 1500242390
[DEBUG] 23:59:51: 1500242391
[DEBUG] 23:59:52: 1500242392
[DEBUG] 23:59:53: 1500242393
[DEBUG] 23:59:54: 1500242394
[DEBUG] 23:59:55: 1500242395
[DEBUG] 23:59:56: 1500242396
[DEBUG] 23:59:57: 1500242397
[DEBUG] 23:59:58: 1500242398
[DEBUG] 23:59:59: 1500242399
[DEBUG] 00:00:00: 1500242400
[DEBUG] 00:00:01: 1500242401
[DEBUG] 00:00:02: 1500242402
[DEBUG] 00:00:16: 1500242403
[DEBUG] 00:00:16: 1500242404
[DEBUG] 00:00:16: 1500242405
[DEBUG] 00:00:16: 1500242406
[DEBUG] 00:00:16: 1500242407
[DEBUG] 00:00:17: 1500242408
[DEBUG] 00:00:17: 1500242409
[DEBUG] 00:00:17: 1500242410
[DEBUG] 00:00:17: 1500242411
[DEBUG] 00:00:17: 1500242412
[DEBUG] 00:00:17: 1500242413
[DEBUG] 00:00:17: 1500242414
[DEBUG] 00:00:17: 1500242415
[DEBUG] 00:00:17: 1500242416
[DEBUG] 00:00:17: 1500242417
[DEBUG] 00:00:18: 1500242418
[DEBUG] 00:00:19: 1500242419
[DEBUG] 00:00:20: 1500242420

Et là comme par hasard, je n'ai eut aucun soucis... on voit bien les secondes s'enchainées l'une derrière l'autre.

Par contre on voit le time code du debug qui ne correspond pas à 00:00:16 et 00:00:17

Mais c'est la première fois depuis au moins 1 semaine que, cette nuit, à minuit, ma scène n'a pas plantée...

je relance le test ce soir pour voir... et vous posterai le debug...

 

Est-ce que quelqu'un à déjà constaté ce genre de comportement ?

Modifié le 17 juillet 2017 par jjacques68

[jjacques68]

chose dite chose promis, scène plantée à minuit.

 

voici le debug de la scène qui observe le os.time :

[DEBUG] 23:59:40: 1500328780
[DEBUG] 23:59:41: 1500328781
[DEBUG] 23:59:42: 1500328782
[DEBUG] 23:59:43: 1500328783
[DEBUG] 23:59:44: 1500328784
[DEBUG] 23:59:45: 1500328785
[DEBUG] 23:59:46: 1500328786
[DEBUG] 23:59:47: 1500328787
[DEBUG] 23:59:48: 1500328788
[DEBUG] 23:59:49: 1500328789
[DEBUG] 23:59:50: 1500328790
[DEBUG] 23:59:51: 1500328791
[DEBUG] 23:59:52: 1500328792
[DEBUG] 23:59:53: 1500328793
[DEBUG] 23:59:54: 1500328794
[DEBUG] 23:59:55: 1500328795
[DEBUG] 23:59:56: 1500328796
[DEBUG] 23:59:57: 1500328797
[DEBUG] 23:59:58: 1500328798
[DEBUG] 23:59:59: 1500328799
[DEBUG] 00:00:00: 1500328800
[DEBUG] 00:00:01: 1500328801
[DEBUG] 00:00:18: 1500328802
[DEBUG] 00:00:18: 1500328803
[DEBUG] 00:00:18: 1500328804
[DEBUG] 00:00:18: 1500328805
[DEBUG] 00:00:18: 1500328806
[DEBUG] 00:00:18: 1500328807
[DEBUG] 00:00:18: 1500328808
[DEBUG] 00:00:18: 1500328809
[DEBUG] 00:00:18: 1500328810
[DEBUG] 00:00:18: 1500328811
[DEBUG] 00:00:18: 1500328812
[DEBUG] 00:00:18: 1500328813
[DEBUG] 00:00:18: 1500328814
[DEBUG] 00:00:18: 1500328815
[DEBUG] 00:00:18: 1500328816
[DEBUG] 00:00:18: 1500328817
[DEBUG] 00:00:18: 1500328818
[DEBUG] 00:00:19: 1500328819
[DEBUG] 00:00:20: 1500328820
[DEBUG] 00:27:01: error : 2 s
[DEBUG] 00:27:05: error : 2 s
[DEBUG] 00:27:07: error : 2 s
[DEBUG] 00:27:13: error : 2 s
[DEBUG] 00:27:15: error : 2 s
[DEBUG] 00:27:24: error : 2 s
[DEBUG] 00:31:03: error : 9 s
[DEBUG] 00:53:08: error : 2 s
[DEBUG] 00:53:11: error : 2 s
[DEBUG] 02:48:34: error : 2 s
[DEBUG] 02:48:37: error : 2 s
[DEBUG] 02:48:39: error : 2 s
[DEBUG] 04:48:41: error : 2 s
[DEBUG] 04:48:44: error : 2 s

j'avoue ne pas trop savoir interpréter le résultat.

On voit que à 00:00:01 le debug par en cou... mais le os.time reste bon !!! et c'est la que ma scène pédale dans la semoule.

 

de plus, replantage de ma scène à 00:31, et là pour le coup c'est lorsque le VD Clock Sync de @Krikroff se lance...

 

si quelqu'un à une idée !??

[Lazer]

Je soupçonne que la HC2 réalise tout seule une syncho NTP (la même chose que fait manuellement le VD Clock Sync)

 

Par ailleurs, ton calcul suivant est mauvais :

if os.time() - last ...

Tu ne peux pas comparer directement des timestamps par soustraction, ça va planter au moins 2 fois par an : décalage horaire été/hiver

 

Il faut utiliser os.difftime() par exemple :

local elapsedTime = os.difftime(newTime, oldTime)

 

 

[jjacques68]

Ok je vais changer mon calcul.

pour ma mise  jour ntp de la box, pas sÛr qu'elle le fasse elle même, j'ai mis ce VD justement à cause du décalage qui se produisait !

je vais désactiver ce module on verra bien.

 

mais ça n'explique toujours pas le plantage de miniuit, ça me pause un vrai problème.  

[Lazer]

à minuit il y a un script cleanDatabase.sh qui s'exécute, je ne sais pas trop ce qu'il fait, mais ça a probablement un impact sur ta scène

[jjacques68]

Pfffff, je vais finir par mettre un sleep de 20 secondes à 23h59:50 dans ma scène Et le problème sera vite réglé...

mais c'est nul...

[Lazer]

Pourquoi as-tu besoin d'une scène qui tourne en boucle toutes les 1s ?

ça ne consomme pas trop de ressource CPU ?

[jjacques68]

c'est plus compliqué que ça...

elle ne tourne pas en boucle toutes les secondes mais toutes les 15 secondes.

Cette scène observe la date de modification d'une variable (cette variable est modifiée par le changement de statut d'une input d'un ipx... je passe par 2 boutons on&off qui me mettent la variable a 1&0... bref...)

Je calcul le temps entre os.time() et la date de dernière modif de cette variable.

 

voici le début de la scène :

local LastUpDate = fibaro:getGlobalModificationTime("IpxIn2")
  --si heure actuelle - heure de la denrière MAJ de la VG < 5 secondes
  if (os.time() - LastUpDate) < 5 then
...
...
...

et donc cette variable (= input de l'ipx) passe de 0 à 1 en une seconde et ça tourne en boucle... tictac-----tictac-----tictac...

je teste le "clignotement" de cette input en fait.

 

et donc j'utilise le os.time(), mais si celui-ci déconne, ma scène déconne aussi.... (le reste de la journée c'est stable)

 

oulà ça semble bien compliqué mon explication... non ?  

[jjacques68]

par contre je viens de changer mon calcul en utilisant le os.difftime(), on verra la différence...

C'est plus propre effectivement, mais je pense pas que ça règlera CE soucis.

[Lazer]

Ton explication est à peu près claire

 

Oui, attendons de voir ce que donne le os/difftime(), mais j'ai quelques doutes aussi....

[jjacques68]

bon ben même résultat, je ne remets pas le debug car il est identique.

Ce qui me surprends, c'est que le os.time() s'affiche bien !

On dirait que c'est la HC2 qui perd les pédales à minuit ! (c'est le timecode qui me fait pensé ça...)

[Lazer]

mouais, bah là je ne sais pas.... ?!?

[jjacques68]

moi non plus...  

 

je viens d'ajouter ça dans mon code de la scène :

  if os.date("%H:%M:%S") >= "23:59:50" or os.date("%H:%M:%S") < "00:00:20" then
    fibaro:sleep(30*1000)
    LastUpDate = os.time()
  end

Mais je trouve ça nul de chez nul de chez nul...

[trainkill666]

Petit Hors sujet, j'utilise également des vds pour le retour et la commande d'ipx, mais sans variable, le résultat passe par l'affichage sur un label, est-il possible d'avoir la valeur de la dernier modification d'un vd (comme avec fibaro:getModificationTime) ?

[jjacques68]

J'ai envie de dire oui, faudrait tester :

 

fibaro:getModificationTime(id_vd, "ui.le_label_en_question.value")

[trainkill666]

Bien joué jjacques68, c'est pourtant si évident .

Un grand Merci !

Modifié le 20 août 2017 par trainkill666

[trainkill666]

Re question bête :

comment convertir le résultat de fibaro:getModificationTime en Heures et Minutes ?

 

Merci d'avance .

[jjacques68]

En utilisant la fonction os.date :

 

un truc du genre : os.date("%H:%M", Le_Resultat_du_getModificationTime)

 

ça te retourne une string de ce style "08:16".

Après tu peux faire de la comparaison avec une autre string : par exemple <>= "09:00"

 

http://www.luteus.biz/Download/LoriotPro_Doc/LUA/LUA_Training_FR/LUA_Fonction_OS.html

[trainkill666]

Merci jjacques68

J'ai ce lien dans mes raccourcis mais j'avais pas vu comment faire avec osdate et un temps. La honte.

Modifié le 29 août 2017 par trainkill666

[pepite]

@jjacques68

evite le sleep ;-) c'est plus propre avec un setTimeout ;-)