The stages are actually executing; we just can't see that. I think that this is actually a Milo-related or logging-related bug, though I'm not sure where. I have long suspected that there was some kind of problem with our logging and I think that this a symptom of that. The DebugSymbols stage actually successfully completed in all of these cases:

mysql> SELECT build_id, name, board, status, start_time, finish_time FROM buildStageTable WHERE build_id = 2856601 AND (name = 'UnitTest' OR name = 'DebugSymbols');
+----------+--------------+------------+--------+---------------------+---------------------+
| build_id | name         | board      | status | start_time          | finish_time         |
+----------+--------------+------------+--------+---------------------+---------------------+
|  2856601 | UnitTest     | auron_yuna | pass   | 2018-08-18 07:33:01 | 2018-08-18 07:53:46 |
|  2856601 | DebugSymbols | auron_yuna | pass   | 2018-08-18 07:53:24 | 2018-08-18 08:37:47 |
+----------+--------------+------------+--------+---------------------+---------------------+
2 rows in set (0.02 sec)

mysql> SELECT build_id, name, board, status, start_time, finish_time FROM buildStageTable WHERE build_id = 2856613 AND (name = 'UnitTest' OR name = 'DebugSymbols');
+----------+--------------+-------+--------+---------------------+---------------------+
| build_id | name         | board | status | start_time          | finish_time         |
+----------+--------------+-------+--------+---------------------+---------------------+
|  2856613 | UnitTest     | tidus | pass   | 2018-08-18 07:42:08 | 2018-08-18 08:00:44 |
|  2856613 | DebugSymbols | tidus | pass   | 2018-08-18 08:00:28 | 2018-08-18 08:44:38 |
+----------+--------------+-------+--------+---------------------+---------------------+
2 rows in set (0.02 sec)

mysql> SELECT build_id, name, board, status, start_time, finish_time FROM buildStageTable WHERE build_id = 2856642 AND (name = 'UnitTest' OR name = 'DebugSymbols');
+----------+--------------+-------+--------+---------------------+---------------------+
| build_id | name         | board | status | start_time          | finish_time         |
+----------+--------------+-------+--------+---------------------+---------------------+
|  2856642 | UnitTest     | eve   | pass   | 2018-08-18 07:55:12 | 2018-08-18 08:21:29 |
|  2856642 | DebugSymbols | eve   | pass   | 2018-08-18 08:21:08 | 2018-08-18 09:07:49 |
+----------+--------------+-------+--------+---------------------+---------------------+
2 rows in set (0.01 sec)

mysql> SELECT build_id, name, board, status, start_time, finish_time FROM buildStageTable WHERE build_id = 2856550 AND (name = 'UnitTest' OR name = 'DebugSymbols');
+----------+--------------+--------+--------+---------------------+---------------------+
| build_id | name         | board  | status | start_time          | finish_time         |
+----------+--------------+--------+--------+---------------------+---------------------+
|  2856550 | UnitTest     | quawks | pass   | 2018-08-18 07:41:40 | 2018-08-18 08:04:01 |
|  2856550 | DebugSymbols | quawks | pass   | 2018-08-18 08:03:54 | 2018-08-18 08:45:40 |
+----------+--------------+--------+--------+---------------------+---------------------+
2 rows in set (0.02 sec)

Here's another rendering failure for completeness:

mysql> SELECT build_id, name, board, status, start_time, finish_time FROM buildStageTable WHERE build_id = 2856578 AND (name = 'UnitTest' OR name = 'DebugSymbols');
+----------+--------------+------------+--------+---------------------+---------------------+
| build_id | name         | board      | status | start_time          | finish_time         |
+----------+--------------+------------+--------+---------------------+---------------------+
|  2856578 | UnitTest     | parrot_ivb | pass   | 2018-08-18 08:05:13 | 2018-08-18 08:23:01 |
|  2856578 | DebugSymbols | parrot_ivb | pass   | 2018-08-18 08:22:56 | 2018-08-18 09:22:52 |
+----------+--------------+------------+--------+---------------------+---------------------+
2 rows in set (0.02 sec)

Strangely, this bug seems to only manifest on failed builds. I can't find an example of this happening on a passing build, so far.

I'm not sure where to look next. Don, do you have any ideas? Assign back to me after thinking about it.

Stages are created in the UI (and logs are gathered together) because a log entry is emitted with special tags. If that tag isn't emitted, the logs will appear as part of whatever stage was running previously.

The most likely case is that https://crrev.com/c/1155705 introduced a problem with the start of the stage. The "Run" method for stages is really overly complex, so this wouldn't be surprising.

The easiest way to debug these kinds of issues is to look in the "all" log, which Legoland is not displaying. Milo seems to be displaying it for some builds, but not all.

http://b/112841583

I'm not so sure: of the builds mentioned, I don't see *any* DebugSymbols stages in the All links: it's as though the log output was lost entirely in the cases where this bug manifests. I don't see any examples of the log output showing up in the All link but not showing up in Milo.

I looked through the stages too (painstakingly) and couldn't find any logs from DebugSymbols. I will double-check but R68 and R69 should not have https://crrev.com/c/1155705 because that was pushed last thursday. There's also the CL to serialize DebugSymbols that might be a culprit as we're only missing that stage.

I haven't looked into this issue at all since Aug. Should we just close this one?

Perhaps this is resolved; we haven't seen a new case. Closing for now.