search

dart-lang / webdev

A CLI for Dart web development.
https://pub.dev/packages/webdev
212 stars 74 forks source link

'webdev daemon' doesn't serve DartAngular sample project until some file is edited #766

Open alexander-doroshko opened 4 years ago

alexander-doroshko commented 4 years ago

Windows 10, Dart SDK 2.6.0-dev.8.1, stagehand 3.3.4, webdev 2.5.3, Chrome 77.0.3865.120

Steps:

Expected: Chrome runs the app. Actual result: Chrome starts but the app doesn't run. The page that opens up shows Loading... placeholder. No errors in Chrome dev console. Here are the last lines of the webdev daemon output:

[{"event":"daemon.log","params":{"log":"[INFO] 1m 6s elapsed, 12226/12226 actions completed."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Running build completed, took 1m 6s\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Caching finalized dependency graph..."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Caching finalized dependency graph completed, took 493ms\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Succeeded after 1m 7s with 5773 outputs (12820 actions)\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------\n"}}]

Note that there's no "app.started" message and no "appId" or "wsUri".

Now, edit any file (for example add a non-meaningful space to web/main.dart file and save. this forces rebuild, which succeeds, and finally the app loads successfully in Chrome! The following lines appear in the webdev daemon console:

[{"event":"daemon.log","params":{"log":"[INFO] About to build [web]..."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Updating asset graph..."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Updating asset graph completed, took 18ms\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Running build..."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Running build completed, took 955ms\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Caching finalized dependency graph..."}}]
[{"event":"daemon.log","params":{"log":"[INFO] Caching finalized dependency graph completed, took 307ms\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Succeeded after 1.3s with 7 outputs (5 actions)\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------\n"}}]
[{"event":"daemon.log","params":{"log":"[INFO] Debug service listening on ws://127.0.0.1:53116/Gs2bJdnH4_4=\n"}}]
[{"event":"app.start","params":{"appId":"yeJMfnpaTmxFjhoc5S1hjg==","directory":"C:\\Users\\alexander.doroshko\\WebstormProjects\\dart-angular","deviceId":"chrome","launchMode":"run"}}]
[{"event":"app.started","params":{"appId":"yeJMfnpaTmxFjhoc5S1hjg=="}}]
[{"event":"app.debugPort","params":{"appId":"yeJMfnpaTmxFjhoc5S1hjg==","port":53116,"wsUri":"ws://127.0.0.1:53116/Gs2bJdnH4_4="}}]
grouma commented 4 years ago

I'm struggling to reproduce this issue with:

Windows 10 Dart SDK 2.6.0-dev.8.1 stagehand 3.3.4 webdev 2.5.3 Chrome 77.0.3865.90

I'm also presented with the Loading... screen but after a second or so, the application will load and I'm presented with My First AngularDart App. It's only after the application fully loads will you get the daemon logs for app.started.

Can you check the network tab to see if you have loading errors?

alexander-doroshko commented 4 years ago

Hm, it's 100% reproducible for me. Waiting doesn't help. Chrome DevTools console is empty. If I open the Network tab and refresh the page - about a hundred of scripts are loaded successfully, no errors, the page is still stuck with Loading.... webdev daemon console still has no "app.started" or "appId" or "wsUri". I'm happy to assist further with the issue investigation.

grouma commented 4 years ago

Can you check to see if /dwds/src/injected/client.jsis loaded in the browser? That is the resource that starts does the connection handshake which will cause the app.started event.

alexander-doroshko commented 4 years ago

It is. But the last line says 'Pending'. image

alexander-doroshko commented 4 years ago

And after editing and saving main.dart file the app finally loads: image

grouma commented 4 years ago

Oh fun. Haven't seen this one before. This is definitely a handshake issue. For some reason the SSE connection is not being established. Does the network tab provide anymore details when you click on the pending request? That request should upgrade to eventsource and initiate the handshake.

alexander-doroshko commented 4 years ago

Yep, after editing and saving main.dart the awaited response finally arrives (see screenshot https://github.com/dart-lang/webdev/issues/766#issuecomment-545605993)

But before that - Preview and Response tabs are empty, Timing tab says that request is not finished yet. Headers tab is like this: image (port is different than on the prev screenshot because I restarted webdev)

grouma commented 4 years ago

I'm struggling to determine what could cause this issue. Are you able to run the tests in package:sse without issue?

alexander-doroshko commented 4 years ago

I've downloaded chromedriver.exe (v77.0.3865.40) to the sse folder locally and here's what I get:

C:\dart_projects\dart-lang\sse>C:\dart\dart-dev-channel\bin\pub run test

00:03 +0: test\sse_test.dart: Can round trip messages
DevTools listening on ws://127.0.0.1:49890/devtools/browser/23457d0c-55c3-44fd-8718-caad2f2d93d8
00:32 +0 -1: test\sse_test.dart: Can round trip messages [E]
  TimeoutException after 0:00:30.000000: Test timed out after 30 seconds.
  package:test_api  Invoker._onRun.<fn>.<fn>.<fn>

  Bad state: No element
  dart:async                Stream.first
  test\sse_test.dart 62:36  main.<fn>
  ===== asynchronous gap ===========================
  dart:async                _asyncThenWrapperHelper
  test\sse_test.dart        main.<fn>

00:33 +0 -1: test\sse_test.dart: Multiple clients can connect
DevTools listening on ws://127.0.0.1:49911/devtools/browser/95b03b9d-b0bd-46aa-b393-fee7709539d6
00:34 +0 -1: test\sse_test.dart: Multiple clients can connect                                                                                                                                          [1029/213745.101:INFO:CONSOLE(839)] "Uncaught ", source: http://localhost:49909/index.dart.js (839)
00:35 +1 -1: test\sse_test.dart: Routes data correctly
DevTools listening on ws://127.0.0.1:49926/devtools/browser/34239214-e043-4795-ac6e-b9343212cba1
01:04 +1 -2: test\sse_test.dart: Routes data correctly [E]
  TimeoutException after 0:00:30.000000: Test timed out after 30 seconds.
  package:test_api  Invoker._onRun.<fn>.<fn>.<fn>

  Bad state: No element
  dart:async                Stream.first
  test\sse_test.dart 78:37  main.<fn>
  ===== asynchronous gap ===========================
  dart:async                _asyncThenWrapperHelper
  test\sse_test.dart        main.<fn>

01:05 +1 -2: test\sse_test.dart: Can close from the server
DevTools listening on ws://127.0.0.1:49947/devtools/browser/cb023806-f4b5-4d81-b23e-0c7cf3369d51
01:07 +2 -2: test\sse_test.dart: Can close from the client-side
DevTools listening on ws://127.0.0.1:49964/devtools/browser/33eff0cc-5750-48d2-b138-a7cda142b025
01:09 +3 -2: test\sse_test.dart: Cancelling the listener closes the connection
DevTools listening on ws://127.0.0.1:49977/devtools/browser/6570db7b-2152-4adf-89fc-95ad1ac21bb4
01:10 +4 -2: test\sse_test.dart: Disconnects when navigating away
DevTools listening on ws://127.0.0.1:49990/devtools/browser/2f69a040-79c7-411a-b641-221e3ee15556
01:12 +4 -2: test\sse_test.dart: Disconnects when navigating away                                                                                                                                      [1029/213822.892:ERROR:CONSOLE(2646)] "Uncaught ", source: http://localhost:49988/index.dart.js (2646)
01:12 +5 -2: Some tests failed.
grouma commented 4 years ago

Thank you. package:sse is not playing well with something in your environment and that's what is causing the issue in package:webdev. I'm going to close this issue in favor of https://github.com/dart-lang/sse/issues/16.

I haven't heard of any similar reports so I'm not too concerned right now. It would be great to get to the bottom of this though. Do you have any special flags enabled / disabled in Chrome?

alexander-doroshko commented 4 years ago

I don't think I have any special Chrome flags. I'm happy to debug it in my environment if you could provide me instructions.

grouma commented 4 years ago

I tried to reproduce this issue on another Windows 10 environment without success. I'm stumped as to what could be the issue.

grouma commented 4 years ago

@alexander-doroshko I'm told you are still experiencing this issue. I haven't been able to reproduce it on multiple Window based machines. Any other details that might help track this issue down?

alexander-doroshko commented 4 years ago

Unfortunately, I'm still seeing the issue. Windows 10, Chrome, SDK and webdev are updated to the latest. Apparently, something is special in my environment, but no idea what. One more hint: webdev serve --debug works fine: Chrome opens and the app starts. webdev daemon doesn't work. Chrome opens but the app doesn't start. Fake edit in any dart file and saving it helps - the app starts.

If this hint doesn't help, and no more ideas what to ask me for, maybe I could run webdev from sources and debug it on my end? Where should I set breakpoints and what to look for?