diff options
Diffstat (limited to 'tools/power')
| -rw-r--r-- | tools/power/cpupower/bench/parse.c | 2 | ||||
| -rw-r--r-- | tools/power/cpupower/po/de.po | 44 | ||||
| -rw-r--r-- | tools/power/cpupower/po/fr.po | 120 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/cpufreq-info.c | 8 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/helpers/amd.c | 11 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/helpers/cpuid.c | 8 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/helpers/helpers.h | 2 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/helpers/misc.c | 2 | ||||
| -rw-r--r-- | tools/power/cpupower/utils/idle_monitor/mperf_monitor.c | 3 | ||||
| -rw-r--r-- | tools/power/pm-graph/Makefile | 4 | ||||
| -rwxr-xr-x | tools/power/pm-graph/bootgraph.py | 125 | ||||
| -rw-r--r-- | tools/power/pm-graph/config/cgskip.txt | 1 | ||||
| -rw-r--r-- | tools/power/pm-graph/config/custom-timeline-functions.cfg | 4 | ||||
| -rw-r--r-- | tools/power/pm-graph/sleepgraph.8 | 13 | ||||
| -rwxr-xr-x | tools/power/pm-graph/sleepgraph.py | 1836 | ||||
| -rw-r--r-- | tools/power/x86/turbostat/turbostat.8 | 4 | ||||
| -rw-r--r-- | tools/power/x86/turbostat/turbostat.c | 166 |
17 files changed, 1275 insertions, 1078 deletions
diff --git a/tools/power/cpupower/bench/parse.c b/tools/power/cpupower/bench/parse.c index 9ba8a44ad2a7..84caee38418f 100644 --- a/tools/power/cpupower/bench/parse.c +++ b/tools/power/cpupower/bench/parse.c @@ -145,7 +145,7 @@ struct config *prepare_default_config() config->cpu = 0; config->prio = SCHED_HIGH; config->verbose = 0; - strncpy(config->governor, "ondemand", 8); + strncpy(config->governor, "ondemand", sizeof(config->governor)); config->output = stdout; diff --git a/tools/power/cpupower/po/de.po b/tools/power/cpupower/po/de.po index 78c09e51663a..840c17cc450a 100644 --- a/tools/power/cpupower/po/de.po +++ b/tools/power/cpupower/po/de.po @@ -323,12 +323,12 @@ msgstr " Hardwarebedingte Grenzen der Taktfrequenz: " #: utils/cpufreq-info.c:256 #, c-format msgid " available frequency steps: " -msgstr " mögliche Taktfrequenzen: " +msgstr " mögliche Taktfrequenzen: " #: utils/cpufreq-info.c:269 #, c-format msgid " available cpufreq governors: " -msgstr " mögliche Regler: " +msgstr " mögliche Regler: " #: utils/cpufreq-info.c:280 #, c-format @@ -381,7 +381,7 @@ msgstr "Optionen:\n" msgid " -e, --debug Prints out debug information [default]\n" msgstr "" " -e, --debug Erzeugt detaillierte Informationen, hilfreich\n" -" zum Aufspüren von Fehlern\n" +" zum Aufspüren von Fehlern\n" #: utils/cpufreq-info.c:475 #, c-format @@ -424,7 +424,7 @@ msgstr " -p, --policy Findet die momentane Taktik heraus *\n" #: utils/cpufreq-info.c:482 #, c-format msgid " -g, --governors Determines available cpufreq governors *\n" -msgstr " -g, --governors Erzeugt eine Liste mit verfügbaren Reglern *\n" +msgstr " -g, --governors Erzeugt eine Liste mit verfügbaren Reglern *\n" #: utils/cpufreq-info.c:483 #, c-format @@ -450,7 +450,7 @@ msgstr "" #, c-format msgid " -s, --stats Shows cpufreq statistics if available\n" msgstr "" -" -s, --stats Zeigt, sofern möglich, Statistiken über cpufreq an.\n" +" -s, --stats Zeigt, sofern möglich, Statistiken über cpufreq an.\n" #: utils/cpufreq-info.c:487 #, c-format @@ -473,9 +473,9 @@ msgid "" "cpufreq\n" " interface in 2.4. and early 2.6. kernels\n" msgstr "" -" -o, --proc Erzeugt Informationen in einem ähnlichem Format zu " +" -o, --proc Erzeugt Informationen in einem ähnlichem Format zu " "dem\n" -" der /proc/cpufreq-Datei in 2.4. und frühen 2.6.\n" +" der /proc/cpufreq-Datei in 2.4. und frühen 2.6.\n" " Kernel-Versionen\n" #: utils/cpufreq-info.c:491 @@ -491,7 +491,7 @@ msgstr "" #: utils/cpufreq-info.c:492 utils/cpuidle-info.c:152 #, c-format msgid " -h, --help Prints out this screen\n" -msgstr " -h, --help Gibt diese Kurzübersicht aus\n" +msgstr " -h, --help Gibt diese Kurzübersicht aus\n" #: utils/cpufreq-info.c:495 #, c-format @@ -501,7 +501,7 @@ msgid "" msgstr "" "Sofern kein anderer Parameter als '-c, --cpu' angegeben wird, liefert " "dieses\n" -"Programm Informationen, die z.B. zum Berichten von Fehlern nützlich sind.\n" +"Programm Informationen, die z.B. zum Berichten von Fehlern nützlich sind.\n" #: utils/cpufreq-info.c:497 #, c-format @@ -557,7 +557,7 @@ msgid "" "select\n" msgstr "" " -d FREQ, --min FREQ neue minimale Taktfrequenz, die der Regler\n" -" auswählen darf\n" +" auswählen darf\n" #: utils/cpufreq-set.c:28 #, c-format @@ -566,7 +566,7 @@ msgid "" "select\n" msgstr "" " -u FREQ, --max FREQ neue maximale Taktfrequenz, die der Regler\n" -" auswählen darf\n" +" auswählen darf\n" #: utils/cpufreq-set.c:29 #, c-format @@ -579,20 +579,20 @@ msgid "" " -f FREQ, --freq FREQ specific frequency to be set. Requires userspace\n" " governor to be available and loaded\n" msgstr "" -" -f FREQ, --freq FREQ setze exakte Taktfrequenz. Benötigt den Regler\n" +" -f FREQ, --freq FREQ setze exakte Taktfrequenz. Benötigt den Regler\n" " 'userspace'.\n" #: utils/cpufreq-set.c:32 #, c-format msgid " -r, --related Switches all hardware-related CPUs\n" msgstr "" -" -r, --related Setze Werte für alle CPUs, deren Taktfrequenz\n" +" -r, --related Setze Werte für alle CPUs, deren Taktfrequenz\n" " hardwarebedingt identisch ist.\n" #: utils/cpufreq-set.c:33 utils/cpupower-set.c:28 utils/cpupower-info.c:27 #, c-format msgid " -h, --help Prints out this screen\n" -msgstr " -h, --help Gibt diese Kurzübersicht aus\n" +msgstr " -h, --help Gibt diese Kurzübersicht aus\n" #: utils/cpufreq-set.c:35 #, fuzzy, c-format @@ -618,8 +618,8 @@ msgstr "" " angenommen\n" "2. Der Parameter -f bzw. --freq kann mit keinem anderen als dem Parameter\n" " -c bzw. --cpu kombiniert werden\n" -"3. FREQuenzen können in Hz, kHz (Standard), MHz, GHz oder THz eingegeben\n" -" werden, indem der Wert und unmittelbar anschließend (ohne Leerzeichen!)\n" +"3. FREQuenzen können in Hz, kHz (Standard), MHz, GHz oder THz eingegeben\n" +" werden, indem der Wert und unmittelbar anschließend (ohne Leerzeichen!)\n" " die Einheit angegeben werden. (Bsp: 1GHz )\n" " (FREQuenz in kHz =^ MHz * 1000 =^ GHz * 1000000).\n" @@ -638,7 +638,7 @@ msgid "" msgstr "" "Beim Einstellen ist ein Fehler aufgetreten. Typische Fehlerquellen sind:\n" "- nicht ausreichende Rechte (Administrator)\n" -"- der Regler ist nicht verfügbar bzw. nicht geladen\n" +"- der Regler ist nicht verfügbar bzw. nicht geladen\n" "- die angegebene Taktik ist inkorrekt\n" "- eine spezifische Frequenz wurde angegeben, aber der Regler 'userspace'\n" " kann entweder hardwarebedingt nicht genutzt werden oder ist nicht geladen\n" @@ -821,7 +821,7 @@ msgstr "" #: utils/cpuidle-info.c:48 #, fuzzy, c-format msgid "Available idle states:" -msgstr " mögliche Taktfrequenzen: " +msgstr " mögliche Taktfrequenzen: " #: utils/cpuidle-info.c:71 #, c-format @@ -924,7 +924,7 @@ msgstr "Aufruf: cpufreq-info [Optionen]\n" msgid " -s, --silent Only show general C-state information\n" msgstr "" " -e, --debug Erzeugt detaillierte Informationen, hilfreich\n" -" zum Aufspüren von Fehlern\n" +" zum Aufspüren von Fehlern\n" #: utils/cpuidle-info.c:150 #, fuzzy, c-format @@ -933,9 +933,9 @@ msgid "" "acpi/processor/*/power\n" " interface in older kernels\n" msgstr "" -" -o, --proc Erzeugt Informationen in einem ähnlichem Format zu " +" -o, --proc Erzeugt Informationen in einem ähnlichem Format zu " "dem\n" -" der /proc/cpufreq-Datei in 2.4. und frühen 2.6.\n" +" der /proc/cpufreq-Datei in 2.4. und frühen 2.6.\n" " Kernel-Versionen\n" #: utils/cpuidle-info.c:209 @@ -949,7 +949,7 @@ msgstr "" #~ " -c CPU, --cpu CPU CPU number which information shall be determined " #~ "about\n" #~ msgstr "" -#~ " -c CPU, --cpu CPU Nummer der CPU, über die Informationen " +#~ " -c CPU, --cpu CPU Nummer der CPU, über die Informationen " #~ "herausgefunden werden sollen\n" #~ msgid "" diff --git a/tools/power/cpupower/po/fr.po b/tools/power/cpupower/po/fr.po index 245ad20a9bf9..b46ca2548f86 100644 --- a/tools/power/cpupower/po/fr.po +++ b/tools/power/cpupower/po/fr.po @@ -212,7 +212,7 @@ msgstr "" #: utils/cpupower.c:91 #, c-format msgid "Report errors and bugs to %s, please.\n" -msgstr "Veuillez rapportez les erreurs et les bogues à %s, s'il vous plait.\n" +msgstr "Veuillez rapportez les erreurs et les bogues à %s, s'il vous plait.\n" #: utils/cpupower.c:114 #, c-format @@ -227,14 +227,14 @@ msgstr "" #: utils/cpufreq-info.c:31 #, c-format msgid "Couldn't count the number of CPUs (%s: %s), assuming 1\n" -msgstr "Détermination du nombre de CPUs (%s : %s) impossible. Assume 1\n" +msgstr "Détermination du nombre de CPUs (%s : %s) impossible. Assume 1\n" #: utils/cpufreq-info.c:63 #, c-format msgid "" " minimum CPU frequency - maximum CPU frequency - governor\n" msgstr "" -" Fréquence CPU minimale - Fréquence CPU maximale - régulateur\n" +" Fréquence CPU minimale - Fréquence CPU maximale - régulateur\n" #: utils/cpufreq-info.c:151 #, c-format @@ -302,12 +302,12 @@ msgstr " pilote : %s\n" #: utils/cpufreq-info.c:219 #, fuzzy, c-format msgid " CPUs which run at the same hardware frequency: " -msgstr " CPUs qui doivent changer de fréquences en même temps : " +msgstr " CPUs qui doivent changer de fréquences en même temps : " #: utils/cpufreq-info.c:230 #, fuzzy, c-format msgid " CPUs which need to have their frequency coordinated by software: " -msgstr " CPUs qui doivent changer de fréquences en même temps : " +msgstr " CPUs qui doivent changer de fréquences en même temps : " #: utils/cpufreq-info.c:241 #, c-format @@ -317,22 +317,22 @@ msgstr "" #: utils/cpufreq-info.c:247 #, c-format msgid " hardware limits: " -msgstr " limitation matérielle : " +msgstr " limitation matérielle : " #: utils/cpufreq-info.c:256 #, c-format msgid " available frequency steps: " -msgstr " plage de fréquence : " +msgstr " plage de fréquence : " #: utils/cpufreq-info.c:269 #, c-format msgid " available cpufreq governors: " -msgstr " régulateurs disponibles : " +msgstr " régulateurs disponibles : " #: utils/cpufreq-info.c:280 #, c-format msgid " current policy: frequency should be within " -msgstr " tactique actuelle : la fréquence doit être comprise entre " +msgstr " tactique actuelle : la fréquence doit être comprise entre " #: utils/cpufreq-info.c:282 #, c-format @@ -345,18 +345,18 @@ msgid "" "The governor \"%s\" may decide which speed to use\n" " within this range.\n" msgstr "" -"Le régulateur \"%s\" est libre de choisir la vitesse\n" -" dans cette plage de fréquences.\n" +"Le régulateur \"%s\" est libre de choisir la vitesse\n" +" dans cette plage de fréquences.\n" #: utils/cpufreq-info.c:293 #, c-format msgid " current CPU frequency is " -msgstr " la fréquence actuelle de ce CPU est " +msgstr " la fréquence actuelle de ce CPU est " #: utils/cpufreq-info.c:296 #, c-format msgid " (asserted by call to hardware)" -msgstr " (vérifié par un appel direct du matériel)" +msgstr " (vérifié par un appel direct du matériel)" #: utils/cpufreq-info.c:304 #, c-format @@ -377,7 +377,7 @@ msgstr "Options :\n" #: utils/cpufreq-info.c:474 #, fuzzy, c-format msgid " -e, --debug Prints out debug information [default]\n" -msgstr " -e, --debug Afficher les informations de déboguage\n" +msgstr " -e, --debug Afficher les informations de déboguage\n" #: utils/cpufreq-info.c:475 #, c-format @@ -385,8 +385,8 @@ msgid "" " -f, --freq Get frequency the CPU currently runs at, according\n" " to the cpufreq core *\n" msgstr "" -" -f, --freq Obtenir la fréquence actuelle du CPU selon le point\n" -" de vue du coeur du système de cpufreq *\n" +" -f, --freq Obtenir la fréquence actuelle du CPU selon le point\n" +" de vue du coeur du système de cpufreq *\n" #: utils/cpufreq-info.c:477 #, c-format @@ -394,8 +394,8 @@ msgid "" " -w, --hwfreq Get frequency the CPU currently runs at, by reading\n" " it from hardware (only available to root) *\n" msgstr "" -" -w, --hwfreq Obtenir la fréquence actuelle du CPU directement par\n" -" le matériel (doit être root) *\n" +" -w, --hwfreq Obtenir la fréquence actuelle du CPU directement par\n" +" le matériel (doit être root) *\n" #: utils/cpufreq-info.c:479 #, c-format @@ -403,13 +403,13 @@ msgid "" " -l, --hwlimits Determine the minimum and maximum CPU frequency " "allowed *\n" msgstr "" -" -l, --hwlimits Affiche les fréquences minimales et maximales du CPU " +" -l, --hwlimits Affiche les fréquences minimales et maximales du CPU " "*\n" #: utils/cpufreq-info.c:480 #, c-format msgid " -d, --driver Determines the used cpufreq kernel driver *\n" -msgstr " -d, --driver Affiche le pilote cpufreq utilisé *\n" +msgstr " -d, --driver Affiche le pilote cpufreq utilisé *\n" #: utils/cpufreq-info.c:481 #, c-format @@ -420,7 +420,7 @@ msgstr " -p, --policy Affiche la tactique actuelle de cpufreq *\n" #, c-format msgid " -g, --governors Determines available cpufreq governors *\n" msgstr "" -" -g, --governors Affiche les régulateurs disponibles de cpufreq *\n" +" -g, --governors Affiche les régulateurs disponibles de cpufreq *\n" #: utils/cpufreq-info.c:483 #, fuzzy, c-format @@ -429,7 +429,7 @@ msgid "" "frequency *\n" msgstr "" " -a, --affected-cpus Affiche quels sont les CPUs qui doivent changer de\n" -" fréquences en même temps *\n" +" fréquences en même temps *\n" #: utils/cpufreq-info.c:484 #, fuzzy, c-format @@ -438,7 +438,7 @@ msgid "" " coordinated by software *\n" msgstr "" " -a, --affected-cpus Affiche quels sont les CPUs qui doivent changer de\n" -" fréquences en même temps *\n" +" fréquences en même temps *\n" #: utils/cpufreq-info.c:486 #, c-format @@ -453,7 +453,7 @@ msgid "" " -y, --latency Determines the maximum latency on CPU frequency " "changes *\n" msgstr "" -" -l, --hwlimits Affiche les fréquences minimales et maximales du CPU " +" -l, --hwlimits Affiche les fréquences minimales et maximales du CPU " "*\n" #: utils/cpufreq-info.c:488 @@ -469,7 +469,7 @@ msgid "" " interface in 2.4. and early 2.6. kernels\n" msgstr "" " -o, --proc Affiche les informations en utilisant l'interface\n" -" fournie par /proc/cpufreq, présente dans les " +" fournie par /proc/cpufreq, présente dans les " "versions\n" " 2.4 et les anciennes versions 2.6 du noyau\n" @@ -485,7 +485,7 @@ msgstr "" #: utils/cpufreq-info.c:492 utils/cpuidle-info.c:152 #, c-format msgid " -h, --help Prints out this screen\n" -msgstr " -h, --help affiche l'aide-mémoire\n" +msgstr " -h, --help affiche l'aide-mémoire\n" #: utils/cpufreq-info.c:495 #, c-format @@ -493,8 +493,8 @@ msgid "" "If no argument or only the -c, --cpu parameter is given, debug output about\n" "cpufreq is printed which is useful e.g. for reporting bugs.\n" msgstr "" -"Par défaut, les informations de déboguage seront affichées si aucun\n" -"argument, ou bien si seulement l'argument -c (--cpu) est donné, afin de\n" +"Par défaut, les informations de déboguage seront affichées si aucun\n" +"argument, ou bien si seulement l'argument -c (--cpu) est donné, afin de\n" "faciliter les rapports de bogues par exemple\n" #: utils/cpufreq-info.c:497 @@ -517,8 +517,8 @@ msgid "" "You can't specify more than one --cpu parameter and/or\n" "more than one output-specific argument\n" msgstr "" -"On ne peut indiquer plus d'un paramètre --cpu, tout comme l'on ne peut\n" -"spécifier plus d'un argument de formatage\n" +"On ne peut indiquer plus d'un paramètre --cpu, tout comme l'on ne peut\n" +"spécifier plus d'un argument de formatage\n" #: utils/cpufreq-info.c:600 utils/cpufreq-set.c:82 utils/cpupower-set.c:42 #: utils/cpupower-info.c:42 utils/cpuidle-info.c:213 @@ -529,7 +529,7 @@ msgstr "option invalide\n" #: utils/cpufreq-info.c:617 #, c-format msgid "couldn't analyze CPU %d as it doesn't seem to be present\n" -msgstr "analyse du CPU %d impossible puisqu'il ne semble pas être présent\n" +msgstr "analyse du CPU %d impossible puisqu'il ne semble pas être présent\n" #: utils/cpufreq-info.c:620 utils/cpupower-info.c:142 #, c-format @@ -547,8 +547,8 @@ msgid "" " -d FREQ, --min FREQ new minimum CPU frequency the governor may " "select\n" msgstr "" -" -d FREQ, --min FREQ nouvelle fréquence minimale du CPU à utiliser\n" -" par le régulateur\n" +" -d FREQ, --min FREQ nouvelle fréquence minimale du CPU à utiliser\n" +" par le régulateur\n" #: utils/cpufreq-set.c:28 #, c-format @@ -556,13 +556,13 @@ msgid "" " -u FREQ, --max FREQ new maximum CPU frequency the governor may " "select\n" msgstr "" -" -u FREQ, --max FREQ nouvelle fréquence maximale du CPU à utiliser\n" -" par le régulateur\n" +" -u FREQ, --max FREQ nouvelle fréquence maximale du CPU à utiliser\n" +" par le régulateur\n" #: utils/cpufreq-set.c:29 #, c-format msgid " -g GOV, --governor GOV new cpufreq governor\n" -msgstr " -g GOV, --governor GOV active le régulateur GOV\n" +msgstr " -g GOV, --governor GOV active le régulateur GOV\n" #: utils/cpufreq-set.c:30 #, c-format @@ -570,9 +570,9 @@ msgid "" " -f FREQ, --freq FREQ specific frequency to be set. Requires userspace\n" " governor to be available and loaded\n" msgstr "" -" -f FREQ, --freq FREQ fixe la fréquence du processeur à FREQ. Il faut\n" -" que le régulateur « userspace » soit disponible \n" -" et activé.\n" +" -f FREQ, --freq FREQ fixe la fréquence du processeur à FREQ. Il faut\n" +" que le régulateur « userspace » soit disponible \n" +" et activé.\n" #: utils/cpufreq-set.c:32 #, c-format @@ -582,7 +582,7 @@ msgstr "" #: utils/cpufreq-set.c:33 utils/cpupower-set.c:28 utils/cpupower-info.c:27 #, fuzzy, c-format msgid " -h, --help Prints out this screen\n" -msgstr " -h, --help affiche l'aide-mémoire\n" +msgstr " -h, --help affiche l'aide-mémoire\n" #: utils/cpufreq-set.c:35 #, fuzzy, c-format @@ -602,11 +602,11 @@ msgid "" " (FREQuency in kHz =^ Hz * 0.001 =^ MHz * 1000 =^ GHz * 1000000).\n" msgstr "" "Remarque :\n" -"1. Le CPU numéro 0 sera utilisé par défaut si -c (ou --cpu) est omis ;\n" -"2. l'argument -f FREQ (ou --freq FREQ) ne peut être utilisé qu'avec --cpu ;\n" -"3. on pourra préciser l'unité des fréquences en postfixant sans aucune " +"1. Le CPU numéro 0 sera utilisé par défaut si -c (ou --cpu) est omis ;\n" +"2. l'argument -f FREQ (ou --freq FREQ) ne peut être utilisé qu'avec --cpu ;\n" +"3. on pourra préciser l'unité des fréquences en postfixant sans aucune " "espace\n" -" les valeurs par hz, kHz (par défaut), MHz, GHz ou THz\n" +" les valeurs par hz, kHz (par défaut), MHz, GHz ou THz\n" " (kHz =^ Hz * 0.001 =^ MHz * 1000 =^ GHz * 1000000).\n" #: utils/cpufreq-set.c:57 @@ -622,21 +622,21 @@ msgid "" "frequency\n" " or because the userspace governor isn't loaded?\n" msgstr "" -"En ajustant les nouveaux paramètres, une erreur est apparue. Les sources\n" +"En ajustant les nouveaux paramètres, une erreur est apparue. Les sources\n" "d'erreur typique sont :\n" -"- droit d'administration insuffisant (êtes-vous root ?) ;\n" -"- le régulateur choisi n'est pas disponible, ou bien n'est pas disponible " +"- droit d'administration insuffisant (êtes-vous root ?) ;\n" +"- le régulateur choisi n'est pas disponible, ou bien n'est pas disponible " "en\n" " tant que module noyau ;\n" "- la tactique n'est pas disponible ;\n" -"- vous voulez utiliser l'option -f/--freq, mais le régulateur « userspace »\n" -" n'est pas disponible, par exemple parce que le matériel ne le supporte\n" -" pas, ou bien n'est tout simplement pas chargé.\n" +"- vous voulez utiliser l'option -f/--freq, mais le régulateur « userspace »\n" +" n'est pas disponible, par exemple parce que le matériel ne le supporte\n" +" pas, ou bien n'est tout simplement pas chargé.\n" #: utils/cpufreq-set.c:170 #, c-format msgid "wrong, unknown or unhandled CPU?\n" -msgstr "CPU inconnu ou non supporté ?\n" +msgstr "CPU inconnu ou non supporté ?\n" #: utils/cpufreq-set.c:302 #, c-format @@ -653,7 +653,7 @@ msgid "" "At least one parameter out of -f/--freq, -d/--min, -u/--max, and\n" "-g/--governor must be passed\n" msgstr "" -"L'un de ces paramètres est obligatoire : -f/--freq, -d/--min, -u/--max et\n" +"L'un de ces paramètres est obligatoire : -f/--freq, -d/--min, -u/--max et\n" "-g/--governor\n" #: utils/cpufreq-set.c:347 @@ -810,7 +810,7 @@ msgstr "" #: utils/cpuidle-info.c:48 #, fuzzy, c-format msgid "Available idle states:" -msgstr " plage de fréquence : " +msgstr " plage de fréquence : " #: utils/cpuidle-info.c:71 #, c-format @@ -911,7 +911,7 @@ msgstr "Usage : cpufreq-info [options]\n" #: utils/cpuidle-info.c:149 #, fuzzy, c-format msgid " -s, --silent Only show general C-state information\n" -msgstr " -e, --debug Afficher les informations de déboguage\n" +msgstr " -e, --debug Afficher les informations de déboguage\n" #: utils/cpuidle-info.c:150 #, fuzzy, c-format @@ -921,7 +921,7 @@ msgid "" " interface in older kernels\n" msgstr "" " -o, --proc Affiche les informations en utilisant l'interface\n" -" fournie par /proc/cpufreq, présente dans les " +" fournie par /proc/cpufreq, présente dans les " "versions\n" " 2.4 et les anciennes versions 2.6 du noyau\n" @@ -929,19 +929,19 @@ msgstr "" #, fuzzy, c-format msgid "You can't specify more than one output-specific argument\n" msgstr "" -"On ne peut indiquer plus d'un paramètre --cpu, tout comme l'on ne peut\n" -"spécifier plus d'un argument de formatage\n" +"On ne peut indiquer plus d'un paramètre --cpu, tout comme l'on ne peut\n" +"spécifier plus d'un argument de formatage\n" #~ msgid "" #~ " -c CPU, --cpu CPU CPU number which information shall be determined " #~ "about\n" #~ msgstr "" -#~ " -c CPU, --cpu CPU Numéro du CPU pour lequel l'information sera " -#~ "affichée\n" +#~ " -c CPU, --cpu CPU Numéro du CPU pour lequel l'information sera " +#~ "affichée\n" #~ msgid "" #~ " -c CPU, --cpu CPU number of CPU where cpufreq settings shall be " #~ "modified\n" #~ msgstr "" -#~ " -c CPU, --cpu CPU numéro du CPU à prendre en compte pour les\n" +#~ " -c CPU, --cpu CPU numéro du CPU à prendre en compte pour les\n" #~ " changements\n" diff --git a/tools/power/cpupower/utils/cpufreq-info.c b/tools/power/cpupower/utils/cpufreq-info.c index df43cd45d810..c3f39d5128ee 100644 --- a/tools/power/cpupower/utils/cpufreq-info.c +++ b/tools/power/cpupower/utils/cpufreq-info.c @@ -170,6 +170,7 @@ static int get_boost_mode(unsigned int cpu) unsigned long pstates[MAX_HW_PSTATES] = {0,}; if (cpupower_cpu_info.vendor != X86_VENDOR_AMD && + cpupower_cpu_info.vendor != X86_VENDOR_HYGON && cpupower_cpu_info.vendor != X86_VENDOR_INTEL) return 0; @@ -190,8 +191,9 @@ static int get_boost_mode(unsigned int cpu) printf(_(" Supported: %s\n"), support ? _("yes") : _("no")); printf(_(" Active: %s\n"), active ? _("yes") : _("no")); - if (cpupower_cpu_info.vendor == X86_VENDOR_AMD && - cpupower_cpu_info.family >= 0x10) { + if ((cpupower_cpu_info.vendor == X86_VENDOR_AMD && + cpupower_cpu_info.family >= 0x10) || + cpupower_cpu_info.vendor == X86_VENDOR_HYGON) { ret = decode_pstates(cpu, cpupower_cpu_info.family, b_states, pstates, &pstate_no); if (ret) @@ -200,6 +202,8 @@ static int get_boost_mode(unsigned int cpu) printf(_(" Boost States: %d\n"), b_states); printf(_(" Total States: %d\n"), pstate_no); for (i = 0; i < pstate_no; i++) { + if (!pstates[i]) + continue; if (i < b_states) printf(_(" Pstate-Pb%d: %luMHz (boost state)" "\n"), i, pstates[i]); diff --git a/tools/power/cpupower/utils/helpers/amd.c b/tools/power/cpupower/utils/helpers/amd.c index bb41cdd0df6b..7c4f83a8c973 100644 --- a/tools/power/cpupower/utils/helpers/amd.c +++ b/tools/power/cpupower/utils/helpers/amd.c @@ -33,7 +33,7 @@ union msr_pstate { unsigned vid:8; unsigned iddval:8; unsigned idddiv:2; - unsigned res1:30; + unsigned res1:31; unsigned en:1; } fam17h_bits; unsigned long long val; @@ -45,7 +45,7 @@ static int get_did(int family, union msr_pstate pstate) if (family == 0x12) t = pstate.val & 0xf; - else if (family == 0x17) + else if (family == 0x17 || family == 0x18) t = pstate.fam17h_bits.did; else t = pstate.bits.did; @@ -59,7 +59,7 @@ static int get_cof(int family, union msr_pstate pstate) int fid, did, cof; did = get_did(family, pstate); - if (family == 0x17) { + if (family == 0x17 || family == 0x18) { fid = pstate.fam17h_bits.fid; cof = 200 * fid / did; } else { @@ -119,6 +119,11 @@ int decode_pstates(unsigned int cpu, unsigned int cpu_family, } if (read_msr(cpu, MSR_AMD_PSTATE + i, &pstate.val)) return -1; + if ((cpu_family == 0x17) && (!pstate.fam17h_bits.en)) + continue; + else if (!pstate.bits.en) + continue; + pstates[i] = get_cof(cpu_family, pstate); } *no = i; diff --git a/tools/power/cpupower/utils/helpers/cpuid.c b/tools/power/cpupower/utils/helpers/cpuid.c index 732b0b41ba26..5cc39d4e23ed 100644 --- a/tools/power/cpupower/utils/helpers/cpuid.c +++ b/tools/power/cpupower/utils/helpers/cpuid.c @@ -8,7 +8,7 @@ #include "helpers/helpers.h" static const char *cpu_vendor_table[X86_VENDOR_MAX] = { - "Unknown", "GenuineIntel", "AuthenticAMD", + "Unknown", "GenuineIntel", "AuthenticAMD", "HygonGenuine", }; #if defined(__i386__) || defined(__x86_64__) @@ -109,6 +109,7 @@ out: fclose(fp); /* Get some useful CPU capabilities from cpuid */ if (cpu_info->vendor != X86_VENDOR_AMD && + cpu_info->vendor != X86_VENDOR_HYGON && cpu_info->vendor != X86_VENDOR_INTEL) return ret; @@ -124,8 +125,9 @@ out: if (cpuid_level >= 6 && (cpuid_ecx(6) & 0x1)) cpu_info->caps |= CPUPOWER_CAP_APERF; - /* AMD Boost state enable/disable register */ - if (cpu_info->vendor == X86_VENDOR_AMD) { + /* AMD or Hygon Boost state enable/disable register */ + if (cpu_info->vendor == X86_VENDOR_AMD || + cpu_info->vendor == X86_VENDOR_HYGON) { if (ext_cpuid_level >= 0x80000007 && (cpuid_edx(0x80000007) & (1 << 9))) cpu_info->caps |= CPUPOWER_CAP_AMD_CBP; diff --git a/tools/power/cpupower/utils/helpers/helpers.h b/tools/power/cpupower/utils/helpers/helpers.h index 41da392be448..902139689315 100644 --- a/tools/power/cpupower/utils/helpers/helpers.h +++ b/tools/power/cpupower/utils/helpers/helpers.h @@ -61,7 +61,7 @@ extern int be_verbose; /* cpuid and cpuinfo helpers **************************/ enum cpupower_cpu_vendor {X86_VENDOR_UNKNOWN = 0, X86_VENDOR_INTEL, - X86_VENDOR_AMD, X86_VENDOR_MAX}; + X86_VENDOR_AMD, X86_VENDOR_HYGON, X86_VENDOR_MAX}; #define CPUPOWER_CAP_INV_TSC 0x00000001 #define CPUPOWER_CAP_APERF 0x00000002 diff --git a/tools/power/cpupower/utils/helpers/misc.c b/tools/power/cpupower/utils/helpers/misc.c index 80fdf55f414d..f406adc40bad 100644 --- a/tools/power/cpupower/utils/helpers/misc.c +++ b/tools/power/cpupower/utils/helpers/misc.c @@ -26,7 +26,7 @@ int cpufreq_has_boost_support(unsigned int cpu, int *support, int *active, * has Hardware determined variable increments instead. */ - if (cpu_info.family == 0x17) { + if (cpu_info.family == 0x17 || cpu_info.family == 0x18) { if (!read_msr(cpu, MSR_AMD_HWCR, &val)) { if (!(val & CPUPOWER_AMD_CPBDIS)) *active = 1; diff --git a/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c b/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c index d7c2a6d13dea..f2a7e9cfd577 100644 --- a/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c +++ b/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c @@ -241,7 +241,8 @@ static int init_maxfreq_mode(void) if (!(cpupower_cpu_info.caps & CPUPOWER_CAP_INV_TSC)) goto use_sysfs; - if (cpupower_cpu_info.vendor == X86_VENDOR_AMD) { + if (cpupower_cpu_info.vendor == X86_VENDOR_AMD || + cpupower_cpu_info.vendor == X86_VENDOR_HYGON) { /* MSR_AMD_HWCR tells us whether TSC runs at P0/mperf * freq. * A test whether hwcr is accessable/available would be: diff --git a/tools/power/pm-graph/Makefile b/tools/power/pm-graph/Makefile index c1899cd72c80..845541544570 100644 --- a/tools/power/pm-graph/Makefile +++ b/tools/power/pm-graph/Makefile @@ -23,8 +23,8 @@ install : uninstall install -m 644 config/suspend-x2-proc.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config install -d $(DESTDIR)$(PREFIX)/bin - ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/bootgraph.py $(DESTDIR)$(PREFIX)/bin/bootgraph - ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/sleepgraph.py $(DESTDIR)$(PREFIX)/bin/sleepgraph + ln -s ../lib/pm-graph/bootgraph.py $(DESTDIR)$(PREFIX)/bin/bootgraph + ln -s ../lib/pm-graph/sleepgraph.py $(DESTDIR)$(PREFIX)/bin/sleepgraph install -d $(DESTDIR)$(PREFIX)/share/man/man8 install bootgraph.8 $(DESTDIR)$(PREFIX)/share/man/man8 diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py index 8ee626c0f6a5..6dae57041537 100755 --- a/tools/power/pm-graph/bootgraph.py +++ b/tools/power/pm-graph/bootgraph.py @@ -34,6 +34,10 @@ from datetime import datetime, timedelta from subprocess import call, Popen, PIPE import sleepgraph as aslib +def pprint(msg): + print(msg) + sys.stdout.flush() + # ----------------- CLASSES -------------------- # Class: SystemValues @@ -157,11 +161,11 @@ class SystemValues(aslib.SystemValues): return cmdline def manualRebootRequired(self): cmdline = self.kernelParams() - print 'To generate a new timeline manually, follow these steps:\n' - print '1. Add the CMDLINE string to your kernel command line.' - print '2. Reboot the system.' - print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n' - print 'CMDLINE="%s"' % cmdline + pprint('To generate a new timeline manually, follow these steps:\n\n'\ + '1. Add the CMDLINE string to your kernel command line.\n'\ + '2. Reboot the system.\n'\ + '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n\n'\ + 'CMDLINE="%s"' % cmdline) sys.exit() def blGrub(self): blcmd = '' @@ -431,7 +435,7 @@ def parseTraceLog(data): if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0): continue if(not cg.postProcess()): - print('Sanity check failed for %s-%d' % (proc, pid)) + pprint('Sanity check failed for %s-%d' % (proc, pid)) continue # match cg data to devices devname = data.deviceMatch(pid, cg) @@ -442,8 +446,8 @@ def parseTraceLog(data): sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\ (kind, cg.name, proc, pid, cg.start, cg.end)) elif len(cg.list) > 1000000: - print 'WARNING: the callgraph found for %s is massive! (%d lines)' %\ - (devname, len(cg.list)) + pprint('WARNING: the callgraph found for %s is massive! (%d lines)' %\ + (devname, len(cg.list))) # Function: retrieveLogs # Description: @@ -528,7 +532,7 @@ def createBootGraph(data): tMax = data.end tTotal = tMax - t0 if(tTotal == 0): - print('ERROR: No timeline data') + pprint('ERROR: No timeline data') return False user_mode = '%.0f'%(data.tUserMode*1000) last_init = '%.0f'%(tTotal*1000) @@ -734,7 +738,7 @@ def updateCron(restore=False): op.close() res = call([cmd, cronfile]) except Exception, e: - print 'Exception: %s' % str(e) + pprint('Exception: %s' % str(e)) shutil.move(backfile, cronfile) res = -1 if res != 0: @@ -750,7 +754,7 @@ def updateGrub(restore=False): call(sysvals.blexec, stderr=PIPE, stdout=PIPE, env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'}) except Exception, e: - print 'Exception: %s\n' % str(e) + pprint('Exception: %s\n' % str(e)) return # extract the option and create a grub config without it sysvals.rootUser(True) @@ -797,7 +801,7 @@ def updateGrub(restore=False): res = call(sysvals.blexec) os.remove(grubfile) except Exception, e: - print 'Exception: %s' % str(e) + pprint('Exception: %s' % str(e)) res = -1 # cleanup shutil.move(tempfile, grubfile) @@ -821,7 +825,7 @@ def updateKernelParams(restore=False): def doError(msg, help=False): if help == True: printHelp() - print 'ERROR: %s\n' % msg + pprint('ERROR: %s\n' % msg) sysvals.outputResult({'error':msg}) sys.exit() @@ -829,52 +833,51 @@ def doError(msg, help=False): # Description: # print out the help text def printHelp(): - print('') - print('%s v%s' % (sysvals.title, sysvals.version)) - print('Usage: bootgraph <options> <command>') - print('') - print('Description:') - print(' This tool reads in a dmesg log of linux kernel boot and') - print(' creates an html representation of the boot timeline up to') - print(' the start of the init process.') - print('') - print(' If no specific command is given the tool reads the current dmesg') - print(' and/or ftrace log and creates a timeline') - print('') - print(' Generates output files in subdirectory: boot-yymmdd-HHMMSS') - print(' HTML output: <hostname>_boot.html') - print(' raw dmesg output: <hostname>_boot_dmesg.txt') - print(' raw ftrace output: <hostname>_boot_ftrace.txt') - print('') - print('Options:') - print(' -h Print this help text') - print(' -v Print the current tool version') - print(' -verbose Print extra information during execution and analysis') - print(' -addlogs Add the dmesg log to the html output') - print(' -result fn Export a results table to a text file for parsing.') - print(' -o name Overrides the output subdirectory name when running a new test') - print(' default: boot-{date}-{time}') - print(' [advanced]') - print(' -fstat Use ftrace to add function detail and statistics (default: disabled)') - print(' -f/-callgraph Add callgraph detail, can be very large (default: disabled)') - print(' -maxdepth N limit the callgraph data to N call levels (default: 2)') - print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') - print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])') - print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') - print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') - print(' -cgfilter S Filter the callgraph output in the timeline') - print(' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)') - print(' -bl name Use the following boot loader for kernel params (default: grub)') - print(' -reboot Reboot the machine automatically and generate a new timeline') - print(' -manual Show the steps to generate a new timeline manually (used with -reboot)') - print('') - print('Other commands:') - print(' -flistall Print all functions capable of being captured in ftrace') - print(' -sysinfo Print out system info extracted from BIOS') - print(' [redo]') - print(' -dmesg file Create HTML output using dmesg input (used with -ftrace)') - print(' -ftrace file Create HTML output using ftrace input (used with -dmesg)') - print('') + pprint('\n%s v%s\n'\ + 'Usage: bootgraph <options> <command>\n'\ + '\n'\ + 'Description:\n'\ + ' This tool reads in a dmesg log of linux kernel boot and\n'\ + ' creates an html representation of the boot timeline up to\n'\ + ' the start of the init process.\n'\ + '\n'\ + ' If no specific command is given the tool reads the current dmesg\n'\ + ' and/or ftrace log and creates a timeline\n'\ + '\n'\ + ' Generates output files in subdirectory: boot-yymmdd-HHMMSS\n'\ + ' HTML output: <hostname>_boot.html\n'\ + ' raw dmesg output: <hostname>_boot_dmesg.txt\n'\ + ' raw ftrace output: <hostname>_boot_ftrace.txt\n'\ + '\n'\ + 'Options:\n'\ + ' -h Print this help text\n'\ + ' -v Print the current tool version\n'\ + ' -verbose Print extra information during execution and analysis\n'\ + ' -addlogs Add the dmesg log to the html output\n'\ + ' -result fn Export a results table to a text file for parsing.\n'\ + ' -o name Overrides the output subdirectory name when running a new test\n'\ + ' default: boot-{date}-{time}\n'\ + ' [advanced]\n'\ + ' -fstat Use ftrace to add function detail and statistics (default: disabled)\n'\ + ' -f/-callgraph Add callgraph detail, can be very large (default: disabled)\n'\ + ' -maxdepth N limit the callgraph data to N call levels (default: 2)\n'\ + ' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\ + ' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])\n'\ + ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ + ' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)\n'\ + ' -cgfilter S Filter the callgraph output in the timeline\n'\ + ' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\ + ' -bl name Use the following boot loader for kernel params (default: grub)\n'\ + ' -reboot Reboot the machine automatically and generate a new timeline\n'\ + ' -manual Show the steps to generate a new timeline manually (used with -reboot)\n'\ + '\n'\ + 'Other commands:\n'\ + ' -flistall Print all functions capable of being captured in ftrace\n'\ + ' -sysinfo Print out system info extracted from BIOS\n'\ + ' [redo]\n'\ + ' -dmesg file Create HTML output using dmesg input (used with -ftrace)\n'\ + ' -ftrace file Create HTML output using ftrace input (used with -dmesg)\n'\ + '' % (sysvals.title, sysvals.version)) return True # ----------------- MAIN -------------------- @@ -895,7 +898,7 @@ if __name__ == '__main__': printHelp() sys.exit() elif(arg == '-v'): - print("Version %s" % sysvals.version) + pprint("Version %s" % sysvals.version) sys.exit() elif(arg == '-verbose'): sysvals.verbose = True @@ -1016,7 +1019,7 @@ if __name__ == '__main__': print f elif cmd == 'checkbl': sysvals.getBootLoader() - print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec) + pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) elif(cmd == 'sysinfo'): sysvals.printSystemInfo(True) sys.exit() diff --git a/tools/power/pm-graph/config/cgskip.txt b/tools/power/pm-graph/config/cgskip.txt index e48d588fbfb4..9ff88e7e2300 100644 --- a/tools/power/pm-graph/config/cgskip.txt +++ b/tools/power/pm-graph/config/cgskip.txt @@ -27,6 +27,7 @@ ktime_get # console calls printk dev_printk +__dev_printk console_unlock # memory handling diff --git a/tools/power/pm-graph/config/custom-timeline-functions.cfg b/tools/power/pm-graph/config/custom-timeline-functions.cfg index f8fcb06fd68b..4f80ad7d7275 100644 --- a/tools/power/pm-graph/config/custom-timeline-functions.cfg +++ b/tools/power/pm-graph/config/custom-timeline-functions.cfg @@ -105,7 +105,7 @@ override-dev-timeline-functions: true # example: [color=#CC00CC] # # arglist: A list of arguments from registers/stack addresses. See URL: -# https://www.kernel.org/doc/Documentation/trace/kprobetrace.rst +# https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt # # example: cpu=%di:s32 # @@ -170,7 +170,7 @@ pm_restore_console: # example: [color=#CC00CC] # # arglist: A list of arguments from registers/stack addresses. See URL: -# https://www.kernel.org/doc/Documentation/trace/kprobetrace.rst +# https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt # # example: port=+36(%di):s32 # diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index 070be2cf7f74..24a2e7d0ae63 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -65,9 +65,9 @@ During test, enable/disable runtime suspend for all devices. The test is delayed by 5 seconds to allow runtime suspend changes to occur. The settings are restored after the test is complete. .TP -\fB-display \fIon/off\fR -Turn the display on or off for the test using the xset command. This helps -maintain the consistecy of test data for better comparison. +\fB-display \fIon/off/standby/suspend\fR +Switch the display to the requested mode for the test using the xset command. +This helps maintain the consistency of test data for better comparison. .TP \fB-skiphtml\fR Run the test and capture the trace logs, but skip the timeline generation. @@ -183,6 +183,13 @@ Print out the contents of the ACPI Firmware Performance Data Table. \fB-battery\fR Print out battery status and current charge. .TP +\fB-xon/-xoff/-xstandby/-xsuspend\fR +Test xset by attempting to switch the display to the given mode. This +is the same command which will be issued by \fB-display \fImode\fR. +.TP +\fB-xstat\fR +Get the current DPMS display mode. +.TP \fB-sysinfo\fR Print out system info extracted from BIOS. Reads /dev/mem directly instead of going through dmidecode. .TP diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 0c760478f7d7..52618f3444d4 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -54,6 +54,7 @@ import os import string import re import platform +import signal from datetime import datetime import struct import ConfigParser @@ -61,6 +62,10 @@ import gzip from threading import Thread from subprocess import call, Popen, PIPE +def pprint(msg): + print(msg) + sys.stdout.flush() + # ----------------- CLASSES -------------------- # Class: SystemValues @@ -69,10 +74,10 @@ from subprocess import call, Popen, PIPE # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '5.1' + version = '5.2' ansi = False rs = 0 - display = 0 + display = '' gzip = False sync = False verbose = False @@ -99,6 +104,7 @@ class SystemValues: tpath = '/sys/kernel/debug/tracing/' fpdtpath = '/sys/firmware/acpi/tables/FPDT' epath = '/sys/kernel/debug/tracing/events/power/' + pmdpath = '/sys/power/pm_debug_messages' traceevents = [ 'suspend_resume', 'device_pm_callback_end', @@ -109,8 +115,10 @@ class SystemValues: mempath = '/dev/mem' powerfile = '/sys/power/state' mempowerfile = '/sys/power/mem_sleep' + diskpowerfile = '/sys/power/disk' suspendmode = 'mem' memmode = '' + diskmode = '' hostname = 'localhost' prefix = 'test' teststamp = '' @@ -137,16 +145,15 @@ class SystemValues: useprocmon = False notestrun = False cgdump = False + devdump = False mixedphaseheight = True devprops = dict() predelay = 0 postdelay = 0 - procexecfmt = 'ps - (?P<ps>.*)$' - devpropfmt = '# Device Properties: .*' - tracertypefmt = '# tracer: (?P<t>.*)' - firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$' + pmdebug = '' tracefuncs = { 'sys_sync': {}, + 'ksys_sync': {}, '__pm_notifier_call_chain': {}, 'pm_prepare_console': {}, 'pm_notifier_call_chain': {}, @@ -187,7 +194,6 @@ class SystemValues: dev_tracefuncs = { # general wait/delay/sleep 'msleep': { 'args_x86_64': {'time':'%di:s32'}, 'ub': 1 }, - 'schedule_timeout_uninterruptible': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 }, 'schedule_timeout': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 }, 'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'}, 'ub': 1 }, 'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'}, 'ub': 1 }, @@ -199,6 +205,9 @@ class SystemValues: # filesystem 'ext4_sync_fs': {}, # 80211 + 'ath10k_bmi_read_memory': { 'args_x86_64': {'length':'%cx:s32'} }, + 'ath10k_bmi_write_memory': { 'args_x86_64': {'length':'%cx:s32'} }, + 'ath10k_bmi_fast_download': { 'args_x86_64': {'length':'%cx:s32'} }, 'iwlagn_mac_start': {}, 'iwlagn_alloc_bcast_station': {}, 'iwl_trans_pcie_start_hw': {}, @@ -241,6 +250,7 @@ class SystemValues: timeformat = '%.3f' cmdline = '%s %s' % \ (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:])) + sudouser = '' def __init__(self): self.archargs = 'args_'+platform.machine() self.hostname = platform.node() @@ -256,27 +266,49 @@ class SystemValues: if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()): self.ansi = True self.testdir = datetime.now().strftime('suspend-%y%m%d-%H%M%S') + if os.getuid() == 0 and 'SUDO_USER' in os.environ and \ + os.environ['SUDO_USER']: + self.sudouser = os.environ['SUDO_USER'] def vprint(self, msg): self.logmsg += msg+'\n' - if(self.verbose): - print(msg) + if self.verbose or msg.startswith('WARNING:'): + pprint(msg) + def signalHandler(self, signum, frame): + if not self.result: + return + signame = self.signames[signum] if signum in self.signames else 'UNKNOWN' + msg = 'Signal %s caused a tool exit, line %d' % (signame, frame.f_lineno) + sysvals.outputResult({'error':msg}) + sys.exit(3) + def signalHandlerInit(self): + capture = ['BUS', 'SYS', 'XCPU', 'XFSZ', 'PWR', 'HUP', 'INT', 'QUIT', + 'ILL', 'ABRT', 'FPE', 'SEGV', 'TERM', 'TSTP'] + self.signames = dict() + for i in capture: + s = 'SIG'+i + try: + signum = getattr(signal, s) + signal.signal(signum, self.signalHandler) + except: + continue + self.signames[signum] = s def rootCheck(self, fatal=True): if(os.access(self.powerfile, os.W_OK)): return True if fatal: msg = 'This command requires sysfs mount and root access' - print('ERROR: %s\n') % msg + pprint('ERROR: %s\n' % msg) self.outputResult({'error':msg}) - sys.exit() + sys.exit(1) return False def rootUser(self, fatal=False): if 'USER' in os.environ and os.environ['USER'] == 'root': return True if fatal: msg = 'This command must be run as root' - print('ERROR: %s\n') % msg + pprint('ERROR: %s\n' % msg) self.outputResult({'error':msg}) - sys.exit() + sys.exit(1) return False def getExec(self, cmd): dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin', @@ -406,8 +438,8 @@ class SystemValues: ktime = m.group('ktime') fp.close() self.dmesgstart = float(ktime) - def getdmesg(self, fwdata=[]): - op = self.writeDatafileHeader(sysvals.dmesgfile, fwdata) + def getdmesg(self, testdata): + op = self.writeDatafileHeader(sysvals.dmesgfile, testdata) # store all new dmesg lines since initdmesg was called fp = Popen('dmesg', stdout=PIPE).stdout for line in fp: @@ -535,7 +567,7 @@ class SystemValues: if len(self.kprobes) < 1: return if output: - print(' kprobe functions in this kernel:') + pprint(' kprobe functions in this kernel:') # first test each kprobe rejects = [] # sort kprobes: trace, ub-dev, custom, dev @@ -557,7 +589,7 @@ class SystemValues: else: kpl[2].append(name) if output: - print(' %s: %s' % (name, res)) + pprint(' %s: %s' % (name, res)) kplist = kpl[0] + kpl[1] + kpl[2] + kpl[3] # remove all failed ones from the list for name in rejects: @@ -571,7 +603,7 @@ class SystemValues: if output: check = self.fgetVal('kprobe_events') linesack = (len(check.split('\n')) - 1) / 2 - print(' kprobe functions enabled: %d/%d' % (linesack, linesout)) + pprint(' kprobe functions enabled: %d/%d' % (linesack, linesout)) self.fsetVal('1', 'events/kprobes/enable') def testKprobe(self, kname, kprobe): self.fsetVal('0', 'events/kprobes/enable') @@ -619,6 +651,8 @@ class SystemValues: self.fsetVal('0', 'events/kprobes/enable') self.fsetVal('', 'kprobe_events') self.fsetVal('1024', 'buffer_size_kb') + if self.pmdebug: + self.setVal(self.pmdebug, self.pmdpath) def setupAllKprobes(self): for name in self.tracefuncs: self.defaultKprobe(name, self.tracefuncs[name]) @@ -637,10 +671,15 @@ class SystemValues: return False def initFtrace(self): self.printSystemInfo(False) - print('INITIALIZING FTRACE...') + pprint('INITIALIZING FTRACE...') # turn trace off self.fsetVal('0', 'tracing_on') self.cleanupFtrace() + # pm debug messages + pv = self.getVal(self.pmdpath) + if pv != '1': + self.setVal('1', self.pmdpath) + self.pmdebug = pv # set the trace clock to global self.fsetVal('global', 'trace_clock') self.fsetVal('nop', 'current_tracer') @@ -649,7 +688,8 @@ class SystemValues: if self.bufsize > 0: tgtsize = self.bufsize elif self.usecallgraph or self.usedevsrc: - tgtsize = min(self.memfree, 3*1024*1024) + bmax = (1*1024*1024) if self.suspendmode == 'disk' else (3*1024*1024) + tgtsize = min(self.memfree, bmax) else: tgtsize = 65536 while not self.fsetVal('%d' % (tgtsize / cpus), 'buffer_size_kb'): @@ -658,7 +698,7 @@ class SystemValues: if tgtsize < 65536: tgtsize = int(self.fgetVal('buffer_size_kb')) * cpus break - print 'Setting trace buffers to %d kB (%d kB per cpu)' % (tgtsize, tgtsize/cpus) + pprint('Setting trace buffers to %d kB (%d kB per cpu)' % (tgtsize, tgtsize/cpus)) # initialize the callgraph trace if(self.usecallgraph): # set trace type @@ -691,7 +731,7 @@ class SystemValues: if self.usedevsrc: for name in self.dev_tracefuncs: self.defaultKprobe(name, self.dev_tracefuncs[name]) - print('INITIALIZING KPROBES...') + pprint('INITIALIZING KPROBES...') self.addKprobes(self.verbose) if(self.usetraceevents): # turn trace events on @@ -728,19 +768,24 @@ class SystemValues: if not self.ansi: return str return '\x1B[%d;40m%s\x1B[m' % (color, str) - def writeDatafileHeader(self, filename, fwdata=[]): + def writeDatafileHeader(self, filename, testdata): fp = self.openlog(filename, 'w') fp.write('%s\n%s\n# command | %s\n' % (self.teststamp, self.sysstamp, self.cmdline)) - if(self.suspendmode == 'mem' or self.suspendmode == 'command'): - for fw in fwdata: + for test in testdata: + if 'fw' in test: + fw = test['fw'] if(fw): fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) + if 'bat' in test: + (a1, c1), (a2, c2) = test['bat'] + fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) + if test['error'] or len(testdata) > 1: + fp.write('# enter_sleep_error %s\n' % test['error']) return fp - def sudouser(self, dir): - if os.path.exists(dir) and os.getuid() == 0 and \ - 'SUDO_USER' in os.environ: + def sudoUserchown(self, dir): + if os.path.exists(dir) and self.sudouser: cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1' - call(cmd.format(os.environ['SUDO_USER'], dir), shell=True) + call(cmd.format(self.sudouser, dir), shell=True) def outputResult(self, testdata, num=0): if not self.result: return @@ -762,7 +807,7 @@ class SystemValues: if 'bugurl' in testdata: fp.write('url%s: %s\n' % (n, testdata['bugurl'])) fp.close() - self.sudouser(self.result) + self.sudoUserchown(self.result) def configFile(self, file): dir = os.path.dirname(os.path.realpath(__file__)) if os.path.exists(file): @@ -800,15 +845,16 @@ suspendmodename = { # Simple class which holds property values collected # for all the devices used in the timeline. class DevProps: - syspath = '' - altname = '' - async = True - xtraclass = '' - xtrainfo = '' + def __init__(self): + self.syspath = '' + self.altname = '' + self.async = True + self.xtraclass = '' + self.xtrainfo = '' def out(self, dev): return '%s,%s,%d;' % (dev, self.altname, self.async) def debug(self, dev): - print '%s:\n\taltname = %s\n\t async = %s' % (dev, self.altname, self.async) + pprint('%s:\n\taltname = %s\n\t async = %s' % (dev, self.altname, self.async)) def altName(self, dev): if not self.altname or self.altname == dev: return dev @@ -831,9 +877,6 @@ class DevProps: # A container used to create a device hierachy, with a single root node # and a tree of child nodes. Used by Data.deviceTopology() class DeviceNode: - name = '' - children = 0 - depth = 0 def __init__(self, nodename, nodedepth): self.name = nodename self.children = [] @@ -861,71 +904,78 @@ class DeviceNode: # } # class Data: - dmesg = {} # root data structure - phases = [] # ordered list of phases - start = 0.0 # test start - end = 0.0 # test end - tSuspended = 0.0 # low-level suspend start - tResumed = 0.0 # low-level resume start - tKernSus = 0.0 # kernel level suspend start - tKernRes = 0.0 # kernel level resume end - tLow = 0.0 # time spent in low-level suspend (standby/freeze) - fwValid = False # is firmware data available - fwSuspend = 0 # time spent in firmware suspend - fwResume = 0 # time spent in firmware resume - dmesgtext = [] # dmesg text file in memory - pstl = 0 # process timeline - testnumber = 0 - idstr = '' - html_device_id = 0 - stamp = 0 - outfile = '' - devpids = [] - kerror = False + phasedef = { + 'suspend_prepare': {'order': 0, 'color': '#CCFFCC'}, + 'suspend': {'order': 1, 'color': '#88FF88'}, + 'suspend_late': {'order': 2, 'color': '#00AA00'}, + 'suspend_noirq': {'order': 3, 'color': '#008888'}, + 'suspend_machine': {'order': 4, 'color': '#0000FF'}, + 'resume_machine': {'order': 5, 'color': '#FF0000'}, + 'resume_noirq': {'order': 6, 'color': '#FF9900'}, + 'resume_early': {'order': 7, 'color': '#FFCC00'}, + 'resume': {'order': 8, 'color': '#FFFF88'}, + 'resume_complete': {'order': 9, 'color': '#FFFFCC'}, + } + errlist = { + 'HWERROR' : '.*\[ *Hardware Error *\].*', + 'FWBUG' : '.*\[ *Firmware Bug *\].*', + 'BUG' : '.*BUG.*', + 'ERROR' : '.*ERROR.*', + 'WARNING' : '.*WARNING.*', + 'IRQ' : '.*genirq: .*', + 'TASKFAIL': '.*Freezing of tasks failed.*', + } def __init__(self, num): idchar = 'abcdefghij' - self.pstl = dict() + self.start = 0.0 # test start + self.end = 0.0 # test end + self.tSuspended = 0.0 # low-level suspend start + self.tResumed = 0.0 # low-level resume start + self.tKernSus = 0.0 # kernel level suspend start + self.tKernRes = 0.0 # kernel level resume end + self.fwValid = False # is firmware data available + self.fwSuspend = 0 # time spent in firmware suspend + self.fwResume = 0 # time spent in firmware resume + self.html_device_id = 0 + self.stamp = 0 + self.outfile = '' + self.kerror = False + self.battery = 0 + self.enterfail = '' + self.currphase = '' + self.pstl = dict() # process timeline self.testnumber = num self.idstr = idchar[num] - self.dmesgtext = [] - self.phases = [] - self.dmesg = { # fixed list of 10 phases - 'suspend_prepare': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#CCFFCC', 'order': 0}, - 'suspend': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#88FF88', 'order': 1}, - 'suspend_late': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#00AA00', 'order': 2}, - 'suspend_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#008888', 'order': 3}, - 'suspend_machine': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#0000FF', 'order': 4}, - 'resume_machine': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#FF0000', 'order': 5}, - 'resume_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#FF9900', 'order': 6}, - 'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#FFCC00', 'order': 7}, - 'resume': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#FFFF88', 'order': 8}, - 'resume_complete': {'list': dict(), 'start': -1.0, 'end': -1.0, - 'row': 0, 'color': '#FFFFCC', 'order': 9} - } - self.phases = self.sortedPhases() + self.dmesgtext = [] # dmesg text file in memory + self.dmesg = dict() # root data structure + self.errorinfo = {'suspend':[],'resume':[]} + self.tLow = [] # time spent in low-level suspends (standby/freeze) + self.devpids = [] + self.devicegroups = 0 + def sortedPhases(self): + return sorted(self.dmesg, key=lambda k:self.dmesg[k]['order']) + def initDevicegroups(self): + # called when phases are all finished being added + for phase in self.dmesg.keys(): + if '*' in phase: + p = phase.split('*') + pnew = '%s%d' % (p[0], len(p)) + self.dmesg[pnew] = self.dmesg.pop(phase) self.devicegroups = [] - for phase in self.phases: + for phase in self.sortedPhases(): self.devicegroups.append([phase]) - self.errorinfo = {'suspend':[],'resume':[]} + def nextPhase(self, phase, offset): + order = self.dmesg[phase]['order'] + offset + for p in self.dmesg: + if self.dmesg[p]['order'] == order: + return p + return '' + def lastPhase(self): + plist = self.sortedPhases() + if len(plist) < 1: + return '' + return plist[-1] def extractErrorInfo(self): - elist = { - 'HWERROR' : '.*\[ *Hardware Error *\].*', - 'FWBUG' : '.*\[ *Firmware Bug *\].*', - 'BUG' : '.*BUG.*', - 'ERROR' : '.*ERROR.*', - 'WARNING' : '.*WARNING.*', - 'IRQ' : '.*genirq: .*', - 'TASKFAIL': '.*Freezing of tasks failed.*', - } lf = sysvals.openlog(sysvals.dmesgfile, 'r') i = 0 list = [] @@ -939,8 +989,8 @@ class Data: continue dir = 'suspend' if t < self.tSuspended else 'resume' msg = m.group('msg') - for err in elist: - if re.match(elist[err], msg): + for err in self.errlist: + if re.match(self.errlist[err], msg): list.append((err, dir, t, i, i)) self.kerror = True break @@ -956,7 +1006,7 @@ class Data: def setEnd(self, time): self.end = time def isTraceEventOutsideDeviceCalls(self, pid, time): - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] for dev in list: d = list[dev] @@ -964,16 +1014,10 @@ class Data: time < d['end']): return False return True - def phaseCollision(self, phase, isbegin, line): - key = 'end' - if isbegin: - key = 'start' - if self.dmesg[phase][key] >= 0: - sysvals.vprint('IGNORE: %s' % line.strip()) - return True - return False def sourcePhase(self, start): - for phase in self.phases: + for phase in self.sortedPhases(): + if 'machine' in phase: + continue pend = self.dmesg[phase]['end'] if start <= pend: return phase @@ -1004,14 +1048,15 @@ class Data: return tgtdev def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata): # try to place the call in a device - tgtdev = self.sourceDevice(self.phases, start, end, pid, 'device') + phases = self.sortedPhases() + tgtdev = self.sourceDevice(phases, start, end, pid, 'device') # calls with device pids that occur outside device bounds are dropped # TODO: include these somehow if not tgtdev and pid in self.devpids: return False # try to place the call in a thread if not tgtdev: - tgtdev = self.sourceDevice(self.phases, start, end, pid, 'thread') + tgtdev = self.sourceDevice(phases, start, end, pid, 'thread') # create new thread blocks, expand as new calls are found if not tgtdev: if proc == '<...>': @@ -1053,7 +1098,7 @@ class Data: def overflowDevices(self): # get a list of devices that extend beyond the end of this test run devlist = [] - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] for devname in list: dev = list[devname] @@ -1064,7 +1109,7 @@ class Data: # merge any devices that overlap devlist for dev in devlist: devname = dev['name'] - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] if devname not in list: continue @@ -1079,7 +1124,7 @@ class Data: del list[devname] def usurpTouchingThread(self, name, dev): # the caller test has priority of this thread, give it to him - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] if name in list: tdev = list[name] @@ -1093,7 +1138,7 @@ class Data: break def stitchTouchingThreads(self, testlist): # merge any threads between tests that touch - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] for devname in list: dev = list[devname] @@ -1103,7 +1148,7 @@ class Data: data.usurpTouchingThread(devname, dev) def optimizeDevSrc(self): # merge any src call loops to reduce timeline size - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] for dev in list: if 'src' not in list[dev]: @@ -1141,7 +1186,7 @@ class Data: self.tKernSus = self.trimTimeVal(self.tKernSus, t0, dT, left) self.tKernRes = self.trimTimeVal(self.tKernRes, t0, dT, left) self.end = self.trimTimeVal(self.end, t0, dT, left) - for phase in self.phases: + for phase in self.sortedPhases(): p = self.dmesg[phase] p['start'] = self.trimTimeVal(p['start'], t0, dT, left) p['end'] = self.trimTimeVal(p['end'], t0, dT, left) @@ -1150,6 +1195,7 @@ class Data: d = list[name] d['start'] = self.trimTimeVal(d['start'], t0, dT, left) d['end'] = self.trimTimeVal(d['end'], t0, dT, left) + d['length'] = d['end'] - d['start'] if('ftrace' in d): cg = d['ftrace'] cg.start = self.trimTimeVal(cg.start, t0, dT, left) @@ -1166,30 +1212,51 @@ class Data: tm = self.trimTimeVal(tm, t0, dT, left) list.append((type, tm, idx1, idx2)) self.errorinfo[dir] = list - def normalizeTime(self, tZero): + def trimFreezeTime(self, tZero): # trim out any standby or freeze clock time - if(self.tSuspended != self.tResumed): - if(self.tResumed > tZero): - self.trimTime(self.tSuspended, \ - self.tResumed-self.tSuspended, True) - else: - self.trimTime(self.tSuspended, \ - self.tResumed-self.tSuspended, False) + lp = '' + for phase in self.sortedPhases(): + if 'resume_machine' in phase and 'suspend_machine' in lp: + tS, tR = self.dmesg[lp]['end'], self.dmesg[phase]['start'] + tL = tR - tS + if tL > 0: + left = True if tR > tZero else False + self.trimTime(tS, tL, left) + self.tLow.append('%.0f'%(tL*1000)) + lp = phase def getTimeValues(self): - sktime = (self.dmesg['suspend_machine']['end'] - \ - self.tKernSus) * 1000 - rktime = (self.dmesg['resume_complete']['end'] - \ - self.dmesg['resume_machine']['start']) * 1000 + sktime = (self.tSuspended - self.tKernSus) * 1000 + rktime = (self.tKernRes - self.tResumed) * 1000 return (sktime, rktime) - def setPhase(self, phase, ktime, isbegin): + def setPhase(self, phase, ktime, isbegin, order=-1): if(isbegin): + # phase start over current phase + if self.currphase: + if 'resume_machine' not in self.currphase: + sysvals.vprint('WARNING: phase %s failed to end' % self.currphase) + self.dmesg[self.currphase]['end'] = ktime + phases = self.dmesg.keys() + color = self.phasedef[phase]['color'] + count = len(phases) if order < 0 else order + # create unique name for every new phase + while phase in phases: + phase += '*' + self.dmesg[phase] = {'list': dict(), 'start': -1.0, 'end': -1.0, + 'row': 0, 'color': color, 'order': count} self.dmesg[phase]['start'] = ktime + self.currphase = phase else: + # phase end without a start + if phase not in self.currphase: + if self.currphase: + sysvals.vprint('WARNING: %s ended instead of %s, ftrace corruption?' % (phase, self.currphase)) + else: + sysvals.vprint('WARNING: %s ended without a start, ftrace corruption?' % phase) + return phase + phase = self.currphase self.dmesg[phase]['end'] = ktime - def dmesgSortVal(self, phase): - return self.dmesg[phase]['order'] - def sortedPhases(self): - return sorted(self.dmesg, key=self.dmesgSortVal) + self.currphase = '' + return phase def sortedDevices(self, phase): list = self.dmesg[phase]['list'] slist = [] @@ -1208,13 +1275,13 @@ class Data: for devname in phaselist: dev = phaselist[devname] if(dev['end'] < 0): - for p in self.phases: + for p in self.sortedPhases(): if self.dmesg[p]['end'] > dev['start']: dev['end'] = self.dmesg[p]['end'] break sysvals.vprint('%s (%s): callback didnt return' % (devname, phase)) def deviceFilter(self, devicefilter): - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] rmlist = [] for name in list: @@ -1229,7 +1296,7 @@ class Data: del list[name] def fixupInitcallsThatDidntReturn(self): # if any calls never returned, clip them at system resume end - for phase in self.phases: + for phase in self.sortedPhases(): self.fixupInitcalls(phase) def phaseOverlap(self, phases): rmgroups = [] @@ -1248,17 +1315,18 @@ class Data: self.devicegroups.append(newgroup) def newActionGlobal(self, name, start, end, pid=-1, color=''): # which phase is this device callback or action in + phases = self.sortedPhases() targetphase = 'none' htmlclass = '' overlap = 0.0 - phases = [] - for phase in self.phases: + myphases = [] + for phase in phases: pstart = self.dmesg[phase]['start'] pend = self.dmesg[phase]['end'] # see if the action overlaps this phase o = max(0, min(end, pend) - max(start, pstart)) if o > 0: - phases.append(phase) + myphases.append(phase) # set the target phase to the one that overlaps most if o > overlap: if overlap > 0 and phase == 'post_resume': @@ -1267,19 +1335,19 @@ class Data: overlap = o # if no target phase was found, pin it to the edge if targetphase == 'none': - p0start = self.dmesg[self.phases[0]]['start'] + p0start = self.dmesg[phases[0]]['start'] if start <= p0start: - targetphase = self.phases[0] + targetphase = phases[0] else: - targetphase = self.phases[-1] + targetphase = phases[-1] if pid == -2: htmlclass = ' bg' elif pid == -3: htmlclass = ' ps' - if len(phases) > 1: + if len(myphases) > 1: htmlclass = ' bg' - self.phaseOverlap(phases) - if targetphase in self.phases: + self.phaseOverlap(myphases) + if targetphase in phases: newname = self.newAction(targetphase, name, pid, '', start, end, '', htmlclass, color) return (targetphase, newname) return False @@ -1311,19 +1379,43 @@ class Data: if(list[child]['par'] == devname): devlist.append(child) return devlist + def maxDeviceNameSize(self, phase): + size = 0 + for name in self.dmesg[phase]['list']: + if len(name) > size: + size = len(name) + return size def printDetails(self): sysvals.vprint('Timeline Details:') sysvals.vprint(' test start: %f' % self.start) sysvals.vprint('kernel suspend start: %f' % self.tKernSus) - for phase in self.phases: - dc = len(self.dmesg[phase]['list']) - sysvals.vprint(' %16s: %f - %f (%d devices)' % (phase, \ - self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc)) + tS = tR = False + for phase in self.sortedPhases(): + devlist = self.dmesg[phase]['list'] + dc, ps, pe = len(devlist), self.dmesg[phase]['start'], self.dmesg[phase]['end'] + if not tS and ps >= self.tSuspended: + sysvals.vprint(' machine suspended: %f' % self.tSuspended) + tS = True + if not tR and ps >= self.tResumed: + sysvals.vprint(' machine resumed: %f' % self.tResumed) + tR = True + sysvals.vprint('%20s: %f - %f (%d devices)' % (phase, ps, pe, dc)) + if sysvals.devdump: + sysvals.vprint(''.join('-' for i in range(80))) + maxname = '%d' % self.maxDeviceNameSize(phase) + fmt = '%3d) %'+maxname+'s - %f - %f' + c = 1 + for name in devlist: + s = devlist[name]['start'] + e = devlist[name]['end'] + sysvals.vprint(fmt % (c, name, s, e)) + c += 1 + sysvals.vprint(''.join('-' for i in range(80))) sysvals.vprint(' kernel resume end: %f' % self.tKernRes) sysvals.vprint(' test end: %f' % self.end) def deviceChildrenAllPhases(self, devname): devlist = [] - for phase in self.phases: + for phase in self.sortedPhases(): list = self.deviceChildren(devname, phase) for dev in list: if dev not in devlist: @@ -1344,7 +1436,7 @@ class Data: if node.name: info = '' drv = '' - for phase in self.phases: + for phase in self.sortedPhases(): list = self.dmesg[phase]['list'] if node.name in list: s = list[node.name]['start'] @@ -1478,8 +1570,29 @@ class Data: c = self.addProcessUsageEvent(ps, tres) if c > 0: sysvals.vprint('%25s (res): %d' % (ps, c)) + def handleEndMarker(self, time): + dm = self.dmesg + self.setEnd(time) + self.initDevicegroups() + # give suspend_prepare an end if needed + if 'suspend_prepare' in dm and dm['suspend_prepare']['end'] < 0: + dm['suspend_prepare']['end'] = time + # assume resume machine ends at next phase start + if 'resume_machine' in dm and dm['resume_machine']['end'] < 0: + np = self.nextPhase('resume_machine', 1) + if np: + dm['resume_machine']['end'] = dm[np]['start'] + # if kernel resume end not found, assume its the end marker + if self.tKernRes == 0.0: + self.tKernRes = time + # if kernel suspend start not found, assume its the end marker + if self.tKernSus == 0.0: + self.tKernSus = time + # set resume complete to end at end marker + if 'resume_complete' in dm: + dm['resume_complete']['end'] = time def debugPrint(self): - for p in self.phases: + for p in self.sortedPhases(): list = self.dmesg[p]['list'] for devname in list: dev = list[devname] @@ -1490,9 +1603,9 @@ class Data: # Description: # A container for kprobe function data we want in the dev timeline class DevFunction: - row = 0 - count = 1 def __init__(self, name, args, caller, ret, start, end, u, proc, pid, color): + self.row = 0 + self.count = 1 self.name = name self.args = args self.caller = caller @@ -1546,16 +1659,15 @@ class DevFunction: # suspend_resume: phase or custom exec block data # device_pm_callback: device callback info class FTraceLine: - time = 0.0 - length = 0.0 - fcall = False - freturn = False - fevent = False - fkprobe = False - depth = 0 - name = '' - type = '' def __init__(self, t, m='', d=''): + self.length = 0.0 + self.fcall = False + self.freturn = False + self.fevent = False + self.fkprobe = False + self.depth = 0 + self.name = '' + self.type = '' self.time = float(t) if not m and not d: return @@ -1633,13 +1745,13 @@ class FTraceLine: return len(str)/2 def debugPrint(self, info=''): if self.isLeaf(): - print(' -- %12.6f (depth=%02d): %s(); (%.3f us) %s' % (self.time, \ + pprint(' -- %12.6f (depth=%02d): %s(); (%.3f us) %s' % (self.time, \ self.depth, self.name, self.length*1000000, info)) elif self.freturn: - print(' -- %12.6f (depth=%02d): %s} (%.3f us) %s' % (self.time, \ + pprint(' -- %12.6f (depth=%02d): %s} (%.3f us) %s' % (self.time, \ self.depth, self.name, self.length*1000000, info)) else: - print(' -- %12.6f (depth=%02d): %s() { (%.3f us) %s' % (self.time, \ + pprint(' -- %12.6f (depth=%02d): %s() { (%.3f us) %s' % (self.time, \ self.depth, self.name, self.length*1000000, info)) def startMarker(self): # Is this the starting line of a suspend? @@ -1675,19 +1787,13 @@ class FTraceLine: # Each instance is tied to a single device in a single phase, and is # comprised of an ordered list of FTraceLine objects class FTraceCallGraph: - id = '' - start = -1.0 - end = -1.0 - list = [] - invalid = False - depth = 0 - pid = 0 - name = '' - partial = False vfname = 'missing_function_name' - ignore = False - sv = 0 def __init__(self, pid, sv): + self.id = '' + self.invalid = False + self.name = '' + self.partial = False + self.ignore = False self.start = -1.0 self.end = -1.0 self.list = [] @@ -1786,7 +1892,7 @@ class FTraceCallGraph: if warning and ('[make leaf]', line) not in info: info.append(('', line)) if warning: - print 'WARNING: ftrace data missing, corrections made:' + pprint('WARNING: ftrace data missing, corrections made:') for i in info: t, obj = i if obj: @@ -1846,10 +1952,10 @@ class FTraceCallGraph: id = 'task %s' % (self.pid) window = '(%f - %f)' % (self.start, line.time) if(self.depth < 0): - print('Data misalignment for '+id+\ + pprint('Data misalignment for '+id+\ ' (buffer overflow), ignoring this callback') else: - print('Too much data for '+id+\ + pprint('Too much data for '+id+\ ' '+window+', ignoring this callback') def slice(self, dev): minicg = FTraceCallGraph(dev['pid'], self.sv) @@ -1902,7 +2008,7 @@ class FTraceCallGraph: elif l.isReturn(): if(l.depth not in stack): if self.sv.verbose: - print 'Post Process Error: Depth missing' + pprint('Post Process Error: Depth missing') l.debugPrint() return False # calculate call length from call/return lines @@ -1919,7 +2025,7 @@ class FTraceCallGraph: return True elif(cnt < 0): if self.sv.verbose: - print 'Post Process Error: Depth is less than 0' + pprint('Post Process Error: Depth is less than 0') return False # trace ended before call tree finished return self.repair(cnt) @@ -1943,7 +2049,7 @@ class FTraceCallGraph: dev['ftrace'] = cg found = devname return found - for p in data.phases: + for p in data.sortedPhases(): if(data.dmesg[p]['start'] <= self.start and self.start <= data.dmesg[p]['end']): list = data.dmesg[p]['list'] @@ -1966,7 +2072,7 @@ class FTraceCallGraph: if fs < data.start or fe > data.end: return phase = '' - for p in data.phases: + for p in data.sortedPhases(): if(data.dmesg[p]['start'] <= self.start and self.start < data.dmesg[p]['end']): phase = p @@ -1978,20 +2084,20 @@ class FTraceCallGraph: phase, myname = out data.dmesg[phase]['list'][myname]['ftrace'] = self def debugPrint(self, info=''): - print('%s pid=%d [%f - %f] %.3f us') % \ + pprint('%s pid=%d [%f - %f] %.3f us' % \ (self.name, self.pid, self.start, self.end, - (self.end - self.start)*1000000) + (self.end - self.start)*1000000)) for l in self.list: if l.isLeaf(): - print('%f (%02d): %s(); (%.3f us)%s' % (l.time, \ + pprint('%f (%02d): %s(); (%.3f us)%s' % (l.time, \ l.depth, l.name, l.length*1000000, info)) elif l.freturn: - print('%f (%02d): %s} (%.3f us)%s' % (l.time, \ + pprint('%f (%02d): %s} (%.3f us)%s' % (l.time, \ l.depth, l.name, l.length*1000000, info)) else: - print('%f (%02d): %s() { (%.3f us)%s' % (l.time, \ + pprint('%f (%02d): %s() { (%.3f us)%s' % (l.time, \ l.depth, l.name, l.length*1000000, info)) - print(' ') + pprint(' ') class DevItem: def __init__(self, test, phase, dev): @@ -2008,23 +2114,20 @@ class DevItem: # A container for a device timeline which calculates # all the html properties to display it correctly class Timeline: - html = '' - height = 0 # total timeline height - scaleH = 20 # timescale (top) row height - rowH = 30 # device row height - bodyH = 0 # body height - rows = 0 # total timeline rows - rowlines = dict() - rowheight = dict() html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n' html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n' html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background:{4}">{5}</div>\n' html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n' html_legend = '<div id="p{3}" class="square" style="left:{0}%;background:{1}"> {2}</div>\n' def __init__(self, rowheight, scaleheight): - self.rowH = rowheight - self.scaleH = scaleheight self.html = '' + self.height = 0 # total timeline height + self.scaleH = scaleheight # timescale (top) row height + self.rowH = rowheight # device row height + self.bodyH = 0 # body height + self.rows = 0 # total timeline rows + self.rowlines = dict() + self.rowheight = dict() def createHeader(self, sv, stamp): if(not stamp['time']): return @@ -2251,18 +2354,18 @@ class Timeline: # Description: # A list of values describing the properties of these test runs class TestProps: - stamp = '' - sysinfo = '' - cmdline = '' - kparams = '' - S0i3 = False - fwdata = [] stampfmt = '# [a-z]*-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\ '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' + batteryfmt = '^# battery (?P<a1>\w*) (?P<c1>\d*) (?P<a2>\w*) (?P<c2>\d*)' + testerrfmt = '^# enter_sleep_error (?P<e>.*)' sysinfofmt = '^# sysinfo .*' cmdlinefmt = '^# command \| (?P<cmd>.*)' kparamsfmt = '^# kparams \| (?P<kp>.*)' + devpropfmt = '# Device Properties: .*' + tracertypefmt = '# tracer: (?P<t>.*)' + firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$' + procexecfmt = 'ps - (?P<ps>.*)$' ftrace_line_fmt_fg = \ '^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\ ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\ @@ -2271,11 +2374,17 @@ class TestProps: ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\[(?P<cpu>[0-9]*)\] *'+\ '(?P<flags>.{4}) *(?P<time>[0-9\.]*): *'+\ '(?P<msg>.*)' - ftrace_line_fmt = ftrace_line_fmt_nop - cgformat = False - data = 0 - ktemp = dict() def __init__(self): + self.stamp = '' + self.sysinfo = '' + self.cmdline = '' + self.kparams = '' + self.testerror = [] + self.battery = [] + self.fwdata = [] + self.ftrace_line_fmt = self.ftrace_line_fmt_nop + self.cgformat = False + self.data = 0 self.ktemp = dict() def setTracerType(self, tracer): if(tracer == 'function_graph'): @@ -2286,6 +2395,7 @@ class TestProps: else: doError('Invalid tracer format: [%s]' % tracer) def parseStamp(self, data, sv): + # global test data m = re.match(self.stampfmt, self.stamp) data.stamp = {'time': '', 'host': '', 'mode': ''} dt = datetime(int(m.group('y'))+2000, int(m.group('m')), @@ -2324,23 +2434,36 @@ class TestProps: sv.kparams = m.group('kp') if not sv.stamp: sv.stamp = data.stamp + # firmware data + if sv.suspendmode == 'mem' and len(self.fwdata) > data.testnumber: + data.fwSuspend, data.fwResume = self.fwdata[data.testnumber] + if(data.fwSuspend > 0 or data.fwResume > 0): + data.fwValid = True + # battery data + if len(self.battery) > data.testnumber: + m = re.match(self.batteryfmt, self.battery[data.testnumber]) + if m: + data.battery = m.groups() + # sleep mode enter errors + if len(self.testerror) > data.testnumber: + m = re.match(self.testerrfmt, self.testerror[data.testnumber]) + if m: + data.enterfail = m.group('e') # Class: TestRun # Description: # A container for a suspend/resume test run. This is necessary as # there could be more than one, and they need to be separate. class TestRun: - ftemp = dict() - ttemp = dict() - data = 0 def __init__(self, dataobj): self.data = dataobj self.ftemp = dict() self.ttemp = dict() class ProcessMonitor: - proclist = dict() - running = False + def __init__(self): + self.proclist = dict() + self.running = False def procstat(self): c = ['cat /proc/[1-9]*/stat 2>/dev/null'] process = Popen(c, shell=True, stdout=PIPE) @@ -2391,8 +2514,8 @@ class ProcessMonitor: # markers, and/or kprobes required for primary parsing. def doesTraceLogHaveTraceEvents(): kpcheck = ['_cal: (', '_cpu_down()'] - techeck = ['suspend_resume'] - tmcheck = ['SUSPEND START', 'RESUME COMPLETE'] + techeck = ['suspend_resume', 'device_pm_callback'] + tmcheck = ['tracing_mark_write'] sysvals.usekprobes = False fp = sysvals.openlog(sysvals.ftracefile, 'r') for line in fp: @@ -2414,23 +2537,14 @@ def doesTraceLogHaveTraceEvents(): check.remove(i) tmcheck = check fp.close() - if len(techeck) == 0: - sysvals.usetraceevents = True - else: - sysvals.usetraceevents = False - if len(tmcheck) == 0: - sysvals.usetracemarkers = True - else: - sysvals.usetracemarkers = False + sysvals.usetraceevents = True if len(techeck) < 2 else False + sysvals.usetracemarkers = True if len(tmcheck) == 0 else False # Function: appendIncompleteTraceLog # Description: # [deprecated for kernel 3.15 or newer] -# Legacy support of ftrace outputs that lack the device_pm_callback -# and/or suspend_resume trace events. The primary data should be -# taken from dmesg, and this ftrace is used only for callgraph data -# or custom actions in the timeline. The data is appended to the Data -# objects provided. +# Adds callgraph data which lacks trace event data. This is only +# for timelines generated from 3.15 or older # Arguments: # testruns: the array of Data objects obtained from parseKernelLog def appendIncompleteTraceLog(testruns): @@ -2460,13 +2574,19 @@ def appendIncompleteTraceLog(testruns): elif re.match(tp.cmdlinefmt, line): tp.cmdline = line continue + elif re.match(tp.batteryfmt, line): + tp.battery.append(line) + continue + elif re.match(tp.testerrfmt, line): + tp.testerror.append(line) + continue # determine the trace data type (required for further parsing) - m = re.match(sysvals.tracertypefmt, line) + m = re.match(tp.tracertypefmt, line) if(m): tp.setTracerType(m.group('t')) continue # device properties line - if(re.match(sysvals.devpropfmt, line)): + if(re.match(tp.devpropfmt, line)): devProps(line) continue # parse only valid lines, if this is not one move on @@ -2506,87 +2626,7 @@ def appendIncompleteTraceLog(testruns): continue # trace event processing if(t.fevent): - # general trace events have two types, begin and end - if(re.match('(?P<name>.*) begin$', t.name)): - isbegin = True - elif(re.match('(?P<name>.*) end$', t.name)): - isbegin = False - else: - continue - m = re.match('(?P<name>.*)\[(?P<val>[0-9]*)\] .*', t.name) - if(m): - val = m.group('val') - if val == '0': - name = m.group('name') - else: - name = m.group('name')+'['+val+']' - else: - m = re.match('(?P<name>.*) .*', t.name) - name = m.group('name') - # special processing for trace events - if re.match('dpm_prepare\[.*', name): - continue - elif re.match('machine_suspend.*', name): - continue - elif re.match('suspend_enter\[.*', name): - if(not isbegin): - data.dmesg['suspend_prepare']['end'] = t.time - continue - elif re.match('dpm_suspend\[.*', name): - if(not isbegin): - data.dmesg['suspend']['end'] = t.time - continue - elif re.match('dpm_suspend_late\[.*', name): - if(isbegin): - data.dmesg['suspend_late']['start'] = t.time - else: - data.dmesg['suspend_late']['end'] = t.time - continue - elif re.match('dpm_suspend_noirq\[.*', name): - if(isbegin): - data.dmesg['suspend_noirq']['start'] = t.time - else: - data.dmesg['suspend_noirq']['end'] = t.time - continue - elif re.match('dpm_resume_noirq\[.*', name): - if(isbegin): - data.dmesg['resume_machine']['end'] = t.time - data.dmesg['resume_noirq']['start'] = t.time - else: - data.dmesg['resume_noirq']['end'] = t.time - continue - elif re.match('dpm_resume_early\[.*', name): - if(isbegin): - data.dmesg['resume_early']['start'] = t.time - else: - data.dmesg['resume_early']['end'] = t.time - continue - elif re.match('dpm_resume\[.*', name): - if(isbegin): - data.dmesg['resume']['start'] = t.time - else: - data.dmesg['resume']['end'] = t.time - continue - elif re.match('dpm_complete\[.*', name): - if(isbegin): - data.dmesg['resume_complete']['start'] = t.time - else: - data.dmesg['resume_complete']['end'] = t.time - continue - # skip trace events inside devices calls - if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)): - continue - # global events (outside device calls) are simply graphed - if(isbegin): - # store each trace event in ttemp - if(name not in testrun[testidx].ttemp): - testrun[testidx].ttemp[name] = [] - testrun[testidx].ttemp[name].append(\ - {'begin': t.time, 'end': t.time}) - else: - # finish off matching trace event in ttemp - if(name in testrun[testidx].ttemp): - testrun[testidx].ttemp[name][-1]['end'] = t.time + continue # call/return processing elif sysvals.usecallgraph: # create a callgraph object for the data @@ -2603,12 +2643,6 @@ def appendIncompleteTraceLog(testruns): tf.close() for test in testrun: - # add the traceevent data to the device hierarchy - if(sysvals.usetraceevents): - for name in test.ttemp: - for event in test.ttemp[name]: - test.data.newActionGlobal(name, event['begin'], event['end']) - # add the callgraph data to the device hierarchy for pid in test.ftemp: for cg in test.ftemp[pid]: @@ -2621,7 +2655,7 @@ def appendIncompleteTraceLog(testruns): continue callstart = cg.start callend = cg.end - for p in test.data.phases: + for p in test.data.sortedPhases(): if(test.data.dmesg[p]['start'] <= callstart and callstart <= test.data.dmesg[p]['end']): list = test.data.dmesg[p]['list'] @@ -2648,10 +2682,13 @@ def parseTraceLog(live=False): doError('%s does not exist' % sysvals.ftracefile) if not live: sysvals.setupAllKprobes() + ksuscalls = ['pm_prepare_console'] + krescalls = ['pm_restore_console'] tracewatch = [] if sysvals.usekprobes: tracewatch += ['sync_filesystems', 'freeze_processes', 'syscore_suspend', - 'syscore_resume', 'resume_console', 'thaw_processes', 'CPU_ON', 'CPU_OFF'] + 'syscore_resume', 'resume_console', 'thaw_processes', 'CPU_ON', + 'CPU_OFF', 'timekeeping_freeze', 'acpi_suspend'] # extract the callgraph and traceevent data tp = TestProps() @@ -2674,18 +2711,24 @@ def parseTraceLog(live=False): elif re.match(tp.cmdlinefmt, line): tp.cmdline = line continue + elif re.match(tp.batteryfmt, line): + tp.battery.append(line) + continue + elif re.match(tp.testerrfmt, line): + tp.testerror.append(line) + continue # firmware line: pull out any firmware data - m = re.match(sysvals.firmwarefmt, line) + m = re.match(tp.firmwarefmt, line) if(m): tp.fwdata.append((int(m.group('s')), int(m.group('r')))) continue # tracer type line: determine the trace data type - m = re.match(sysvals.tracertypefmt, line) + m = re.match(tp.tracertypefmt, line) if(m): tp.setTracerType(m.group('t')) continue # device properties line - if(re.match(sysvals.devpropfmt, line)): + if(re.match(tp.devpropfmt, line)): devProps(line) continue # ignore all other commented lines @@ -2714,20 +2757,20 @@ def parseTraceLog(live=False): continue # find the start of suspend if(t.startMarker()): - phase = 'suspend_prepare' data = Data(len(testdata)) testdata.append(data) testrun = TestRun(data) testruns.append(testrun) tp.parseStamp(data, sysvals) data.setStart(t.time) - data.tKernSus = t.time + data.first_suspend_prepare = True + phase = data.setPhase('suspend_prepare', t.time, True) continue if(not data): continue # process cpu exec line if t.type == 'tracing_mark_write': - m = re.match(sysvals.procexecfmt, t.name) + m = re.match(tp.procexecfmt, t.name) if(m): proclist = dict() for ps in m.group('ps').split(','): @@ -2740,28 +2783,17 @@ def parseTraceLog(live=False): continue # find the end of resume if(t.endMarker()): - data.setEnd(t.time) - if data.tKernRes == 0.0: - data.tKernRes = t.time - if data.dmesg['resume_complete']['end'] < 0: - data.dmesg['resume_complete']['end'] = t.time - if sysvals.suspendmode == 'mem' and len(tp.fwdata) > data.testnumber: - data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] - if(data.tSuspended != 0 and data.tResumed != 0 and \ - (data.fwSuspend > 0 or data.fwResume > 0)): - data.fwValid = True + data.handleEndMarker(t.time) if(not sysvals.usetracemarkers): # no trace markers? then quit and be sure to finish recording # the event we used to trigger resume end - if(len(testrun.ttemp['thaw_processes']) > 0): + if('thaw_processes' in testrun.ttemp and len(testrun.ttemp['thaw_processes']) > 0): # if an entry exists, assume this is its end testrun.ttemp['thaw_processes'][-1]['end'] = t.time break continue # trace event processing if(t.fevent): - if(phase == 'post_resume'): - data.setEnd(t.time) if(t.type == 'suspend_resume'): # suspend_resume trace events have two types, begin and end if(re.match('(?P<name>.*) begin$', t.name)): @@ -2786,86 +2818,62 @@ def parseTraceLog(live=False): # -- phase changes -- # start of kernel suspend if(re.match('suspend_enter\[.*', t.name)): - if(isbegin and data.start == data.tKernSus): - data.dmesg[phase]['start'] = t.time + if(isbegin): data.tKernSus = t.time continue # suspend_prepare start elif(re.match('dpm_prepare\[.*', t.name)): - phase = 'suspend_prepare' - if(not isbegin): - data.dmesg[phase]['end'] = t.time - if data.dmesg[phase]['start'] < 0: - data.dmesg[phase]['start'] = data.start + if isbegin and data.first_suspend_prepare: + data.first_suspend_prepare = False + if data.tKernSus == 0: + data.tKernSus = t.time + continue + phase = data.setPhase('suspend_prepare', t.time, isbegin) continue # suspend start elif(re.match('dpm_suspend\[.*', t.name)): - phase = 'suspend' - data.setPhase(phase, t.time, isbegin) + phase = data.setPhase('suspend', t.time, isbegin) continue # suspend_late start elif(re.match('dpm_suspend_late\[.*', t.name)): - phase = 'suspend_late' - data.setPhase(phase, t.time, isbegin) + phase = data.setPhase('suspend_late', t.time, isbegin) continue # suspend_noirq start elif(re.match('dpm_suspend_noirq\[.*', t.name)): - if data.phaseCollision('suspend_noirq', isbegin, line): - continue - phase = 'suspend_noirq' - data.setPhase(phase, t.time, isbegin) - if(not isbegin): - phase = 'suspend_machine' - data.dmesg[phase]['start'] = t.time + phase = data.setPhase('suspend_noirq', t.time, isbegin) continue # suspend_machine/resume_machine elif(re.match('machine_suspend\[.*', t.name)): if(isbegin): - phase = 'suspend_machine' - data.dmesg[phase]['end'] = t.time - data.tSuspended = t.time + lp = data.lastPhase() + phase = data.setPhase('suspend_machine', data.dmesg[lp]['end'], True) + data.setPhase(phase, t.time, False) + if data.tSuspended == 0: + data.tSuspended = t.time else: - if(sysvals.suspendmode in ['mem', 'disk'] and not tp.S0i3): - data.dmesg['suspend_machine']['end'] = t.time + phase = data.setPhase('resume_machine', t.time, True) + if(sysvals.suspendmode in ['mem', 'disk']): + susp = phase.replace('resume', 'suspend') + if susp in data.dmesg: + data.dmesg[susp]['end'] = t.time data.tSuspended = t.time - phase = 'resume_machine' - data.dmesg[phase]['start'] = t.time data.tResumed = t.time - data.tLow = data.tResumed - data.tSuspended - continue - # acpi_suspend - elif(re.match('acpi_suspend\[.*', t.name)): - # acpi_suspend[0] S0i3 - if(re.match('acpi_suspend\[0\] begin', t.name)): - if(sysvals.suspendmode == 'mem'): - tp.S0i3 = True - data.dmesg['suspend_machine']['end'] = t.time - data.tSuspended = t.time continue # resume_noirq start elif(re.match('dpm_resume_noirq\[.*', t.name)): - if data.phaseCollision('resume_noirq', isbegin, line): - continue - phase = 'resume_noirq' - data.setPhase(phase, t.time, isbegin) - if(isbegin): - data.dmesg['resume_machine']['end'] = t.time + phase = data.setPhase('resume_noirq', t.time, isbegin) continue # resume_early start elif(re.match('dpm_resume_early\[.*', t.name)): - phase = 'resume_early' - data.setPhase(phase, t.time, isbegin) + phase = data.setPhase('resume_early', t.time, isbegin) continue # resume start elif(re.match('dpm_resume\[.*', t.name)): - phase = 'resume' - data.setPhase(phase, t.time, isbegin) + phase = data.setPhase('resume', t.time, isbegin) continue # resume complete start elif(re.match('dpm_complete\[.*', t.name)): - phase = 'resume_complete' - if(isbegin): - data.dmesg[phase]['start'] = t.time + phase = data.setPhase('resume_complete', t.time, isbegin) continue # skip trace events inside devices calls if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)): @@ -2881,13 +2889,10 @@ def parseTraceLog(live=False): if(len(testrun.ttemp[name]) > 0): # if an entry exists, assume this is its end testrun.ttemp[name][-1]['end'] = t.time - elif(phase == 'post_resume'): - # post resume events can just have ends - testrun.ttemp[name].append({ - 'begin': data.dmesg[phase]['start'], - 'end': t.time}) # device callback start elif(t.type == 'device_pm_callback_start'): + if phase not in data.dmesg: + continue m = re.match('(?P<drv>.*) (?P<d>.*), parent: *(?P<p>.*), .*',\ t.name); if(not m): @@ -2901,6 +2906,8 @@ def parseTraceLog(live=False): data.devpids.append(pid) # device callback finish elif(t.type == 'device_pm_callback_end'): + if phase not in data.dmesg: + continue m = re.match('(?P<drv>.*) (?P<d>.*), err.*', t.name); if(not m): continue @@ -2931,6 +2938,9 @@ def parseTraceLog(live=False): 'cdata': kprobedata, 'proc': m_proc, }) + # start of kernel resume + if(phase == 'suspend_prepare' and kprobename in ksuscalls): + data.tKernSus = t.time elif(t.freturn): if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1: continue @@ -2941,9 +2951,9 @@ def parseTraceLog(live=False): e['end'] = t.time e['rdata'] = kprobedata # end of kernel resume - if(kprobename == 'pm_notifier_call_chain' or \ - kprobename == 'pm_restore_console'): - data.dmesg[phase]['end'] = t.time + if(phase != 'suspend_prepare' and kprobename in krescalls): + if phase in data.dmesg: + data.dmesg[phase]['end'] = t.time data.tKernRes = t.time # callgraph processing @@ -2961,10 +2971,13 @@ def parseTraceLog(live=False): if(res == -1): testrun.ftemp[key][-1].addLine(t) tf.close() + if data and not data.devicegroups: + sysvals.vprint('WARNING: end marker is missing') + data.handleEndMarker(t.time) if sysvals.suspendmode == 'command': for test in testruns: - for p in test.data.phases: + for p in test.data.sortedPhases(): if p == 'suspend_prepare': test.data.dmesg[p]['start'] = test.data.start test.data.dmesg[p]['end'] = test.data.end @@ -2973,13 +2986,20 @@ def parseTraceLog(live=False): test.data.dmesg[p]['end'] = test.data.end test.data.tSuspended = test.data.end test.data.tResumed = test.data.end - test.data.tLow = 0 test.data.fwValid = False # dev source and procmon events can be unreadable with mixed phase height if sysvals.usedevsrc or sysvals.useprocmon: sysvals.mixedphaseheight = False + # expand phase boundaries so there are no gaps + for data in testdata: + lp = data.sortedPhases()[0] + for p in data.sortedPhases(): + if(p != lp and not ('machine' in p and 'machine' in lp)): + data.dmesg[lp]['end'] = data.dmesg[p]['start'] + lp = p + for i in range(len(testruns)): test = testruns[i] data = test.data @@ -3040,8 +3060,8 @@ def parseTraceLog(live=False): sortkey = '%f%f%d' % (cg.start, cg.end, pid) sortlist[sortkey] = cg elif len(cg.list) > 1000000: - print 'WARNING: the callgraph for %s is massive (%d lines)' %\ - (devname, len(cg.list)) + sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\ + (devname, len(cg.list))) # create blocks for orphan cg data for sortkey in sorted(sortlist): cg = sortlist[sortkey] @@ -3057,25 +3077,29 @@ def parseTraceLog(live=False): for data in testdata: tn = '' if len(testdata) == 1 else ('%d' % (data.testnumber + 1)) terr = '' - lp = data.phases[0] - for p in data.phases: - if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0): + phasedef = data.phasedef + lp = 'suspend_prepare' + for p in sorted(phasedef, key=lambda k:phasedef[k]['order']): + if p not in data.dmesg: if not terr: - print 'TEST%s FAILED: %s failed in %s phase' % (tn, sysvals.suspendmode, lp) + pprint('TEST%s FAILED: %s failed in %s phase' % (tn, sysvals.suspendmode, lp)) terr = '%s%s failed in %s phase' % (sysvals.suspendmode, tn, lp) error.append(terr) + if data.tSuspended == 0: + data.tSuspended = data.dmesg[lp]['end'] + if data.tResumed == 0: + data.tResumed = data.dmesg[lp]['end'] + data.fwValid = False sysvals.vprint('WARNING: phase "%s" is missing!' % p) - if(data.dmesg[p]['start'] < 0): - data.dmesg[p]['start'] = data.dmesg[lp]['end'] - if(p == 'resume_machine'): - data.tSuspended = data.dmesg[lp]['end'] - data.tResumed = data.dmesg[lp]['end'] - data.tLow = 0 - if(data.dmesg[p]['end'] < 0): - data.dmesg[p]['end'] = data.dmesg[p]['start'] - if(p != lp and not ('machine' in p and 'machine' in lp)): - data.dmesg[lp]['end'] = data.dmesg[p]['start'] lp = p + if not terr and data.enterfail: + pprint('test%s FAILED: enter %s failed with %s' % (tn, sysvals.suspendmode, data.enterfail)) + terr = 'test%s failed to enter %s mode' % (tn, sysvals.suspendmode) + error.append(terr) + if data.tSuspended == 0: + data.tSuspended = data.tKernRes + if data.tResumed == 0: + data.tResumed = data.tSuspended if(len(sysvals.devicefilter) > 0): data.deviceFilter(sysvals.devicefilter) @@ -3127,7 +3151,13 @@ def loadKernelLog(): elif re.match(tp.cmdlinefmt, line): tp.cmdline = line continue - m = re.match(sysvals.firmwarefmt, line) + elif re.match(tp.batteryfmt, line): + tp.battery.append(line) + continue + elif re.match(tp.testerrfmt, line): + tp.testerror.append(line) + continue + m = re.match(tp.firmwarefmt, line) if(m): tp.fwdata.append((int(m.group('s')), int(m.group('r')))) continue @@ -3140,10 +3170,6 @@ def loadKernelLog(): testruns.append(data) data = Data(len(testruns)) tp.parseStamp(data, sysvals) - if len(tp.fwdata) > data.testnumber: - data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] - if(data.fwSuspend > 0 or data.fwResume > 0): - data.fwValid = True if(not data): continue m = re.match('.* *(?P<k>[0-9]\.[0-9]{2}\.[0-9]-.*) .*', msg) @@ -3158,7 +3184,7 @@ def loadKernelLog(): if data: testruns.append(data) if len(testruns) < 1: - print('ERROR: dmesg log has no suspend/resume data: %s' \ + pprint('ERROR: dmesg log has no suspend/resume data: %s' \ % sysvals.dmesgfile) # fix lines with same timestamp/function with the call and return swapped @@ -3199,30 +3225,30 @@ def parseKernelLog(data): # dmesg phase match table dm = { - 'suspend_prepare': 'PM: Syncing filesystems.*', - 'suspend': 'PM: Entering [a-z]* sleep.*', - 'suspend_late': 'PM: suspend of devices complete after.*', - 'suspend_noirq': 'PM: late suspend of devices complete after.*', - 'suspend_machine': 'PM: noirq suspend of devices complete after.*', - 'resume_machine': 'ACPI: Low-level resume complete.*', - 'resume_noirq': 'ACPI: Waking up from system sleep state.*', - 'resume_early': 'PM: noirq resume of devices complete after.*', - 'resume': 'PM: early resume of devices complete after.*', - 'resume_complete': 'PM: resume of devices complete after.*', - 'post_resume': '.*Restarting tasks \.\.\..*', + 'suspend_prepare': ['PM: Syncing filesystems.*'], + 'suspend': ['PM: Entering [a-z]* sleep.*', 'Suspending console.*'], + 'suspend_late': ['PM: suspend of devices complete after.*'], + 'suspend_noirq': ['PM: late suspend of devices complete after.*'], + 'suspend_machine': ['PM: noirq suspend of devices complete after.*'], + 'resume_machine': ['ACPI: Low-level resume complete.*'], + 'resume_noirq': ['ACPI: Waking up from system sleep state.*'], + 'resume_early': ['PM: noirq resume of devices complete after.*'], + 'resume': ['PM: early resume of devices complete after.*'], + 'resume_complete': ['PM: resume of devices complete after.*'], + 'post_resume': ['.*Restarting tasks \.\.\..*'], } if(sysvals.suspendmode == 'standby'): - dm['resume_machine'] = 'PM: Restoring platform NVS memory' + dm['resume_machine'] = ['PM: Restoring platform NVS memory'] elif(sysvals.suspendmode == 'disk'): - dm['suspend_late'] = 'PM: freeze of devices complete after.*' - dm['suspend_noirq'] = 'PM: late freeze of devices complete after.*' - dm['suspend_machine'] = 'PM: noirq freeze of devices complete after.*' - dm['resume_machine'] = 'PM: Restoring platform NVS memory' - dm['resume_early'] = 'PM: noirq restore of devices complete after.*' - dm['resume'] = 'PM: early restore of devices complete after.*' - dm['resume_complete'] = 'PM: restore of devices complete after.*' + dm['suspend_late'] = ['PM: freeze of devices complete after.*'] + dm['suspend_noirq'] = ['PM: late freeze of devices complete after.*'] + dm['suspend_machine'] = ['PM: noirq freeze of devices complete after.*'] + dm['resume_machine'] = ['PM: Restoring platform NVS memory'] + dm['resume_early'] = ['PM: noirq restore of devices complete after.*'] + dm['resume'] = ['PM: early restore of devices complete after.*'] + dm['resume_complete'] = ['PM: restore of devices complete after.*'] elif(sysvals.suspendmode == 'freeze'): - dm['resume_machine'] = 'ACPI: resume from mwait' + dm['resume_machine'] = ['ACPI: resume from mwait'] # action table (expected events that occur and show up in dmesg) at = { @@ -3264,81 +3290,89 @@ def parseKernelLog(data): else: continue + # check for a phase change line + phasechange = False + for p in dm: + for s in dm[p]: + if(re.match(s, msg)): + phasechange, phase = True, p + break + # hack for determining resume_machine end for freeze if(not sysvals.usetraceevents and sysvals.suspendmode == 'freeze' \ and phase == 'resume_machine' and \ re.match('calling (?P<f>.*)\+ @ .*, parent: .*', msg)): - data.dmesg['resume_machine']['end'] = ktime - phase = 'resume_noirq' - data.dmesg[phase]['start'] = ktime - - # suspend start - if(re.match(dm['suspend_prepare'], msg)): - phase = 'suspend_prepare' - data.dmesg[phase]['start'] = ktime - data.setStart(ktime) - data.tKernSus = ktime - # suspend start - elif(re.match(dm['suspend'], msg)): - data.dmesg['suspend_prepare']['end'] = ktime - phase = 'suspend' - data.dmesg[phase]['start'] = ktime - # suspend_late start - elif(re.match(dm['suspend_late'], msg)): - data.dmesg['suspend']['end'] = ktime - phase = 'suspend_late' - data.dmesg[phase]['start'] = ktime - # suspend_noirq start - elif(re.match(dm['suspend_noirq'], msg)): - data.dmesg['suspend_late']['end'] = ktime - phase = 'suspend_noirq' - data.dmesg[phase]['start'] = ktime - # suspend_machine start - elif(re.match(dm['suspend_machine'], msg)): - data.dmesg['suspend_noirq']['end'] = ktime - phase = 'suspend_machine' - data.dmesg[phase]['start'] = ktime - # resume_machine start - elif(re.match(dm['resume_machine'], msg)): - if(sysvals.suspendmode in ['freeze', 'standby']): - data.tSuspended = prevktime - data.dmesg['suspend_machine']['end'] = prevktime - else: - data.tSuspended = ktime - data.dmesg['suspend_machine']['end'] = ktime - phase = 'resume_machine' - data.tResumed = ktime - data.tLow = data.tResumed - data.tSuspended - data.dmesg[phase]['start'] = ktime - # resume_noirq start - elif(re.match(dm['resume_noirq'], msg)): - data.dmesg['resume_machine']['end'] = ktime + data.setPhase(phase, ktime, False) phase = 'resume_noirq' - data.dmesg[phase]['start'] = ktime - # resume_early start - elif(re.match(dm['resume_early'], msg)): - data.dmesg['resume_noirq']['end'] = ktime - phase = 'resume_early' - data.dmesg[phase]['start'] = ktime - # resume start - elif(re.match(dm['resume'], msg)): - data.dmesg['resume_early']['end'] = ktime - phase = 'resume' - data.dmesg[phase]['start'] = ktime - # resume complete start - elif(re.match(dm['resume_complete'], msg)): - data.dmesg['resume']['end'] = ktime - phase = 'resume_complete' - data.dmesg[phase]['start'] = ktime - # post resume start - elif(re.match(dm['post_resume'], msg)): - data.dmesg['resume_complete']['end'] = ktime - data.setEnd(ktime) - data.tKernRes = ktime - break + data.setPhase(phase, ktime, True) + + if phasechange: + if phase == 'suspend_prepare': + data.setPhase(phase, ktime, True) + data.setStart(ktime) + data.tKernSus = ktime + elif phase == 'suspend': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'suspend_late': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'suspend_noirq': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'suspend_machine': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'resume_machine': + lp = data.lastPhase() + if(sysvals.suspendmode in ['freeze', 'standby']): + data.tSuspended = prevktime + if lp: + data.setPhase(lp, prevktime, False) + else: + data.tSuspended = ktime + if lp: + data.setPhase(lp, prevktime, False) + data.tResumed = ktime + data.setPhase(phase, ktime, True) + elif phase == 'resume_noirq': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'resume_early': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'resume': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'resume_complete': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setPhase(phase, ktime, True) + elif phase == 'post_resume': + lp = data.lastPhase() + if lp: + data.setPhase(lp, ktime, False) + data.setEnd(ktime) + data.tKernRes = ktime + break # -- device callbacks -- - if(phase in data.phases): + if(phase in data.sortedPhases()): # device init call if(re.match('calling (?P<f>.*)\+ @ .*, parent: .*', msg)): sm = re.match('calling (?P<f>.*)\+ @ '+\ @@ -3396,24 +3430,31 @@ def parseKernelLog(data): actions[cpu].append({'begin': cpu_start, 'end': ktime}) cpu_start = ktime prevktime = ktime + data.initDevicegroups() # fill in any missing phases - lp = data.phases[0] - for p in data.phases: - if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0): - print('WARNING: phase "%s" is missing, something went wrong!' % p) - print(' In %s, this dmesg line denotes the start of %s:' % \ - (sysvals.suspendmode, p)) - print(' "%s"' % dm[p]) - if(data.dmesg[p]['start'] < 0): - data.dmesg[p]['start'] = data.dmesg[lp]['end'] - if(p == 'resume_machine'): - data.tSuspended = data.dmesg[lp]['end'] - data.tResumed = data.dmesg[lp]['end'] - data.tLow = 0 - if(data.dmesg[p]['end'] < 0): - data.dmesg[p]['end'] = data.dmesg[p]['start'] + phasedef = data.phasedef + terr, lp = '', 'suspend_prepare' + for p in sorted(phasedef, key=lambda k:phasedef[k]['order']): + if p not in data.dmesg: + if not terr: + pprint('TEST FAILED: %s failed in %s phase' % (sysvals.suspendmode, lp)) + terr = '%s failed in %s phase' % (sysvals.suspendmode, lp) + if data.tSuspended == 0: + data.tSuspended = data.dmesg[lp]['end'] + if data.tResumed == 0: + data.tResumed = data.dmesg[lp]['end'] + sysvals.vprint('WARNING: phase "%s" is missing!' % p) lp = p + lp = data.sortedPhases()[0] + for p in data.sortedPhases(): + if(p != lp and not ('machine' in p and 'machine' in lp)): + data.dmesg[lp]['end'] = data.dmesg[p]['start'] + lp = p + if data.tSuspended == 0: + data.tSuspended = data.tKernRes + if data.tResumed == 0: + data.tResumed = data.tSuspended # fill in any actions we've found for name in actions: @@ -3462,7 +3503,7 @@ def addCallgraphs(sv, hf, data): hf.write('<section id="callgraphs" class="callgraph">\n') # write out the ftrace data converted to html num = 0 - for p in data.phases: + for p in data.sortedPhases(): if sv.cgphase and p != sv.cgphase: continue list = data.dmesg[p]['list'] @@ -3495,7 +3536,7 @@ def addCallgraphs(sv, hf, data): # Create summary html file for a series of tests # Arguments: # testruns: array of Data objects from parseTraceLog -def createHTMLSummarySimple(testruns, htmlfile, folder): +def createHTMLSummarySimple(testruns, htmlfile, title): # write the html header first (html head, css code, up to body start) html = '<!DOCTYPE html>\n<html>\n<head>\n\ <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\ @@ -3505,7 +3546,7 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): table {width:100%;border-collapse: collapse;}\n\ .summary {border:1px solid;}\n\ th {border: 1px solid black;background:#222;color:white;}\n\ - td {font: 16px "Times New Roman";text-align: center;}\n\ + td {font: 14px "Times New Roman";text-align: center;}\n\ tr.head td {border: 1px solid black;background:#aaa;}\n\ tr.alt {background-color:#ddd;}\n\ tr.notice {color:red;}\n\ @@ -3521,7 +3562,7 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 lastmode = '' - cnt = {'pass':0, 'fail':0, 'hang':0} + cnt = dict() for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])): mode = data['mode'] if mode not in list: @@ -3541,10 +3582,14 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): tVal = [float(data['suspend']), float(data['resume'])] list[mode]['data'].append([data['host'], data['kernel'], data['time'], tVal[0], tVal[1], data['url'], data['result'], - data['issues']]) + data['issues'], data['sus_worst'], data['sus_worsttime'], + data['res_worst'], data['res_worsttime']]) idx = len(list[mode]['data']) - 1 + if data['result'] not in cnt: + cnt[data['result']] = 1 + else: + cnt[data['result']] += 1 if data['result'] == 'pass': - cnt['pass'] += 1 for i in range(2): tMed[i].append(tVal[i]) tAvg[i] += tVal[i] @@ -3555,10 +3600,6 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): iMax[i] = idx tMax[i] = tVal[i] num += 1 - elif data['result'] == 'hang': - cnt['hang'] += 1 - elif data['result'] == 'fail': - cnt['fail'] += 1 lastmode = mode if lastmode and num > 0: for i in range(2): @@ -3575,7 +3616,7 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): for ilk in sorted(cnt, reverse=True): if cnt[ilk] > 0: desc.append('%d %s' % (cnt[ilk], ilk)) - html += '<div class="stamp">%s (%d tests: %s)</div>\n' % (folder, len(testruns), ', '.join(desc)) + html += '<div class="stamp">%s (%d tests: %s)</div>\n' % (title, len(testruns), ', '.join(desc)) th = '\t<th>{0}</th>\n' td = '\t<td>{0}</td>\n' tdh = '\t<td{1}>{0}</td>\n' @@ -3585,11 +3626,14 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): html += '<table class="summary">\n<tr>\n' + th.format('#') +\ th.format('Mode') + th.format('Host') + th.format('Kernel') +\ th.format('Test Time') + th.format('Result') + th.format('Issues') +\ - th.format('Suspend') + th.format('Resume') + th.format('Detail') + '</tr>\n' + th.format('Suspend') + th.format('Resume') +\ + th.format('Worst Suspend Device') + th.format('SD Time') +\ + th.format('Worst Resume Device') + th.format('RD Time') +\ + th.format('Detail') + '</tr>\n' # export list into html head = '<tr class="head"><td>{0}</td><td>{1}</td>'+\ - '<td colspan=8 class="sus">Suspend Avg={2} '+\ + '<td colspan=12 class="sus">Suspend Avg={2} '+\ '<span class=minval><a href="#s{10}min">Min={3}</a></span> '+\ '<span class=medval><a href="#s{10}med">Med={4}</a></span> '+\ '<span class=maxval><a href="#s{10}max">Max={5}</a></span> '+\ @@ -3598,7 +3642,7 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): '<span class=medval><a href="#r{10}med">Med={8}</a></span> '+\ '<span class=maxval><a href="#r{10}max">Max={9}</a></span></td>'+\ '</tr>\n' - headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan=8></td></tr>\n' + headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan=12></td></tr>\n' for mode in list: # header line for each suspend mode num = 0 @@ -3641,6 +3685,10 @@ def createHTMLSummarySimple(testruns, htmlfile, folder): html += td.format(d[7]) # issues html += tdh.format('%.3f ms' % d[3], tHigh[0]) if d[3] else td.format('') # suspend html += tdh.format('%.3f ms' % d[4], tHigh[1]) if d[4] else td.format('') # resume + html += td.format(d[8]) # sus_worst + html += td.format('%.3f ms' % d[9]) if d[9] else td.format('') # sus_worst time + html += td.format(d[10]) # res_worst + html += td.format('%.3f ms' % d[11]) if d[11] else td.format('') # res_worst time html += tdlink.format(d[5]) if d[5] else td.format('') # url html += '</tr>\n' num += 1 @@ -3670,14 +3718,15 @@ def ordinal(value): # True if the html file was created, false if it failed def createHTML(testruns, testfail): if len(testruns) < 1: - print('ERROR: Not enough test data to build a timeline') + pprint('ERROR: Not enough test data to build a timeline') return kerror = False for data in testruns: if data.kerror: kerror = True - data.normalizeTime(testruns[-1].tSuspended) + if(sysvals.suspendmode in ['freeze', 'standby']): + data.trimFreezeTime(testruns[-1].tSuspended) # html function templates html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">{2}→</div>\n' @@ -3721,8 +3770,8 @@ def createHTML(testruns, testfail): sktime, rktime = data.getTimeValues() if(tTotal == 0): doError('No timeline data') - if(data.tLow > 0): - low_time = '%.0f'%(data.tLow*1000) + if(len(data.tLow) > 0): + low_time = '|'.join(data.tLow) if sysvals.suspendmode == 'command': run_time = '%.0f'%((data.end-data.start)*1000) if sysvals.testcommand: @@ -3743,7 +3792,7 @@ def createHTML(testruns, testfail): if(len(testruns) > 1): testdesc1 = testdesc2 = ordinal(data.testnumber+1) testdesc2 += ' ' - if(data.tLow == 0): + if(len(data.tLow) == 0): thtml = html_timetotal.format(suspend_time, \ resume_time, testdesc1, stitle, rtitle) else: @@ -3762,7 +3811,7 @@ def createHTML(testruns, testfail): rtitle = 'time from firmware mode to return from kernel enter_state(%s) [kernel time only]' % sysvals.suspendmode if(len(testruns) > 1): testdesc = ordinal(data.testnumber+1)+' '+testdesc - if(data.tLow == 0): + if(len(data.tLow) == 0): thtml = html_timetotal.format(suspend_time, \ resume_time, testdesc, stitle, rtitle) else: @@ -3820,15 +3869,14 @@ def createHTML(testruns, testfail): # draw the full timeline devtl.createZoomBox(sysvals.suspendmode, len(testruns)) - phases = {'suspend':[],'resume':[]} - for phase in data.dmesg: - if 'resume' in phase: - phases['resume'].append(phase) - else: - phases['suspend'].append(phase) - - # draw each test run chronologically for data in testruns: + # draw each test run and block chronologically + phases = {'suspend':[],'resume':[]} + for phase in data.sortedPhases(): + if data.dmesg[phase]['start'] >= data.tSuspended: + phases['resume'].append(phase) + else: + phases['suspend'].append(phase) # now draw the actual timeline blocks for dir in phases: # draw suspend and resume blocks separately @@ -3850,7 +3898,7 @@ def createHTML(testruns, testfail): continue width = '%f' % (((mTotal*100.0)-sysvals.srgap/2)/tTotal) devtl.html += devtl.html_tblock.format(bname, left, width, devtl.scaleH) - for b in sorted(phases[dir]): + for b in phases[dir]: # draw the phase color background phase = data.dmesg[b] length = phase['end']-phase['start'] @@ -3865,7 +3913,7 @@ def createHTML(testruns, testfail): id = '%d_%d' % (idx1, idx2) right = '%f' % (((mMax-t)*100.0)/mTotal) devtl.html += html_error.format(right, id, type) - for b in sorted(phases[dir]): + for b in phases[dir]: # draw the devices for this phase phaselist = data.dmesg[b]['list'] for d in data.tdevlist[b]: @@ -3942,19 +3990,17 @@ def createHTML(testruns, testfail): # draw a legend which describes the phases by color if sysvals.suspendmode != 'command': - data = testruns[-1] + phasedef = testruns[-1].phasedef devtl.html += '<div class="legend">\n' - pdelta = 100.0/len(data.phases) + pdelta = 100.0/len(phasedef.keys()) pmargin = pdelta / 4.0 - for phase in data.phases: - tmp = phase.split('_') - id = tmp[0][0] - if(len(tmp) > 1): - id += tmp[1][0] - order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin) + for phase in sorted(phasedef, key=lambda k:phasedef[k]['order']): + id, p = '', phasedef[phase] + for word in phase.split('_'): + id += word[0] + order = '%.2f' % ((p['order'] * pdelta) + pmargin) name = string.replace(phase, '_', ' ') - devtl.html += devtl.html_legend.format(order, \ - data.dmesg[phase]['color'], name, id) + devtl.html += devtl.html_legend.format(order, p['color'], name, id) devtl.html += '</div>\n' hf = open(sysvals.htmlfile, 'w') @@ -3970,7 +4016,7 @@ def createHTML(testruns, testfail): pscolor = 'linear-gradient(to top left, #ccc, #eee)' hf.write(devtl.html_phaselet.format('pre_suspend_process', \ '0', '0', pscolor)) - for b in data.phases: + for b in data.sortedPhases(): phase = data.dmesg[b] length = phase['end']-phase['start'] left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal) @@ -4522,18 +4568,18 @@ def setRuntimeSuspend(before=True): sv.rstgt, sv.rsval, sv.rsdir = 'on', 'auto', 'enabled' else: sv.rstgt, sv.rsval, sv.rsdir = 'auto', 'on', 'disabled' - print('CONFIGURING RUNTIME SUSPEND...') + pprint('CONFIGURING RUNTIME SUSPEND...') sv.rslist = deviceInfo(sv.rstgt) for i in sv.rslist: sv.setVal(sv.rsval, i) - print('runtime suspend %s on all devices (%d changed)' % (sv.rsdir, len(sv.rslist))) - print('waiting 5 seconds...') + pprint('runtime suspend %s on all devices (%d changed)' % (sv.rsdir, len(sv.rslist))) + pprint('waiting 5 seconds...') time.sleep(5) else: # runtime suspend re-enable or re-disable for i in sv.rslist: sv.setVal(sv.rstgt, i) - print('runtime suspend settings restored on %d devices' % len(sv.rslist)) + pprint('runtime suspend settings restored on %d devices' % len(sv.rslist)) # Function: executeSuspend # Description: @@ -4542,25 +4588,21 @@ def setRuntimeSuspend(before=True): def executeSuspend(): pm = ProcessMonitor() tp = sysvals.tpath - fwdata = [] + testdata = [] + battery = True if getBattery() else False # run these commands to prepare the system for suspend if sysvals.display: - if sysvals.display > 0: - print('TURN DISPLAY ON') - call('xset -d :0.0 dpms force suspend', shell=True) - call('xset -d :0.0 dpms force on', shell=True) - else: - print('TURN DISPLAY OFF') - call('xset -d :0.0 dpms force suspend', shell=True) + pprint('SET DISPLAY TO %s' % sysvals.display.upper()) + displayControl(sysvals.display) time.sleep(1) if sysvals.sync: - print('SYNCING FILESYSTEMS') + pprint('SYNCING FILESYSTEMS') call('sync', shell=True) # mark the start point in the kernel ring buffer just as we start sysvals.initdmesg() # start ftrace if(sysvals.usecallgraph or sysvals.usetraceevents): - print('START TRACING') + pprint('START TRACING') sysvals.fsetVal('1', 'tracing_on') if sysvals.useprocmon: pm.start() @@ -4573,15 +4615,16 @@ def executeSuspend(): sysvals.fsetVal('WAIT END', 'trace_marker') # start message if sysvals.testcommand != '': - print('COMMAND START') + pprint('COMMAND START') else: if(sysvals.rtcwake): - print('SUSPEND START') + pprint('SUSPEND START') else: - print('SUSPEND START (press a key to resume)') + pprint('SUSPEND START (press a key to resume)') + bat1 = getBattery() if battery else False # set rtcwake if(sysvals.rtcwake): - print('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime) + pprint('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime) sysvals.rtcWakeAlarmOn() # start of suspend trace marker if(sysvals.usecallgraph or sysvals.usetraceevents): @@ -4592,8 +4635,11 @@ def executeSuspend(): time.sleep(sysvals.predelay/1000.0) sysvals.fsetVal('WAIT END', 'trace_marker') # initiate suspend or command + tdata = {'error': ''} if sysvals.testcommand != '': - call(sysvals.testcommand+' 2>&1', shell=True); + res = call(sysvals.testcommand+' 2>&1', shell=True); + if res != 0: + tdata['error'] = 'cmd returned %d' % res else: mode = sysvals.suspendmode if sysvals.memmode and os.path.exists(sysvals.mempowerfile): @@ -4601,13 +4647,18 @@ def executeSuspend(): pf = open(sysvals.mempowerfile, 'w') pf.write(sysvals.memmode) pf.close() + if sysvals.diskmode and os.path.exists(sysvals.diskpowerfile): + mode = 'disk' + pf = open(sysvals.diskpowerfile, 'w') + pf.write(sysvals.diskmode) + pf.close() pf = open(sysvals.powerfile, 'w') pf.write(mode) # execution will pause here try: pf.close() - except: - pass + except Exception as e: + tdata['error'] = str(e) if(sysvals.rtcwake): sysvals.rtcWakeAlarmOff() # postdelay delay @@ -4616,27 +4667,33 @@ def executeSuspend(): time.sleep(sysvals.postdelay/1000.0) sysvals.fsetVal('WAIT END', 'trace_marker') # return from suspend - print('RESUME COMPLETE') + pprint('RESUME COMPLETE') if(sysvals.usecallgraph or sysvals.usetraceevents): sysvals.fsetVal('RESUME COMPLETE', 'trace_marker') if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'): - fwdata.append(getFPDT(False)) + tdata['fw'] = getFPDT(False) + bat2 = getBattery() if battery else False + if battery and bat1 and bat2: + tdata['bat'] = (bat1, bat2) + testdata.append(tdata) # stop ftrace if(sysvals.usecallgraph or sysvals.usetraceevents): if sysvals.useprocmon: pm.stop() sysvals.fsetVal('0', 'tracing_on') - print('CAPTURING TRACE') - op = sysvals.writeDatafileHeader(sysvals.ftracefile, fwdata) + # grab a copy of the dmesg output + pprint('CAPTURING DMESG') + sysvals.getdmesg(testdata) + # grab a copy of the ftrace output + if(sysvals.usecallgraph or sysvals.usetraceevents): + pprint('CAPTURING TRACE') + op = sysvals.writeDatafileHeader(sysvals.ftracefile, testdata) fp = open(tp+'trace', 'r') for line in fp: op.write(line) op.close() sysvals.fsetVal('', 'trace') devProps() - # grab a copy of the dmesg output - print('CAPTURING DMESG') - sysvals.getdmesg(fwdata) def readFile(file): if os.path.islink(file): @@ -4673,15 +4730,15 @@ def yesno(val): # a list of USB device names to sysvals for better timeline readability def deviceInfo(output=''): if not output: - print('LEGEND') - print('---------------------------------------------------------------------------------------------') - print(' A = async/sync PM queue (A/S) C = runtime active children') - print(' R = runtime suspend enabled/disabled (E/D) rACTIVE = runtime active (min/sec)') - print(' S = runtime status active/suspended (A/S) rSUSPEND = runtime suspend (min/sec)') - print(' U = runtime usage count') - print('---------------------------------------------------------------------------------------------') - print('DEVICE NAME A R S U C rACTIVE rSUSPEND') - print('---------------------------------------------------------------------------------------------') + pprint('LEGEND\n'\ + '---------------------------------------------------------------------------------------------\n'\ + ' A = async/sync PM queue (A/S) C = runtime active children\n'\ + ' R = runtime suspend enabled/disabled (E/D) rACTIVE = runtime active (min/sec)\n'\ + ' S = runtime status active/suspended (A/S) rSUSPEND = runtime suspend (min/sec)\n'\ + ' U = runtime usage count\n'\ + '---------------------------------------------------------------------------------------------\n'\ + 'DEVICE NAME A R S U C rACTIVE rSUSPEND\n'\ + '---------------------------------------------------------------------------------------------') res = [] tgtval = 'runtime_status' @@ -4766,7 +4823,7 @@ def devProps(data=0): alreadystamped = True continue # determine the trace data type (required for further parsing) - m = re.match(sysvals.tracertypefmt, line) + m = re.match(tp.tracertypefmt, line) if(m): tp.setTracerType(m.group('t')) continue @@ -4870,6 +4927,11 @@ def getModes(): fp.close() if 'mem' in modes and not deep: modes.remove('mem') + if('disk' in modes and os.path.exists(sysvals.diskpowerfile)): + fp = open(sysvals.diskpowerfile, 'r') + for m in string.split(fp.read()): + modes.append('disk-%s' % m.strip('[]')) + fp.close() return modes # Function: dmidecode @@ -4994,8 +5056,9 @@ def dmidecode(mempath, fatal=False): return out def getBattery(): - p = '/sys/class/power_supply' - bat = dict() + p, charge, bat = '/sys/class/power_supply', 0, {} + if not os.path.exists(p): + return False for d in os.listdir(p): type = sysvals.getVal(os.path.join(p, d, 'type')).strip().lower() if type != 'battery': @@ -5003,15 +5066,47 @@ def getBattery(): for v in ['status', 'energy_now', 'capacity_now']: bat[v] = sysvals.getVal(os.path.join(p, d, v)).strip().lower() break - ac = True - if 'status' in bat and 'discharging' in bat['status']: - ac = False - charge = 0 + if 'status' not in bat: + return False + ac = False if 'discharging' in bat['status'] else True for v in ['energy_now', 'capacity_now']: if v in bat and bat[v]: charge = int(bat[v]) return (ac, charge) +def displayControl(cmd): + xset, ret = 'xset -d :0.0 {0}', 0 + if sysvals.sudouser: + xset = 'sudo -u %s %s' % (sysvals.sudouser, xset) + if cmd == 'init': + ret = call(xset.format('dpms 0 0 0'), shell=True) + if not ret: + ret = call(xset.format('s off'), shell=True) + elif cmd == 'reset': + ret = call(xset.format('s reset'), shell=True) + elif cmd in ['on', 'off', 'standby', 'suspend']: + b4 = displayControl('stat') + ret = call(xset.format('dpms force %s' % cmd), shell=True) + if not ret: + curr = displayControl('stat') + sysvals.vprint('Display Switched: %s -> %s' % (b4, curr)) + if curr != cmd: + sysvals.vprint('WARNING: Display failed to change to %s' % cmd) + if ret: + sysvals.vprint('WARNING: Display failed to change to %s with xset' % cmd) + return ret + elif cmd == 'stat': + fp = Popen(xset.format('q').split(' '), stdout=PIPE).stdout + ret = 'unknown' + for line in fp: + m = re.match('[\s]*Monitor is (?P<m>.*)', line) + if(m and len(m.group('m')) >= 2): + out = m.group('m').lower() + ret = out[3:] if out[0:2] == 'in' else out + break + fp.close() + return ret + # Function: getFPDT # Description: # Read the acpi bios tables and pull out FPDT, the firmware data @@ -5055,18 +5150,19 @@ def getFPDT(output): table = struct.unpack('4sIBB6s8sI4sI', buf[0:36]) if(output): - print('') - print('Firmware Performance Data Table (%s)' % table[0]) - print(' Signature : %s' % table[0]) - print(' Table Length : %u' % table[1]) - print(' Revision : %u' % table[2]) - print(' Checksum : 0x%x' % table[3]) - print(' OEM ID : %s' % table[4]) - print(' OEM Table ID : %s' % table[5]) - print(' OEM Revision : %u' % table[6]) - print(' Creator ID : %s' % table[7]) - print(' Creator Revision : 0x%x' % table[8]) - print('') + pprint('\n'\ + 'Firmware Performance Data Table (%s)\n'\ + ' Signature : %s\n'\ + ' Table Length : %u\n'\ + ' Revision : %u\n'\ + ' Checksum : 0x%x\n'\ + ' OEM ID : %s\n'\ + ' OEM Table ID : %s\n'\ + ' OEM Revision : %u\n'\ + ' Creator ID : %s\n'\ + ' Creator Revision : 0x%x\n'\ + '' % (table[0], table[0], table[1], table[2], table[3], + table[4], table[5], table[6], table[7], table[8])) if(table[0] != 'FPDT'): if(output): @@ -5092,22 +5188,24 @@ def getFPDT(output): first = fp.read(8) except: if(output): - print('Bad address 0x%x in %s' % (addr, sysvals.mempath)) + pprint('Bad address 0x%x in %s' % (addr, sysvals.mempath)) return [0, 0] rechead = struct.unpack('4sI', first) recdata = fp.read(rechead[1]-8) if(rechead[0] == 'FBPT'): record = struct.unpack('HBBIQQQQQ', recdata) if(output): - print('%s (%s)' % (rectype[header[0]], rechead[0])) - print(' Reset END : %u ns' % record[4]) - print(' OS Loader LoadImage Start : %u ns' % record[5]) - print(' OS Loader StartImage Start : %u ns' % record[6]) - print(' ExitBootServices Entry : %u ns' % record[7]) - print(' ExitBootServices Exit : %u ns' % record[8]) + pprint('%s (%s)\n'\ + ' Reset END : %u ns\n'\ + ' OS Loader LoadImage Start : %u ns\n'\ + ' OS Loader StartImage Start : %u ns\n'\ + ' ExitBootServices Entry : %u ns\n'\ + ' ExitBootServices Exit : %u ns'\ + '' % (rectype[header[0]], rechead[0], record[4], record[5], + record[6], record[7], record[8])) elif(rechead[0] == 'S3PT'): if(output): - print('%s (%s)' % (rectype[header[0]], rechead[0])) + pprint('%s (%s)' % (rectype[header[0]], rechead[0])) j = 0 while(j < len(recdata)): prechead = struct.unpack('HBB', recdata[j:j+4]) @@ -5117,27 +5215,26 @@ def getFPDT(output): record = struct.unpack('IIQQ', recdata[j:j+prechead[1]]) fwData[1] = record[2] if(output): - print(' %s' % prectype[prechead[0]]) - print(' Resume Count : %u' % \ - record[1]) - print(' FullResume : %u ns' % \ - record[2]) - print(' AverageResume : %u ns' % \ - record[3]) + pprint(' %s\n'\ + ' Resume Count : %u\n'\ + ' FullResume : %u ns\n'\ + ' AverageResume : %u ns'\ + '' % (prectype[prechead[0]], record[1], + record[2], record[3])) elif(prechead[0] == 1): record = struct.unpack('QQ', recdata[j+4:j+prechead[1]]) fwData[0] = record[1] - record[0] if(output): - print(' %s' % prectype[prechead[0]]) - print(' SuspendStart : %u ns' % \ - record[0]) - print(' SuspendEnd : %u ns' % \ - record[1]) - print(' SuspendTime : %u ns' % \ - fwData[0]) + pprint(' %s\n'\ + ' SuspendStart : %u ns\n'\ + ' SuspendEnd : %u ns\n'\ + ' SuspendTime : %u ns'\ + '' % (prectype[prechead[0]], record[0], + record[1], fwData[0])) + j += prechead[1] if(output): - print('') + pprint('') i += header[1] fp.close() return fwData @@ -5149,26 +5246,26 @@ def getFPDT(output): # Output: # True if the test will work, False if not def statusCheck(probecheck=False): - status = True + status = '' - print('Checking this system (%s)...' % platform.node()) + pprint('Checking this system (%s)...' % platform.node()) # check we have root access res = sysvals.colorText('NO (No features of this tool will work!)') if(sysvals.rootCheck(False)): res = 'YES' - print(' have root access: %s' % res) + pprint(' have root access: %s' % res) if(res != 'YES'): - print(' Try running this script with sudo') - return False + pprint(' Try running this script with sudo') + return 'missing root access' # check sysfs is mounted res = sysvals.colorText('NO (No features of this tool will work!)') if(os.path.exists(sysvals.powerfile)): res = 'YES' - print(' is sysfs mounted: %s' % res) + pprint(' is sysfs mounted: %s' % res) if(res != 'YES'): - return False + return 'sysfs is missing' # check target mode is a valid mode if sysvals.suspendmode != 'command': @@ -5177,11 +5274,11 @@ def statusCheck(probecheck=False): if(sysvals.suspendmode in modes): res = 'YES' else: - status = False - print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res)) + status = '%s mode is not supported' % sysvals.suspendmode + pprint(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res)) if(res == 'NO'): - print(' valid power modes are: %s' % modes) - print(' please choose one with -m') + pprint(' valid power modes are: %s' % modes) + pprint(' please choose one with -m') # check if ftrace is available res = sysvals.colorText('NO') @@ -5189,8 +5286,8 @@ def statusCheck(probecheck=False): if(ftgood): res = 'YES' elif(sysvals.usecallgraph): - status = False - print(' is ftrace supported: %s' % res) + status = 'ftrace is not properly supported' + pprint(' is ftrace supported: %s' % res) # check if kprobes are available res = sysvals.colorText('NO') @@ -5199,7 +5296,7 @@ def statusCheck(probecheck=False): res = 'YES' else: sysvals.usedevsrc = False - print(' are kprobes supported: %s' % res) + pprint(' are kprobes supported: %s' % res) # what data source are we using res = 'DMESG' @@ -5210,15 +5307,15 @@ def statusCheck(probecheck=False): sysvals.usetraceevents = False if(sysvals.usetraceevents): res = 'FTRACE (all trace events found)' - print(' timeline data source: %s' % res) + pprint(' timeline data source: %s' % res) # check if rtcwake res = sysvals.colorText('NO') if(sysvals.rtcpath != ''): res = 'YES' elif(sysvals.rtcwake): - status = False - print(' is rtcwake supported: %s' % res) + status = 'rtcwake is not properly supported' + pprint(' is rtcwake supported: %s' % res) if not probecheck: return status @@ -5243,9 +5340,9 @@ def statusCheck(probecheck=False): def doError(msg, help=False): if(help == True): printHelp() - print('ERROR: %s\n') % msg + pprint('ERROR: %s\n' % msg) sysvals.outputResult({'error':msg}) - sys.exit() + sys.exit(1) # Function: getArgInt # Description: @@ -5286,7 +5383,7 @@ def getArgFloat(name, args, min, max, main=True): return val def processData(live=False): - print('PROCESSING DATA') + pprint('PROCESSING DATA') error = '' if(sysvals.usetraceevents): testruns, error = parseTraceLog(live) @@ -5301,16 +5398,22 @@ def processData(live=False): appendIncompleteTraceLog(testruns) sysvals.vprint('Command:\n %s' % sysvals.cmdline) for data in testruns: + if data.battery: + a1, c1, a2, c2 = data.battery + s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ + (a1, int(c1), a2, int(c2)) + sysvals.vprint(s) data.printDetails() if sysvals.cgdump: for data in testruns: data.debugPrint() - sys.exit() + sys.exit(0) if len(testruns) < 1: + pprint('ERROR: Not enough test data to build a timeline') return (testruns, {'error': 'timeline generation failed'}) sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile) createHTML(testruns, error) - print('DONE') + pprint('DONE') data = testruns[0] stamp = data.stamp stamp['suspend'], stamp['resume'] = data.getTimeValues() @@ -5335,6 +5438,7 @@ def rerunTest(): elif not os.access(sysvals.htmlfile, os.W_OK): doError('missing permission to write to %s' % sysvals.htmlfile) testruns, stamp = processData(False) + sysvals.logmsg = '' return stamp # Function: runTest @@ -5349,13 +5453,16 @@ def runTest(n=0): executeSuspend() sysvals.cleanupFtrace() if sysvals.skiphtml: - sysvals.sudouser(sysvals.testdir) + sysvals.sudoUserchown(sysvals.testdir) return testruns, stamp = processData(True) for data in testruns: del data - sysvals.sudouser(sysvals.testdir) + sysvals.sudoUserchown(sysvals.testdir) sysvals.outputResult(stamp, n) + if 'error' in stamp: + return 2 + return 0 def find_in_html(html, start, end, firstonly=True): n, out = 0, [] @@ -5380,15 +5487,87 @@ def find_in_html(html, start, end, firstonly=True): return '' return out +def data_from_html(file, outpath, devlist=False): + html = open(file, 'r').read() + suspend = find_in_html(html, 'Kernel Suspend', 'ms') + resume = find_in_html(html, 'Kernel Resume', 'ms') + line = find_in_html(html, '<div class="stamp">', '</div>') + stmp = line.split() + if not suspend or not resume or len(stmp) != 8: + return False + try: + dt = datetime.strptime(' '.join(stmp[3:]), '%B %d %Y, %I:%M:%S %p') + except: + return False + tstr = dt.strftime('%Y/%m/%d %H:%M:%S') + error = find_in_html(html, '<table class="testfail"><tr><td>', '</td>') + if error: + m = re.match('[a-z]* failed in (?P<p>[a-z0-9_]*) phase', error) + if m: + result = 'fail in %s' % m.group('p') + else: + result = 'fail' + else: + result = 'pass' + ilist = [] + e = find_in_html(html, 'class="err"[\w=":;\.%\- ]*>', '→</div>', False) + for i in list(set(e)): + ilist.append('%sx%d' % (i, e.count(i)) if e.count(i) > 1 else i) + low = find_in_html(html, 'freeze time: <b>', ' ms</b>') + if low and '|' in low: + ilist.append('FREEZEx%d' % len(low.split('|'))) + devices = dict() + for line in html.split('\n'): + m = re.match(' *<div id=\"[a,0-9]*\" *title=\"(?P<title>.*)\" class=\"thread.*', line) + if not m or 'thread kth' in line or 'thread sec' in line: + continue + m = re.match('(?P<n>.*) \((?P<t>[0-9,\.]*) ms\) (?P<p>.*)', m.group('title')) + if not m: + continue + name, time, phase = m.group('n'), m.group('t'), m.group('p') + if ' async' in name or ' sync' in name: + name = ' '.join(name.split(' ')[:-1]) + d = phase.split('_')[0] + if d not in devices: + devices[d] = dict() + if name not in devices[d]: + devices[d][name] = 0.0 + devices[d][name] += float(time) + worst = {'suspend': {'name':'', 'time': 0.0}, + 'resume': {'name':'', 'time': 0.0}} + for d in devices: + if d not in worst: + worst[d] = dict() + dev = devices[d] + if len(dev.keys()) > 0: + n = sorted(dev, key=dev.get, reverse=True)[0] + worst[d]['name'], worst[d]['time'] = n, dev[n] + data = { + 'mode': stmp[2], + 'host': stmp[0], + 'kernel': stmp[1], + 'time': tstr, + 'result': result, + 'issues': ' '.join(ilist), + 'suspend': suspend, + 'resume': resume, + 'sus_worst': worst['suspend']['name'], + 'sus_worsttime': worst['suspend']['time'], + 'res_worst': worst['resume']['name'], + 'res_worsttime': worst['resume']['time'], + 'url': os.path.relpath(file, outpath), + } + if devlist: + data['devlist'] = devices + return data + # Function: runSummary # Description: # create a summary of tests in a sub-directory def runSummary(subdir, local=True, genhtml=False): inpath = os.path.abspath(subdir) - outpath = inpath - if local: - outpath = os.path.abspath('.') - print('Generating a summary of folder "%s"' % inpath) + outpath = os.path.abspath('.') if local else inpath + pprint('Generating a summary of folder "%s"' % inpath) if genhtml: for dirname, dirnames, filenames in os.walk(subdir): sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' @@ -5400,49 +5579,30 @@ def runSummary(subdir, local=True, genhtml=False): sysvals.setOutputFile() if sysvals.ftracefile and sysvals.htmlfile and \ not os.path.exists(sysvals.htmlfile): - print('FTRACE: %s' % sysvals.ftracefile) + pprint('FTRACE: %s' % sysvals.ftracefile) if sysvals.dmesgfile: - print('DMESG : %s' % sysvals.dmesgfile) + pprint('DMESG : %s' % sysvals.dmesgfile) rerunTest() testruns = [] + desc = {'host':[],'mode':[],'kernel':[]} for dirname, dirnames, filenames in os.walk(subdir): for filename in filenames: if(not re.match('.*.html', filename)): continue - file = os.path.join(dirname, filename) - html = open(file, 'r').read() - suspend = find_in_html(html, 'Kernel Suspend', 'ms') - resume = find_in_html(html, 'Kernel Resume', 'ms') - line = find_in_html(html, '<div class="stamp">', '</div>') - stmp = line.split() - if not suspend or not resume or len(stmp) != 8: + data = data_from_html(os.path.join(dirname, filename), outpath) + if(not data): continue - try: - dt = datetime.strptime(' '.join(stmp[3:]), '%B %d %Y, %I:%M:%S %p') - except: - continue - tstr = dt.strftime('%Y/%m/%d %H:%M:%S') - error = find_in_html(html, '<table class="testfail"><tr><td>', '</td>') - result = 'fail' if error else 'pass' - ilist = [] - e = find_in_html(html, 'class="err"[\w=":;\.%\- ]*>', '→</div>', False) - for i in list(set(e)): - ilist.append('%sx%d' % (i, e.count(i)) if e.count(i) > 1 else i) - data = { - 'mode': stmp[2], - 'host': stmp[0], - 'kernel': stmp[1], - 'time': tstr, - 'result': result, - 'issues': ','.join(ilist), - 'suspend': suspend, - 'resume': resume, - 'url': os.path.relpath(file, outpath), - } testruns.append(data) + for key in desc: + if data[key] not in desc[key]: + desc[key].append(data[key]) outfile = os.path.join(outpath, 'summary.html') - print('Summary file: %s' % outfile) - createHTMLSummarySimple(testruns, outfile, inpath) + pprint('Summary file: %s' % outfile) + if len(desc['host']) == len(desc['mode']) == len(desc['kernel']) == 1: + title = '%s %s %s' % (desc['host'][0], desc['kernel'][0], desc['mode'][0]) + else: + title = inpath + createHTMLSummarySimple(testruns, outfile, title) # Function: checkArgBool # Description: @@ -5499,13 +5659,10 @@ def configFromFile(file): else: doError('invalid value --> (%s: %s), use "enable/disable"' % (option, value), True) elif(option == 'display'): - if value in switchvalues: - if value in switchoff: - sysvals.display = -1 - else: - sysvals.display = 1 - else: - doError('invalid value --> (%s: %s), use "on/off"' % (option, value), True) + disopt = ['on', 'off', 'standby', 'suspend'] + if value not in disopt: + doError('invalid value --> (%s: %s), use %s' % (option, value, disopt), True) + sysvals.display = value elif(option == 'gzip'): sysvals.gzip = checkArgBool(option, value) elif(option == 'cgfilter'): @@ -5521,9 +5678,9 @@ def configFromFile(file): sysvals.cgtest = getArgInt('cgtest', value, 0, 1, False) elif(option == 'cgphase'): d = Data(0) - if value not in d.phases: + if value not in d.sortedPhases(): doError('invalid phase --> (%s: %s), valid phases are %s'\ - % (option, value, d.phases), True) + % (option, value, d.sortedPhases()), True) sysvals.cgphase = value elif(option == 'fadd'): file = sysvals.configFile(value) @@ -5660,84 +5817,86 @@ def configFromFile(file): # Description: # print out the help text def printHelp(): - print('') - print('%s v%s' % (sysvals.title, sysvals.version)) - print('Usage: sudo sleepgraph <options> <commands>') - print('') - print('Description:') - print(' This tool is designed to assist kernel and OS developers in optimizing') - print(' their linux stack\'s suspend/resume time. Using a kernel image built') - print(' with a few extra options enabled, the tool will execute a suspend and') - print(' capture dmesg and ftrace data until resume is complete. This data is') - print(' transformed into a device timeline and an optional callgraph to give') - print(' a detailed view of which devices/subsystems are taking the most') - print(' time in suspend/resume.') - print('') - print(' If no specific command is given, the default behavior is to initiate') - print(' a suspend/resume and capture the dmesg/ftrace output as an html timeline.') - print('') - print(' Generates output files in subdirectory: suspend-yymmdd-HHMMSS') - print(' HTML output: <hostname>_<mode>.html') - print(' raw dmesg output: <hostname>_<mode>_dmesg.txt') - print(' raw ftrace output: <hostname>_<mode>_ftrace.txt') - print('') - print('Options:') - print(' -h Print this help text') - print(' -v Print the current tool version') - print(' -config fn Pull arguments and config options from file fn') - print(' -verbose Print extra information during execution and analysis') - print(' -m mode Mode to initiate for suspend (default: %s)') % (sysvals.suspendmode) - print(' -o name Overrides the output subdirectory name when running a new test') - print(' default: suspend-{date}-{time}') - print(' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)') - print(' -addlogs Add the dmesg and ftrace logs to the html output') - print(' -srgap Add a visible gap in the timeline between sus/res (default: disabled)') - print(' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)') - print(' -result fn Export a results table to a text file for parsing.') - print(' [testprep]') - print(' -sync Sync the filesystems before starting the test') - print(' -rs on/off Enable/disable runtime suspend for all devices, restore all after test') - print(' -display on/off Turn the display on or off for the test') - print(' [advanced]') - print(' -gzip Gzip the trace and dmesg logs to save space') - print(' -cmd {s} Run the timeline over a custom command, e.g. "sync -d"') - print(' -proc Add usermode process info into the timeline (default: disabled)') - print(' -dev Add kernel function calls and threads to the timeline (default: disabled)') - print(' -x2 Run two suspend/resumes back to back (default: disabled)') - print(' -x2delay t Include t ms delay between multiple test runs (default: 0 ms)') - print(' -predelay t Include t ms delay before 1st suspend (default: 0 ms)') - print(' -postdelay t Include t ms delay after last resume (default: 0 ms)') - print(' -mindev ms Discard all device blocks shorter than ms milliseconds (e.g. 0.001 for us)') - print(' -multi n d Execute <n> consecutive tests at <d> seconds intervals. The outputs will') - print(' be created in a new subdirectory with a summary page.') - print(' [debug]') - print(' -f Use ftrace to create device callgraphs (default: disabled)') - print(' -maxdepth N limit the callgraph data to N call levels (default: 0=all)') - print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') - print(' -fadd file Add functions to be graphed in the timeline from a list in a text file') - print(' -filter "d1,d2,..." Filter out all but this comma-delimited list of device names') - print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') - print(' -cgphase P Only show callgraph data for phase P (e.g. suspend_late)') - print(' -cgtest N Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)') - print(' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)') - print(' -cgfilter S Filter the callgraph output in the timeline') - print(' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)') - print(' -bufsize N Set trace buffer size to N kilo-bytes (default: all of free memory)') - print('') - print('Other commands:') - print(' -modes List available suspend modes') - print(' -status Test to see if the system is enabled to run this tool') - print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table') - print(' -battery Print out battery info (if available)') - print(' -sysinfo Print out system info extracted from BIOS') - print(' -devinfo Print out the pm settings of all devices which support runtime suspend') - print(' -flist Print the list of functions currently being captured in ftrace') - print(' -flistall Print all functions capable of being captured in ftrace') - print(' -summary dir Create a summary of tests in this dir [-genhtml builds missing html]') - print(' [redo]') - print(' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)') - print(' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)') - print('') + pprint('\n%s v%s\n'\ + 'Usage: sudo sleepgraph <options> <commands>\n'\ + '\n'\ + 'Description:\n'\ + ' This tool is designed to assist kernel and OS developers in optimizing\n'\ + ' their linux stack\'s suspend/resume time. Using a kernel image built\n'\ + ' with a few extra options enabled, the tool will execute a suspend and\n'\ + ' capture dmesg and ftrace data until resume is complete. This data is\n'\ + ' transformed into a device timeline and an optional callgraph to give\n'\ + ' a detailed view of which devices/subsystems are taking the most\n'\ + ' time in suspend/resume.\n'\ + '\n'\ + ' If no specific command is given, the default behavior is to initiate\n'\ + ' a suspend/resume and capture the dmesg/ftrace output as an html timeline.\n'\ + '\n'\ + ' Generates output files in subdirectory: suspend-yymmdd-HHMMSS\n'\ + ' HTML output: <hostname>_<mode>.html\n'\ + ' raw dmesg output: <hostname>_<mode>_dmesg.txt\n'\ + ' raw ftrace output: <hostname>_<mode>_ftrace.txt\n'\ + '\n'\ + 'Options:\n'\ + ' -h Print this help text\n'\ + ' -v Print the current tool version\n'\ + ' -config fn Pull arguments and config options from file fn\n'\ + ' -verbose Print extra information during execution and analysis\n'\ + ' -m mode Mode to initiate for suspend (default: %s)\n'\ + ' -o name Overrides the output subdirectory name when running a new test\n'\ + ' default: suspend-{date}-{time}\n'\ + ' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)\n'\ + ' -addlogs Add the dmesg and ftrace logs to the html output\n'\ + ' -srgap Add a visible gap in the timeline between sus/res (default: disabled)\n'\ + ' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\ + ' -result fn Export a results table to a text file for parsing.\n'\ + ' [testprep]\n'\ + ' -sync Sync the filesystems before starting the test\n'\ + ' -rs on/off Enable/disable runtime suspend for all devices, restore all after test\n'\ + ' -display m Change the display mode to m for the test (on/off/standby/suspend)\n'\ + ' [advanced]\n'\ + ' -gzip Gzip the trace and dmesg logs to save space\n'\ + ' -cmd {s} Run the timeline over a custom command, e.g. "sync -d"\n'\ + ' -proc Add usermode process info into the timeline (default: disabled)\n'\ + ' -dev Add kernel function calls and threads to the timeline (default: disabled)\n'\ + ' -x2 Run two suspend/resumes back to back (default: disabled)\n'\ + ' -x2delay t Include t ms delay between multiple test runs (default: 0 ms)\n'\ + ' -predelay t Include t ms delay before 1st suspend (default: 0 ms)\n'\ + ' -postdelay t Include t ms delay after last resume (default: 0 ms)\n'\ + ' -mindev ms Discard all device blocks shorter than ms milliseconds (e.g. 0.001 for us)\n'\ + ' -multi n d Execute <n> consecutive tests at <d> seconds intervals. The outputs will\n'\ + ' be created in a new subdirectory with a summary page.\n'\ + ' [debug]\n'\ + ' -f Use ftrace to create device callgraphs (default: disabled)\n'\ + ' -maxdepth N limit the callgraph data to N call levels (default: 0=all)\n'\ + ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ + ' -fadd file Add functions to be graphed in the timeline from a list in a text file\n'\ + ' -filter "d1,d2,..." Filter out all but this comma-delimited list of device names\n'\ + ' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\ + ' -cgphase P Only show callgraph data for phase P (e.g. suspend_late)\n'\ + ' -cgtest N Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)\n'\ + ' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)\n'\ + ' -cgfilter S Filter the callgraph output in the timeline\n'\ + ' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\ + ' -bufsize N Set trace buffer size to N kilo-bytes (default: all of free memory)\n'\ + ' -devdump Print out all the raw device data for each phase\n'\ + ' -cgdump Print out all the raw callgraph data\n'\ + '\n'\ + 'Other commands:\n'\ + ' -modes List available suspend modes\n'\ + ' -status Test to see if the system is enabled to run this tool\n'\ + ' -fpdt Print out the contents of the ACPI Firmware Performance Data Table\n'\ + ' -battery Print out battery info (if available)\n'\ + ' -x<mode> Test xset by toggling the given mode (on/off/standby/suspend)\n'\ + ' -sysinfo Print out system info extracted from BIOS\n'\ + ' -devinfo Print out the pm settings of all devices which support runtime suspend\n'\ + ' -flist Print the list of functions currently being captured in ftrace\n'\ + ' -flistall Print all functions capable of being captured in ftrace\n'\ + ' -summary dir Create a summary of tests in this dir [-genhtml builds missing html]\n'\ + ' [redo]\n'\ + ' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)\n'\ + ' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)\n'\ + '' % (sysvals.title, sysvals.version, sysvals.suspendmode)) return True # ----------------- MAIN -------------------- @@ -5745,7 +5904,9 @@ def printHelp(): if __name__ == '__main__': genhtml = False cmd = '' - simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', '-devinfo', '-status', '-battery'] + simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', + '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby', + '-xsuspend', '-xinit', '-xreset', '-xstat'] if '-f' in sys.argv: sysvals.cgskip = sysvals.configFile('cgskip.txt') # loop through the command line arguments @@ -5763,10 +5924,10 @@ if __name__ == '__main__': cmd = arg[1:] elif(arg == '-h'): printHelp() - sys.exit() + sys.exit(0) elif(arg == '-v'): - print("Version %s" % sysvals.version) - sys.exit() + pprint("Version %s" % sysvals.version) + sys.exit(0) elif(arg == '-x2'): sysvals.execcount = 2 elif(arg == '-x2delay'): @@ -5781,10 +5942,16 @@ if __name__ == '__main__': sysvals.skiphtml = True elif(arg == '-cgdump'): sysvals.cgdump = True + elif(arg == '-devdump'): + sysvals.devdump = True elif(arg == '-genhtml'): genhtml = True elif(arg == '-addlogs'): sysvals.dmesglog = sysvals.ftracelog = True + elif(arg == '-addlogdmesg'): + sysvals.dmesglog = True + elif(arg == '-addlogftrace'): + sysvals.ftracelog = True elif(arg == '-verbose'): sysvals.verbose = True elif(arg == '-proc'): @@ -5811,14 +5978,11 @@ if __name__ == '__main__': try: val = args.next() except: - doError('-display requires "on" or "off"', True) - if val.lower() in switchvalues: - if val.lower() in switchoff: - sysvals.display = -1 - else: - sysvals.display = 1 - else: - doError('invalid option: %s, use "on/off"' % val, True) + doError('-display requires an mode value', True) + disopt = ['on', 'off', 'standby', 'suspend'] + if val.lower() not in disopt: + doError('valid display mode values are %s' % disopt, True) + sysvals.display = val.lower() elif(arg == '-maxdepth'): sysvals.max_graph_depth = getArgInt('-maxdepth', args, 0, 1000) elif(arg == '-rtcwake'): @@ -5847,9 +6011,9 @@ if __name__ == '__main__': except: doError('No phase name supplied', True) d = Data(0) - if val not in d.phases: + if val not in d.phasedef: doError('invalid phase --> (%s: %s), valid phases are %s'\ - % (arg, val, d.phases), True) + % (arg, val, d.phasedef.keys()), True) sysvals.cgphase = val elif(arg == '-cgfilter'): try: @@ -5951,6 +6115,7 @@ if __name__ == '__main__': except: doError('No result file supplied', True) sysvals.result = val + sysvals.signalHandlerInit() else: doError('Invalid argument: '+arg, True) @@ -5975,12 +6140,20 @@ if __name__ == '__main__': # just run a utility command and exit if(cmd != ''): + ret = 0 if(cmd == 'status'): - statusCheck(True) + if not statusCheck(True): + ret = 1 elif(cmd == 'fpdt'): - getFPDT(True) + if not getFPDT(True): + ret = 1 elif(cmd == 'battery'): - print 'AC Connect: %s\nCharge: %d' % getBattery() + out = getBattery() + if out: + pprint('AC Connect : %s\nBattery Charge: %d' % out) + else: + pprint('no battery found') + ret = 1 elif(cmd == 'sysinfo'): sysvals.printSystemInfo(True) elif(cmd == 'devinfo'): @@ -5993,25 +6166,28 @@ if __name__ == '__main__': sysvals.getFtraceFilterFunctions(False) elif(cmd == 'summary'): runSummary(sysvals.outdir, True, genhtml) - sys.exit() + elif(cmd in ['xon', 'xoff', 'xstandby', 'xsuspend', 'xinit', 'xreset']): + sysvals.verbose = True + ret = displayControl(cmd[1:]) + elif(cmd == 'xstat'): + pprint('Display Status: %s' % displayControl('stat').upper()) + sys.exit(ret) # if instructed, re-analyze existing data files if(sysvals.notestrun): stamp = rerunTest() sysvals.outputResult(stamp) - sys.exit() + sys.exit(0) # verify that we can run a test - if(not statusCheck()): - doError('Check FAILED, aborting the test run!') + error = statusCheck() + if(error): + doError(error) - # extract mem modes and convert + # extract mem/disk extra modes and convert mode = sysvals.suspendmode - if 'mem' == mode[:3]: - if '-' in mode: - memmode = mode.split('-')[-1] - else: - memmode = 'deep' + if mode.startswith('mem'): + memmode = mode.split('-', 1)[-1] if '-' in mode else 'deep' if memmode == 'shallow': mode = 'standby' elif memmode == 's2idle': @@ -6020,13 +6196,16 @@ if __name__ == '__main__': mode = 'mem' sysvals.memmode = memmode sysvals.suspendmode = mode + if mode.startswith('disk-'): + sysvals.diskmode = mode.split('-', 1)[-1] + sysvals.suspendmode = 'disk' sysvals.systemInfo(dmidecode(sysvals.mempath)) setRuntimeSuspend(True) if sysvals.display: - call('xset -d :0.0 dpms 0 0 0', shell=True) - call('xset -d :0.0 s off', shell=True) + displayControl('init') + ret = 0 if sysvals.multitest['run']: # run multiple tests in a separate subdirectory if not sysvals.outdir: @@ -6036,22 +6215,23 @@ if __name__ == '__main__': os.mkdir(sysvals.outdir) for i in range(sysvals.multitest['count']): if(i != 0): - print('Waiting %d seconds...' % (sysvals.multitest['delay'])) + pprint('Waiting %d seconds...' % (sysvals.multitest['delay'])) time.sleep(sysvals.multitest['delay']) - print('TEST (%d/%d) START' % (i+1, sysvals.multitest['count'])) + pprint('TEST (%d/%d) START' % (i+1, sysvals.multitest['count'])) fmt = 'suspend-%y%m%d-%H%M%S' sysvals.testdir = os.path.join(sysvals.outdir, datetime.now().strftime(fmt)) - runTest(i+1) - print('TEST (%d/%d) COMPLETE' % (i+1, sysvals.multitest['count'])) + ret = runTest(i+1) + pprint('TEST (%d/%d) COMPLETE' % (i+1, sysvals.multitest['count'])) sysvals.logmsg = '' if not sysvals.skiphtml: runSummary(sysvals.outdir, False, False) - sysvals.sudouser(sysvals.outdir) + sysvals.sudoUserchown(sysvals.outdir) else: if sysvals.outdir: sysvals.testdir = sysvals.outdir # run the test in the current directory - runTest() + ret = runTest() if sysvals.display: - call('xset -d :0.0 s reset', shell=True) + displayControl('reset') setRuntimeSuspend(False) + sys.exit(ret) diff --git a/tools/power/x86/turbostat/turbostat.8 b/tools/power/x86/turbostat/turbostat.8 index d39e4ff7d0bf..a6db83a88e85 100644 --- a/tools/power/x86/turbostat/turbostat.8 +++ b/tools/power/x86/turbostat/turbostat.8 @@ -106,7 +106,7 @@ The system configuration dump (if --quiet is not used) is followed by statistics \fBC1%, C2%, C3%\fP The residency percentage that Linux requested C1, C2, C3.... The system summary is the average of all CPUs in the system. Note that these are software, reflecting what was requested. The hardware counters reflect what was actually achieved. \fBCPU%c1, CPU%c3, CPU%c6, CPU%c7\fP show the percentage residency in hardware core idle states. These numbers are from hardware residency counters. \fBCoreTmp\fP Degrees Celsius reported by the per-core Digital Thermal Sensor. -\fBPkgTtmp\fP Degrees Celsius reported by the per-package Package Thermal Monitor. +\fBPkgTmp\fP Degrees Celsius reported by the per-package Package Thermal Monitor. \fBGFX%rc6\fP The percentage of time the GPU is in the "render C6" state, rc6, during the measurement interval. From /sys/class/drm/card0/power/rc6_residency_ms. \fBGFXMHz\fP Instantaneous snapshot of what sysfs presents at the end of the measurement interval. From /sys/class/graphics/fb0/device/drm/card0/gt_cur_freq_mhz. \fBPkg%pc2, Pkg%pc3, Pkg%pc6, Pkg%pc7\fP percentage residency in hardware package idle states. These numbers are from hardware residency counters. @@ -114,7 +114,7 @@ The system configuration dump (if --quiet is not used) is followed by statistics \fBCorWatt\fP Watts consumed by the core part of the package. \fBGFXWatt\fP Watts consumed by the Graphics part of the package -- available only on client processors. \fBRAMWatt\fP Watts consumed by the DRAM DIMMS -- available only on server processors. -\fBPKG_%\fP percent of the interval that RAPL throttling was active on the Package. +\fBPKG_%\fP percent of the interval that RAPL throttling was active on the Package. Note that the system summary is the sum of the package throttling time, and thus may be higher than 100% on a multi-package system. Note that the meaning of this field is model specific. For example, some hardware increments this counter when RAPL responds to thermal limits, but does not increment this counter when RAPL responds to power limits. Comparing PkgWatt and PkgTmp to system limits is necessary. \fBRAM_%\fP percent of the interval that RAPL throttling was active on DRAM. .fi .SH TOO MUCH INFORMATION EXAMPLE diff --git a/tools/power/x86/turbostat/turbostat.c b/tools/power/x86/turbostat/turbostat.c index 4d14bbbf9b63..328f62e6ea02 100644 --- a/tools/power/x86/turbostat/turbostat.c +++ b/tools/power/x86/turbostat/turbostat.c @@ -1163,9 +1163,7 @@ void format_all_counters(struct thread_data *t, struct core_data *c, struct pkg_ if (!printed || !summary_only) print_header("\t"); - if (topo.num_cpus > 1) - format_counters(&average.threads, &average.cores, - &average.packages); + format_counters(&average.threads, &average.cores, &average.packages); printed = 1; @@ -1692,7 +1690,7 @@ void get_apic_id(struct thread_data *t) t->x2apic_id = edx; if (debug && (t->apic_id != t->x2apic_id)) - fprintf(stderr, "cpu%d: apic 0x%x x2apic 0x%x\n", t->cpu_id, t->apic_id, t->x2apic_id); + fprintf(outf, "cpu%d: apic 0x%x x2apic 0x%x\n", t->cpu_id, t->apic_id, t->x2apic_id); } /* @@ -2084,7 +2082,7 @@ int has_turbo_ratio_group_limits(int family, int model) switch (model) { case INTEL_FAM6_ATOM_GOLDMONT: case INTEL_FAM6_SKYLAKE_X: - case INTEL_FAM6_ATOM_DENVERTON: + case INTEL_FAM6_ATOM_GOLDMONT_X: return 1; } return 0; @@ -2473,55 +2471,43 @@ int get_core_id(int cpu) void set_node_data(void) { - char path[80]; - FILE *filep; - int pkg, node, cpu; - - struct pkg_node_info { - int count; - int min; - } *pni; - - pni = calloc(topo.num_packages, sizeof(struct pkg_node_info)); - if (!pni) - err(1, "calloc pkg_node_count"); - - for (pkg = 0; pkg < topo.num_packages; pkg++) - pni[pkg].min = topo.num_cpus; - - for (node = 0; node <= topo.max_node_num; node++) { - /* find the "first" cpu in the node */ - sprintf(path, "/sys/bus/node/devices/node%d/cpulist", node); - filep = fopen(path, "r"); - if (!filep) - continue; - fscanf(filep, "%d", &cpu); - fclose(filep); - - pkg = cpus[cpu].physical_package_id; - pni[pkg].count++; - - if (node < pni[pkg].min) - pni[pkg].min = node; - } - - for (pkg = 0; pkg < topo.num_packages; pkg++) - if (pni[pkg].count > topo.nodes_per_pkg) - topo.nodes_per_pkg = pni[0].count; - - /* Fake 1 node per pkg for machines that don't - * expose nodes and thus avoid -nan results - */ - if (topo.nodes_per_pkg == 0) - topo.nodes_per_pkg = 1; - - for (cpu = 0; cpu < topo.num_cpus; cpu++) { - pkg = cpus[cpu].physical_package_id; - node = cpus[cpu].physical_node_id; - cpus[cpu].logical_node_id = node - pni[pkg].min; + int pkg, node, lnode, cpu, cpux; + int cpu_count; + + /* initialize logical_node_id */ + for (cpu = 0; cpu <= topo.max_cpu_num; ++cpu) + cpus[cpu].logical_node_id = -1; + + cpu_count = 0; + for (pkg = 0; pkg < topo.num_packages; pkg++) { + lnode = 0; + for (cpu = 0; cpu <= topo.max_cpu_num; ++cpu) { + if (cpus[cpu].physical_package_id != pkg) + continue; + /* find a cpu with an unset logical_node_id */ + if (cpus[cpu].logical_node_id != -1) + continue; + cpus[cpu].logical_node_id = lnode; + node = cpus[cpu].physical_node_id; + cpu_count++; + /* + * find all matching cpus on this pkg and set + * the logical_node_id + */ + for (cpux = cpu; cpux <= topo.max_cpu_num; cpux++) { + if ((cpus[cpux].physical_package_id == pkg) && + (cpus[cpux].physical_node_id == node)) { + cpus[cpux].logical_node_id = lnode; + cpu_count++; + } + } + lnode++; + if (lnode > topo.nodes_per_pkg) + topo.nodes_per_pkg = lnode; + } + if (cpu_count >= topo.max_cpu_num) + break; } - free(pni); - } int get_physical_node_id(struct cpu_topology *thiscpu) @@ -3163,9 +3149,9 @@ int probe_nhm_msrs(unsigned int family, unsigned int model) pkg_cstate_limits = skx_pkg_cstate_limits; has_misc_feature_control = 1; break; - case INTEL_FAM6_ATOM_SILVERMONT1: /* BYT */ + case INTEL_FAM6_ATOM_SILVERMONT: /* BYT */ no_MSR_MISC_PWR_MGMT = 1; - case INTEL_FAM6_ATOM_SILVERMONT2: /* AVN */ + case INTEL_FAM6_ATOM_SILVERMONT_X: /* AVN */ pkg_cstate_limits = slv_pkg_cstate_limits; break; case INTEL_FAM6_ATOM_AIRMONT: /* AMT */ @@ -3177,8 +3163,8 @@ int probe_nhm_msrs(unsigned int family, unsigned int model) pkg_cstate_limits = phi_pkg_cstate_limits; break; case INTEL_FAM6_ATOM_GOLDMONT: /* BXT */ - case INTEL_FAM6_ATOM_GEMINI_LAKE: - case INTEL_FAM6_ATOM_DENVERTON: /* DNV */ + case INTEL_FAM6_ATOM_GOLDMONT_PLUS: + case INTEL_FAM6_ATOM_GOLDMONT_X: /* DNV */ pkg_cstate_limits = bxt_pkg_cstate_limits; break; default: @@ -3207,9 +3193,9 @@ int has_slv_msrs(unsigned int family, unsigned int model) return 0; switch (model) { - case INTEL_FAM6_ATOM_SILVERMONT1: - case INTEL_FAM6_ATOM_MERRIFIELD: - case INTEL_FAM6_ATOM_MOOREFIELD: + case INTEL_FAM6_ATOM_SILVERMONT: + case INTEL_FAM6_ATOM_SILVERMONT_MID: + case INTEL_FAM6_ATOM_AIRMONT_MID: return 1; } return 0; @@ -3221,7 +3207,7 @@ int is_dnv(unsigned int family, unsigned int model) return 0; switch (model) { - case INTEL_FAM6_ATOM_DENVERTON: + case INTEL_FAM6_ATOM_GOLDMONT_X: return 1; } return 0; @@ -3738,8 +3724,8 @@ double get_tdp(unsigned int model) return ((msr >> 0) & RAPL_POWER_GRANULARITY) * rapl_power_units; switch (model) { - case INTEL_FAM6_ATOM_SILVERMONT1: - case INTEL_FAM6_ATOM_SILVERMONT2: + case INTEL_FAM6_ATOM_SILVERMONT: + case INTEL_FAM6_ATOM_SILVERMONT_X: return 30.0; default: return 135.0; @@ -3805,7 +3791,7 @@ void rapl_probe(unsigned int family, unsigned int model) } break; case INTEL_FAM6_ATOM_GOLDMONT: /* BXT */ - case INTEL_FAM6_ATOM_GEMINI_LAKE: + case INTEL_FAM6_ATOM_GOLDMONT_PLUS: do_rapl = RAPL_PKG | RAPL_PKG_POWER_INFO; if (rapl_joules) BIC_PRESENT(BIC_Pkg_J); @@ -3864,8 +3850,8 @@ void rapl_probe(unsigned int family, unsigned int model) BIC_PRESENT(BIC_RAMWatt); } break; - case INTEL_FAM6_ATOM_SILVERMONT1: /* BYT */ - case INTEL_FAM6_ATOM_SILVERMONT2: /* AVN */ + case INTEL_FAM6_ATOM_SILVERMONT: /* BYT */ + case INTEL_FAM6_ATOM_SILVERMONT_X: /* AVN */ do_rapl = RAPL_PKG | RAPL_CORES; if (rapl_joules) { BIC_PRESENT(BIC_Pkg_J); @@ -3875,7 +3861,7 @@ void rapl_probe(unsigned int family, unsigned int model) BIC_PRESENT(BIC_CorWatt); } break; - case INTEL_FAM6_ATOM_DENVERTON: /* DNV */ + case INTEL_FAM6_ATOM_GOLDMONT_X: /* DNV */ do_rapl = RAPL_PKG | RAPL_DRAM | RAPL_DRAM_POWER_INFO | RAPL_DRAM_PERF_STATUS | RAPL_PKG_PERF_STATUS | RAPL_PKG_POWER_INFO | RAPL_CORES_ENERGY_STATUS; BIC_PRESENT(BIC_PKG__); BIC_PRESENT(BIC_RAM__); @@ -3898,7 +3884,7 @@ void rapl_probe(unsigned int family, unsigned int model) return; rapl_power_units = 1.0 / (1 << (msr & 0xF)); - if (model == INTEL_FAM6_ATOM_SILVERMONT1) + if (model == INTEL_FAM6_ATOM_SILVERMONT) rapl_energy_units = 1.0 * (1 << (msr >> 8 & 0x1F)) / 1000000; else rapl_energy_units = 1.0 / (1 << (msr >> 8 & 0x1F)); @@ -4155,8 +4141,8 @@ int has_snb_msrs(unsigned int family, unsigned int model) case INTEL_FAM6_CANNONLAKE_MOBILE: /* CNL */ case INTEL_FAM6_SKYLAKE_X: /* SKX */ case INTEL_FAM6_ATOM_GOLDMONT: /* BXT */ - case INTEL_FAM6_ATOM_GEMINI_LAKE: - case INTEL_FAM6_ATOM_DENVERTON: /* DNV */ + case INTEL_FAM6_ATOM_GOLDMONT_PLUS: + case INTEL_FAM6_ATOM_GOLDMONT_X: /* DNV */ return 1; } return 0; @@ -4188,7 +4174,7 @@ int has_hsw_msrs(unsigned int family, unsigned int model) case INTEL_FAM6_KABYLAKE_DESKTOP: /* KBL */ case INTEL_FAM6_CANNONLAKE_MOBILE: /* CNL */ case INTEL_FAM6_ATOM_GOLDMONT: /* BXT */ - case INTEL_FAM6_ATOM_GEMINI_LAKE: + case INTEL_FAM6_ATOM_GOLDMONT_PLUS: return 1; } return 0; @@ -4223,8 +4209,8 @@ int is_slm(unsigned int family, unsigned int model) if (!genuine_intel) return 0; switch (model) { - case INTEL_FAM6_ATOM_SILVERMONT1: /* BYT */ - case INTEL_FAM6_ATOM_SILVERMONT2: /* AVN */ + case INTEL_FAM6_ATOM_SILVERMONT: /* BYT */ + case INTEL_FAM6_ATOM_SILVERMONT_X: /* AVN */ return 1; } return 0; @@ -4471,7 +4457,9 @@ void process_cpuid() family = (fms >> 8) & 0xf; model = (fms >> 4) & 0xf; stepping = fms & 0xf; - if (family == 6 || family == 0xf) + if (family == 0xf) + family += (fms >> 20) & 0xff; + if (family >= 6) model += ((fms >> 16) & 0xf) << 4; if (!quiet) { @@ -4593,11 +4581,11 @@ void process_cpuid() case INTEL_FAM6_KABYLAKE_DESKTOP: /* KBL */ crystal_hz = 24000000; /* 24.0 MHz */ break; - case INTEL_FAM6_ATOM_DENVERTON: /* DNV */ + case INTEL_FAM6_ATOM_GOLDMONT_X: /* DNV */ crystal_hz = 25000000; /* 25.0 MHz */ break; case INTEL_FAM6_ATOM_GOLDMONT: /* BXT */ - case INTEL_FAM6_ATOM_GEMINI_LAKE: + case INTEL_FAM6_ATOM_GOLDMONT_PLUS: crystal_hz = 19200000; /* 19.2 MHz */ break; default: @@ -4840,16 +4828,8 @@ void topology_probe() siblings = get_thread_siblings(&cpus[i]); if (siblings > max_siblings) max_siblings = siblings; - if (cpus[i].thread_id != -1) + if (cpus[i].thread_id == 0) topo.num_cores++; - - if (debug > 1) - fprintf(outf, - "cpu %d pkg %d node %d core %d thread %d\n", - i, cpus[i].physical_package_id, - cpus[i].physical_node_id, - cpus[i].physical_core_id, - cpus[i].thread_id); } topo.cores_per_node = max_core_id + 1; @@ -4875,6 +4855,20 @@ void topology_probe() topo.threads_per_core = max_siblings; if (debug > 1) fprintf(outf, "max_siblings %d\n", max_siblings); + + if (debug < 1) + return; + + for (i = 0; i <= topo.max_cpu_num; ++i) { + fprintf(outf, + "cpu %d pkg %d node %d lnode %d core %d thread %d\n", + i, cpus[i].physical_package_id, + cpus[i].physical_node_id, + cpus[i].logical_node_id, + cpus[i].physical_core_id, + cpus[i].thread_id); + } + } void @@ -5102,7 +5096,7 @@ int get_and_dump_counters(void) } void print_version() { - fprintf(outf, "turbostat version 18.06.20" + fprintf(outf, "turbostat version 18.07.27" " - Len Brown <lenb@kernel.org>\n"); } |
