webdev icon indicating copy to clipboard operation
webdev copied to clipboard

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

Open alexander-doroshko opened this issue 6 years ago • 14 comments

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

Steps:

  • pub global activate stagehand
  • pub global run stagehand web-angular
  • pub get
  • pub global activate webdev
  • pub global run webdev daemon

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="}}]

alexander-doroshko avatar Oct 22 '19 15:10 alexander-doroshko

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?

grouma avatar Oct 23 '19 17:10 grouma

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.

alexander-doroshko avatar Oct 23 '19 18:10 alexander-doroshko

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.

grouma avatar Oct 23 '19 18:10 grouma

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

alexander-doroshko avatar Oct 23 '19 19:10 alexander-doroshko

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

alexander-doroshko avatar Oct 23 '19 19:10 alexander-doroshko

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.

grouma avatar Oct 23 '19 19:10 grouma

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)

alexander-doroshko avatar Oct 23 '19 19:10 alexander-doroshko

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

grouma avatar Oct 29 '19 18:10 grouma

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.

alexander-doroshko avatar Oct 29 '19 18:10 alexander-doroshko

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/tools/issues/1636.

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?

grouma avatar Oct 29 '19 19:10 grouma

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.

alexander-doroshko avatar Oct 29 '19 20:10 alexander-doroshko

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

grouma avatar Nov 07 '19 19:11 grouma

@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?

grouma avatar Jan 10 '20 20:01 grouma

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?

alexander-doroshko avatar Jan 10 '20 21:01 alexander-doroshko