From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Fabrice Popineau Newsgroups: gmane.emacs.bugs Subject: bug#22534: File notify broken on Windows Date: Thu, 11 Feb 2016 16:19:49 +0100 Message-ID: References: <83h9hrytom.fsf@gnu.org> <87lh72xln0.fsf@gmx.de> <838u30wbx5.fsf@gnu.org> <83fux7v56c.fsf@gnu.org> <871t8rm5x8.fsf@gmx.de> <83si17t02p.fsf@gnu.org> <83wpqhsrv3.fsf@gnu.org> <874mdllk0f.fsf@gmx.de> <83r3gpsjey.fsf@gnu.org> <83a8ncs9b4.fsf@gnu.org> <871t8nwl80.fsf@gmx.de> <831t8nqdk3.fsf@gnu.org> <83io1w9y1l.fsf@gnu.org> NNTP-Posting-Host: plane.gmane.org Mime-Version: 1.0 Content-Type: multipart/alternative; boundary=001a1135fd060d8d58052b801630 X-Trace: ger.gmane.org 1455204089 22677 80.91.229.3 (11 Feb 2016 15:21:29 GMT) X-Complaints-To: usenet@ger.gmane.org NNTP-Posting-Date: Thu, 11 Feb 2016 15:21:29 +0000 (UTC) Cc: 22534@debbugs.gnu.org, Michael Albinus To: Eli Zaretskii Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Thu Feb 11 16:21:17 2016 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane.org Original-Received: from lists.gnu.org ([208.118.235.17]) by plane.gmane.org with esmtp (Exim 4.69) (envelope-from ) id 1aTt3U-00084r-Ia for geb-bug-gnu-emacs@m.gmane.org; Thu, 11 Feb 2016 16:21:16 +0100 Original-Received: from localhost ([::1]:50939 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aTt3T-000739-Vs for geb-bug-gnu-emacs@m.gmane.org; Thu, 11 Feb 2016 10:21:16 -0500 Original-Received: from eggs.gnu.org ([2001:4830:134:3::10]:53284) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aTt3K-0006uM-0G for bug-gnu-emacs@gnu.org; Thu, 11 Feb 2016 10:21:13 -0500 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1aTt3G-00062I-N5 for bug-gnu-emacs@gnu.org; Thu, 11 Feb 2016 10:21:05 -0500 Original-Received: from debbugs.gnu.org ([208.118.235.43]:55949) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1aTt3G-000627-Hq for bug-gnu-emacs@gnu.org; Thu, 11 Feb 2016 10:21:02 -0500 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84) (envelope-from ) id 1aTt3G-0001E6-9K for bug-gnu-emacs@gnu.org; Thu, 11 Feb 2016 10:21:02 -0500 X-Loop: help-debbugs@gnu.org Resent-From: Fabrice Popineau Original-Sender: "Debbugs-submit" Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Thu, 11 Feb 2016 15:21:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 22534 X-GNU-PR-Package: emacs X-GNU-PR-Keywords: Original-Received: via spool by 22534-submit@debbugs.gnu.org id=B22534.14552040184652 (code B ref 22534); Thu, 11 Feb 2016 15:21:02 +0000 Original-Received: (at 22534) by debbugs.gnu.org; 11 Feb 2016 15:20:18 +0000 Original-Received: from localhost ([127.0.0.1]:36857 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84) (envelope-from ) id 1aTt2X-0001Cw-Gi for submit@debbugs.gnu.org; Thu, 11 Feb 2016 10:20:18 -0500 Original-Received: from mail-ob0-f170.google.com ([209.85.214.170]:33678) by debbugs.gnu.org with esmtp (Exim 4.84) (envelope-from ) id 1aTt2V-0001Ce-1l for 22534@debbugs.gnu.org; Thu, 11 Feb 2016 10:20:15 -0500 Original-Received: by mail-ob0-f170.google.com with SMTP id is5so77522813obc.0 for <22534@debbugs.gnu.org>; Thu, 11 Feb 2016 07:20:15 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:from:date:message-id:subject:to :cc:content-type; bh=HWQ3DT0oV6T53oMOp1GOT22yapYnn//jElkacblF/HM=; b=oUqY7iRBpsTdVWnMLwdEh9jJwqXiTrwUkjd719abA1TeFb3pc/FlqOe7Lr9KlEnsuj ijO1Q8vFN+OMdRGGITIoyo/DNPswRqKmuPqHWxt8OG7HgnWYQwjpYZIwvAx8wlwzRXmy JL6YqN9mUT6uTtsxCRvhQlwJbTYjNi3UsPqrkam9MBv8Qd9r6d94HCkQEVuyJUBdut6Q l6K5r42TEcbkj19n9sk6cu5rrMLU5NYplj4k0rl9C8fVUJ9CBBBRyHl8vpCanpSJb/7G jekr9ZiG2bYjjzsmRH4O+ZLucNXpbjMMgLOMpo/D5PIRaojKTYPbTHf+P232jRbCxcWY OkNw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to:cc:content-type; bh=HWQ3DT0oV6T53oMOp1GOT22yapYnn//jElkacblF/HM=; b=LzHbniweHAkqeD+seZ/JlYMc7lASAl6KivHn9JvBAJYiJZ/Axg1T4seMdK32E27Tkh PpBnx7Nquj0lN7Pw3rnjyvYwQLXTnqYKTWf5qdQHv7/Sb5X+vcr6N2JP0jLB40PfdTcG takBMwPi/A2nyGJsb9tQ3AIFA4pacCMYFdsguvZn1SJ6nVy2RW6oLsT2JlSViibPGufu OpzaozM6cdKGKa03J7UjwagZvTpu/lmHRoNzE0FlgXUiEZr1LZS6HO6BcuRfC7ig8jN0 TQdO4NFgNnYw2fqeuR7qzj0iyQTI3fEetYENo0dhcHu5PwLT8rN1GSYxKNDANQE7iPjr FOLw== X-Gm-Message-State: AG10YOQoKNfBzxo5WxY0loHNgTVIhSpnJS6dlgUj6QYpmoH2SVH+nFKfbqKs4SApRhddYS+9qykpb2wYTE3Bzg== X-Received: by 10.60.73.170 with SMTP id m10mr48315552oev.51.1455204009346; Thu, 11 Feb 2016 07:20:09 -0800 (PST) Original-Received: by 10.202.78.75 with HTTP; Thu, 11 Feb 2016 07:19:49 -0800 (PST) In-Reply-To: <83io1w9y1l.fsf@gnu.org> X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 208.118.235.43 X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Original-Sender: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.bugs:112893 Archived-At: --001a1135fd060d8d58052b801630 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Some information regarding the original problem. I have turned on some tracing and this is what I get with file-notify-test02-events along these lines: $ git diff -w origin/emacs-25 src/w32notify.c diff --git a/src/w32notify.c b/src/w32notify.c index 71787c4..66ad277 100644 --- a/src/w32notify.c +++ b/src/w32notify.c @@ -207,6 +207,7 @@ watch_completion (DWORD status, DWORD bytes_ret, OVERLAPPED *io_info) freed by someone already? In any case, we cannot do anything with this request, so just punt and skip it. FIXME: should we raise the 'terminate' flag in this case? */ + DebPrint(("status =3D %lx, io_info =3D %lx\n", status, io_info)); if (!io_info) return; @@ -227,6 +228,7 @@ watch_completion (DWORD status, DWORD bytes_ret, OVERLAPPED *io_info) by its buffers; this is done by the main thread in remove_watch. Calling malloc/free from a thread other than the main thread is a no-no. */ + DebPrint(("Operation aborted.")); dirwatch->dir =3D NULL; dirwatch->terminate =3D 1; } @@ -406,11 +408,13 @@ remove_watch (struct notification *dirwatch) break; Sleep (10); } + DebPrint(("status =3D %lx, exit_code =3D %lx\n", status, exit_code))= ; if ((status =3D=3D FALSE && (err =3D GetLastError ()) =3D=3D ERROR_INVALID_HANDLE) || exit_code =3D=3D STILL_ACTIVE) { if (!(status =3D=3D FALSE && err =3D=3D ERROR_INVALID_HANDLE)) { + DebPrint(("Terminating thread.\n")); TerminateThread (dirwatch->thr, 0); if (dirwatch->dir) CloseHandle (dirwatch->dir); @@ -523,7 +527,7 @@ generate notifications correctly, though. */) char *errstr; CHECK_LIST (filter); - + DebPrint(("AddWatch\n")); /* The underlying features are available only since XP. */ if (os_subtype =3D=3D OS_9X || (w32_major_version =3D=3D 5 && w32_minor_version < 1)) I also forced DebPrint to write on stderr. When run in batch mode: $ make SELECTOR=3D'(quote (eql file-notify-test02-events))' -C test/automated file-notify-tests make : on entre dans le r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated =C2=BB make[1] : on entre dans le r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated =C2=BB make[2] : on entre dans le r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated =C2=BB Compiling ../../../emacs/test/automated/file-notify-tests.el make[2] : on quitte le r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated =C2=BB Testing ../../../emacs/test/automated/file-notify-tests.elc Running 1 tests (2016-02-11 16:14:39+0100) AddWatch status =3D 0, io_info =3D 3dd8090 status =3D 0, io_info =3D 3dd8090 status =3D 0, io_info =3D 3dd8090 status =3D 3e3, io_info =3D 3dd8090 Operation aborted. status =3D 1, exit_code =3D 0 AddWatch status =3D 0, io_info =3D 3dd8210 status =3D 0, io_info =3D 3dd8210 status =3D 0, io_info =3D 3dd8210 status =3D 3e3, io_info =3D 3dd8210 Operation aborted. status =3D 1, exit_code =3D 0 AddWatch status =3D 0, io_info =3D 3dd8000 status =3D 0, io_info =3D 3dd8000 watch_worker, abnormal exit: 5 QueueUserAPC failed (31)! status =3D 1, exit_code =3D 1 Test file-notify-test02-events backtrace: #[0 "\306\307\310C\307C\3111(\312\313\314\315$\317\"\32 ert--run-test-internal([cl-struct-ert--test-execution-info [cl-struc ert-run-test([cl-struct-ert-test file-notify-test02-events "Check fi ert-run-or-rerun-test([cl-struct-ert--stats (eql file-notify-test02- ert-run-tests((eql file-notify-test02-events) #[385 "\306\307\"\203 ert-run-tests-batch((eql file-notify-test02-events)) ert-run-tests-batch-and-exit((eql file-notify-test02-events)) eval((ert-run-tests-batch-and-exit (quote (eql file-notify-test02-ev command-line-1(("-L" ";../../../emacs/test/automated" "-l" "ert" "-l command-line() normal-top-level() Test file-notify-test02-events condition: (ert-test-failed ((should (file-notify--test-with-events-check events)) :form (file-notify--test-with-events-check ((created changed deleted))) :value nil :explanation "Received events `(created changed)' do not match expected events `(created changed deleted)'")) FAILED 1/1 file-notify-test02-events Ran 1 tests, 0 results as expected, 1 unexpected (2016-02-11 16:15:20+0100) 1 unexpected results: FAILED file-notify-test02-events When I run in normal mode: $ src/emacs -Q -l ../emacs/test/automated/file-notify-tests.el AddWatch status =3D 0, io_info =3D 42dd0a0 status =3D 0, io_info =3D 42dd0a0 status =3D 0, io_info =3D 42dd0a0 status =3D 0, io_info =3D 42dd0a0 status =3D 3e3, io_info =3D 42dd0a0 Operation aborted.status =3D 1, exit_code =3D 0 AddWatch status =3D 0, io_info =3D 42dcc50 status =3D 0, io_info =3D 42dcc50 status =3D 0, io_info =3D 42dcc50 status =3D 0, io_info =3D 42dcc50 status =3D 3e3, io_info =3D 42dcc50 Operation aborted.status =3D 1, exit_code =3D 0 AddWatch status =3D 0, io_info =3D 42dd310 status =3D 0, io_info =3D 42dd310 status =3D 0, io_info =3D 42dd310 watch_worker, abnormal exit: 5 QueueUserAPC failed (31)! status =3D 1, exit_code =3D 1 AddWatch status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 status =3D 0, io_info =3D 42dd2b0 watch_worker, abnormal exit: 5 QueueUserAPC failed (31)! status =3D 1, exit_code =3D 1 AddWatch status =3D 0, io_info =3D 42dcec0 status =3D 0, io_info =3D 42dcec0 status =3D 0, io_info =3D 42dcec0 status =3D 0, io_info =3D 42dcec0 status =3D 5, io_info =3D 42dcec0 watch_worker, abnormal exit: 5 QueueUserAPC failed (31)! status =3D 1, exit_code =3D 1 AddWatch status =3D 0, io_info =3D 42dcec0 status =3D 0, io_info =3D 42dcec0 status =3D 3e3, io_info =3D 42dcec0 Operation aborted.status =3D 1, exit_code =3D 0 and the test is passed. The first diagnostic is that QueueUserAPC shouldn't fail with error 31. This happens because the worker thread is already terminating, but that does not leave a chance for watch_end to run. Fabrice 2016-02-10 20:15 GMT+01:00 Eli Zaretskii : > > From: Fabrice Popineau > > Date: Mon, 8 Feb 2016 20:15:59 +0100 > > Cc: Michael Albinus , 22534@debbugs.gnu.org > > > > > From: Fabrice Popineau > > > Date: Mon, 8 Feb 2016 11:43:10 +0100 > > > Cc: Eli Zaretskii , 22534@debbugs.gnu.org > > > > > > > events: ((created changed deleted)) ((17491048 created > > > > > c:/Users/Fabrice/AppData/Local/Temp/file-notify-test-parent20748Ali/file-= notify-test20748Nvo) > > > > (17491048 changed > > > > > c:/Users/Fabrice/AppData/Local/Temp/file-notify-test-parent20748Ali/file-= notify-test20748Nvo)) > > > > > > Fails also for me in batch mode. Surprisingly, it doesn't fail alway= s, > > > sometimes (about 1 in 10 runs) it succeeds here, and fails in the ne= xt > > > step. Strange. > > > > > > I see the same. The deleted notifications number vary. When you > expect 2, sometimes I see 1. > > > When you expect one, sometimes I see it. But not frequently. > > > > Did you try adding calls to read-event after the functions that are > > supposed to produce these events? > > > > Yes, but with no results. > > Strange. I see none of that on my machine. Maybe it's because my > disk is SSD, maybe because this is XP. Who knows? > > Michael, I think it's time to do what you suggested: > > > If we do not care the missing `deleted' event in batch mode, I could > > make it optional in the test. > > Re this: > > > But maybe it is an indication for a serious problem in w32notify. > > It might, but it's unlikely, and I won't have time to dig into this in > the following weeks, so I guess this will have to wait for a recipe I > can reproduce on one of my machines. > > Thanks. > --001a1135fd060d8d58052b801630 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
Some information regarding the original problem.

<= /div>
I have turned on some tracing and this is what I get with file-no= tify-test02-events
along these lines:

$ git diff -w origin/emacs-25 src/w32notify.c
diff --git a/src= /w32notify.c b/src/w32notify.c
index 71787c4..66ad277 100644
--- a/src/w32notify.c
+++ b/src/w32notify.c
@@ -2= 07,6 +207,7 @@ watch_completion (DWORD status, DWORD bytes_ret, OVERLAPPED = *io_info)
=C2=A0 =C2=A0 =C2=A0 freed by someone already?=C2=A0 In= any case, we cannot do anything
=C2=A0 =C2=A0 =C2=A0 with this r= equest, so just punt and skip it.=C2=A0 FIXME: should we
=C2=A0 = =C2=A0 =C2=A0 raise the 'terminate' flag in this case? =C2=A0*/
+ =C2=A0DebPrint(("status =3D %lx, io_info =3D %lx\n", sta= tus, io_info));
=C2=A0 =C2=A0if (!io_info)
=C2=A0 =C2= =A0 =C2=A0return;

@@ -227,6 +228,7 @@ watch_comple= tion (DWORD status, DWORD bytes_ret, OVERLAPPED *io_info)
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 by its buffers; this is done by the main thread= in
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 remove_watch.=C2=A0 Callin= g malloc/free from a thread other than
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 the main thread is a no-no. =C2=A0*/
+ =C2=A0 =C2=A0 = =C2=A0DebPrint(("Operation aborted."));
=C2=A0 =C2=A0 = =C2=A0 =C2=A0dirwatch->dir =3D NULL;
=C2=A0 =C2=A0 =C2=A0 =C2= =A0dirwatch->terminate =3D 1;
=C2=A0 =C2=A0 =C2=A0}
= @@ -406,11 +408,13 @@ remove_watch (struct notification *dirwatch)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0break;
=C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Sleep (10);
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 }
+ =C2=A0 =C2=A0 =C2=A0DebPrint(("status =3D %lx= , exit_code =3D %lx\n", status, exit_code));
=C2=A0 =C2=A0 = =C2=A0 =C2=A0if ((status =3D=3D FALSE && (err =3D GetLastError ()) = =3D=3D ERROR_INVALID_HANDLE)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0|| exit_code =3D=3D STILL_ACTIVE)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 {
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0if (!(status =3D= =3D FALSE && err =3D=3D ERROR_INVALID_HANDLE))
=C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0{
+ =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0DebPrint(("Terminating thread.\n"));
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0TerminateTh= read (dirwatch->thr, 0);
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0if (dirwatch->dir)
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 CloseHandle (dirwatch->dir);
@@ -523,7 +527,7 @@ generate notifications correctly, though. =C2=A0*/)
=C2=A0 =C2=A0char *errstr;

=C2=A0 =C2=A0C= HECK_LIST (filter);
-
+ =C2=A0DebPrint(("AddWatch\= n"));
=C2=A0 =C2=A0/* The underlying features are available = only since XP. =C2=A0*/
=C2=A0 =C2=A0if (os_subtype =3D=3D OS_9X<= /div>
=C2=A0 =C2=A0 =C2=A0 =C2=A0|| (w32_major_version =3D=3D 5 &&a= mp; w32_minor_version < 1))

I also forced= DebPrint to write on stderr.


When = run in batch mode:

$ make SELECTOR=3D'(qu= ote (eql file-notify-test02-events))' =C2=A0 -C test/automated file-not= ify-tests
make : on entre dans le r=C3=A9pertoire =C2=AB /d/Sourc= e/emacs/build-emacs-25/test/automated =C2=BB
make[1] : on entre d= ans le r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated= =C2=BB
make[2] : on entre dans le r=C3=A9pertoire =C2=AB /d/Sour= ce/emacs/build-emacs-25/test/automated =C2=BB
Compiling ../../../= emacs/test/automated/file-notify-tests.el
make[2] : on quitte le = r=C3=A9pertoire =C2=AB /d/Source/emacs/build-emacs-25/test/automated =C2=BB=
Testing ../../../emacs/test/automated/file-notify-tests.elc
Running 1 tests (2016-02-11 16:14:39+0100)
AddWatch
status =3D 0, io_info =3D 3dd8090
status =3D 0, io_info =3D 3d= d8090
status =3D 0, io_info =3D 3dd8090
status =3D 3e3,= io_info =3D 3dd8090
Operation aborted.
status =3D 1, e= xit_code =3D 0
AddWatch
status =3D 0, io_info =3D 3dd82= 10
status =3D 0, io_info =3D 3dd8210
status =3D 0, io_i= nfo =3D 3dd8210
status =3D 3e3, io_info =3D 3dd8210
Ope= ration aborted.
status =3D 1, exit_code =3D 0
AddWatch<= /div>
status =3D 0, io_info =3D 3dd8000
status =3D 0, io_info= =3D 3dd8000
watch_worker, abnormal exit: 5
QueueUserAP= C failed (31)!
status =3D 1, exit_code =3D 1
Test file-= notify-test02-events backtrace:
=C2=A0 #[0 "\306\307\310C\30= 7C\3111(\312\313\314\315$\317\"\32
=C2=A0 ert--run-test-inte= rnal([cl-struct-ert--test-execution-info [cl-struc
=C2=A0 ert-run= -test([cl-struct-ert-test file-notify-test02-events "Check fi
=C2=A0 ert-run-or-rerun-test([cl-struct-ert--stats (eql file-notify-test0= 2-
=C2=A0 ert-run-tests((eql file-notify-test02-events) #[385 &qu= ot;\306\307\"\203
=C2=A0 ert-run-tests-batch((eql file-notif= y-test02-events))
=C2=A0 ert-run-tests-batch-and-exit((eql file-n= otify-test02-events))
=C2=A0 eval((ert-run-tests-batch-and-exit (= quote (eql file-notify-test02-ev
=C2=A0 command-line-1(("-L&= quot; ";../../../emacs/test/automated" "-l" "ert&q= uot; "-l
=C2=A0 command-line()
=C2=A0 normal-top-l= evel()
Test file-notify-test02-events condition:
=C2=A0= =C2=A0 (ert-test-failed
=C2=A0 =C2=A0 =C2=A0((should
= =C2=A0 =C2=A0 =C2=A0 =C2=A0(file-notify--test-with-events-check events))
=C2=A0 =C2=A0 =C2=A0 :form
=C2=A0 =C2=A0 =C2=A0 (file-not= ify--test-with-events-check
=C2=A0 =C2=A0 =C2=A0 =C2=A0((created = changed deleted)))
=C2=A0 =C2=A0 =C2=A0 :value nil :explanation &= quot;Received events `(created changed)' do not match expected events `= (created changed deleted)'"))
=C2=A0 =C2=A0FAILED =C2=A0= 1/1 =C2=A0file-notify-test02-events

Ran 1 tests, 0= results as expected, 1 unexpected (2016-02-11 16:15:20+0100)
1 unexpected results:
=C2=A0 =C2=A0FAILED =C2=A0file-= notify-test02-events

When I run in normal mo= de:

$ src/emacs -Q -l ../emacs/test/automated= /file-notify-tests.el
AddWatch
status =3D 0, io_info = =3D 42dd0a0
status =3D 0, io_info =3D 42dd0a0
status = =3D 0, io_info =3D 42dd0a0
status =3D 0, io_info =3D 42dd0a0
status =3D 3e3, io_info =3D 42dd0a0
Operation aborted.statu= s =3D 1, exit_code =3D 0
AddWatch
status =3D 0, io_info= =3D 42dcc50
status =3D 0, io_info =3D 42dcc50
status = =3D 0, io_info =3D 42dcc50
status =3D 0, io_info =3D 42dcc50
status =3D 3e3, io_info =3D 42dcc50
Operation aborted.statu= s =3D 1, exit_code =3D 0
AddWatch
status =3D 0, io_info= =3D 42dd310
status =3D 0, io_info =3D 42dd310
status = =3D 0, io_info =3D 42dd310
watch_worker, abnormal exit: 5
QueueUserAPC failed (31)!
status =3D 1, exit_code =3D 1
<= div>AddWatch
status =3D 0, io_info =3D 42dd2b0
status = =3D 0, io_info =3D 42dd2b0
status =3D 0, io_info =3D 42dd2b0
status =3D 0, io_info =3D 42dd2b0
status =3D 0, io_info =3D= 42dd2b0
status =3D 0, io_info =3D 42dd2b0
status =3D 0= , io_info =3D 42dd2b0
status =3D 0, io_info =3D 42dd2b0
watch_worker, abnormal exit: 5
QueueUserAPC failed (31)!
status =3D 1, exit_code =3D 1
AddWatch
status =3D 0,= io_info =3D 42dcec0
status =3D 0, io_info =3D 42dcec0
= status =3D 0, io_info =3D 42dcec0
status =3D 0, io_info =3D 42dce= c0
status =3D 5, io_info =3D 42dcec0
watch_worker, abno= rmal exit: 5
QueueUserAPC failed (31)!
status =3D 1, ex= it_code =3D 1
AddWatch
status =3D 0, io_info =3D 42dcec= 0
status =3D 0, io_info =3D 42dcec0
status =3D 3e3, io_= info =3D 42dcec0
Operation aborted.status =3D 1, exit_code =3D 0<= /div>

and the test is passed.

=

The first diagnostic is that QueueUserAPC shouldn't= fail with error 31.
This happens because the worker thread is al= ready terminating, but that does not leave
a chance for watch_end= to run.

Fabrice

2016-02-10 20:15 GMT+01:00 Eli Zaretski= i <e= liz@gnu.org>:
> From: Fa= brice Popineau <fabrice.po= pineau@gmail.com>
> Date: Mon, 8 Feb 2016 20:15:59 +0100
> Cc: Michael Albinus <michael.albinus@gmx.de>, 22534@debbugs.gnu.org
>
>=C2=A0 > From: Fabrice Popineau <fabrice.popineau@gmail.com> >=C2=A0 > Date: Mon, 8 Feb 2016 11:43:10 +0100
>=C2=A0 > Cc: Eli Zaretskii <eliz@= gnu.org>, 22534@debbugs.gnu= .org
>=C2=A0 >
>=C2=A0 > > events: ((created changed deleted)) ((17491048 created=
>=C2=A0 > > c:/Users/Fabrice/AppData/Local/Temp/file-notify-test-p= arent20748Ali/file-notify-test20748Nvo)
>=C2=A0 > > (17491048 changed
>=C2=A0 > > c:/Users/Fabrice/AppData/Local/Temp/file-notify-test-p= arent20748Ali/file-notify-test20748Nvo))
>=C2=A0 >
>=C2=A0 > Fails also for me in batch mode. Surprisingly, it doesn'= ;t fail always,
>=C2=A0 > sometimes (about 1 in 10 runs) it succeeds here, and fails = in the next
>=C2=A0 > step. Strange.
>=C2=A0 >
>=C2=A0 > I see the same. The deleted notifications number vary. When= you expect 2, sometimes I see 1.
>=C2=A0 > When you expect one, sometimes I see it. But not frequently= .
>
>=C2=A0 Did you try adding calls to read-event after the functions that = are
>=C2=A0 supposed to produce these events?
>
> Yes, but with no results.

Strange.=C2=A0 I see none of that on my machine.=C2=A0 Maybe it'= s because my
disk is SSD, maybe because this is XP.=C2=A0 Who knows?

Michael, I think it's time to do what you suggested:

> If we do not care the missing `deleted' event in batch mode, I cou= ld
> make it optional in the test.

Re this:

> But maybe it is an indication for a serious problem in w32notify.

It might, but it's unlikely, and I won't have time to dig in= to this in
the following weeks, so I guess this will have to wait for a recipe I
can reproduce on one of my machines.

Thanks.

--001a1135fd060d8d58052b801630--