Merge ~smoser/cloud-init:cleanup/collect-logs-stderr into cloud-init:master

[Scott Moser]

collect-logs: add -v flag, write to stderr, limit journal to single boot.

With no output at all from collect-logs, users have been confused
on where the output is. By default now, write to stderr what that
file is.

Also
 * add '-v' to increase verbosity. With a single -v flag, mention
   what file/info is being collected.
 * limit the 'journalctl' collection to this boot (--boot=0).
   collecting entire journal seems unnecessary and can be huge.
 * do not fail when collecting files or directories that are not there.

LP: #1766335

see commit message

[Server Team CI bot (server-team-bot)]

FAILED: Continuous integration, rev:42590af381e9a4fd0e750733f6419d1abfdc18b6
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1083/
Executed test runs:
    SUCCESS: Checkout
    FAILED: Unit & Style Tests

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1083/rebuild

review: Needs Fixing (continuous-integration)

[Server Team CI bot (server-team-bot)]

FAILED: Continuous integration, rev:5abc18c747aa0e52680c7830528ad42ea9f3fccb
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1084/
Executed test runs:
    SUCCESS: Checkout
    FAILED: Unit & Style Tests

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1084/rebuild

review: Needs Fixing (continuous-integration)

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:0680529933ec324313d050695d3cac815661b7ce
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1086/
Executed test runs:
    SUCCESS: Checkout
    SUCCESS: Unit & Style Tests
    SUCCESS: Ubuntu LTS: Build
    SUCCESS: Ubuntu LTS: Integration
    SUCCESS: MAAS Compatability Testing
    IN_PROGRESS: Declarative: Post Actions

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1086/rebuild

review: Approve (continuous-integration)

[Server Team CI bot (server-team-bot)]

FAILED: Continuous integration, rev:c821c5f783747394555977286791d4c94d85a8a3
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1088/
Executed test runs:
    SUCCESS: Checkout
    FAILED: Unit & Style Tests

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1088/rebuild

review: Needs Fixing (continuous-integration)

[Server Team CI bot (server-team-bot)]

PASSED: Continuous integration, rev:a6707315e674846bfff079520173d18d50fb0b79
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1089/
Executed test runs:
    SUCCESS: Checkout
    SUCCESS: Unit & Style Tests
    SUCCESS: Ubuntu LTS: Build
    SUCCESS: Ubuntu LTS: Integration
    SUCCESS: MAAS Compatability Testing
    IN_PROGRESS: Declarative: Post Actions

Click here to trigger a rebuild:
https://jenkins.ubuntu.com/server/job/cloud-init-ci/1089/rebuild

review: Approve (continuous-integration)

[Chad Smith (chad.smith)]

+1 LGTM!

review: Approve

[Chad Smith (chad.smith)]

An upstream commit landed for this bug.

To view that commit see the following URL:
https://git.launchpad.net/cloud-init/commit/?id=9f5907e1

diff --git a/cloudinit/cmd/devel/logs.py b/cloudinit/cmd/devel/logs.py
index 35ca478..df72520 100644
--- a/cloudinit/cmd/devel/logs.py
+++ b/cloudinit/cmd/devel/logs.py
@@ -11,6 +11,7 @@ from cloudinit.temp_utils import tempdir
 from datetime import datetime
 import os
 import shutil
+import sys
 
 
 CLOUDINIT_LOGS = ['/var/log/cloud-init.log', '/var/log/cloud-init-output.log']
@@ -31,6 +32,8 @@ def get_parser(parser=None):
         parser = argparse.ArgumentParser(
             prog='collect-logs',
             description='Collect and tar all cloud-init debug info')
+    parser.add_argument('--verbose', '-v', action='count', default=0,
+                        dest='verbosity', help="Be more verbose.")
     parser.add_argument(
         "--tarfile", '-t', default='cloud-init.tar.gz',
         help=('The tarfile to create containing all collected logs.'
@@ -43,17 +46,33 @@ def get_parser(parser=None):
     return parser
 
 
-def _write_command_output_to_file(cmd, filename):
+def _write_command_output_to_file(cmd, filename, msg, verbosity):
     """Helper which runs a command and writes output or error to filename."""
     try:
         out, _ = subp(cmd)
     except ProcessExecutionError as e:
         write_file(filename, str(e))
+        _debug("collecting %s failed.\n" % msg, 1, verbosity)
     else:
         write_file(filename, out)
+        _debug("collected %s\n" % msg, 1, verbosity)
+        return out
 
 
-def collect_logs(tarfile, include_userdata):
+def _debug(msg, level, verbosity):
+    if level <= verbosity:
+        sys.stderr.write(msg)
+
+
+def _collect_file(path, out_dir, verbosity):
+    if os.path.isfile(path):
+        copy(path, out_dir)
+        _debug("collected file: %s\n" % path, 1, verbosity)
+    else:
+        _debug("file %s did not exist\n" % path, 2, verbosity)
+
+
+def collect_logs(tarfile, include_userdata, verbosity=0):
     """Collect all cloud-init logs and tar them up into the provided tarfile.
 
     @param tarfile: The path of the tar-gzipped file to create.
@@ -64,28 +83,46 @@ def collect_logs(tarfile, include_userdata):
     log_dir = 'cloud-init-logs-{0}'.format(date)
     with tempdir(dir='/tmp') as tmp_dir:
         log_dir = os.path.join(tmp_dir, log_dir)
-        _write_command_output_to_file(
+        version = _write_command_output_to_file(
+            ['cloud-init', '--version'],
+            os.path.join(log_dir, 'version'),
+            "cloud-init --version", verbosity)
+        dpkg_ver = _write_command_output_to_file(
             ['dpkg-query', '--show', "-f=${Version}\n", 'cloud-init'],
-            os.path.join(log_dir, 'version'))
+            os.path.join(log_dir, 'dpkg-version'),
+            "dpkg version", verbosity)
+        if not version:
+            version = dpkg_ver if dpkg_ver else "not-available"
+        _debug("collected cloud-init version: %s\n" % version, 1, verbosity)
         _write_command_output_to_file(
-            ['dmesg'], os.path.join(log_dir, 'dmesg.txt'))
+            ['dmesg'], os.path.join(log_dir, 'dmesg.txt'),
+            "dmesg output", verbosity)
         _write_command_output_to_file(
-            ['journalctl', '-o', 'short-precise'],
-            os.path.join(log_dir, 'journal.txt'))
+            ['journalctl', '--boot=0', '-o', 'short-precise'],
+            os.path.join(log_dir, 'journal.txt'),
+            "systemd journal of current boot", verbosity)
+
         for log in CLOUDINIT_LOGS:
-            copy(log, log_dir)
+            _collect_file(log, log_dir, verbosity)
         if include_userdata:
-            copy(USER_DATA_FILE, log_dir)
+            _collect_file(USER_DATA_FILE, log_dir, verbosity)
         run_dir = os.path.join(log_dir, 'run')
         ensure_dir(run_dir)
-        shutil.copytree(CLOUDINIT_RUN_DIR, os.path.join(run_dir, 'cloud-init'))
+        if os.path.exists(CLOUDINIT_RUN_DIR):
+            shutil.copytree(CLOUDINIT_RUN_DIR,
+                            os.path.join(run_dir, 'cloud-init'))
+            _debug("collected dir %s\n" % CLOUDINIT_RUN_DIR, 1, verbosity)
+        else:
+            _debug("directory '%s' did not exist\n" % CLOUDINIT_RUN_DIR, 1,
+                   verbosity)
         with chdir(tmp_dir):
             subp(['tar', 'czvf', tarfile, log_dir.replace(tmp_dir + '/', '')])
+    sys.stderr.write("Wrote %s\n" % tarfile)
 
 
 def handle_collect_logs_args(name, args):
     """Handle calls to 'cloud-init collect-logs' as a subcommand."""
-    collect_logs(args.tarfile, args.userdata)
+    collect_logs(args.tarfile, args.userdata, args.verbosity)
 
 
 def main():
diff --git a/cloudinit/cmd/devel/tests/test_logs.py b/cloudinit/cmd/devel/tests/test_logs.py
index dc4947c..98b4756 100644
--- a/cloudinit/cmd/devel/tests/test_logs.py
+++ b/cloudinit/cmd/devel/tests/test_logs.py
@@ -4,6 +4,7 @@ from cloudinit.cmd.devel import logs
 from cloudinit.util import ensure_dir, load_file, subp, write_file
 from cloudinit.tests.helpers import FilesystemMockingTestCase, wrap_and_call
 from datetime import datetime
+import mock
 import os
 
 
@@ -27,11 +28,13 @@ class TestCollectLogs(FilesystemMockingTestCase):
         date = datetime.utcnow().date().strftime('%Y-%m-%d')
         date_logdir = 'cloud-init-logs-{0}'.format(date)
 
+        version_out = '/usr/bin/cloud-init 18.2fake\n'
         expected_subp = {
             ('dpkg-query', '--show', "-f=${Version}\n", 'cloud-init'):
                 '0.7fake\n',
+            ('cloud-init', '--version'): version_out,
             ('dmesg',): 'dmesg-out\n',
-            ('journalctl', '-o', 'short-precise'): 'journal-out\n',
+            ('journalctl', '--boot=0', '-o', 'short-precise'): 'journal-out\n',
             ('tar', 'czvf', output_tarfile, date_logdir): ''
         }
 
@@ -44,9 +47,12 @@ class TestCollectLogs(FilesystemMockingTestCase):
                 subp(cmd)  # Pass through tar cmd so we can check output
             return expected_subp[cmd_tuple], ''
 
+        fake_stderr = mock.MagicMock()
+
         wrap_and_call(
             'cloudinit.cmd.devel.logs',
             {'subp': {'side_effect': fake_subp},
+             'sys.stderr': {'new': fake_stderr},
              'CLOUDINIT_LOGS': {'new': [log1, log2]},
              'CLOUDINIT_RUN_DIR': {'new': self.run_dir}},
             logs.collect_logs, output_tarfile, include_userdata=False)
@@ -55,7 +61,9 @@ class TestCollectLogs(FilesystemMockingTestCase):
         out_logdir = self.tmp_path(date_logdir, self.new_root)
         self.assertEqual(
             '0.7fake\n',
-            load_file(os.path.join(out_logdir, 'version')))
+            load_file(os.path.join(out_logdir, 'dpkg-version')))
+        self.assertEqual(version_out,
+                         load_file(os.path.join(out_logdir, 'version')))
         self.assertEqual(
             'cloud-init-log',
             load_file(os.path.join(out_logdir, 'cloud-init.log')))
@@ -72,6 +80,7 @@ class TestCollectLogs(FilesystemMockingTestCase):
             'results',
             load_file(
                 os.path.join(out_logdir, 'run', 'cloud-init', 'results.json')))
+        fake_stderr.write.assert_any_call('Wrote %s\n' % output_tarfile)
 
     def test_collect_logs_includes_optional_userdata(self):
         """collect-logs include userdata when --include-userdata is set."""
@@ -88,11 +97,13 @@ class TestCollectLogs(FilesystemMockingTestCase):
         date = datetime.utcnow().date().strftime('%Y-%m-%d')
         date_logdir = 'cloud-init-logs-{0}'.format(date)
 
+        version_out = '/usr/bin/cloud-init 18.2fake\n'
         expected_subp = {
             ('dpkg-query', '--show', "-f=${Version}\n", 'cloud-init'):
                 '0.7fake',
+            ('cloud-init', '--version'): version_out,
             ('dmesg',): 'dmesg-out\n',
-            ('journalctl', '-o', 'short-precise'): 'journal-out\n',
+            ('journalctl', '--boot=0', '-o', 'short-precise'): 'journal-out\n',
             ('tar', 'czvf', output_tarfile, date_logdir): ''
         }
 
@@ -105,9 +116,12 @@ class TestCollectLogs(FilesystemMockingTestCase):
                 subp(cmd)  # Pass through tar cmd so we can check output
             return expected_subp[cmd_tuple], ''
 
+        fake_stderr = mock.MagicMock()
+
         wrap_and_call(
             'cloudinit.cmd.devel.logs',
             {'subp': {'side_effect': fake_subp},
+             'sys.stderr': {'new': fake_stderr},
              'CLOUDINIT_LOGS': {'new': [log1, log2]},
              'CLOUDINIT_RUN_DIR': {'new': self.run_dir},
              'USER_DATA_FILE': {'new': userdata}},
@@ -118,3 +132,4 @@ class TestCollectLogs(FilesystemMockingTestCase):
         self.assertEqual(
             'user-data',
             load_file(os.path.join(out_logdir, 'user-data.txt')))
+        fake_stderr.write.assert_any_call('Wrote %s\n' % output_tarfile)