-
Notifications
You must be signed in to change notification settings - Fork 28
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
co19_2/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06 is flaky #186
Comments
Issue dart-lang/co19#186 Change-Id: Id15b08a4d1483431a8f8b2ad0224e0d672d61878 Reviewed-on: https://dart-review.googlesource.com/c/83387 Reviewed-by: Martin Kustermann <kustermann@google.com> Commit-Queue: Martin Kustermann <kustermann@google.com> Auto-Submit: Martin Kustermann <kustermann@google.com>
@mkustermann thank you for advises. But before start rewriting of the tests I want to clarify a couple of things
What if there is a bug somewhere and expected event is not fired? Then test will wait until timeout occurs and cleanup will not be performed. We need something like this: ...
final event = await eventCompleter.future.timeout(Duration(seconds: X), onTimeout: () {
subscription.cancel();
Expect.fail("No event was fired for $X seconds");
});
... If so, do you have any suggestions regarding X value?
I'm going simply to use deleteSync(recursive: true) instead of delete()
Do you mean |
One option is that: Another option is that the creation of the symlink and the deletion of the directory in Very unlikely but it could be that some other process creates files/directories in this tests's temporary directory. Since it's using a randomly generated name, it should not really happen.
Sounds good to me. Before it would just silently pass, because there is no check that the callback given to
I have some general guidance: Every test executed in our system has at least 60 seconds (depending on configuration it can be much longer, e.g. in debug mode it is 120 seconds, ...) time to succeed. To avoid the leaking of directories, you could set it to something a bit lower, like 50 seconds.
Sounds good
With timing dependent tests I mean something in the order of seconds (in this test it was 2 seconds). This is problematic because some of our configurations we run are executing very slowly (e.g. debug interpreter) and our So if the only purpose for timeouts is to do cleanup directories, it is best to use a timeout which is close but lower than 60 seconds. |
Thank you, for clarification. I'm not familiar with the details of your test environment. As for the failure it looks strage. Please, note, that the current code is if (event is FileSystemCreateEvent) {
Expect.isFalse(event.isDirectory); // here test failed
asyncEnd();
} So we have FileSystemCreateEvent with isDirectory property set to true. Taking into account that Link is created in a sandbox created by Directory.createTempSync() I don't think that another process may do that. Looks like an issue. For Windows I created dart-lang/sdk#35102 Anyway I'll change this test and all odf the similar and send you PR for review. |
Thank you for filing the issue and changing the tests, @sgrekhov !
Agree. My thought was that perhaps the file watcher will report if the directory itself is deleted (i.e. the one it is watching). |
@mkustermann, please review #187 |
Fix for issue #186. Use Completer to get an event to test
Fixed by #187 |
After the fix, this test is still flaky (on mac). This test actually reliably fails on my mac because the
/**
* Synchronously creates the directory with this name.
*
* If [recursive] is false, only the last directory in the path is
* created. If [recursive] is true, all non-existing path components
* are created. If the directory already exists nothing is done.
*
* If the directory cannot be created an exception is thrown.
*/
void createSync({bool recursive: false}); If I sleep after creating the directories, the test succeeds: _main(Directory sandbox) async {
Directory dir = getTempDirectorySync(parent: sandbox);
Directory target = getTempDirectorySync(parent: sandbox);
sleep(Duration(seconds: 1));
asyncStart();
await testFileSystemEvent<FileSystemCreateEvent>(dir,
createEvent: () {
getTempLinkSync(parent: dir, target: target.path);
}, test: (FileSystemEvent event) {
Expect.isFalse(event.isDirectory);
});
asyncEnd();
} However, this is not an ideal solution (for reasons mentioned earlier in this issue). A better solution would be to await 1 to 3 events, and see whether the last one is is not a directory. /**
* Start watching the [FileSystemEntity] for changes.
*
* The implementation uses platform-dependent event-based APIs for receiving
* file-system notifications, thus behavior depends on the platform.
*
* * `Windows`: Uses `ReadDirectoryChangesW`. The implementation only
* supports watching directories. Recursive watching is supported.
* * `Linux`: Uses `inotify`. The implementation supports watching both
* files and directories. Recursive watching is not supported.
* Note: When watching files directly, delete events might not happen
* as expected.
* * `OS X`: Uses `FSEvents`. The implementation supports watching both
* files and directories. Recursive watching is supported.
*
* The system will start listening for events once the returned [Stream] is
* being listened to, not when the call to [watch] is issued.
*
* The returned value is an endless broadcast [Stream], that only stops when
* one of the following happens:
*
* * The [Stream] is canceled, e.g. by calling `cancel` on the
* [StreamSubscription].
* * The [FileSystemEntity] being watches, is deleted.
*
* Use `events` to specify what events to listen for. The constants in
* [FileSystemEvent] can be or'ed together to mix events. Default is
* [FileSystemEvent.ALL].
*
* A move event may be reported as seperate delete and create events.
*/
Stream<FileSystemEvent> watch(
{int events: FileSystemEvent.all, bool recursive: false}) crash log on bot: FAILED: dartk-vm product_x64 co19_2/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06
Expected: Timeout Pass
Actual: RuntimeError
--- Command "vm" (took 699ms):
DART_CONFIGURATION=ProductX64 xcodebuild/ProductX64/dart --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/tests/co19_2/src/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06.dart
exit code:
255
stdout:
unittest-suite-wait-for-done
stderr:
Unhandled exception:
Expect.isFalse(true) fails.
#0 _fail (file:///b/s/w/ir/tests/co19_2/src/Utils/expect.dart:21:5)
#1 Expect.isFalse (file:///b/s/w/ir/tests/co19_2/src/Utils/expect_common.dart:48:5)
#2 _main.<anonymous closure> (file:///b/s/w/ir/tests/co19_2/src/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06.dart:33:16)
#3 testFileSystemEvent (file:///b/s/w/ir/tests/co19_2/src/LibTest/io/file_utils.dart:53:7)
#4 _RootZone.runUnary (dart:async/zone.dart:1379:54)
#5 _FutureListener.handleValue (dart:async/future_impl.dart:126:18)
#6 Future._propagateToListeners.handleValueCallback (dart:async/future_impl.dart:639:45)
#7 Future._propagateToListeners (dart:async/future_impl.dart:668:32)
#8 Future._completeWithValue (dart:async/future_impl.dart:483:5)
#9 Future.timeout.<anonymous closure> (dart:async/future_impl.dart:737:16)
#10 _RootZone.runUnary (dart:async/zone.dart:1379:54)
#11 _FutureListener.handleValue (dart:async/future_impl.dart:126:18)
#12 Future._propagateToListeners.handleValueCallback (dart:async/future_impl.dart:639:45)
#13 Future._propagateToListeners (dart:async/future_impl.dart:668:32)
#14 Future._completeWithValue (dart:async/future_impl.dart:483:5)
#15 Future._asyncComplete.<anonymous closure> (dart:async/future_impl.dart:513:7)
#16 _microtaskLoop (dart:async/schedule_microtask.dart:41:21)
#17 _startMicrotaskLoop (dart:async/schedule_microtask.dart:50:5)
#18 _runPendingImmediateCallback (dart:isolate/runtime/libisolate_patch.dart:115:13)
#19 _RawReceivePortImpl._handleMessage (dart:isolate/runtime/libisolate_patch.dart:172:5)
--- Re-run this test:
python tools/test.py -m product -n dartk-mac-product-x64 co19_2/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06 |
… flaky The test makes assumptions about file system events firing synchronously with file system operations Issue dart-lang/co19#186 Change-Id: Ic54782662e453c240d92113d25f7a6897b268130 Reviewed-on: https://dart-review.googlesource.com/c/85684 Reviewed-by: Daco Harkes <dacoharkes@google.com> Commit-Queue: Daco Harkes <dacoharkes@google.com> Auto-Submit: Daco Harkes <dacoharkes@google.com>
@dcharkes, thank you for additional info. Seems, that @mkustermann, what do you think about this? |
So firstly the test itself looks kind of correct to me. I've just chatted with @dcharkes about this: The directory we are watching is empty before watching and the only thing we create inside there should be the link. If we get other events we have an issue (the only other event I can imagine is we get a directory-creation-event for the same directory we are watching, not sure if that is possible). For illustration purposes: 24 _main(Directory sandbox) async {
25 Directory dir = getTempDirectorySync(parent: sandbox);
26 Directory target = getTempDirectorySync(parent: sandbox);
27 asyncStart();
28
29 // We have
30 // sandbox
31 // | ---- dir // <- will start watching this one
32 // | ---- target
33 await testFileSystemEvent<FileSystemCreateEvent>(dir,
34 createEvent: () {
35 getTempLinkSync(parent: dir, target: target.path);
36 // Now we have
37 // sandbox
38 // | ---- dir
39 // | |--- symlink -| // <- new link should trigger event
40 // | -|
41 // | ---- target <----|
42 }, test: (FileSystemEvent event) {
43 Expect.isFalse(event.isDirectory);
44 });
45 asyncEnd();
46 } |
I'm sure that here we sometime catch create event for the same directory we are watching. As I said before, my hypotese is that event for creation of directory I can fix the test by addig check for the event path, and if event path is not equals to the link path, throw an error that wrong event is caught. But is it correct? If firing of create event with some delay is a normal behaviour on Mac, then the wrong event should be simply ignored. |
We've looked at the implementation code, which is in runtime/bin/file_system_watcher_macos.cc: FSEventStreamRef ref = FSEventStreamCreate(
NULL, Callback, &context, array, kFSEventStreamEventIdSinceNow, 0.10,
kFSEventStreamCreateFlagFileEvents); We explicitly tell the macos |
@mkustermann, thank you! We've figured out the reason of the flakness! Now we may fix the test to wait for some time on Mac after creating of the directories Directory dir = getTempDirectorySync(parent: sandbox);
Directory target = getTempDirectorySync(parent: sandbox);
// On Mac FileSystemCreateEvent is delayed to 0.1 seconds. Wait to allow
// these create event to be fired. Otherwise we may caught a wrong event
if (Platform.isMacOS) {
sleep(Duration(milliseconds: 200));
}
... But my opinion, it's an issue and SDK should remove 0.1 seconds delay. It took us plenty of time to figure out what's going on here. Users of Dart FileSystemEvents API on Mac will be surprized by this behaviour as well as we were. If this delay cannot be removed, then |
Maybe it wasn't clear, but what I meant is that we specify Maybe there is an issue in the MacOS implementation where the directory creation gets the same timestamp as when we start watching, then the |
Below is my understanding of what's going on
|
If watching starts at From Mac OS documentation of FSEventStreamCreate:
|
Ok, any suggestions what to do with the test? Fail, if wrong event arrived or ignore it? Or leave it as is (simply add link to this discussion)? |
@sgrekhov did you check this? If this is the case, then the question is what does the MacOS API provide exactly? And would that be enough to write a wrapper around it in Dart to make it consistent with the other OSes. Alternatively we could document the different behavior, and change the test so it works with the least common denominator of all OSes. |
@dcharkes I'm unable to check this, but according to the conversation above it is an issue with Mac API. See #186 (comment) |
$ xcodebuild/DebugX64/dart tests/co19_2/src/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06.dart
unittest-suite-wait-for-done
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_TJkb21/isDirectory_A01_t06_v0RisS/isDirectory_A01_t06_4563-7084-6159-1502.lnk')
false
unittest-suite-success $ xcodebuild/ProductX64/dart tests/co19_2/src/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06.dart
unittest-suite-wait-for-done
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_13LVL7/isDirectory_A01_t06_isVAv0')
true
Unhandled exception:
Expect.isFalse(true) fails.
#0 _fail (file:///Users/dacoharkes/dart-sdk/sdk/tests/co19_2/src/Utils/expect.dart:21:5)
#1 Expect.isFalse (file:///Users/dacoharkes/dart-sdk/sdk/tests/co19_2/src/Utils/expect_common.dart:48:5)
#2 _main.<anonymous closure> (file:///Users/dacoharkes/dart-sdk/sdk/tests/co19_2/src/LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06.dart:37:16)
#3 testFileSystemEvent (file:///Users/dacoharkes/dart-sdk/sdk/tests/co19_2/src/LibTest/io/file_utils.dart:53:7)
#4 _RootZone.runUnary (dart:async/zone.dart:1379:54)
#5 _FutureListener.handleValue (dart:async/future_impl.dart:126:18)
#6 Future._propagateToListeners.handleValueCallback (dart:async/future_impl.dart:639:45)
#7 Future._propagateToListeners (dart:async/future_impl.dart:668:32)
#8 Future._completeWithValue (dart:async/future_impl.dart:483:5)
#9 Future.timeout.<anonymous closure> (dart:async/future_impl.dart:737:16)
#10 _RootZone.runUnary (dart:async/zone.dart:1379:54)
#11 _FutureListener.handleValue (dart:async/future_impl.dart:126:18)
#12 Future._propagateToListeners.handleValueCallback (dart:async/future_impl.dart:639:45)
#13 Future._propagateToListeners (dart:async/future_impl.dart:668:32)
#14 Future._completeWithValue (dart:async/future_impl.dart:483:5)
#15 Future._asyncComplete.<anonymous closure> (dart:async/future_impl.dart:513:7)
#16 _microtaskLoop (dart:async/schedule_microtask.dart:41:21)
#17 _startMicrotaskLoop (dart:async/schedule_microtask.dart:50:5)
#18 _runPendingImmediateCallback (dart:isolate/runtime/libisolate_patch.dart:115:13)
#19 _RawReceivePortImpl._handleMessage (dart:isolate/runtime/libisolate_patch.dart:172:5) Interesting, debug has different behavior from product and release, this might be a real bug after all. Edit: maybe debug is just sufficiently slower, I do not see any ifdefs related to file system events. |
Looking at the paths, that is true. |
Changing our invocation with no latency does not fix the problem. FSEventStreamRef ref = FSEventStreamCreate(
NULL, Callback, &context, array, kFSEventStreamEventIdSinceNow, 0.0,
kFSEventStreamCreateFlagFileEvents); |
If I don't exit the test after the first event I get two events in product/release mode: FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_p2msZg/isDirectory_A01_t06_b4m65U')
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_p2msZg/isDirectory_A01_t06_b4m65U/isDirectory_A01_t06_6057-561-7428-7694.lnk') It looks like we're not the only one with an issue: https://stackoverflow.com/questions/47679298/howto-avoid-receiving-old-events-in-fseventstream-callback-fsevents-framework-o @mkustermann: should we make a work-around in Dart? edit: I'm unsure if we can detect that we're getting events from too early though. |
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_6x5WTs/isDirectory_A01_t06_6KZHZ2')
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_6x5WTs/isDirectory_A01_t06_6KZHZ2/isDirectory_A01_t06_z3cb87')
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_6x5WTs/isDirectory_A01_t06_6KZHZ2/isDirectory_A01_t06_IzLYgz')
FileSystemCreateEvent('/var/folders/6l/j64crzh16j7djnq676q0994h00klzg/T/isDirectory_A01_t06_6x5WTs/isDirectory_A01_t06_6KZHZ2/isDirectory_A01_t06_5737-4795-8524-6591.lnk') Great, if we create some extra subfolders before we start watching, we also get those events... |
@mkustermann , @dcharkes , I'm going to close this issue. According to the conversation above it's not an issue with the test, but some issue with... And I'm not sure whith what. Dart SDK for Mac (I'll fill an issue for that, then), or with Mac API. What's your opinion? |
dart-lang/sdk#37342 created for tracking this issue. |
From log:
Looking at LibTest/io/FileSystemCreateEvent/isDirectory_A01_t06:
This function should wait until it's done with the test, which can for example be done via:
This will ensure we got an event and validated the event is the one we expect and then returns to the
inSandbox()
.Furthermore in LibTest/io/file_utils:
The
delete()
method returns aFuture
and needs to be await'ed. Also we do not want any timing dependent tests. If the purpose is to make sure the directory gets cleaned up, then we should increase the timeout way up, for example 50 seconds.The text was updated successfully, but these errors were encountered: