Merge lp:~ctf/checkbox/dump_options_to_log into lp:checkbox

[TienFu Chen]

While doing sru testing, some options in different files as followings won't be saved to log file.
* /etc/default/checkbox-certification-client
* /etc/xdg/autostart/checkbox-certification-client.desktop
So we have no idea what options are given while running the test.
Dump options to log file, so we can examine the options in log file.

A sample output will be like:

2012-02-16 06:42:49,586 INFO Options: {'blacklist_file': None, 'whitelist_file': '/usr/share/checkbox-certification/data/sru.whitelist', 'log_level': 'debug', 'log': '/home/ubuntu/.checkbox/checkbox-certification.log', 'whitelist': None, 'blacklist': None, 'version': None, 'config': ['checkbox/plugins/delay_prompt/timeout=60', 'checkbox/plugins/user_interface/interface_class=UserInterface', 'checkbox/plugins/jobs_info/whitelist_file=/usr/share/checkbox-certification/data/sru.whitelist']}

[Brendan Donegan (brendan-donegan)]

Good idea!

review: Approve

[Marc Tardif (cr3)]

First, this is really DEBUG rather than INFO logging information. This should be fixed.

Second, I'm not sure how helpful these two parts of the output are to the user:

  'whitelist_file': '/usr/share/checkbox-certification/data/sru.whitelist'
  'checkbox/plugins/jobs_info/whitelist_file=/usr/share/checkbox-certification/data/sru.whitelist'

If these pointed to different whitelist files, how would you know which one is being used?

review: Needs Fixing

[lp:~ctf/checkbox/dump_options_to_log]

1266. By Tim Chen <ctf@yantok> on 2012-02-17

use logging.debug instead of logging.info

[TienFu Chen (ctf)]

Updated. Use logging.debug instead of logging.info
Hi Marc,
I think the following two items point to same file.
whitelist_file': '/usr/share/checkbox-certification/data/sru.whitelist' [1]
'.*/jobs_info/whitelist_file=/usr/share/checkbox-certification/data/sru.whitelist' [2]

As the following code in checkbox/application.py:
        # Replace shorthands
        for shorthand in "blacklist", "blacklist_file", "whitelist", "whitelist_file":
            key = ".*/jobs_info/%s" % shorthand
            value = getattr(options, shorthand)
            if value:
                options.config.append("=".join([key, value]))

The [2] (option.config) is from options [1].

review: Needs Resubmitting

[Marc Tardif (cr3)]

As stated in my previous message, what if these pointed to different whitelist files, I'm not sure I understand how someone looking at the log file would understand which of the two whitelist files is actually being used.

[Marc Tardif (cr3)]

If all you want is to be notified of the whitelist file that was used, which I concede is valuable information, then I would propose the following change. Notice how I use logging.info instead of logging.debug because the whitelist file being read is oddly more important than just printing the command line options which may contain the same information:

=== modified file 'plugins/jobs_info.py'
--- plugins/jobs_info.py 2012-02-15 16:31:04 +0000
+++ plugins/jobs_info.py 2012-02-29 17:58:46 +0000
@@ -71,7 +71,12 @@
     def register(self, manager):
         super(JobsInfo, self).register(manager)

+ if self.whitelist_file:
+ logging.info("Reading whitelist patterns from %s" % self.whitelist_file)
         self.whitelist_patterns = self.get_patterns(self.whitelist, self.whitelist_file)
+
+ if self.blacklist_file:
+ logging.info("Reading blacklist patterns from %s" % self.blacklist_file)
         self.blacklist_patterns = self.get_patterns(self.blacklist, self.blacklist_file)

         self._manager.reactor.call_on("gather", self.gather)

[TienFu Chen (ctf)]

I looked at the trunk of checkbox/lib/config.py which already has the implementation I want(bzr diff -r1120..1121 config.py).

+ for section in sections:
+ logging.debug('Setting configuration parameter: '
+ '%(section)s/%(option)s = %(value)s'
+ % {'section': section,
+ 'option': option,
+ 'value': value})

Will make the log output like:
2012-03-01 22:06:20,229 DEBUG Setting configuration parameter: checkbox/plugins/delay_prompt/timeout = 1
2012-03-01 22:06:20,229 DEBUG Setting configuration parameter: checkbox/plugins/user_interface/interface_class = UserInterface
2012-03-01 22:06:20,230 DEBUG Setting configuration parameter: checkbox/plugins/jobs_info/whitelist_file = /usr/share/checkbox-certification/data/test.whitelist

[Marc Tardif (cr3)]

Does that mean we can set the status of this branch to Rejected?

review: Needs Information

[TienFu Chen (ctf)]

Hi Marc,
Sure, I have disapproved this.

review: Disapprove

Unmerged revisions

1266. By Tim Chen <ctf@yantok> on 2012-02-17

use logging.debug instead of logging.info

1265. By Tim Chen <ctf@yantok> on 2012-02-16

dump options to log file

=== modified file 'checkbox/application.py'
--- checkbox/application.py	2010-09-23 10:11:27 +0000
+++ checkbox/application.py	2012-02-17 08:34:18 +0000
@@ -109,6 +109,7 @@
 
         # Set logging early
         set_logging(options.log_level, options.log)
+        logging.debug("Options: %s" % options)
 
         # Config setup
         if len(args) != 2: