Bonjour à tous
Après trois semaines de vacances à la maison, beaucoup de bricolage, et aussi un peu de programmation pour voir de quoi est fait l'ESP32, j'ai enfin quelques éléments de réponse sur notre problème de timing découvert voilà maintenant plusieurs mois...
Premier objectif pour moi, tester les timings interruptions simples sur ESP32. Rien ne permet de penser que ces interruptions ne fonctionnent pas bien, mais quand on cherche à résoudre un problème, on commence par la base... J'ai donc pondu un fichier ino (joint ici) avec un programme de test de timing. Il fonctionne -a priori- aussi bien en ESP32 que sur un Nano. Son but est d'abord de compter le temps entre deux appels à la fonction d'interruption et de rendre un rapport après un certain nombre de mesures. Je l'ai fixé à peu près au maximum d'un entier non signé, c'est à dire 60000 mesures. Ce devrait statistiquement être suffisant. Chaque interruption va mesurer le temps passé depuis le précédent appel, et selon le résultat, incrémenter un compteur. Comme le temps est idéalement fixé à 58us, j'ai donc utilisé une matrice de compteurs qui vont stocker le nombre trouvé de timings à +-10us autour du temps référence. C'est donc une matrice de 48 à 68, mais comme elle commence à 48, c'est en réalité une matrice de 20 longs non signés. L'élément 0 donne le compteur des 48us, l'élément 1 de 49us, etc... Deux autres compteurs sont ajoutés : l'élément 20 qui compte le nombre de timings en dessous de 48us, et l'élément 21 qui compte le nombre au dessus de 68us. Trois autres temps sont mesurés : le timing le plus court de toute la série, le plus long, et le temps passé à l'intérieur de la fonction d'interruption. Un pourcentage permet de rendre compte de la proportion de timings à la valeur idéale de 58us, et aussi la proportion de timings conformes à la norme NMRA, c'est à dire entre 55 et 61us inclus. Le timing moyen est aussi calculé.
Pour mieux comprendre l'influence de ce qui tourne autour de l'interruption, j'ai ajouté des define à l'entrée du programme pour jouer avec différents paramètres:
- LOOP_COMPUTE ajoute un traitement qui se veut un peu lourd dans la loop, un calcul de nombres premiers.
- LOOP_ANALOG_READ ajoute à la loop l'analyse du courant consommé à base d'analogRead tel qu'elle est faite dans DCCpp.
- INT_COMPUTE alourdit la routine d'interruption en faisant des digitalRead. Et on se rend compte là que le ESP32 est bien plus rapide là que le Nano... L'ESP32 passe malgré tout de 2 à 20us...
- SET_PIN fait alterner une broche digitale dans la routine d'interruption. C'est ce que fait DCCpp pour le signal DCC.
- INT_SECOND_CORE envoie la routine d'interruption sur le second coeur. Bien sûr ça ne marche qu'en ESP32...
Voici le rapport sans rien activer du tout, juste la mesure des temps :
isr : 2
min : 54
max : 62
ave : 57.50
< 48: 0
= 48: 0
= 49: 0
= 50: 0
= 51: 0
= 52: 0
= 53: 0
= 54: 120
= 55: 0
= 56: 120
= 57: 0
= 58: 59520 (99.20%)
= 59: 0
= 60: 120
= 61: 0
= 62: 120
= 63: 0
= 64: 0
= 65: 0
= 66: 0
= 67: 0
> 68: 0
NMRA compliant: 59760 (99.60%)
Le temps passé dans la routine d'interruption est de 2us, ce qui est très raisonnable avec un temps moyen de 57.5us très correct.
L'ensemble des temps mesurés se situe entre 54 et 62us, on est donc à près de 100% de réussite sur une norme NMRA.
Le timer de l'ESP32 fonctionne sur une démultiplication des ticks donnés par la fréquence du processeur. Ca explique les timings réguliers toutes les deux us : 54, 56, 58, 60, 62, 64... Certaines fois le timer doit arriver un chouilla trop tôt ou trop tard...
Voyons ce que ça donne avec LOOP_COMPUTE, INT_COMPUTE et SETPIN activés :
isr : 23
min : 53
max : 63
ave : 57.50
< 48: 0
= 48: 0
= 49: 0
= 50: 0
= 51: 0
= 52: 0
= 53: 120
= 54: 0
= 55: 120
= 56: 0
= 57: 240
= 58: 59043 (98.40%)
= 59: 241
= 60: 0
= 61: 120
= 62: 0
= 63: 120
= 64: 0
= 65: 0
= 66: 0
= 67: 0
> 68: 0
NMRA compliant: 59764 (99.60%)
Le temps passé dans la routine d'interruption s'est bien alourdi, mais le bilan global reste correct. On a un peu de timings perturbés à 57 ou 59us, et les temps mini/maxi se sont un peu aggravés, mais restent corrects.
Voyons ce qui se passe si l'on active uniquement la mesure de courant LOOP_ANALOG_READ:
isr : 3
min : 25
max : 90
ave : 57.50
< 48: 2352
= 48: 0
= 49: 0
= 50: 0
= 51: 0
= 52: 0
= 53: 0
= 54: 198
= 55: 960
= 56: 1849
= 57: 6489
= 58: 6554 (10.92%)
= 59: 20937
= 60: 17559
= 61: 1059
= 62: 174
= 63: 91
= 64: 99
= 65: 857
= 66: 272
= 67: 214
> 68: 344
NMRA compliant: 55407 (92.33%)
Et là c'est le drame... Les temps mini/maxi ont explosé, seulement 10% des timings sont respectés. Et même si d'un point de vue NMRA 92% des timings sont respectés, ont voit bien que dans un signal DCC de grandes disparités peuvent intervenir entre les fronts montants et les fronts descendants du signal... Le fait de passer la routine d'interruption sur le second coeur améliore un peu le traitement, mais pas au point de redevenir acceptable.
Le constat est sans appel, l'analogRead ESP32 est très lent. J'ai lu quelque part qu'il lui fallait 100us pour faire sa tâche, et que pendant une partie de ce temps les interruptions sont bloquées... C'est un problème que le nano n'a pas.
Voilà pour la partie théorique de l'analyse. Reste à trouver une solution et à l'appliquer à DCCpp et donc à Labox.