dart:developer debugger() does not trigger from within tests

[sethladd]

I have a debugger() call inside one of my libraries. When I run the program, the debugger triggers and I see the stack.

However, when I run the library via the tests (dart --observe test/thing_test.dart), the debugger is not triggered correctly and I don't see a stack in Observatory.

It does appear that Observatory things the isolate is paused. I'm not sure if it's paused because of the debugger() call itself.

When I run with dart --observe main_app.dart, I see this:

Which makes me think my debugger() call is wired in correctly.

Thanks for taking a look!

[nex3]

This sounds like a bug in dart:developer. It seems like there should be nothing that a surrounding could do that would disable debugger(), so if it is being disabled by the test context that's probably a bug in the function itself.

[johnmccutchan]

@sethladd In the one screenshot you can see that the isolate hit an unhandled exception. It's likely you aren't hitting the debugger() statement.

@nex3 This is definitely not an issue with the debugger() function. All it does is call into C++ and flips the isolate into single stepping mode.

[sethladd]

To help me figure this out, how many isolates are used when I run a test via dart test/foo_test.dart? Does it spawn any?

[nex3]

No, it runs everything in the main isolate.

Can you produce a minimal repro of this?

[sethladd]

Can you produce a minimal repro of this?

Sure thing! Apologies, I should have done that for the initial report. Happy to see if I can repro this down.

[schwa423]

I was slogging through this myself, before noticing this bug, and I have some observations to add.

1. First, I noticed that "pub test" spawns another process, which spawns an isolate from ".pub/bin/test/test.dart.snapshot".
2. When I run "pub test" in an environment containing DART_VM_OPTIONS="--enable-vm-service --pause-isolates-on-start", these VM options are not passed to the VM in the spawned process.
3. If I manually invoke Dart with the test snapshot and "--enable-vm-service", then debugger() works. For example:
   dart --packages=$MY_PACKAGES --enable-vm-service .pub/bin/test/test.dart.snapshot test/first_test.dart
4. However, if I omit "--enable-vm-service", then debugger() does not work. The console output says "Hit Debugger!", but execution immediately proceeds past it.
5. John Mccutchan demonstrated to me a simple hello world app that only does "debugger(); print('hello world!');". When this is run via "dart hw.dart" it blocks in the debugger function, even though Observatory isn't running. Then, by sending SIGQUIT to the process, Observatory can be started, and connected to the debugger.
6. When I described/demonstrated observations 1-4 to John, he said that the test package interacts with the VM via the service interface, and that (although he doesn't know the details) this must be causing it to proceed past the debugger() call.

One thing that I haven't tried to replicate is Seth's observation that this happens when you run a test file directly (i.e. not by invoking "test.dart.snapshot"). I'll try this, and report back.

[johnmccutchan]

@nex3 What information do you need?

[schwa423]

Here's some more info. I made interesting observations when running this simple program in several different ways:

// test_debug.dart
import 'package:test/test.dart';
import 'dart:developer';
void main() {
  group('First group', () {
    test('First test', () {
      print('before debugger');
      debugger();
      print('after debugger');
      expect(true, equals(true));
    });
  });
}

1. "dart test_debug.dart"

• pauses in the debugger
• can send SIGQUIT to start Observatory server (URL is printed to stdout), and then connect to debugger

2. "dart --enable-vm-service test_debug.dart"

• pauses in the debugger
• can immediately connect to Observatory at localhost:8181

3. "dart .pub/bin/test/test.dart.snapshot test_debug.dart"

• prints "Hit Debugger!" (interestingly, before it prints "before debugger")
• proceeds directly through the debugger() call without stopping

4. "dart --enable-vm-service .pub/bin/test/test.dart.snapshot test_debug.dart"

• prints "Hit Debugger!" (again, before it prints "before debugger")
• pauses in the debugger
• can immediately connect to Observatory at localhost:8181

Some further observations and inferences:

A) Regarding Seth's question about how many isolates are spawned by "dart test/foo_test.dart", the answer was correct: the test is run in a single isolate. However, when running like "dart .pub/bin/test/test.dart.snapshot test/foo_test.dart", a separate isolate is spawned.

B) I only fail to pause in debugger() when running via "test.dart.snapshot". If I run the test file directly, debugger() works as expected. Note: I'm not sure if this is consistent with Seth's observations.

C) Perhaps related to B): When running via "test.dart.snapshot", "Hit Debugger!" is printed before "before debugger". Here's a hypothesis about what is happening:

• the test invocation buffers the test-isolate's "stdout", and prints it out after the test has completed
• the debugger() call in the test-isolate is noticed (somehow) by the main-isolate, which prints out "Hit Debugger!" before the test has completed.

I don't claim to fully understand what's happening, but my high-level conclusion is that test.dart.snapshot (and by extension, "pub run test") somehow messes with the debugger() call, unless --enable-vm-service is explicitly specified.

[schwa423]

Here's that code again, properly formatted:

// test_debug.dart
import 'package:test/test.dart';
import 'dart:developer';
void main() {
  group('First group', () {
    test('First test', () {
      print('before debugger');
      debugger();
      print('after debugger');
      expect(true, equals(true));
    });
  });
}

[schwa423]

One final note, then on to other things for now...

I thought the issue might be related to Isolates, but it appears not (at least in the simple scenario I created)... in the code below, the debugger() function still works as expected when invoked as "dart test_isolate_debug.dart":

// test_isolate_debug.dart
import 'package:test/test.dart';
import 'dart:developer';
import 'dart:isolate';

void main() {
  var port = new ReceivePort();
  Isolate.spawn(runTest, port.sendPort, onExit: port.sendPort);
  port.forEach((result) {
    print(result ?? "Tests finished");
  });
}

void runTest(var port) {
  group('First group', () {
    test('First test', () {
      port.send('before debugger');
      debugger();
      port.send('after debugger');
      expect(true, equals(true));
    });
  });
  port.send("Finished setting up tests");
}

[johnmccutchan]

I suspect the test package is somehow interfering with the slave isolate's ability to pause at a breakpoint

[nex3]

So, first of all, the test packages does not currently officially support any sort of debugging of the command-line VM (see issue #50). You're welcome to try to get it working on your own however you want, but be aware that you're straying off the beaten path and the only support I can only provide limited support. As such, I'm going to close this issue out, since it's a bug report against a piece of functionality we don't support anyway.

Second, @johnmccutchan, I don't understand how the test package could interfere with breakpoint-setting. As far as I know, there are no APIs that disable stopping at a breakpoint—if there are, we certainly don't intend to call them in the test runner. We don't even connect to the VM service protocol for command-line tests. So even if something the test package is doing is indirectly causing this, it still seems like a bug in the VM or Observatory that this can be caused at all.