{"id":2453,"date":"2012-06-18T07:00:52","date_gmt":"2012-06-18T06:00:52","guid":{"rendered":"http:\/\/www.blaess.fr\/christophe\/?p=2453"},"modified":"2012-11-30T13:42:47","modified_gmt":"2012-11-30T12:42:47","slug":"la-pandaboard-au-poteau-de-torture-2-fluctuations-de-timers-linux","status":"publish","type":"post","link":"https:\/\/www.blaess.fr\/christophe\/2012\/06\/18\/la-pandaboard-au-poteau-de-torture-2-fluctuations-de-timers-linux\/","title":{"rendered":"La Pandaboard au poteau de torture &#8211; 2 &#8211; Fluctuations de timers Linux"},"content":{"rendered":"<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/2012\/06\/18\/la-pandaboard-au-poteau-de-torture-2-fluctuations-de-timers-linux\/\"><img loading=\"lazy\" decoding=\"async\" class=\"alignright  wp-image-2455\" title=\"Pandaboard au poteau de torture\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/panda-poteau1-300x217.png\" alt=\"Pandaboard au poteau de torture\" width=\"150\" height=\"109\" \/><\/a>Dans <a title=\"La Pandaboard au poteau de torture \u2013 1 \u2013 Disjonction thermique\" href=\"http:\/\/www.blaess.fr\/christophe\/2012\/06\/11\/la-andaboard-au-poteau-de-torture-1-disjonction-thermique\/\">le pr\u00e9c\u00e9dent article<\/a>, nous avons examin\u00e9 les possibilit\u00e9s de fonctionnement en continu d&rsquo;une carte Pandaboard. Il s&rsquo;est av\u00e9r\u00e9 que l&rsquo;ajout d&rsquo;un dissipateur thermique \u00e9tait indispensable pour maintenir un r\u00e9gime permanent \u00e0 100% du CPU.<\/p>\n<p style=\"text-align: justify;\">Nous allons dans cet article observer le comportement d&rsquo;un timer logiciel Linux sur cette carte sous une haute charge &#8211; tant logicielle qu&rsquo;en interruptions &#8211; et mesurer les fluctuations maximales.<\/p>\n<p style=\"text-align: justify;\">\n<!--more-->\n<\/p>\n<h1 style=\"text-align: justify;\">M\u00e9thode de mesure<\/h1>\n<h2 id=\"programme\">Timers Linux<\/h2>\n<p style=\"text-align: justify;\">Le programme suivant utilise l&rsquo;API des timers Posix <code>timer_create()<\/code> et <code>timer_settime()<\/code> propos\u00e9e par le noyau Linux. Il programme la r\u00e9ception p\u00e9riodique d&rsquo;un signal. Dans les exp\u00e9riences ci-dessous, j&rsquo;ai utilis\u00e9 un timer de 100 micro-secondes. Cette valeur est choisie de mani\u00e8re \u00e0 ce que la p\u00e9riode soit sensiblement plus courte que celle du tick syst\u00e8me (pour les noyaux compil\u00e9s sans l&rsquo;option <em>tickless<\/em>). Sur les syst\u00e8mes ARM, le tick est g\u00e9n\u00e9ralement r\u00e9gl\u00e9 \u00e0 une fr\u00e9quence de 128Hz, parfois 1000Hz. En utilisant un d\u00e9clenchement \u00e0 10kHz, nous obligeons le kernel \u00e0 utiliser des timers de pr\u00e9cision \u00e9lev\u00e9e (<em>High Resolution Timers<\/em>). En contrepartie, nous choisissons une p\u00e9riode relativement longue par rapport \u00e0 la dur\u00e9e du traitement \u00e0 r\u00e9aliser lors de la r\u00e9ception du signal (quelques microsecondes).<\/p>\n<p style=\"text-align: justify;\">Lorsque le timer se d\u00e9clenche, notre programme mesure la dur\u00e9e \u00e9coul\u00e9e depuis l&rsquo;occurrence pr\u00e9c\u00e9dente gr\u00e2ce \u00e0 l&rsquo;API <code>clock_gettime()<\/code>. Il affiche toutes les cinq secondes les dur\u00e9es minimale, maximale et moyenne observ\u00e9es. En outre, il conserve la pire valeur (intitul\u00e9e \u00ab\u00a0Max Max\u00a0\u00bb dans les r\u00e9sultats) rencontr\u00e9e depuis le d\u00e9but de son ex\u00e9cution.<\/p>\n<pre><a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/fluctuations-timer.c\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/fluctuations-timer.c\"><strong>fluctuations-timer.c: <\/strong><\/a>\n\n#include &lt;signal.h&gt;\n#include &lt;stdio.h&gt;\n#include &lt;stdlib.h&gt;\n#include &lt;time.h&gt;\n#include &lt;unistd.h&gt;\n\nstatic int nb_mesures = 0;\n\nvoid handler_alarm(int unused)\n{\n    static long long int min;\n    static long long int max;\n    static double sum;\n    static long long int max_max = 0;\n    static struct timespec precedent;\n    static int mesure = -1;\n\n    long long int duree;\n    struct timespec ts;\n\n    \/\/ Reinitialisation des mesures intermediaires\n    if (mesure == -1) {\n        min = -1;\n        max = 0;\n        sum = 0;\n        clock_gettime(CLOCK_REALTIME, &amp; precedent);\n        mesure ++;\n        return;\n    } \n\n    <strong>clock_gettime(CLOCK_REALTIME, &amp; ts)<\/strong>;\n    duree  = ts.tv_sec - precedent.tv_sec;\n    duree *= 1000000000; \/\/ en nanosecondes\n    duree += ts.tv_nsec - precedent.tv_nsec;\n    duree \/= 1000; \/\/ en microsecondes\n    if ((min == -1) || (duree &lt; min))\n        min = duree;\n    if (duree &gt; max) {\n        max = duree;\n        if (max_max &lt; max)\n            max_max = duree;\n    }\n    sum += duree;\n    precedent = ts;\n    mesure ++;\n    if (mesure == nb_mesures) {\n        fprintf(stdout, \"[%ld] Min.= %lld, Moy.= %.1lf, Max.= %lld,  Max.Max.= %lldn\",\n            time(NULL), min, sum \/ nb_mesures, max, max_max);\n        fflush(stdout);\n        mesure = -1;\n    }\n\n}\n\nint main (int argc, char * argv[])\n{\n    long int periode;\n    timer_t tmr;\n    struct sigevent notification;\n    struct itimerspec itimer;\n\n    if ((argc != 2) || (sscanf(argv[1], \"%ld\", &amp; periode) != 1)) {\n        fprintf(stderr, \"usage: %s periode_usn\", argv[0]);\n        exit(EXIT_FAILURE);\n    }\n    if ((periode &lt;= 0) || (periode &gt; 2000000)) {\n        fprintf(stderr, \"%s: La periode doit etre dans [1, 2000000]n\", argv[0]);\n        exit(EXIT_FAILURE);\n    }\n\n    nb_mesures = 5000000 \/ periode;\n    if (nb_mesures == 0) {\n        fprintf(stderr, \"periode trop longuen\");\n        exit(EXIT_FAILURE);\n    }\n    signal(SIGALRM, handler_alarm);\n    notification.sigev_notify = SIGEV_SIGNAL;\n    notification.sigev_signo  = SIGALRM;\n    if (<strong>timer_create(CLOCK_REALTIME, &amp; notification, &amp; tmr)<\/strong> != 0) {\n        perror(\"timer_create\");\n        exit(EXIT_FAILURE);\n    }\n\n    itimer.it_value.tv_sec  = itimer.it_interval.tv_sec  = periode \/ 1000000;  \/\/ en secondes\n    itimer.it_value.tv_nsec = itimer.it_interval.tv_nsec = (periode % 1000000) * 1000; \/\/ en nanosecondes\n    if (<strong>timer_settime(tmr, 0, &amp; itimer, NULL)<\/strong> != 0) {\n        perror(\"timer_settime\");\n        exit(EXIT_FAILURE);\n    }\n\n    while(1)\n        pause();\n\n    return EXIT_SUCCESS;\n}<\/pre>\n<p style=\"text-align: justify;\">Voici le type de r\u00e9sultats que nous fournit ce programme. Naturellement nous l&rsquo;ex\u00e9cutons sous un ordonnancement temps-r\u00e9el afin de s&rsquo;affranchir des fluctuations li\u00e9es \u00e0 l&rsquo;ordonnancement en temps partag\u00e9.<\/p>\n<pre># <strong>chrt -f 80 .\/fluctuations-timer 100 <\/strong>\n[1339860164] Min.= 00, Moy.= 99.7, Max.= 305,  Max.Max.= 305\n[1339860169] Min.= 30, Moy.= 99.7, Max.= 274,  Max.Max.= 305\n[1339860174] Min.= 30, Moy.= 99.7, Max.= 366,  Max.Max.= 366\n[1339860179] Min.=  0, Moy.= 99.7, Max.= 274,  Max.Max.= 366\n[1339860184] Min.= 30, Moy.= 99.7, Max.= 305,  Max.Max.= 366\n[1339860189] Min.=  0, Moy.= 99.7, Max.= 305,  Max.Max.= 366\n  <strong>(<em>Contr\u00f4le-C<\/em>)<\/strong>\n#<\/pre>\n<h2>Mesures de longues dur\u00e9es<\/h2>\n<p style=\"text-align: justify;\">Lorsque l&rsquo;on d\u00e9sire conna\u00eetre les pires fluctuations auxquelles on peut s&rsquo;attendre sur un syst\u00e8me donn\u00e9, il est n\u00e9cessaire de r\u00e9aliser ce genre d&rsquo;exp\u00e9rience de mani\u00e8re prolong\u00e9e, avec une charge tr\u00e8s \u00e9lev\u00e9e, tant en ce qui concerne les processus et l&rsquo;ordonnancement qu&rsquo;en termes d&rsquo;interruptions et d&rsquo;appels syst\u00e8me.<\/p>\n<p style=\"text-align: justify;\">Pour cela, nous allons \u00e9crire un script qui fait tourner ce programme en boucle en remplissant des fichiers de mesure. Chaque ex\u00e9cution (chaque fichier) durera une journ\u00e9e. Nous mesurerons les secondes \u00e0 partir de z\u00e9ro en ramenant chaque fois l&rsquo;heure syst\u00e8me au 1er janvier 1970.<\/p>\n<p style=\"text-align: justify;\">Le principe est donc en substance repr\u00e9sent\u00e9 par le squelette de script suivant.<\/p>\n<pre>#! \/bin\/sh\n\n# Trouver le premier nom de fichier inutilise. \nCOMPTEUR=0\nwhile true\ndo\n    COMPTEUR=$((COMPTEUR + 1))\n    FICHIER_RESULTATS=\/root\/resultat-fluctuations-timer-linux-${COMPTEUR}.txt\n    if ! [ -f \"${FICHIER_RESULTATS}\" ]; then break; fi\ndone\n\nwhile true\ndo\n    # Retour dans le passe ! \n    date -s 1970.01.01-00:00\n\n    # Lancer la mesure\n\n    date +\"##[%s] Debut de l'experience\" &gt; \"${FICHIER_RESULTATS}\"\n    txt=$(uname -a)\n    date +\"##[%s] $txt\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n    <strong>chrt -f 99 \/usr\/local\/bin\/fluctuations-timer 100 &gt;&gt; \"${FICHIER_RESULTATS}\" &amp;<\/strong>\n\n    while true\n    do\n        # Charger le systeme\n        [...]\n\n        sleep 300\n        SECONDES=$(date +%s)\n        if [ $SECONDES -ge 86400 ]; then break; fi\n    done\n\n    killall fluctuations-timer\n    echo \"##[$SECONDES] Fin de l'experience\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n    COMPTEUR=$((COMPTEUR + 1))\n    FICHIER_RESULTATS=\/root\/resultat-fluctuations-timer-linux-${COMPTEUR}.txt\ndone<\/pre>\n<h2>Charge syst\u00e8me importante<\/h2>\n<p style=\"text-align: justify;\">Pour avoir des chances de rencontrer assez rapidement les pires fluctuations, il est tr\u00e8s important de charger excessivement le syst\u00e8me. Pour ce faire, je me suis inspir\u00e9 du script <strong><code>dohell<\/code><\/strong> qui est livr\u00e9 avec Xenomai. Celui-ci multiplie les commandes pour surcharger tous les aspects du syst\u00e8me.<\/p>\n<p style=\"text-align: justify;\">J&rsquo;ai d\u00e9cid\u00e9 d&rsquo;alterner les p\u00e9riodes de tr\u00e8s fortes charge pendant cinq minutes avec des p\u00e9riodes de repos de trente secondes. Ceci permet d&rsquo;augmenter les phases de transition, pendant lesquelles surviennent souvent les pires conditions plut\u00f4t que durant les phases de fonctionnement en r\u00e9gime permanent.<\/p>\n<p style=\"text-align: justify;\">Pendant les p\u00e9riodes de charge, nous lan\u00e7ons des t\u00e2ches qui r\u00e9alisent de tr\u00e8s nombreux appels-syst\u00e8me.<\/p>\n<ul>\n<li><code>top -d 0<\/code> sur chaque CPU<\/li>\n<li><code>cat \/proc\/interrupts<\/code> en boucle sur chaque CPU<\/li>\n<li><code>ps<\/code> en boucle sur chaque CPU<\/li>\n<\/ul>\n<p style=\"text-align: justify;\">D&rsquo;autres t\u00e2ches vont r\u00e9aliser beaucoup d&rsquo;op\u00e9rations d&rsquo;entr\u00e9es-sorties.<\/p>\n<ul>\n<li><code>dd if=\/dev\/zero of=\/dev\/null<\/code> sur chaque CPU<\/li>\n<li><code>dd if=\/dev\/zero of=\/mnt\/ramdisk\/file bs=1024000 count=100<\/code> alternativement sur chaque CPU<\/li>\n<li><code>ls -lR \/ &gt; \/dev\/null<\/code> alternativement sur chaque CPU<\/li>\n<\/ul>\n<p style=\"text-align: justify;\">Enfin, nous provoquons des interruptions externes en utilisant <code>nc<\/code> afin de faire des transferts volumineux par le r\u00e9seau \u00e0 destination d&rsquo;une machine h\u00f4te&nbsp;: <code>nc $HOTE $PORT &lt; \/tmp\/netcat.data<\/code> le fichier transf\u00e9r\u00e9 faisant environ 2.5Mo.<\/p>\n<p style=\"text-align: justify;\">Au bout de quelques jours, j&rsquo;ai decid\u00e9 d&rsquo;augmenter la charge en interruptions r\u00e9seau avec un <code>ping<\/code> \u00ab\u00a0flood\u00a0\u00bb depuis un h\u00f4te qui envoie des paquets ICMP le plus rapidement possible en direction de la cible. Les paquets non acquitt\u00e9s apparaissent sous forme de points qui \u00e9voluent dynamiquement pendant l&rsquo;ex\u00e9cution du <code>ping<\/code>.<\/p>\n<pre># ping -f 192.168.3.152\nPING 192.168.3.152 (192.168.3.152) 56(84) bytes of data.\n...<\/pre>\n<h2 id=\"script\">Script de test<\/h2>\n<p style=\"text-align: justify;\">Voici le script complet de test que j&rsquo;ai lanc\u00e9 sur la cible Pandaboard<\/p>\n<pre><a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/lance-test-fluctuations-timer-linux.sh\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/lance-test-fluctuations-timer-linux.sh\"><strong>lance-test-fluctuations-timer-linux.sh <\/strong><\/a>\n#! \/bin\/sh\n\n# Trouver le premier nom de fichier inutilise.\nCOMPTEUR=0\nwhile true\ndo\n    COMPTEUR=$((COMPTEUR + 1))\n    FICHIER_RESULTATS=\/root\/resultat-fluctuations-timer-linux-${COMPTEUR}.txt\n    if ! [ -f \"${FICHIER_RESULTATS}\" ]; then break; fi\ndone\n\nwhile true\ndo\n    # Retour dans le passe ! \n    date -s 1970.01.01-00:00\n\n        # Lancer la mesure\n\n    date +\"##[%s] Debut de l'experience\" &gt; \"${FICHIER_RESULTATS}\"\n    txt=$(uname -a)\n    date +\"##[%s] $txt\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n    chrt -f 99 \/usr\/local\/bin\/<strong>fluctuations-timer<\/strong> 100 &gt;&gt; \"${FICHIER_RESULTATS}\"  &amp;\n\n    mkdir -p \/mnt\/ramdisk\n    mount none \/mnt\/ramdisk -t ramfs\n\n    if [ -e \/proc\/sys\/kernel\/hung_task_timeout_secs ]\n    then \n        echo 0 &gt; \/proc\/sys\/kernel\/hung_task_timeout_secs\n    fi\n\n    while true\n    do \n        txt=$(uptime)\n        date +\"##[%s] $txt\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n        txt=$(\/usr\/local\/bin\/omap4_temp)\n        date +\"##[%s] temperature : $txt\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n        date +\"##[%s] Periode de repos\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n        sleep 60\n\n        date +\"##[%s] Periode de charge\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n        PIDS=\"\"\n\n        # --------------------------------------------------------      \n        # Charge importante en appels systeme sur les deux CPU\n\n        taskset 1 <strong>top<\/strong> -d 0 &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n        taskset 2 <strong>top<\/strong> -d 0 &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n\n        while true; do taskset 1 <strong>cat \/proc\/interrupts<\/strong>; done &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n        while true; do taskset 2 <strong>cat \/proc\/interrupts<\/strong>; done &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n\n        while true; do taskset 1 <strong>ps<\/strong> ; done &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n        while true; do taskset 2 <strong>ps<\/strong> ; done &gt; \/dev\/null 2&gt;&amp;1 &amp;\n        PIDS=\"$PIDS $!\"\n\n        # -------------------------------------------------------       \n        # Charge importante en I\/O fichiers sur les deux CPUs   \n\n        taskset 1 <strong>dd if=\/dev\/zero of=\/dev\/null<\/strong> &amp;\n        PIDS=\"$PIDS $!\"\n        taskset 2 <strong>dd if=\/dev\/zero of=\/dev\/null<\/strong> &amp;\n        PIDS=\"$PIDS $!\"\n\n        cpu=1\n        while true ; do taskset $cpu <strong>dd if=\/dev\/zero of=\/mnt\/ramdisk\/file<\/strong> bs=1024000 count=100; i=$((3-i)); done &amp;\n        PIDS=\"$PIDS $!\"\n\n        cpu=2\n        while true ; do taskset $cpu <strong>ls -lR \/ &gt; \/dev\/null<\/strong> 2&gt;&amp;1; i=$((3-i)); done &amp;\n        PIDS=\"$PIDS $!\"\n\n        # ------------------------------------------------------\n        # Charge importante en interruptions sur les deux CPU\n\n        CIBLE=192.168.3.1\n        PORT=2012\n        # Il faut lancer auparavant \n        # nc $CIBLE $PORT -l -k &gt; \/dev\/null\n        # sur la machine cible du transfert reseau\n        seq 1 399999 &gt; \/tmp\/netcat.data\n        while true ; do <strong>nc $CIBLE $PORT<\/strong> &lt; \/tmp\/netcat.data ; sleep 15; done  &amp;\n        PIDS=\"$PIDS $!\"\n\n        sleep 300\n\n        kill -KILL $PIDS 2&gt;\/dev\/null\n        killall -KILL dd ls  nc sleep 2&gt;\/dev\/null\n\n        SECONDES=$(date +%s)\n        if [ $SECONDES -ge 86400 ]; then break; fi\n    done\n\n    killall fluctuations-timer\n    echo \"##[$SECONDES] Fin de l'experience\" &gt;&gt; \"${FICHIER_RESULTATS}\"\n\n    COMPTEUR=$((COMPTEUR + 1))\n    FICHIER_RESULTATS=\/root\/resultat-fluctuations-timer-linux-${COMPTEUR}.txt\ndone<\/pre>\n<p style=\"text-align: justify;\">Le programme stocke donc ses r\u00e9sultats dans des fichiers quotidiens num\u00e9rot\u00e9s successivement. Au vu du script ci-dessus, il est \u00e9vident que le syst\u00e8me vit un v\u00e9ritable enfer en charge syst\u00e8me et interruptive. La temp\u00e9rature du processeur est v\u00e9rifi\u00e9e r\u00e9guli\u00e8rement, et il se maintient (avec l&rsquo;aide d&rsquo;un dissipateur) dans une zone thermique tr\u00e8s raisonnable.<\/p>\n<h1 style=\"text-align: justify;\">R\u00e9sultats<\/h1>\n<p style=\"text-align: justify;\">J&rsquo;ai obtenu quelques r\u00e9sultats, mais j&rsquo;ai mis au point le script ci-dessous en le compl\u00e9tant au vu des premiers essais. Il y a donc des \u00e9volutions au cours des journ\u00e9es de test.<\/p>\n<p style=\"text-align: justify;\">Les mesures ont \u00e9t\u00e9 r\u00e9alis\u00e9es sur un noyau Linux \u00ab\u00a0vanilla\u00a0\u00bb 3.4.1, dont voici <a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/config-linux-3.4.1-vanilla\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/config-linux-3.4.1-vanilla\">le fichier de configuration<\/a>.<\/p>\n<h2 style=\"text-align: justify;\">Jour 1<\/h2>\n<pre>[Panda]# <strong>tail <a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-1.txt\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-1.txt\">resultat-fluctuations-timer-linux-1.txt<\/a><\/strong>\n[86566] Min.= 0, Moy.= 99.7, Max.= 213,  Max.Max.= 3173\n[86571] Min.= 30, Moy.= 99.7, Max.= 213,  Max.Max.= 3173\n[86576] Min.= 0, Moy.= 99.7, Max.= 244,  Max.Max.= 3173\n[86581] Min.= 0, Moy.= 99.7, Max.= 244,  Max.Max.= 3173\n[86586] Min.= 0, Moy.= 99.7, Max.= 244,  Max.Max.= 3173\n[86591] Min.= 0, Moy.= 99.7, Max.= 274,  Max.Max.= 3173\n[86596] Min.= 0, Moy.= 99.7, Max.= 244,  Max.Max.= 3173\n[86601] Min.= 0, Moy.= 99.7, Max.= 213,  Max.Max.= 3173\n[86606] Min.= 0, Moy.= 99.6, Max.= 213,  Max.Max.= 3173\n##[86608] Fin de l'experience<\/pre>\n<p style=\"text-align: justify;\">Plusieurs observations peuvent \u00eatre faites d&rsquo;ors et d\u00e9j\u00e0.<\/p>\n<ul>\n<li style=\"text-align: justify;\">La moyenne des intervalles entre les d\u00e9clenchements des timers est toujours tr\u00e8s proche des 100 microsecondes demand\u00e9es. C&rsquo;est le comportement que l&rsquo;on attend d&rsquo;un syst\u00e8me temps r\u00e9el souple comme Linux.<\/li>\n<li style=\"text-align: justify;\">Sur chaque p\u00e9riode de cinq secondes (donc 50000 d\u00e9clenchements de timers), il y a des fluctuations suffisament importantes pour que l&rsquo;on \u00ab\u00a0rate\u00a0\u00bb un d\u00e9clenchement th\u00e9orique, ce qui n\u00e9cessite un rattrapage avec deux d\u00e9clenchements cons\u00e9cutifs avant que l&rsquo;heure syst\u00e8me ne soit mise \u00e0 jour. C&rsquo;est ce que traduit la valeur minimale \u00e0 z\u00e9ro.<\/li>\n<li style=\"text-align: justify;\">Sur la journ\u00e9e, nous avons rencontr\u00e9 des pr\u00e9emptions de plus de 3 millisecondes. C&rsquo;est le genre de valeurs que je souhaite conna\u00eetre avec des tests de longue dur\u00e9e.<\/li>\n<\/ul>\n<p style=\"text-align: justify;\">J&rsquo;ai mis au point un petit script qui pr\u00e9sente graphiquement les valeurs maximales sur chaque it\u00e9ration (sous forme de points) et le maximum rencontr\u00e9 jusqu&rsquo;alors (sous forme de ligne).<\/p>\n<pre><a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/affiche-fluctuations-max.sh\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/affiche-fluctuations-max.sh\"><strong>.\/affiche-fluctuations-max.sh <\/strong><\/a>\n#! \/bin\/sh\n\nif [ $# -ne 1 ]\nthen\n    echo \"usage: $0 fichier-fluctuations...\" &gt;&amp;2\n    exit 1\nfi\n\nfor fichier in \"$@\"\ndo\n    if [ ! -f \"$fichier\" ]\n    then\n        echo \"$fichier: inexistant\" &gt;&amp;2\n        continue\n    fi\n\n    # Supprimer les lignes de commentaires (commencant par un diese)\n    sed -e '\/^#\/d;' &lt; \"$fichier\" &gt; fichier-tmp-1\n    # Isoler les valeurs max sur cinq secondes\n\u00a0\u00a0\u00a0 sed -e 's\/[\/\/; s\/].* Max.=\/\/; s\/,.*$\/\/' &lt; fichier-tmp-1 &gt; fichier-tmp-2\n\u00a0\u00a0\u00a0 # Isoler les valeurs max de la journ\u00e9e\n\u00a0\u00a0\u00a0 sed -e 's\/[\/\/; s\/].*Max.=\/\/' &lt; fichier-tmp-1 &gt; fichier-tmp-3\n    # Creer le graphique\n    gnuplot &lt;&lt;-EOF\n            set terminal png size 800,600 \n            set title \"$fichier\"\n            set output '${fichier}.png'\n        set multiplot\n        plot \"fichier-tmp-2\" notitle with dots lc rgb \"#000080\"\n        replot \"fichier-tmp-3\" notitle with lines lc rgb \"#800000\"\n    EOF\ndone<\/pre>\n<p style=\"text-align: justify;\">Je l&rsquo;invoque ainsi&nbsp;:<\/p>\n<pre>$ <strong>.\/affiche-fluctuations-max.sh resultat-fluctuations-timer-linux-1.txt<\/strong>\n$<\/pre>\n<p style=\"text-align: justify;\">Il cr\u00e9e alors un fichier <code>resultat-fluctuations-timer-linux-1.txt<strong>.png<\/strong><\/code> avec la repr\u00e9sentation graphique.<\/p>\n<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-1.txt3.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-medium wp-image-2490\" title=\"Fluctuations d'un timer Linux - Jour 1\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-1.txt3-300x225.png\" alt=\"Fluctuations d'un timer Linux - Jour 1\" width=\"300\" height=\"225\" \/><\/a><\/p>\n<p style=\"text-align: justify;\">A l&rsquo;issue du premier jour de test, je me suis aper\u00e7u que les t\u00e2ches d\u00e9crites ci-dessus ne chargeaient pas totalement les deux CPU simultan\u00e9ment. La fluctuation maximale sur la journ\u00e9e de test avait \u00e9t\u00e9 de plus de 3 millisecondes. Elle avait \u00e9t\u00e9 obtenue au bout de 16718 secondes, soit un peu plus de quatre heures et demi.<\/p>\n<pre>[Panda]# <strong>grep \"3173, \" resultat-fluctuations-timer-linux-1.txt<\/strong> \n[16718] Min.= 0, Moy.= 99.9, Max.= 3173,  Max.Max.= 3173\n[Panda]#<\/pre>\n<p style=\"text-align: justify;\">Nous pouvons remarquer les pires fluctuations rencontr\u00e9es furent les suivantes<\/p>\n<ul>\n<li style=\"text-align: justify;\">946 microsecondes apr\u00e8s 156 secondes (2 minutes et demi) d&rsquo;exp\u00e9rience<\/li>\n<li style=\"text-align: justify;\">1129 microsecondes au bout d&rsquo;une heure (3602 sec.) d&rsquo;exp\u00e9rience<\/li>\n<li style=\"text-align: justify;\">1464 microsecondes apr\u00e8s une heure et demi d&rsquo;exp\u00e9rience<\/li>\n<li style=\"text-align: justify;\">2105 microsecondes au bout de quatre heures d&rsquo;exp\u00e9rience<\/li>\n<li style=\"text-align: justify;\">3173 microsecondes apr\u00e8s quatre heures et demi d&rsquo;exp\u00e9rience<\/li>\n<\/ul>\n<p style=\"text-align: justify;\">Autrement dit, comme on pouvait s&rsquo;y attendre, il est n\u00e9cessaire de r\u00e9aliser des tests pendant plusieurs heures avant de pouvoir approcher des fluctuations maximales.<\/p>\n<h2 style=\"text-align: justify;\">Jour 2<\/h2>\n<p style=\"text-align: justify;\">J&rsquo;ai relanc\u00e9 le test modifi\u00e9 (avec une charge importante sur les deux CPU), mais j&rsquo;ai d\u00fb l&rsquo;interrompre au bout de 8 heures environ pour v\u00e9rifier mon script. Le fichier se termine donc un peu abruptement.<\/p>\n<pre>[Panda]# <strong>tail <a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-2.txt\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-2.txt\">resultat-fluctuations-timer-linux-2.txt <\/a><\/strong>\n[29230] Min.= 30, Moy.= 99.7, Max.= 305,  Max.Max.= 6072\n[29235] Min.= 30, Moy.= 99.7, Max.= 305,  Max.Max.= 6072\n[29240] Min.= 30, Moy.= 99.7, Max.= 305,  Max.Max.= 6072\n[29245] Min.= 30, Moy.= 99.7, Max.= 274,  Max.Max.= 6072\n[29250] Min.= 30, Moy.= 99.7, Max.= 274,  Max.Max.= 6072\n[29255] Min.= 30, Moy.= 99.7, Max.= 274,  Max.Max.= 6072\n##[29257] Periode de charge\n[29260] Min.= 0, Moy.= 99.9, Max.= 396,  Max.Max.= 6072\n[29265] Min.= 0, Moy.= 99.9, Max.= 396,  Max.Max.= 6072\n[29270] Min.= 0, Moy.= 99.9, Max.= 366,  Max.Max.= 6072<\/pre>\n<p style=\"text-align: justify;\">La fluctuation maximale est beaucoup plus importante. Elle a \u00e9t\u00e9 obtenue quelques instants avant l&rsquo;arr\u00eat du programme (peut-\u00eatre un artefact de la connexion par SSH sur la cible). La pr\u00e9c\u00e9dente (5126 microsecondes) \u00e9tait survenue apr\u00e8s trois heures et demi de mesure.<\/p>\n<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-2.txt2.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-medium wp-image-2492\" title=\"Fluctuations d'un timer Linux - Jour 2\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-2.txt2-300x225.png\" alt=\"Fluctuations d'un timer Linux - Jour 2\" width=\"300\" height=\"225\" \/><\/a><\/p>\n<p style=\"text-align: justify;\">Nous pouvons remarquer une plus grande dispersion des fluctuations maximales vers le haut.<\/p>\n<h2 style=\"text-align: justify;\">Jour 3<\/h2>\n<p style=\"text-align: justify;\">J&rsquo;ai pu relancer le programme et le laisser s&rsquo;ex\u00e9cuter une journ\u00e9e sans interruption, dans les m\u00eames conditions que pr\u00e9c\u00e9demment.<\/p>\n<pre>[Panda]# <strong>tail <a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-3.txt\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-3.txt\">resultat-fluctuations-timer-linux-3.txt<\/a><\/strong> \n[86506] Min.= 0, Moy.= 101.1, Max.= 2777,  Max.Max.= 5523\n[86511] Min.= 0, Moy.= 100.3, Max.= 1770,  Max.Max.= 5523\n[86517] Min.= 0, Moy.= 99.9, Max.= 396,  Max.Max.= 5523\n[86522] Min.= 0, Moy.= 99.9, Max.= 457,  Max.Max.= 5523\n[86527] Min.= 0, Moy.= 101.4, Max.= 3814,  Max.Max.= 5523\n[86532] Min.= 0, Moy.= 99.9, Max.= 427,  Max.Max.= 5523\n[86537] Min.= 0, Moy.= 99.9, Max.= 396,  Max.Max.= 5523\n[86542] Min.= 0, Moy.= 100.5, Max.= 2288,  Max.Max.= 5523\n[86547] Min.= 0, Moy.= 100.8, Max.= 3601,  Max.Max.= 5523\n##[86550] Fin de l'experience<\/pre>\n<p style=\"text-align: justify;\">Nous sommes dans le m\u00eame ordre de fluctuation maximale. La pire valeur a \u00e9t\u00e9 observ\u00e9e apr\u00e8s plus de 21 heures de test.<\/p>\n<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-3.txt1.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-medium wp-image-2493\" title=\"Fluctuations d'un timer Linux - Jour 3\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-3.txt1-300x225.png\" alt=\"Fluctuations d'un timer Linux - Jour 3\" width=\"300\" height=\"225\" \/><\/a><\/p>\n<h2 style=\"text-align: justify;\">Jour 4<\/h2>\n<p style=\"text-align: justify;\">Lors du quatri\u00e8me jour, j&rsquo;ai d\u00e9cid\u00e9 d&rsquo;augmenter sensiblement en ajoutant un ping \u00ab\u00a0flood\u00a0\u00bb depuis un autre poste, afin de d\u00e9clencher de nombreuses interruptions r\u00e9seau.<\/p>\n<p style=\"text-align: justify;\">Quelle ne f\u00fbt pas ma surprise, en regardant des r\u00e9sultats temporaires au bout de 21 heures, de voir que les fluctuations \u00e9taient beaucoup plus faibles que celles observ\u00e9es pr\u00e9c\u00e9demment&nbsp;! En voici une repr\u00e9sentation graphique.<\/p>\n<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-4.1.txt1.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-medium wp-image-2494\" title=\"Fluctuations d'un timer Linux - Jour 4 (d\u00e9but)\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-4.1.txt1-300x225.png\" alt=\"Fluctuations d'un timer Linux - Jour 4 (d\u00e9but)\" width=\"300\" height=\"225\" \/><\/a>C&rsquo;est en voulant v\u00e9rifier dans le pseudo fichier <code>\/proc\/interrupts<\/code> si la charge en interruptions \u00e9tait aussi \u00e9lev\u00e9e que pr\u00e9vu que j&rsquo;ai compris o\u00f9 se situait le probl\u00e8me.<\/p>\n<pre>[Panda]# <strong>cat \/proc\/interrupts<\/strong> \n           CPU0       CPU1       \n 29: 1624296339 1089370474       GIC  twd\n 39:          0          0       GIC  TWL6030-PIH\n 41:          0          0       GIC  l3-dbg-irq\n 42:          0          0       GIC  l3-app-irq\n 44:     401065          0       GIC  DMA\n 52:          0          0       GIC  gpmc\n 57:          6          0       GIC  OMAP DISPC\n 69:          9          0       GIC  gp timer\n 85:          0          0       GIC  omapdss_dsi.0\n 88:        240          0       GIC  omap_i2c\n 89:          0          0       GIC  omap_i2c\n 91:         13          0       GIC  mmc1\n 93:          0          0       GIC  omap_i2c\n 94:          0          0       GIC  omap_i2c\n108:          1          0       GIC  ohci_hcd:usb2\n109:  160087021          0       GIC  ehci_hcd:usb1\n115:     435894          0       GIC  mmc0\n116:          0          0       GIC  omapdss_dsi.1\n363:          0          0   twl6030  rtc0\n419:          0          0      PRCM  hwmod_io\nIPI0:         0          0    Timer broadcast interrupts\nIPI1:   1771432    2429790    Rescheduling interrupts\nIPI2:         0          0    Function call interrupts\nIPI3:     95149      68083    Single function call interrupts\nIPI4:         0          0    CPU stop interrupts\nErr:          0\n[Panda]#<\/pre>\n<p style=\"text-align: justify;\">Visiblement toutes les interruptions DMA (44), r\u00e9seau (109) et celles de la carte micro-SD (115) ne sont trait\u00e9es que sur le c\u0153ur 0, pas sur le 1. Si le programme de test s&rsquo;ex\u00e9cute sur ce CPU 0, il sera fortement perturb\u00e9 par les interruptions et les fluctuations plus importantes que s&rsquo;il tourne sur le CPU 1.<\/p>\n<p style=\"text-align: justify;\">Pour en avoir le c\u0153ur net, j&rsquo;ai d\u00e9plac\u00e9 le programme de test (avec la commande <code>taskset<\/code> pour le faire fonctionner sur le CPU 0. Les performances ce sont instantan\u00e9ment d\u00e9grad\u00e9es comme nous le voyons sur ce second graphique. (<a title=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-4.txt\" href=\"http:\/\/www.blaess.fr\/christophe\/files\/article-2012-06-18\/resultat-fluctuations-timer-linux-4.txt\">resultat-fluctuations-timer-linux-4.txt<\/a>)<\/p>\n<p style=\"text-align: justify;\"><a href=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-4.txt.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-medium wp-image-2495\" title=\"Fluctuations d'un timer Linux - Jour 4\" src=\"http:\/\/www.blaess.fr\/christophe\/wp-content\/uploads\/2012\/06\/resultat-fluctuations-timer-linux-4.txt-300x225.png\" alt=\"Fluctuations d'un timer Linux - Jour 4\" width=\"300\" height=\"225\" \/><\/a><\/p>\n<h1 style=\"text-align: justify;\">Conclusion<\/h1>\n<p style=\"text-align: justify;\">Pour continuer cette exp\u00e9rience, il est important de r\u00e9partir correctement les traitements des interruptions et les mesures sur les deux coeurs disponibles. Ceci fera l&rsquo;objet du <a title=\"La Pandaboard au porteau de torture \u2013 3 \u2013 Timers Linux et Linux-rt\" href=\"http:\/\/www.blaess.fr\/christophe\/2012\/07\/02\/la-pandaboard-au-porteau-de-torture-3-timers-linux-et-linux-rt\/\">prochain article<\/a>.<\/p>","protected":false},"excerpt":{"rendered":"<p>Dans le pr&eacute;c&eacute;dent article, nous avons examin&eacute; les possibilit&eacute;s de fonctionnement en continu d&rsquo;une carte Pandaboard. Il s&rsquo;est av&eacute;r&eacute; que l&rsquo;ajout d&rsquo;un dissipateur thermique &eacute;tait indispensable pour maintenir un r&eacute;gime permanent &agrave; 100% du CPU. Nous allons dans cet article observer le comportement d&rsquo;un timer logiciel Linux sur cette carte sous une haute charge &ndash; [&hellip;]<\/p>","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[5,8,13,14],"tags":[],"class_list":["post-2453","post","type-post","status-publish","format-standard","hentry","category-embarque","category-linux-2","category-shell","category-temps-reel"],"_links":{"self":[{"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/posts\/2453","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/comments?post=2453"}],"version-history":[{"count":1,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/posts\/2453\/revisions"}],"predecessor-version":[{"id":3239,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/posts\/2453\/revisions\/3239"}],"wp:attachment":[{"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/media?parent=2453"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/categories?post=2453"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.blaess.fr\/christophe\/wp-json\/wp\/v2\/tags?post=2453"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}