Internal Server Error with --log-performance handler

[sinegovsky-ivan]

Hello! I'm trying to collect performance data for big dart project. I'm ran pub run build_runner serve web:8181 --log-performance ./PERF After building i open http://localhost:8181/$perf and got Internal Server Error Console logs:

Serving `web` on http://localhost:8181
ERROR - 2020-08-12 21:31:42.733735
GET /$perf
Error thrown by handler.
NoSuchMethodError: The getter 'stopTime' was called on null.
Receiver: null
Tried calling: stopTime
dart:core                                           Object.noSuchMethod
package:build_runner/src/server/server.dart 410:27  _renderPerformance
package:build_runner/src/server/server.dart 164:9   ServeHandler._performanceHandler
package:build_runner/src/server/server.dart 107:16  ServeHandler.handlerFor.<fn>
dart:async                                          _completeOnAsyncReturn
package:build_runner/src/server/server.dart         ServeHandler._blockOnCurrentBuild

• Dart SDK Version Dart VM version: 2.7.2 (Mon Mar 23 22:11:27 2020 +0100) on "macos_x64"
• What package(s) from this repo you are using, and the version
  • build_runner 1.10.0
  • build_runner_core 5.2.0
  • build_modules 2.8.1
  • build 1.3.0
  • webdev 2.5.9
• What builder(s) you are using (or writing yourself). dart_less and angular latest MacOSX / Chrome

performance information: 2020-08-12_17-30-52.txt

[jakemac53]

It sounds like your build did not actually have any performance information from that stack trace... possibly you tried to load it before the first build completed? (if that is the case then it is still a bug but that would help narrow it down)

Can you reproduce this consistently?

[DisDis]

@jakemac53

pub run build_runner serve web:8181 --log-performance ./PERF

All console output:

[INFO] Generating build script completed, took 548ms
[WARNING] Deleted previous snapshot due to missing asset graph.
[INFO] Creating build script snapshot... completed, took 15.2s
[INFO] Setting up file watchers completed, took 10ms
[INFO] Waiting for all file watchers to be ready completed, took 699ms
[INFO] Building new asset graph completed, took 59.5s
[INFO] Checking for unexpected pre-existing outputs. completed, took 1ms
[INFO] Generating SDK summary completed, took 3.8s
[WARNING] No actions completed for 17.3s, waiting on:

[INFO] Running build completed, took 23m 48s
[WARNING] No actions completed for 16.1s, waiting on:

[INFO] Caching finalized dependency graph completed, took 16.5s
[INFO] Writing performance log to ./PERF/2020-08-31_19-33-53...Exhausted heap space, trying to allocate 736 bytes.
Exhausted heap space, trying to allocate 128 bytes.
Exhausted heap space, trying to allocate 128 bytes.
Exhausted heap space, trying to allocate 128 bytes.
Exhausted heap space, trying to allocate 128 bytes.
[SEVERE] Unhandled build failure!
Out of Memory
[SEVERE] Failed after 30m 59s
Serving `web` on http://localhost:8181
ERROR - 2020-08-31 20:42:30.330533
GET /$perf
Error thrown by handler.
NoSuchMethodError: The getter 'stopTime' was called on null.
Receiver: null
Tried calling: stopTime
dart:core                                           Object.noSuchMethod
package:build_runner/src/server/server.dart 410:27  _renderPerformance
package:build_runner/src/server/server.dart 164:9   ServeHandler._performanceHandler
package:build_runner/src/server/server.dart 107:16  ServeHandler.handlerFor.<fn>
dart:async                                          _completeOnAsyncReturn
package:build_runner/src/server/server.dart         ServeHandler._blockOnCurrentBuild

[sinegovsky-ivan]

@jakemac53 yes, it's reproduces every time. We are trying to build code on 64Gb RAM / 32 core CPU machine, but had no luck.

We have very big project (1.5 billion LOC), maybe this is root of the issue? --log-performance works good for small and medium projects.

[jakemac53]

Yes, it looks like it fails to write the performance logs. These logs do have very fine grained performance information, so they could potentially get very large on a large project, and our current JSON implementation doesn't have the ability to do a streaming write so we need to serialize the entire thing and this is probably where it is running out of memory...

[jakemac53]

I don't see any reasonable way to fix this (or at least not worth the time investment given few people are actually affected and this isn't a required workflow). So I am going to close this.