CHROMIUM: scheduler: dump build log too for long running builds

Our old parallel_emerge wrapper would dump build logs for packages
that were taking too long to help debug.  Implement similar logic
here in our new long task tracker.

BUG=chromium:1095661
TEST=CQ passes
TEST=looked at output behavior with manual lower timeouts

Change-Id: I8488708da80315afa711b9c18382f95b74f7a423
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/portage_tool/+/2347447
Tested-by: Mike Frysinger <vapier@chromium.org>
Reviewed-by: Chris McDonald <cjmcdonald@chromium.org>
diff --git a/lib/_emerge/MergeListItem.py b/lib/_emerge/MergeListItem.py
index ba92409..cbacea0 100644
--- a/lib/_emerge/MergeListItem.py
+++ b/lib/_emerge/MergeListItem.py
@@ -24,7 +24,7 @@
 		"pkg_count", "pkg_to_replace", "prefetcher",
 		"settings", "statusMessage", "world_atom") + \
 		("_install_task",) + \
-		("start_time", "next_ping")
+		("start_time", "next_ping", "last_log_hash")
 
 	def _start(self):
 
diff --git a/lib/_emerge/Scheduler.py b/lib/_emerge/Scheduler.py
index 9b483e6..4d4773d 100644
--- a/lib/_emerge/Scheduler.py
+++ b/lib/_emerge/Scheduler.py
@@ -1687,7 +1687,44 @@
 					pstree = subprocess.run(
 						['pstree', '-Apals', str(subtask.pid)],
 						stdout=subprocess.PIPE, encoding='utf-8', errors='replace')
-					msg += pstree.stdout
+					msg += '\n' + pstree.stdout.strip()
+
+				if self._background and self.myopts.get('--quiet-fail', 'n') != 'y':
+					log_path = task.settings.get('PORTAGE_LOG_FILE')
+					if log_path:
+						msg += '\n>>> %s: Dumping log file %s:' % (task.pkg.cpv, log_path)
+
+						with open(log_path, 'r', encoding='utf-8') as fp:
+							data = fp.read()
+
+						# Only dump the last 5MiB of logs.  This should fit the vast
+						# majority of packages, and avoid dumping the entire log for
+						# the few that are extremely large (e.g. Chrome).
+						LOG_LIMIT = 5 * 1024 * 1024
+
+						# If the log hasn't changed, don't keep dumping the same output.
+						# For builds that hang for a long time, redumping the log can
+						# quickly add up to more than browsers can handle.
+						new_hash = portage.checksum.checksum_str(data.encode('utf-8'))
+						if new_hash != task.last_log_hash:
+							task.last_log_hash = new_hash
+
+							if len(data) > LOG_LIMIT:
+								msg += '\n>>> NB: File is %i bytes; showing last ~%i MiB' % (
+									len(data), LOG_LIMIT / 1024 / 1024)
+								data = data[-LOG_LIMIT:]
+								# Scan to the first newline to avoid confusing display.
+								try:
+									pos = data.index('\n')
+									data = data[pos + 1:]
+								except ValueError:
+									pass
+						else:
+							data = '<NO NEW LOG OUTPUT SINCE LAST DUMP>'
+
+						msg += '\n' + data.strip()
+
+				msg += '\n>>> %s: End of debugging info' % (task.pkg.cpv,)
 
 			task.statusMessage(msg)