Build: Build output is broken down into several lines.

[ehmicky]

See https://github.com/netlify/build/issues/226#issuecomment-544243448.

1:17:47 PM: ┌───────────────────────────────────────────────┐
1:17:47 PM: │ 3. Running postBuild lifecycle from subfont   │
1:17:47 PM: └───────────────────────────────────────────────┘
1:17:50 PM: 
1:17:50 PM:  ✔ 0.004 secs: logEvents
1:17:50 PM:  ✔ 0.112
1:17:50 PM:  secs: loadAssets
1:17:50 PM:  ✔ 0.2
1:17:51 PM: 17 secs: populate
1:17:51 PM:  ✔ 0.0
1:18:01 PM: 21 secs: checkIncompatibleTypes
1:18:01 PM:  ✔ 
391:18:01 PM: m0.001 secs: populate
1:18:01 PM:  ✔ 0.009 se
1:18:01 PM: cs: populate
1:18:01 PM:  ✔ 0.189 secs: compressJavaScript
1:18:01 PM:  ✔ 0.006 secs: writeAssetsToDisc
1:18:01 PM: dist/
1:18:01 PM: index.html: 1 font (2 variants) in use, 92.4 kB total. Created subsets: 8.56 kB total
1:18:01 PM:   Noto Serif:
1:18:01 PM:     700 : 14/229 codepoints used,
1:18:01 PM: 48.8 kB (ttf) => 4.75 kB (woff2)
1:18:01 PM:     400 :  9/229 codepoints used, 43.6 kB (ttf) => 3.81 kB (woff
1:18:01 PM: 2)
1:18:01 PM: dist/gaver/index.html: 3 fonts (3 variants) in use, 679 kB total. Created subsets: 39.7 kB total
1:18:01 PM:   Chalk:
1:18:01 PM:     normal : 11/219 codepoints used, 524 kB (ttf) => 23.
1:18:01 PM: 6 kB (woff2)
1:18:01 PM:   Permanent Marker:
1:18:01 PM:     400 : 24/213 codepoints used, 70.6 kB (ttf) => 5.56 kB (woff2)
1:18:01 PM:   Reenie Beanie:
1:18:01 PM:     400 : 54/214 codepoints used, 85 kB (ttf) => 10.6 kB (woff2)
1:18:01 PM: HTML
1:18:01 PM: /JS/CSS size increase: 2.29 kB
1:18:01 PM: Total savings: 721 kB
1:18:01 PM: Output written to file:///opt/build/repo/dist/
1:18:01 PM:  ✔  subfont.postBuild completed in 13623ms

It seems like this might be a BuildBot issue since the timestamp is added by the BuildBot. Locally this problem does not seem to happen.

A temporary fix could be to disable plugin output streaming. I.e. for each plugin lifecycle, we print the full output all at once when the lifecycle ends, instead of streaming it. What do you think @DavidWells?

[DavidWells]

A temporary fix could be to disable plugin output streaming. I.e. for each plugin lifecycle, we print the full output all at once when the lifecycle ends, instead of streaming it. What do you think @DavidWells?

Yeah we can do this. Only in netlify CI tho. Keep it streaming if it works fine locally

Logging is up in the air right now with SRE team. Need to see where it lands

[Munter]

Locally I'm not seeing the same issues. But locally I don't see the time stamps either

[DavidWells]

Streaming CLI tools, like spinners, etc have always been problematic in CI logs.

Example from CLI site build:

12:18:26 PM: Synced!
12:18:26 PM:  x0  @compositor/x0
12:18:26 PM:  x0  ⠋ building static site
12:18:27 PM:  x0  ⠙ building static site
12:18:27 PM: 
12:18:27 PM:  x0  ⠹ building static site
12:18:28 PM: 
12:18:28 PM:  x0  ⠸ building static site
12:18:29 PM: 
12:18:29 PM:  x0  ⠼ building static site
12:18:29 PM:  x0  ⠴ building static site
12:18:29 PM: 
12:18:29 PM:  x0  ⠦ building static site
12:18:32 PM: 
12:18:32 PM:  x0  ⠧ building static site
12:18:32 PM: 
12:18:32 PM:  x0  ⠇ building static site
12:18:32 PM: 
12:18:32 PM:  x0  ⠏ building static site
12:18:32 PM: 
12:18:32 PM:  x0  ⠋ building static site
12:18:33 PM: 
12:18:33 PM:  x0  ⠙ building static site
12:18:33 PM:  x0  ⠹ building static site
12:18:33 PM: 
12:18:33 PM:  x0  ⠸ building static site
12:18:33 PM: 
12:18:33 PM:  x0  ⠼ building static site
12:18:34 PM:  x0  ⠴ building static site
12:18:34 PM: 
12:18:34 PM:  x0  ⠦ building static site
12:18:34 PM: 
12:18:34 PM:  x0  ⠧ building static site
12:18:34 PM: 
12:18:34 PM:  x0  ⠇ building static site

This repeats for like 5000 lines

We should look for patterns/ways to automatically disable these.

The quick fix for (only) remote CI would be disabling streaming until our logging system can handle it properly.

Personally I like seeing the streaming logs locally to see things chug along 😃

[ehmicky]

Fixed in #358.