portage_util: Add more information to log on failure of chromeos-version.sh

More logging for chromium:917099

BUG=None
TEST=Updated unit tests pass.

Change-Id: Ibfe62ef0dac18967f37d5c6a0ac9aeda4919d606
Reviewed-on: https://chromium-review.googlesource.com/1417954
Commit-Ready: LaMont Jones <lamontjones@chromium.org>
Tested-by: LaMont Jones <lamontjones@chromium.org>
Reviewed-by: LaMont Jones <lamontjones@chromium.org>
Reviewed-by: Mike Frysinger <vapier@chromium.org>
(cherry picked from commit d56ea596998e32dcbde1dd02ec8b052bfcf21ffb)
Reviewed-on: https://chromium-review.googlesource.com/c/1427341
Commit-Queue: LaMont Jones <lamontjones@chromium.org>
diff --git a/lib/portage_util.py b/lib/portage_util.py
index ec87c27..516d1ff 100644
--- a/lib/portage_util.py
+++ b/lib/portage_util.py
@@ -885,16 +885,25 @@
 
     # The chromeos-version script will output a usable raw version number,
     # or nothing in case of error or no available version
-    try:
-      output = self._RunCommand([vers_script] + srcdirs).strip()
-    except cros_build_lib.RunCommandError as e:
-      cros_build_lib.Die('Package %s chromeos-version.sh failed: %s' %
-                         (self.pkgname, e))
+    result = cros_build_lib.RunCommand(['bash', '-x', vers_script] + srcdirs,
+                                       capture_output=True, error_code_ok=True)
 
-    if not output:
-      cros_build_lib.Die('Package %s has a chromeos-version.sh script but '
-                         'it returned no valid version for "%s"' %
-                         (self.pkgname, ' '.join(srcdirs)))
+    output = result.output.strip()
+    if result.returncode or not output:
+      # Crbug.com/917099 - Let's get more information for debugging, at least
+      # temporarily.
+      fsck_out = {}
+      for srcdir in srcdirs:
+        fsck_out[srcdir] = self._RunCommand(['git', 'fsck', srcdir],
+                                            error_code_ok=True)
+      # TODO(crbug.com/917099): Remove this long-term because it's verbose.
+      ls_out = self._RunCommand(['ls', '-lRa'] + srcdirs, error_code_ok=True)
+      cros_build_lib.Die(
+          'Package %s has a chromeos-version.sh script but failed:\n'
+          'return code = %s\nstdout = %s\nstderr = %s\ndir listing = %s\n'
+          'git fsck = %s\nsrcdirs = %s\n',
+          self.pkgname, result.returncode, result.output, result.error,
+          ls_out, fsck_out, srcdirs)
 
     # Sanity check: disallow versions that will be larger than the 9999 ebuild
     # used by cros-workon.
diff --git a/lib/portage_util_unittest.py b/lib/portage_util_unittest.py
index f0d0cfb..34ed0dd 100644
--- a/lib/portage_util_unittest.py
+++ b/lib/portage_util_unittest.py
@@ -716,7 +716,9 @@
     self.PatchObject(portage_util.EBuild, 'GetSourceInfo',
                      return_value=portage_util.SourceInfo(
                          projects=None, srcdirs=[], subdirs=[], subtrees=[]))
-    self.PatchObject(portage_util.EBuild, '_RunCommand', return_value='1122')
+    self.PatchObject(cros_build_lib, 'RunCommand',
+                     return_value=cros_build_lib.CommandResult(
+                         returncode=0, output='1122', error='STDERR'))
     self.assertEqual('1122', self.m_ebuild.GetVersion(None, None, '1234'))
     # Sanity check.
     self.assertEqual(exists.call_count, 1)
@@ -727,17 +729,27 @@
     self.PatchObject(portage_util.EBuild, 'GetSourceInfo',
                      return_value=portage_util.SourceInfo(
                          projects=None, srcdirs=[], subdirs=[], subtrees=[]))
-    run = self.PatchObject(portage_util.EBuild, '_RunCommand')
+    run = self.PatchObject(cros_build_lib, 'RunCommand')
 
     # Reject no output.
-    run.return_value = ''
+    run.return_value = cros_build_lib.CommandResult(
+        returncode=0, output='', error='STDERR')
     self.assertRaises(SystemExit, self.m_ebuild.GetVersion, None, None, '1234')
     # Sanity check.
     self.assertEqual(exists.call_count, 1)
     exists.reset_mock()
 
     # Reject simple output.
-    run.return_value = '\n'
+    run.return_value = cros_build_lib.CommandResult(
+        returncode=0, output='\n', error='STDERR')
+    self.assertRaises(SystemExit, self.m_ebuild.GetVersion, None, None, '1234')
+    # Sanity check.
+    self.assertEqual(exists.call_count, 1)
+    exists.reset_mock()
+
+    # Reject error.
+    run.return_value = cros_build_lib.CommandResult(
+        returncode=1, output='FAIL\n', error='STDERR')
     self.assertRaises(SystemExit, self.m_ebuild.GetVersion, None, None, '1234')
     # Sanity check.
     self.assertEqual(exists.call_count, 1)
@@ -748,7 +760,9 @@
     self.PatchObject(portage_util.EBuild, 'GetSourceInfo',
                      return_value=portage_util.SourceInfo(
                          projects=None, srcdirs=[], subdirs=[], subtrees=[]))
-    self.PatchObject(portage_util.EBuild, '_RunCommand', return_value='999999')
+    self.PatchObject(cros_build_lib, 'RunCommand',
+                     return_value=cros_build_lib.CommandResult(
+                         returncode=0, output='999999', error='STDERR'))
     self.assertRaises(ValueError, self.m_ebuild.GetVersion, None, None, '1234')
     # Sanity check.
     self.assertEqual(exists.call_count, 1)
@@ -759,7 +773,9 @@
     self.PatchObject(portage_util.EBuild, 'GetSourceInfo',
                      return_value=portage_util.SourceInfo(
                          projects=None, srcdirs=[], subdirs=[], subtrees=[]))
-    self.PatchObject(portage_util.EBuild, '_RunCommand', return_value='abcd')
+    self.PatchObject(cros_build_lib, 'RunCommand',
+                     return_value=cros_build_lib.CommandResult(
+                         returncode=0, output='abcd', error='STDERR'))
     self.assertRaises(ValueError, self.m_ebuild.GetVersion, None, None, '1234')
     # Sanity check.
     self.assertEqual(exists.call_count, 1)