Merge lp:~milo/linaro-image-tools/bug1059579 into lp:linaro-image-tools/11.11

[Milo Casagrande]

Re-using the same branch: we reapply the logger refactoring, and fix the regression found - it was missing the global declaration when initializing the variable.

[Данило Шеган (danilo)]

Based on the fact that this was already reviewed, I'll just review the simple change in 586.

Is there any simple way you can add a test that exercises this code path? If not, land as-is, though I'd very much prefer a test.

review: Approve

[Milo Casagrande (milo)]

On Wed, Oct 24, 2012 at 1:46 PM, Данило Шеган <email address hidden> wrote:
> Review: Approve
>
> Based on the fact that this was already reviewed, I'll just review the simple change in 586.
>
> Is there any simple way you can add a test that exercises this code path? If not, land as-is, though I'd very much prefer a test.

I looked into that, but it is not that easy. It should be possible to
use the already mocking infrastructure to fake hwpack and deb files in
this case, but the problem is that all this code is inside a user
script (it is linaro-hwpack-replace), and we cannot really import
anything from it to test it out and use it as a module. It would
really call to refactor all the code of that script (something that
would be cool to do).

--
Milo Casagrande
Infrastructure Engineer
Linaro.org <www.linaro.org> │ Open source software for ARM SoCs

=== modified file 'linaro-hwpack-convert'
--- linaro-hwpack-convert	2012-10-20 06:17:46 +0000
+++ linaro-hwpack-convert	2012-10-22 07:04:22 +0000
@@ -22,35 +22,17 @@
 
 
 import argparse
-import logging
 import sys
-import os
 
 from linaro_image_tools.hwpack.hwpack_convert import (
     HwpackConverter,
     HwpackConverterException,
     check_and_validate_args,
     )
+from linaro_image_tools.utils import get_logger
 from linaro_image_tools.__version__ import __version__
 
 
-def get_logger(debug=False):
-    ch = logging.StreamHandler()
-    logger = logging.getLogger("linaro_hwpack_converter")
-
-    if debug:
-        ch.setLevel(logging.DEBUG)
-        formatter = logging.Formatter(
-            "%(asctime)s - %(name)s - %(levelname)s - %(message)s")
-        ch.setFormatter(formatter)
-        logger.setLevel(logging.DEBUG)
-    else:
-        ch.setLevel(logging.INFO)
-        formatter = logging.Formatter("%(message)s")
-        ch.setFormatter(formatter)
-        logger.setLevel(logging.INFO)
-        logger.addHandler(ch)
-
 if __name__ == '__main__':
     parser = argparse.ArgumentParser(version='%(prog)s ' + __version__)
     parser.add_argument("CONFIG_FILE",
@@ -64,10 +46,10 @@
     logger = get_logger(debug=args.debug)
     try:
         input_file, output_file = check_and_validate_args(args)
-        print "Converting '%s' into new YAML format..." % (input_file)
+        logger.info("Converting '%s' into new YAML format..." % input_file)
         converter = HwpackConverter(input_file, output_file)
     except HwpackConverterException, e:
-        sys.stderr.write(str(e) + "\n")
+        logger.error(str(e))
         sys.exit(1)
     converter.convert()
-    print "File '%s' converted in '%s'." % (input_file, output_file)
+    logger.info("File '%s' converted in '%s'." % (input_file, output_file))

=== modified file 'linaro-hwpack-create'
--- linaro-hwpack-create	2012-10-20 06:17:46 +0000
+++ linaro-hwpack-create	2012-10-22 07:04:22 +0000
@@ -21,14 +21,14 @@
 # USA.
 
 import argparse
-import logging
 import sys
 
 from linaro_image_tools.hwpack.builder import (
     ConfigFileMissing, HardwarePackBuilder)
-
+from linaro_image_tools.utils import get_logger
 from linaro_image_tools.__version__ import __version__
 
+
 if __name__ == '__main__':
     parser = argparse.ArgumentParser(version='%(prog)s ' + __version__)
     parser.add_argument(
@@ -44,24 +44,14 @@
               "version than a package that would be otherwise installed.  "
               "Can be used more than once."))
     parser.add_argument("--debug", action="store_true")
+
     args = parser.parse_args()
-    ch = logging.StreamHandler()
-    ch.setLevel(logging.INFO)
-    formatter = logging.Formatter("%(message)s")
-    ch.setFormatter(formatter)
-    logger = logging.getLogger("linaro_image_tools")
-    logger.setLevel(logging.INFO)
-    logger.addHandler(ch)
-    if args.debug:
-        ch.setLevel(logging.DEBUG)
-        formatter = logging.Formatter(
-            "%(asctime)s - %(name)s - %(levelname)s - %(message)s")
-        ch.setFormatter(formatter)
-        logger.setLevel(logging.DEBUG)
+    logger = get_logger(debug=args.debug)
+
     try:
-        builder = HardwarePackBuilder(
-            args.CONFIG_FILE, args.VERSION, args.local_debs)
+        builder = HardwarePackBuilder(args.CONFIG_FILE,
+                                      args.VERSION, args.local_debs)
     except ConfigFileMissing, e:
-        sys.stderr.write(str(e) + "\n")
+        logger.error(str(e))
         sys.exit(1)
     builder.build()

=== modified file 'linaro-hwpack-replace'
--- linaro-hwpack-replace	2012-10-20 06:17:46 +0000
+++ linaro-hwpack-replace	2012-10-22 07:04:22 +0000
@@ -26,7 +26,6 @@
 import sys
 import shutil
 import glob
-import logging
 import tarfile
 import tempfile
 import argparse
@@ -35,6 +34,7 @@
 from debian.deb822 import Packages
 from linaro_image_tools.hwpack.packages import get_packages_file
 from linaro_image_tools.hwpack.packages import FetchedPackage
+from linaro_image_tools.utils import get_logger
 
 
 parser = argparse.ArgumentParser()
@@ -53,7 +53,7 @@
 parser.add_argument("-d", "--debug-output", action="store_true", dest="debug",
                     help="Verbose messages are displayed when specified")
 
-logger = logging.getLogger("linaro-hwpack-replace")
+logger = None
 
 
 class DummyStanza(object):
@@ -65,20 +65,6 @@
         fd.write(get_packages_file([self.info]))
 
 
-def set_logging_param(args):
-    ch = logging.StreamHandler()
-    ch.setLevel(logging.INFO)
-    formatter = logging.Formatter("%(message)s")
-    ch.setFormatter(formatter)
-    logger.setLevel(logging.INFO)
-    logger.addHandler(ch)
-    if args.debug:
-        ch.setLevel(logging.DEBUG)
-        formatter = logging.Formatter(
-            "%(asctime)s - %(name)s - %(levelname)s - %(message)s")
-        ch.setFormatter(formatter)
-        logger.setLevel(logging.DEBUG)
-
 
 def get_hwpack_name(old_hwpack, build_number):
     # The build_number would be the job build number.
@@ -178,7 +164,8 @@
                      "and the debian package information\n")
         return 1
 
-    set_logging_param(args)
+    global logger
+    logger = get_logger(debug=args.debug)
 
     old_hwpack = args.hwpack_name
     new_deb_file_to_copy = args.deb_pack

=== modified file 'linaro-media-create'
--- linaro-media-create	2012-10-20 06:17:46 +0000
+++ linaro-media-create	2012-10-22 07:04:22 +0000
@@ -22,7 +22,6 @@
 import os
 import sys
 import tempfile
-import logging
 
 from linaro_image_tools import cmd_runner
 
@@ -57,6 +56,7 @@
     MissingRequiredOption,
     path_in_tarfile_exists,
     prep_media_path,
+    get_logger,
     )
 
 # Just define the global variables
@@ -106,35 +106,29 @@
     parser = get_args_parser()
     args = parser.parse_args()
 
-    ch = logging.StreamHandler()
-    ch.setLevel(logging.INFO)
-    formatter = logging.Formatter("%(message)s")
-    ch.setFormatter(formatter)
-    logger = logging.getLogger("linaro_image_tools")
-    logger.setLevel(logging.INFO)
-    logger.addHandler(ch)
+    logger = get_logger(debug=args.debug)
 
     try:
         additional_option_checks(args)
     except IncompatibleOptions as e:
         parser.print_help()
-        print >> sys.stderr, "\nError:", e.value
+        logger.error(e.value)
         sys.exit(1)
 
     if args.readhwpack:
         try:
             reader = HwpackReader(args.hwpacks)
-            print reader.get_supported_boards()
+            logger.info(reader.get_supported_boards())
             sys.exit(0)
         except HwpackReaderError as e:
-            print >> sys.stderr, "\nError:", e.value
+            logger.error(e.value)
             sys.exit(1)
 
     try:
         check_required_args(args)
     except MissingRequiredOption as e:
         parser.print_help()
-        print >> sys.stderr, "\nError:", e.value
+        logger.error(e.value)
         sys.exit(1)
 
     board_config = board_configs[args.dev]
@@ -147,16 +141,16 @@
 
     if media.is_block_device:
         if not board_config.supports_writing_to_mmc:
-            print ("The board '%s' does not support the --mmc option. "
-                    "Please use --image_file to create an image file for this "
-                    "board." % args.dev)
+            logger.error("The board '%s' does not support the --mmc option. "
+                         "Please use --image_file to create an image file for "
+                         "this board." % args.dev)
             sys.exit(1)
         if not confirm_device_selection_and_ensure_it_is_ready(
                 args.device, args.nocheck_mmc):
             sys.exit(1)
     elif not args.should_format_rootfs or not args.should_format_bootfs:
-        print ("Do not use --no-boot or --no-part in conjunction with "
-               "--image_file.")
+        logger.error("Do not use --no-boot or --no-part in conjunction with "
+                     "--image_file.")
         sys.exit(1)
     else:
         # All good, move on.
@@ -170,6 +164,7 @@
     BIN_DIR = os.path.join(TMP_DIR, 'rootfs')
     os.mkdir(BIN_DIR)
 
+    logger.info('Searching correct rootfs path')
     # Identify the correct path for the rootfs
     filesystem_dir = ''
     if path_in_tarfile_exists('binary/etc', args.binary):
@@ -212,12 +207,12 @@
 
     if args.rootfs == 'btrfs':
         if not extract_kpkgs:
-            print ("Desired rootfs type is 'btrfs', trying to auto-install "
-                   "the 'btrfs-tools' package")
+            logger.info("Desired rootfs type is 'btrfs', trying to "
+                        "auto-install the 'btrfs-tools' package")
             install_packages(ROOTFS_DIR, TMP_DIR, "btrfs-tools")
         else:
-            print ("Desired rootfs type is 'btrfs', please make sure the "
-                   "rootfs also includes 'btrfs-tools'")
+            logger.info("Desired rootfs type is 'btrfs', please make sure the "
+                        "rootfs also includes 'btrfs-tools'")
 
     boot_partition, root_partition = setup_partitions(
         board_config, media, args.image_size, args.boot_label, args.rfs_label,
@@ -248,4 +243,4 @@
             board_config.mmc_device_id, board_config.mmc_part_offset,
             board_config)
 
-    print "Done creating Linaro image on %s" % media.path
+    logger.info("Done creating Linaro image on %s" % media.path)

=== modified file 'linaro_image_tools/hwpack/__init__.py'
--- linaro_image_tools/hwpack/__init__.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/hwpack/__init__.py	2012-10-22 07:04:22 +0000
@@ -20,6 +20,7 @@
 # USA.
 
 import logging
+from linaro_image_tools.utils import DEFAULT_LOGGER_NAME
 
 
 class NullHandler(logging.Handler):
@@ -28,4 +29,4 @@
 
 
 h = NullHandler()
-logging.getLogger(__name__).addHandler(h)
+logging.getLogger(DEFAULT_LOGGER_NAME).addHandler(h)

=== modified file 'linaro_image_tools/hwpack/hwpack_convert.py'
--- linaro_image_tools/hwpack/hwpack_convert.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/hwpack/hwpack_convert.py	2012-10-22 07:04:22 +0000
@@ -85,7 +85,7 @@
 # The default name used for renaming dtb file
 DEFAULT_DTB_NAME = 'board.dtb'
 
-logger = logging.getLogger("linaro_hwpack_converter")
+logger = logging.getLogger(__name__)
 
 
 class HwpackConverterException(Exception):

=== modified file 'linaro_image_tools/media_create/__init__.py'
--- linaro_image_tools/media_create/__init__.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/media_create/__init__.py	2012-10-22 07:04:22 +0000
@@ -173,6 +173,7 @@
         help="Select a bootloader from a hardware pack that contains more "
              "than one. If not specified, it will default to '%s'." %
              DEFAULT_BOOTLOADER)
+    parser.add_argument("--debug", action="store_true")
 
     add_common_options(parser)
     return parser

=== modified file 'linaro_image_tools/media_create/boards.py'
--- linaro_image_tools/media_create/boards.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/media_create/boards.py	2012-10-22 07:04:22 +0000
@@ -47,6 +47,8 @@
     partition_mounted, SECTOR_SIZE, register_loopback)
 from StringIO import StringIO
 
+logger = logging.getLogger(__name__)
+
 KERNEL_GLOB = 'vmlinuz-*-%(kernel_flavor)s'
 INITRD_GLOB = 'initrd.img-*-%(kernel_flavor)s'
 DTB_GLOB = 'dt-*-%(kernel_flavor)s/%(dtb_name)s'
@@ -457,14 +459,6 @@
 
     hardwarepack_handler = None
 
-    @staticmethod
-    def _get_logger():
-        """
-        Gets the logger instance.
-        :return: The logger instance
-        """
-        return logging.getLogger('linaro_image_tools')
-
     @classmethod
     def get_metadata_field(cls, field_name):
         """ Return the metadata value for field_name if it can be found.
@@ -877,7 +871,6 @@
         :param dest_dir: The directory where to copy each dtb file.
         :param search_dir: The directory where to search for the real file.
         """
-        logger = logging.getLogger("linaro_image_tools")
         logger.info("Copying dtb files")
         for dtb_file in dtb_files:
             if dtb_file:
@@ -922,7 +915,6 @@
         if max_size is not None:
             assert os.path.getsize(from_file) <= max_size, (
                     "'%s' is larger than %s" % (from_file, max_size))
-        logger = logging.getLogger("linaro_image_tools")
         logger.info("Writing '%s' to '%s' at %s." % (from_file, to_file, seek))
         _dd(from_file, to_file, seek=seek)
 
@@ -945,7 +937,6 @@
             if cls.spl_in_boot_part:
                 assert spl_file is not None, (
                     "SPL binary could not be found")
-                logger = logging.getLogger("linaro_image_tools")
                 logger.info(
                     "Copying spl '%s' to boot partition." % spl_file)
                 cmd_runner.run(["cp", "-v", spl_file, boot_dir],
@@ -1105,7 +1096,6 @@
     @classmethod
     def _get_kflavor_files_v2(cls, path):
         kernel = initrd = dtb = None
-        logger = logging.getLogger("linaro_image_tools")
 
         if cls.vmlinuz:
             kernel = _get_file_matching(os.path.join(path, cls.vmlinuz))

=== modified file 'linaro_image_tools/media_create/partitions.py'
--- linaro_image_tools/media_create/partitions.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/media_create/partitions.py	2012-10-22 07:04:22 +0000
@@ -36,6 +36,8 @@
 
 from linaro_image_tools import cmd_runner
 
+logger = logging.getLogger(__name__)
+
 HEADS = 128
 SECTORS = 32
 SECTOR_SIZE = 512  # bytes
@@ -205,7 +207,6 @@
         try:
             umount(path)
         except cmd_runner.SubcommandNonZeroReturnValue, e:
-            logger = logging.getLogger("linaro_image_tools")
             logger.warn("Failed to umount %s, but ignoring it because of a "
                         "previous error" % path)
             logger.warn(e)
@@ -586,7 +587,6 @@
 
     :param media: A setup_partitions.Media object to partition.
     """
-    logger = logging.getLogger("linaro_image_tools")
     tts = 1
     while (tts > 0) and (tts <= MAX_TTS):
         try:

=== modified file 'linaro_image_tools/utils.py'
--- linaro_image_tools/utils.py	2012-10-20 06:17:46 +0000
+++ linaro_image_tools/utils.py	2012-10-22 07:04:22 +0000
@@ -28,6 +28,8 @@
 
 from linaro_image_tools import cmd_runner
 
+DEFAULT_LOGGER_NAME = 'linaro_image_tools'
+
 
 # try_import was copied from python-testtools 0.9.12 and was originally
 # licensed under a MIT-style license but relicensed under the GPL in Linaro
@@ -76,13 +78,15 @@
 
 
 def path_in_tarfile_exists(path, tar_file):
-    tarinfo = tarfile.open(tar_file, 'r:gz')
+    exists = True
     try:
+        tarinfo = tarfile.open(tar_file, 'r:gz')
         tarinfo.getmember(path)
-        return True
+        tarinfo.close()
     except KeyError:
-        return False
-    tarinfo.close()
+        exists = False
+    finally:
+        return exists
 
 
 def verify_file_integrity(sig_file_list):
@@ -145,24 +149,24 @@
 
     # Check the outputs from verify_file_integrity
     # Abort if anything fails.
+    logger = logging.getLogger(__name__)
     if len(sig_file_list):
         if not gpg_sig_pass:
-            logging.error("GPG signature verification failed.")
+            logger.error("GPG signature verification failed.")
             return False, []
 
         if not os.path.basename(binary) in verified_files:
-            logging.error("OS Binary verification failed")
+            logger.error("OS Binary verification failed")
             return False, []
 
         for hwpack in hwpacks:
             if not os.path.basename(hwpack) in verified_files:
-                logging.error("Hwpack {0} verification failed".format(hwpack))
+                logger.error("Hwpack {0} verification failed".format(hwpack))
                 return False, []
 
         for verified_file in verified_files:
-            logging.info('Hash verification of file {0} OK.'.format(
+            logger.info('Hash verification of file {0} OK.'.format(
                                                                 verified_file))
-
     return True, verified_files
 
 
@@ -348,3 +352,31 @@
         raise MissingRequiredOption("--dev option is required")
     if args.binary is None:
         raise MissingRequiredOption("--binary option is required")
+
+
+def get_logger(name=DEFAULT_LOGGER_NAME, debug=False):
+    """
+    Retrieves a named logger. Default name is set in the variable
+    DEFAULT_LOG_NAME. Debug is set to False by default.
+
+    :param name: The name of the logger.
+    :param debug: If debug level should be turned on
+    :return: A logger instance.
+    """
+    logger = logging.getLogger(name)
+    ch = logging.StreamHandler()
+
+    if debug:
+        ch.setLevel(logging.DEBUG)
+        formatter = logging.Formatter(
+            "%(asctime)s - %(name)s - %(levelname)s - %(message)s")
+        ch.setFormatter(formatter)
+        logger.setLevel(logging.DEBUG)
+    else:
+        ch.setLevel(logging.INFO)
+        formatter = logging.Formatter("%(message)s")
+        ch.setFormatter(formatter)
+        logger.setLevel(logging.INFO)
+
+    logger.addHandler(ch)
+    return logger