Comments (18)
Okay, so the problem is a 15 second idle timeout applied because of keepAlive connection in pub http client. dartdev should probably close the globalHttpClient
from pub.
To confirm the above modifying dartdev.dart
fixes the problem.
import 'package:pub/src/http.dart';
/// The entry point for dartdev.
Future<void> main(List<String> args, SendPort? port) async {
await runDartdev(args, port);
globalHttpClient.close();
}
...
from sdk.
I'll second lrhn's assessment: excellent debugging!
I'm able to reproduce, albeit in a different fashion:
dart create -t cli test_1
- Add an invalid dependency to
pubspec.yaml
(e.g.,http: 10.0.0
) dart run
Resolving dependencies in /private/tmp/test_1...
Because test_1 depends on http 10.0.0 which doesn't match any versions, version solving failed.
You can try the following suggestion to make the pubspec resolve:
* Consider downgrading your constraint on http: dart pub add http:^1.2.1
real 0m15.955s
user 0m1.088s
sys 0m0.227s
I can confirm that adding the patch from #55289 (comment) fixes the issue.
@sigurdm @jonasfj, are we okay with reaching into package:pub/src/http.dart
and closing globalHttpClient
directly from DartDev? It looks like we should be safe to call close()
multiple times, so this won't cause any issues when the client is closed by the dart pub
command handler. If that's not okay, can we get a cleanup()
method added to package:pub
?
from sdk.
Thanks for the fix! I think this can be closed.
from sdk.
I'll close it when it is rolled to the sdk
from sdk.
Seems to be rolled in main. Should this be cherry-picked to stable?
from sdk.
Reproducible with local build (3.4.0-266.0.dev) but only when the package was ran with 255.0 (current flutter main) before.
* frame #0: 0x0000000183e60524 libsystem_kernel.dylib`__psynch_mutexwait + 8
frame #1: 0x0000000183e9b168 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_wait + 84
frame #2: 0x0000000183e98af8 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_slow + 248
frame #3: 0x0000000183e9e688 libsystem_pthread.dylib`_pthread_cond_wait + 1368
frame #4: 0x00000001001c4eb0 dart`dart::bin::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at thread_macos.cc:236:18
frame #5: 0x00000001000a6ec0 dart`dart::bin::DartDevIsolate::DartDevRunner::Run(this=0x00000001024d7d90, create_isolate=<unavailable>, packages_file=<unavailable>, script=<unavailable>, force_no_sound_null_safety=<unavailable>, dart_options=<unavailable>) at dartdev_isolate.cc:114:13
frame #6: 0x00000001000a7590 dart`dart::bin::DartDevIsolate::RunDartDev(create_isolate=<unavailable>, packages_file=<unavailable>, script=<unavailable>, force_no_sound_null_safety=<unavailable>, dart_options=<unavailable>) at dartdev_isolate.cc:292:11
frame #7: 0x00000001000a9e94 dart`dart::bin::main(argc=2, argv=0x000000016fd5f418) at main_impl.cc:1418:53
frame #8: 0x00000001000a8fe4 dart`main(argc=<unavailable>, argv=<unavailable>) at main.cc:9:3
frame #9: 0x0000000183b1d0e0 dyld`start + 2360
from sdk.
So this is quite weird. I have the same SDK revision (567a19a), when built locally as part of flutter engine (profile/arm64) I don't get the problem. But when using prebuilt SDK shipped with Flutter (same revision), I get the issue.
from sdk.
Actually, I get the issue when I copy (copy, not just symlink) the dart-sdk
from engine out
into flutter/bin/cache
.
from sdk.
Here's complete stacktrace
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
* frame #0: 0x0000000183e60524 libsystem_kernel.dylib`__psynch_mutexwait + 8
frame #1: 0x0000000183e9b168 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_wait + 84
frame #2: 0x0000000183e98af8 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_slow + 248
frame #3: 0x0000000183e9e688 libsystem_pthread.dylib`_pthread_cond_wait + 1368
frame #4: 0x0000000100d78eb0 dart`dart::bin::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at thread_macos.cc:236:18
frame #5: 0x0000000100c5aec0 dart`dart::bin::DartDevIsolate::DartDevRunner::Run(this=0x000000010308bd90, create_isolate=<unavailable>, packages_file=<unavailable>, script=<unavailable>, force_no_sound_null_safety=<unavailable>, dart_options=<unavailable>) at dartdev_isolate.cc:114:13
frame #6: 0x0000000100c5b590 dart`dart::bin::DartDevIsolate::RunDartDev(create_isolate=<unavailable>, packages_file=<unavailable>, script=<unavailable>, force_no_sound_null_safety=<unavailable>, dart_options=<unavailable>) at dartdev_isolate.cc:292:11
frame #7: 0x0000000100c5de94 dart`dart::bin::main(argc=2, argv=0x000000016f1ab418) at main_impl.cc:1418:53
frame #8: 0x0000000100c5cfe4 dart`main(argc=<unavailable>, argv=<unavailable>) at main.cc:9:3
frame #9: 0x0000000183b1d0e0 dyld`start + 2360
thread #2, name = 'dart:io EventHandler'
frame #0: 0x0000000183e639c0 libsystem_kernel.dylib`kevent + 8
frame #1: 0x0000000100c6845c dart`dart::bin::EventHandlerImplementation::EventHandlerEntry(args=105553128980960) at eventhandler_macos.cc:459:23
frame #2: 0x0000000100d78704 dart`dart::bin::ThreadStart(data_ptr=<unavailable>) at thread_macos.cc:91:3
frame #3: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
thread #3, name = 'DartDev Runner'
frame #0: 0x0000000183e6106c libsystem_kernel.dylib`__psynch_cvwait + 8
frame #1: 0x0000000183e9e5fc libsystem_pthread.dylib`_pthread_cond_wait + 1228
frame #2: 0x0000000100eef230 dart`dart::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at os_thread_macos.cc:435:18
frame #3: 0x00000001011fa8d4 dart`::Dart_RunLoop() [inlined] dart::MonitorLocker::Wait(this=<unavailable>, millis=0) at lockers.h:173:22
frame #4: 0x00000001011fa8c8 dart`::Dart_RunLoop() at dart_api_impl.cc:2020:12
frame #5: 0x0000000100c5b24c dart`dart::bin::DartDevIsolate::DartDevRunner::RunCallback(args=4345871760) at dartdev_isolate.cc:270:3
frame #6: 0x0000000100d78704 dart`dart::bin::ThreadStart(data_ptr=<unavailable>) at thread_macos.cc:91:3
frame #7: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
thread #4, name = 'DartWorker'
frame #0: 0x0000000183e6106c libsystem_kernel.dylib`__psynch_cvwait + 8
frame #1: 0x0000000183e9e628 libsystem_pthread.dylib`_pthread_cond_wait + 1272
frame #2: 0x0000000100eef218 dart`dart::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at os_thread_macos.cc:449:9
frame #3: 0x0000000100e0a4f4 dart`dart::MutatorThreadPool::OnEnterIdleLocked(dart::MonitorLocker*) [inlined] dart::MonitorLocker::WaitMicros(this=<unavailable>, micros=<unavailable>) at lockers.h:181:22
frame #4: 0x0000000100e0a4ec dart`dart::MutatorThreadPool::OnEnterIdleLocked(this=0x0000000154605f30, ml=<unavailable>) at isolate.cc:299:11
frame #5: 0x0000000100f77e04 dart`dart::ThreadPool::WorkerLoop(this=0x0000000154605f30, worker=0x000060000262c270) at thread_pool.cc:167:7
frame #6: 0x0000000100f78148 dart`dart::ThreadPool::Worker::Main(args=105553156293232) at thread_pool.cc:330:9
frame #7: 0x0000000100eee618 dart`dart::ThreadStart(data_ptr=<unavailable>) at os_thread_macos.cc:136:5
frame #8: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
thread #5, name = 'DartWorker'
frame #0: 0x0000000183e6106c libsystem_kernel.dylib`__psynch_cvwait + 8
frame #1: 0x0000000183e9e628 libsystem_pthread.dylib`_pthread_cond_wait + 1272
frame #2: 0x0000000100eef218 dart`dart::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at os_thread_macos.cc:449:9
frame #3: 0x0000000100e0a4f4 dart`dart::MutatorThreadPool::OnEnterIdleLocked(dart::MonitorLocker*) [inlined] dart::MonitorLocker::WaitMicros(this=<unavailable>, micros=<unavailable>) at lockers.h:181:22
frame #4: 0x0000000100e0a4ec dart`dart::MutatorThreadPool::OnEnterIdleLocked(this=0x0000000156104080, ml=<unavailable>) at isolate.cc:299:11
frame #5: 0x0000000100f77e04 dart`dart::ThreadPool::WorkerLoop(this=0x0000000156104080, worker=0x0000600002637f00) at thread_pool.cc:167:7
frame #6: 0x0000000100f78148 dart`dart::ThreadPool::Worker::Main(args=105553156341504) at thread_pool.cc:330:9
frame #7: 0x0000000100eee618 dart`dart::ThreadStart(data_ptr=<unavailable>) at os_thread_macos.cc:136:5
frame #8: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
thread #6
frame #0: 0x0000000000000000
thread #7, name = 'dart:io Process.start'
frame #0: 0x0000000183e6106c libsystem_kernel.dylib`__psynch_cvwait + 8
frame #1: 0x0000000183e9e5fc libsystem_pthread.dylib`_pthread_cond_wait + 1228
frame #2: 0x0000000100d78eb0 dart`dart::bin::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at thread_macos.cc:236:18
frame #3: 0x0000000100c7137c dart`dart::bin::ExitCodeHandler::ExitCodeHandlerEntry(param=<unavailable>) at process_macos.cc:194:21
frame #4: 0x0000000100d78704 dart`dart::bin::ThreadStart(data_ptr=<unavailable>) at thread_macos.cc:91:3
frame #5: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
Seems to be stuck here for about 15 seconds. I don't quite understand why this only happens when I copy the entire sdk to flutter/bin/cache
.
from sdk.
Is there any logging that can be obtained when starting DartDev
? The stacktrace doesn't seem to be very helpful, as it doesn't show what exactly what the waiting is for.
from sdk.
So DartDev seems to be sending this almost instantly to the VM:
[1, .dart_tool/pub/bin/test_1/test_1.dart-3.4.0-266.0.dev.snapshot, .dart_tool/package_config.json, false, []]
from sdk.
So the main thread is stuck at monitor_->WaitMicros(Monitor::kNoTimeout);
, even though the monitor gets notified in DartDevIsolate::DartDev_Result_Exit:
almost immediately.
It seems like the monitor gets notified immediately but RunCallback
is holding it until the runloop finishes, that's why the main thread is blocked.
from sdk.
So dartdev main method finishes, but there are still some events pending which prevent the runloop from stopping. I'm guessing related to network I/O
These are the messages received by RunLoop after the delay (assuming a timeout somewhere).
[>] Posting message:
len: 7
source: <native code>
dest: dartdev
dest_port: 4026228539302727
[<] Handling message:
len: 7
handler: dartdev
port: 4026228539302727
[>] Posting message:
len: 10
source: <native code>
dest: dartdev
dest_port: 375847752348831
[>] Posting message:
len: 10
source: <native code>
dest: dartdev
dest_port: 375847752348831
[-] Closing port:
handler: SSLCertContextTrustEvaluate
port: 7577917443237711
[.] Message handled (OK):
len: 7
handler: dartdev
port: 4026228539302727
[<] Handling message:
len: 10
handler: dartdev
port: 375847752348831
[.] Message handled (OK):
len: 10
handler: dartdev
port: 375847752348831
[<] Handling message:
len: 10
handler: dartdev
port: 375847752348831
[-] Closing port:
handler: dartdev
port: 375847752348831
[.] Message handled (OK):
len: 10
handler: dartdev
port: 375847752348831
[-] Stopping message handler (OK):
handler: dartdev
from sdk.
Impressive sleuthing!
Sounds very probable. I've had similar unexpected "hangs" at exit of my own scripts that use HttpClient
, until I learned to close it properly.
If there are some (if not all) paths through dartdev that doesn't close a HttpClient
, we should figure out where that happens.
If it's only the script itself that uses an http client, then the script should close its own client. (Check if that stoned your problem, if it's your own program which keeps the Dart process alive after both it and dartdev have ended.)
If the script using an http client makes dartdev wait, then we should worry about whether it can be affected by the rubbing program in other ways. Meaning to be - very aware of any process-wide properties that are used after the user program has run.
from sdk.
To elaborate, pub
seems to close its globalHttpClient
only when running as command:
dartdev
is however using pub
as package, and thus the http client is never closed. In this case dartdev
calls getExecutableForCommand
from pub
, which in turn will attempt to get advisories for the http dependency package, which fires up the http client, but never closes it. This keeps the dartdev
run loop alive until the connection keepAlive timeout expires.
Not sure why this manifests now, maybe the client before had connection:close
or the pub server or reverse proxy had disabled keepalives.
Also maybe it's not clear from the description. This all happens before any of my code even starts getting executed.
dart run
first starts dartdev
isolate and will not run the main program before the dartdev
isolate RunLoop finishes. It is this thread:
thread #3, name = 'DartDev Runner'
frame #0: 0x0000000183e6106c libsystem_kernel.dylib`__psynch_cvwait + 8
frame #1: 0x0000000183e9e5fc libsystem_pthread.dylib`_pthread_cond_wait + 1228
frame #2: 0x0000000100eef230 dart`dart::Monitor::WaitMicros(this=<unavailable>, micros=<unavailable>) at os_thread_macos.cc:435:18
frame #3: 0x00000001011fa8d4 dart`::Dart_RunLoop() [inlined] dart::MonitorLocker::Wait(this=<unavailable>, millis=0) at lockers.h:173:22
frame #4: 0x00000001011fa8c8 dart`::Dart_RunLoop() at dart_api_impl.cc:2020:12
frame #5: 0x0000000100c5b24c dart`dart::bin::DartDevIsolate::DartDevRunner::RunCallback(args=4345871760) at dartdev_isolate.cc:270:3
frame #6: 0x0000000100d78704 dart`dart::bin::ThreadStart(data_ptr=<unavailable>) at thread_macos.cc:91:3
frame #7: 0x0000000183e9e034 libsystem_pthread.dylib`_pthread_start + 136
It holds the DartDevRunner::monitor_
and until the this thread finishes, the main thread won't resume and launch the main program. And the runloop is stuck until the pub http client is closed.
from sdk.
Ohh what an oversight.
I think we should better close the client inside pub - here:
https://github.com/dart-lang/pub/blob/e08f72021717ddb36fb883884fefcd0fa7aa86b4/lib/pub.dart#L52
I'll make a PR.
from sdk.
Roll is here: https://dart-review.googlesource.com/c/sdk/+/359480
from sdk.
Thanks for the quick fix @sigurdm!
from sdk.
Related Issues (20)
- Reproducible Builds HOT 13
- `--print-dtd` flag not working for `dart run` HOT 1
- Weird type inference issue HOT 17
- Extension type implementing Stream can't be used as a return types of a async* function HOT 3
- Generic function type mismatch: `type '(Subtype) => ReturnType' is not a subtype of type '((Supertype) => ReturnType)?'` HOT 4
- Null check exceptions during json serialization during dry run HOT 1
- Extension type doesn't extend `Object` HOT 2
- Analyzer Feedback from IntelliJ
- Create an issue HOT 1
- Incorrect error messages while parsing (non-existent) logical operators `or`, `and`, and `xor` HOT 2
- No error in the analyzer to augment different type
- No error in the analyzer if augmenting type declares different number of parameters
- No error in the analyzer if augment class goes before original class HOT 2
- Hot reload test suite crashes test bots when parsing results logs
- [dart2js] Incorrect code generated in body of a function used as a .call getter
- [ddc] flaky behavior in for-loop eval test HOT 2
- evaluate performance for multi-option contexts HOT 1
- CFE allows trailing comma in catch clause
- Analyzer Feedback from IntelliJ
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from sdk.