| Prochaine révision | Révision précédente |
| prog:uftrace [2017/10/29 00:55] – Création root | prog:uftrace [2020/05/11 01:15] (Version actuelle) – Amélioration de la description "Source" root |
|---|
| [[https://github.com/namhyung/uftrace|Source]], [[https://github.com/namhyung/uftrace/tree/master/doc|Doc]] | [[https://github.com/namhyung/uftrace|Code source]], [[https://github.com/namhyung/uftrace/tree/master/doc|Doc]] [[https://www.youtube.com/watch?v=s0B8hV2O8ps|CppCon 2017: Honggyu Kim “Understanding the runtime behaviors of C++ programs using uftrace tool”]] |
| |
| =====Prérequis===== | =====Prérequis===== |
| |
| Arguments de ''foo'' : ''-A foo@arg1/u64''. ''arg'' pour nombre entier, ''1'' pour l'argument 1, ''u'' pour ''unsigned int'', ''64'' pour la taille. Il est aussi possible d'utiliser ''fparg'' pour les flottants. | Arguments de ''foo'' : ''-A foo@arg1/u64''. ''arg'' pour nombre entier, ''1'' pour l'argument 1, ''u'' pour ''unsigned int'', ''64'' pour la taille. Il est aussi possible d'utiliser ''fparg'' pour les flottants. |
| | |
| | Il y a l'option ''%%--%%auto-args'' mais qui est dans une [[https://github.com/namhyung/uftrace/tree/review/auto-args-v2|branche]] et pas encore dans le code source ''master''. |
| |
| * Limiter l'affichage au fonction les plus longues : | * Limiter l'affichage au fonction les plus longues : |
| ''-t 5us'' : limiter à minimum 5 microsecondes | ''-t 5us'' : limiter à minimum 5 microsecondes |
| | |
| | * Inclure les appels entre librairie et pas seulement ceux du programme vers ses dépendances directes : |
| | ''--nest-libcall'' |
| |
| * Affichage graphique de l'état de la pile en fonction du temps : | * Affichage graphique de l'état de la pile en fonction du temps : |
| |
| et ouvrir le fichier ''log.js'' avec Google Chrome depuis l'adresse interne ''chrome:%%//%%tracing''. | et ouvrir le fichier ''log.js'' avec Google Chrome depuis l'adresse interne ''chrome:%%//%%tracing''. |
| | |
| | {{:prog:uftrace:tracing.png|Tracing}} |
| | |
| | Pour mémo : [[https://github.com/catapult-project/catapult/blob/master/tracing/bin/trace2html|trace2html]] et [[https://github.com/brendangregg/FlameGraph|Flame Graph]] |
| | |
| | ===Différences entre 2 exécutions=== |
| | uftrace record -d 1 a.out |
| | uftrace record -d 2 a.out |
| | uftrace report --data 1 --diff 2 |
| | |
| | Mais j'ai quelques doutes sur le résultat. Normalement, les deux premières colonnes de temps devraient être à peu près identique alors que là, on dirait que c'est la première colonne qui contient le diff. |
| | # |
| | # uftrace diff |
| | # [0] base: 1 (from uftrace record -d 1 -k a.out ) |
| | # [1] diff: 2 (from uftrace record -d 2 -k a.out ) |
| | # |
| | Total time (diff) Self time (diff) Calls (diff) Function |
| | =================================== =================================== ================================ ================================================ |
| | - 572.484 us +572.484 us - 572.484 us +572.484 us 0 157 +157 __do_page_fault |
| | - 217.218 us +217.218 us - 217.218 us +217.218 us 0 1 +1 do_syscall_64 |
| | - 167.109 us +167.109 us - 162.286 us +162.286 us 0 34 +34 sys_mmap |
| | 4.394 us 170.853 us +166.459 us 4.394 us 170.853 us +166.459 us 3 237 +234 smp_irq_work_interrupt |
| | - 155.828 us +155.828 us - 148.641 us +148.641 us 0 21 +21 sys_read |
| | - 152.856 us +152.856 us - 149.136 us +149.136 us 0 30 +30 sys_open |
| | - 117.696 us +117.696 us - 109.732 us +109.732 us 0 23 +23 sys_mprotect |
| | 55.976 us 145.693 us +89.717 us 55.976 us 145.693 us +89.717 us 1 12 +11 exit_to_usermode_loop |
| | - 53.185 us +53.185 us - 50.139 us +50.139 us 0 6 +6 sys_munmap |
| | 81.100 us 133.748 us +52.648 us 1.174 us 1.285 us +0.111 us 1 1 0 main |
| | 79.926 us 132.463 us +52.537 us 5.419 us 3.635 us -1.784 us 1 1 0 puts |
| | - 20.987 us +20.987 us - 20.429 us +20.429 us 0 1 +1 sys_readlink |
| | 2.705 us 23.271 us +20.566 us 2.122 us 20.099 us +17.977 us 1 19 +18 sys_newfstat |
| | - 16.990 us +16.990 us - 16.383 us +16.383 us 0 5 +5 sys_writev |
| | - 15.621 us +15.621 us - 14.503 us +14.503 us 0 21 +21 sys_close |
| | 12.015 us 23.654 us +11.639 us 12.015 us 23.084 us +11.069 us 1 3 +2 sys_write |
| | - 9.853 us +9.853 us - 5.503 us +5.503 us 0 6 +6 sys_rt_sigaction |
| | - 6.998 us +6.998 us - 6.430 us +6.430 us 0 1 +1 sys_statfs |
| | - 5.634 us +5.634 us - 5.634 us +5.634 us 0 3 +3 sys_newstat |
| | - 5.449 us +5.449 us - 3.925 us +3.925 us 0 3 +3 sys_brk |
| | - 5.327 us +5.327 us - 4.085 us +4.085 us 0 3 +3 sys_futex |
| | - 4.470 us +4.470 us - 4.470 us +4.470 us 0 1 +1 finish_task_switch |
| | - 3.929 us +3.929 us - 3.929 us +3.929 us 0 2 +2 sys_ftruncate |
| | - 3.099 us +3.099 us - 3.099 us +3.099 us 0 1 +1 sys_access |
| | - 2.976 us +2.976 us - 2.349 us +2.349 us 0 3 +3 sys_fcntl |
| | - 1.780 us +1.780 us - 1.780 us +1.780 us 0 1 +1 smp_reschedule_interrupt |
| | - 1.288 us +1.288 us - 1.288 us +1.288 us 0 3 +3 sys_getpid |
| | - 0.854 us +0.854 us - 0.854 us +0.854 us 0 1 +1 sys_prlimit64 |
| | - 0.535 us +0.535 us - 0.535 us +0.535 us 0 1 +1 sys_rt_sigprocmask |
| | - 0.499 us +0.499 us - 0.499 us +0.499 us 0 1 +1 sys_set_tid_address |
| | - 0.443 us +0.443 us - 0.443 us +0.443 us 0 1 +1 sys_arch_prctl |
| | - 0.383 us +0.383 us - 0.383 us +0.383 us 0 1 +1 sys_gettid |
| | - 0.292 us +0.292 us - 0.292 us +0.292 us 0 1 +1 fsnotify |
| | - 0.290 us +0.290 us - 0.290 us +0.290 us 0 1 +1 __fsnotify_parent |
| | - 0.269 us +0.269 us - 0.269 us +0.269 us 0 1 +1 sys_set_robust_list |
| | - 0.246 us +0.246 us - 0.246 us +0.246 us 0 1 +1 _raw_spin_lock_irq |
| | 0.526 us 0.548 us +0.022 us 0.526 us 0.548 us +0.022 us 1 1 0 __cxa_atexit |
| | 0.735 us 0.726 us -0.009 us 0.735 us 0.726 us -0.009 us 1 1 0 __monstartup |
| | - - 0 us - - 0 us 0 1 +1 sys_exit_group |
| | |
| | ====Python==== |
| | Pour mémo, il est aussi possible d'appliquer des filtres plus évolués en utilisant Python. Voir la [[https://github.com/namhyung/uftrace/blob/master/doc/uftrace-script.md|doc]] |
