provivder:checkbox: Add system logs to stress tests logs

As explained in lp:1584607, more information is needed to investigate some issues when running stress tests (or tests using fwts_test or pm_test scripts). The content of dmesg and /var/log/syslog is added to the logs generated by these scripts. Since the resulting log files become really big, the attachment jobs are modified to compress (using xz) and encode the result in base64 because of a limitation in our system (all attachments must be strings, not binary). 

8 files changed, 48 insertions, 19 deletions

diff --git a/bin/fwts_test b/bin/fwts_test
index ef03bcaf..9b0f616c 100755
--- a/bin/fwts_test
+++ b/bin/fwts_test
@@ -4,7 +4,7 @@ import sys
 import re
 from time import time
 from argparse import ArgumentParser, RawTextHelpFormatter, REMAINDER
-from subprocess import Popen, PIPE
+from subprocess import Popen, PIPE, check_output
 from syslog import *
 from distutils.spawn import find_executable
 import os
@@ -408,6 +408,17 @@ def main():
 results[test] = (Popen(command, stdout=PIPE, shell=True)
 .communicate()[0].strip()).decode()
 
+ # lp:1584607
+ # We append the content of dmesg and syslog at the end of the logfile
+ # generated by FWTS.
+ with open(args.log, 'a') as logfile:
+ logfile.write("--- beginning of dmesg ---\n")
+ logfile.write(check_output('dmesg', universal_newlines=True))
+ logfile.write("--- end of dmesg ---\n")
+ logfile.write("--- beginning of syslog ---\n")
+ logfile.write(check_output(['cat', '/var/log/syslog'], universal_newlines=True))
+ logfile.write("--- end of syslog ---\n")
+
 # parse the summaries
 for test in results.keys():
 if 'FAILED_CRITICAL' in results[test]:
diff --git a/bin/pm_test b/bin/pm_test
index 1449604a..732588bc 100755
--- a/bin/pm_test
+++ b/bin/pm_test
@@ -369,21 +369,27 @@ class CountdownDialog(Gtk.Dialog):
 {'template': 'Gathering hardware information in {time} seconds...',
 'timeout': hardware_delay,
 'callback': self.on_hardware_info_timeout_cb}
+ system_info_event = \
+ {'template': 'Gathering system information in {time} seconds...',
+ 'timeout': 2,
+ 'callback': self.on_system_info_timeout_cb}
 
 if iterations == 0:
- # In first iteration, gather hardware information directly
- # and perform pm-operation
+ # In first iteration, gather hardware and system information
+ # directly and perform pm-operation
 self.on_hardware_info_timeout_cb()
+ self.on_system_info_timeout_cb()
 self.events = [operation_event]
 elif iterations < iterations_count:
 # In last iteration, wait before gathering hardware information
 # and perform pm-operation
 self.events = [operation_event,
- hardware_info_event]
+ hardware_info_event,
+ system_info_event]
 else:
 # In last iteration, wait before gathering hardware information
 # and finish the test
- self.events = [hardware_info_event]
+ self.events = [hardware_info_event, system_info_event]
 
 self.label = Gtk.Label()
 self.vbox.pack_start(self.label, True, True, 0)
@@ -481,6 +487,18 @@ class CountdownDialog(Gtk.Dialog):
 # errors can be retrieved by pm_log_check
 logging.error('Problem found in logs by fwts')
 
+ def on_system_info_timeout_cb(self):
+ """
+ Gather system information and print it to logs
+ """
+ logging.info('Gathering system information...')
+ logging.debug('--- beginning of dmesg ---')
+ logging.debug(Command('dmesg').run().stdout)
+ logging.debug('--- end of dmesg ---')
+ logging.debug('--- beginning of syslog ---')
+ logging.debug(Command('cat /var/log/syslog').run().stdout)
+ logging.debug('--- end of syslog ---')
+
 
 class MessageDialog(object):
 """
diff --git a/jobs/cpu.txt.in b/jobs/cpu.txt.in
index 8842ffe1..3eff8848 100644
--- a/jobs/cpu.txt.in
+++ b/jobs/cpu.txt.in
@@ -17,7 +17,7 @@ category_id: 2013.com.canonical.plainbox::cpu
 id: cpu/scaling_test-log-attach
 estimated_duration: 1.0
 depends: cpu/scaling_test
-command: [[ -e ${PLAINBOX_SESSION_SHARE}/scaling_test.log ]] && cat ${PLAINBOX_SESSION_SHARE}/scaling_test.log
+command: [[ -e ${PLAINBOX_SESSION_SHARE}/scaling_test.log ]] && xz -c ${PLAINBOX_SESSION_SHARE}/scaling_test.log | base64
 _description:
 Attaches the log generated by cpu/scaling_test to the results submission.
 
@@ -40,7 +40,7 @@ category_id: 2013.com.canonical.plainbox::cpu
 id: cpu/maxfreq_test-log-attach
 estimated_duration: 1.0
 depends: cpu/maxfreq_test
-command: [ -e $PLAINBOX_SESSION_SHARE/maxfreq_test.log ] && cat $PLAINBOX_SESSION_SHARE/maxfreq_test.log
+command: [ -e $PLAINBOX_SESSION_SHARE/maxfreq_test.log ] && xz -c $PLAINBOX_SESSION_SHARE/maxfreq_test.log | base64
 _summary:
 Attach log file from cpu/maxfreq_test
 _description:
@@ -113,6 +113,6 @@ category_id: 2013.com.canonical.plainbox::cpu
 estimated_duration: 0.5
 id: cpu/cstates_results.log
 command:
- [ -e ${PLAINBOX_SESSION_SHARE}/fwts_cstates_results.log ] && cat ${PLAINBOX_SESSION_SHARE}/fwts_cstates_results.log
+ [ -e ${PLAINBOX_SESSION_SHARE}/fwts_cstates_results.log ] && xz -c ${PLAINBOX_SESSION_SHARE}/fwts_cstates_results.log | base64
 _description: Attaches the FWTS desktop diagnosis results log to the submission
 
diff --git a/jobs/firmware.txt.in b/jobs/firmware.txt.in
index 34e28cc0..eb81cc66 100644
--- a/jobs/firmware.txt.in
+++ b/jobs/firmware.txt.in
@@ -18,7 +18,7 @@ id: firmware/fwts_{name}.log
 estimated_duration: 1.2
 requires: package.name == 'fwts'
 user: root
-command: [[ -e $PLAINBOX_SESSION_SHARE/fwts_{name}.log ]] && cat $PLAINBOX_SESSION_SHARE/fwts_{name}.log
+command: [[ -e $PLAINBOX_SESSION_SHARE/fwts_{name}.log ]] && xz -c $PLAINBOX_SESSION_SHARE/fwts_{name}.log | base64
 _description: Attach log for FWTS {name} test.
 _summary: Attach log for FWTS {name} test.
 
diff --git a/jobs/miscellanea.txt.in b/jobs/miscellanea.txt.in
index ea1efe5d..8710fed1 100644
--- a/jobs/miscellanea.txt.in
+++ b/jobs/miscellanea.txt.in
@@ -71,7 +71,7 @@ id: miscellanea/fwts_results.log
 requires:
 package.name == 'fwts'
 command:
- [[ -e ${PLAINBOX_SESSION_SHARE}/fwts_results.log ]] && cat ${PLAINBOX_SESSION_SHARE}/fwts_results.log
+ [[ -e ${PLAINBOX_SESSION_SHARE}/fwts_results.log ]] && xz -c ${PLAINBOX_SESSION_SHARE}/fwts_results.log | base64
 _description: Attaches the miscellanes/fwts_test results log to the submission.
 
 plugin: attachment
@@ -261,7 +261,7 @@ category_id: 2013.com.canonical.plainbox::miscellanea
 estimated_duration: 0.5
 id: miscellanea/oops_results.log
 command:
- [ -e ${PLAINBOX_SESSION_SHARE}/fwts_oops_results.log ] && cat ${PLAINBOX_SESSION_SHARE}/fwts_oops_results.log
+ [ -e ${PLAINBOX_SESSION_SHARE}/fwts_oops_results.log ] && xz -c ${PLAINBOX_SESSION_SHARE}/fwts_oops_results.log | base64
 _description: Attaches the FWTS oops results log to the submission
 
 plugin: shell
diff --git a/jobs/power-management.txt.in b/jobs/power-management.txt.in
index 5240b77c..a55058b9 100644
--- a/jobs/power-management.txt.in
+++ b/jobs/power-management.txt.in
@@ -31,7 +31,7 @@ estimated_duration: 2.0
 _description: Attach log from fwts wakealarm test
 requires:
 package.name == 'fwts'
-command: [ -e ${PLAINBOX_SESSION_SHARE}/fwts-wakealarm.log ] && cat ${PLAINBOX_SESSION_SHARE}/fwts-wakealarm.log
+command: [ -e ${PLAINBOX_SESSION_SHARE}/fwts-wakealarm.log ] && xz -c ${PLAINBOX_SESSION_SHARE}/fwts-wakealarm.log | base64
 
 plugin: user-interact-verify
 category_id: 2013.com.canonical.plainbox::power-management
diff --git a/jobs/stress.txt.in b/jobs/stress.txt.in
index 2a812b58..c1016979 100644
--- a/jobs/stress.txt.in
+++ b/jobs/stress.txt.in
@@ -127,7 +127,7 @@ category_id: 2013.com.canonical.plainbox::stress
 id: power-management/suspend-30-cycle-log-attach
 estimated_duration: 1.0
 depends: power-management/suspend_30_cycles
-command: [ -e $PLAINBOX_SESSION_SHARE/suspend_30_cycles.log ] && cat $PLAINBOX_SESSION_SHARE/suspend_30_cycles.log
+command: [ -e $PLAINBOX_SESSION_SHARE/suspend_30_cycles.log ] && xz -c $PLAINBOX_SESSION_SHARE/suspend_30_cycles.log | base64
 _description:
 Attaches the log from the 30 cycle Suspend/Resume test if it exists
 
@@ -136,7 +136,7 @@ category_id: 2013.com.canonical.plainbox::stress
 id: power-management/suspend-30-cycle-log-attach-with-reboots
 estimated_duration: 1.0
 depends: power-management/suspend_30_cycles_with_reboots
-command: [ -e $PLAINBOX_SESSION_SHARE/pm_test.reboot.3.log ] && cat $PLAINBOX_SESSION_SHARE/pm_test.reboot.3.log
+command: [ -e $PLAINBOX_SESSION_SHARE/pm_test.reboot.3.log ] && xz -c $PLAINBOX_SESSION_SHARE/pm_test.reboot.3.log | base64
 _description:
 Attaches the log from the '30 cycle Suspend/Resume and one reboot times 3' test if it exists
 
diff --git a/jobs/suspend.txt.in b/jobs/suspend.txt.in
index 7fde1148..d304970d 100644
--- a/jobs/suspend.txt.in
+++ b/jobs/suspend.txt.in
@@ -310,7 +310,7 @@ _description:
 plugin: attachment
 category_id: 2013.com.canonical.plainbox::suspend
 id: suspend/suspend-single-log-attach
-command: [ -e $PLAINBOX_SESSION_SHARE/suspend_single.log ] && cat $PLAINBOX_SESSION_SHARE/suspend_single.log
+command: [ -e $PLAINBOX_SESSION_SHARE/suspend_single.log ] && xz -c $PLAINBOX_SESSION_SHARE/suspend_single.log | base64
 _description:
 Attaches the log from the single suspend/resume test to the results
 
@@ -320,7 +320,7 @@ plugin: attachment
 category_id: 2013.com.canonical.plainbox::suspend
 id: suspend/{index}_suspend-single-log-attach_{product_slug}
 depends: suspend/{index}_suspend_after_switch_to_card_{product_slug}
-command: [ -e $PLAINBOX_SESSION_SHARE/{index}_suspend_single.log ] && cat $PLAINBOX_SESSION_SHARE/{index}_suspend_single.log
+command: [ -e $PLAINBOX_SESSION_SHARE/{index}_suspend_single.log ] && xz -c $PLAINBOX_SESSION_SHARE/{index}_suspend_single.log | base64
 _description:
 Attaches the log from the single suspend/resume test to the results
 
@@ -341,7 +341,7 @@ plugin: attachment
 category_id: 2013.com.canonical.plainbox::suspend
 id: suspend/{index}_hybrid-sleep-single-log-attach_{product_slug}
 depends: suspend/{index}_hybrid_sleep_{product_slug}
-command: [ -e $PLAINBOX_SESSION_SHARE/{index}_hybrid_sleep_single.log ] && cat $PLAINBOX_SESSION_SHARE/{index}_hybrid_sleep_single.log
+command: [ -e $PLAINBOX_SESSION_SHARE/{index}_hybrid_sleep_single.log ] && xz -c $PLAINBOX_SESSION_SHARE/{index}_hybrid_sleep_single.log | base64
 _description:
 Attaches the log from the single hybrid sleep/resume test to the results
 
@@ -1594,7 +1594,7 @@ _description:
 plugin: attachment
 category_id: 2013.com.canonical.plainbox::suspend
 id: suspend/suspend-auto-single-log-attach
-command: [ -e $PLAINBOX_SESSION_SHARE/suspend_auto_single_log ] && cat $PLAINBOX_SESSION_SHARE/suspend_auto_single_log
+command: [ -e $PLAINBOX_SESSION_SHARE/suspend_auto_single_log ] && xz -c $PLAINBOX_SESSION_SHARE/suspend_auto_single_log | base64
 _description:
 Attaches the log from the single suspend/resume test to the results
 
@@ -2833,6 +2833,6 @@ plugin: attachment
 category_id: 2013.com.canonical.plainbox::suspend
 estimated_duration: 0.5
 command:
- [ -e ${PLAINBOX_SESSION_SHARE}/fwts_oops_results_after_s3.log ] && cat ${PLAINBOX_SESSION_SHARE}/fwts_oops_results_after_s3.log
+ [ -e ${PLAINBOX_SESSION_SHARE}/fwts_oops_results_after_s3.log ] && xz -c ${PLAINBOX_SESSION_SHARE}/fwts_oops_results_after_s3.log | base64
 _description: Attaches the FWTS oops results log to the submission after suspend