auto-revert error on macOS when auto-revert-use-notify is t

auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 1553 bytes --]

Emacs: 26.0.90
OS: macOS 10.13.2

1. start Emacs with -Q
2. open a test file (like 1.c)
3. turn on auto-revert-mode by run global-auto-revert-mode
4. add auto-revert-use-notify as a watcher variable by debug-on-variable-change
5. open the test file with vim
6. modify the test file in vim and save it
7. Emacs enter debug with the following msg:

Debugger entered--setting auto-revert-use-notify in buffer 1.c to nil:
  debug--implement-debug-watch(auto-revert-use-notify nil set #<buffer 1.c>)
  auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
  file-notify--rm-descriptor(13)
  file-notify-rm-watch(13)
  #f(compiled-function (key value) #<bytecode 0x40a952e1>)(13 (#<buffer 1.c>))
  maphash(#f(compiled-function (key value) #<bytecode 0x40a952e1>) #<hash-table equal 7/65 0x40e7896d>)
  auto-revert-notify-rm-watch()
  auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
  file-notify--rm-descriptor(13)
  file-notify-rm-watch(13)
  file-notify-callback((13 (rename delete) "/Users/jun/test/1.c"))
  file-notify-handle-event((file-notify (13 (rename delete) "/Users/jun/test/1.c") file-notify-callback))
  funcall-interactively(file-notify-handle-event (file-notify (13 (rename delete) "/Users/jun/test/1.c") file-notify-callback))
  call-interactively(file-notify-handle-event nil [(file-notify (13 (rename delete) "/Users/jun/test/1.c") file-notify-callback)])
  command-execute(file-notify-handle-event nil [(file-notify (13 (rename delete) "/Users/jun/test/1.c") file-notify-callback)] t)



[-- Attachment #2: Type: text/html, Size: 2513 bytes --]

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Michael Albinus]

zhang cc <ccsmile2008@outlook.com> writes:

Hi,

> Emacs: 26.0.90 
> OS: macOS 10.13.2
>
> 1. start Emacs with -Q
> 2. open a test file (like 1.c)
> 3. turn on auto-revert-mode by run global-auto-revert-mode
> 4. add auto-revert-use-notify as a watcher variable by
> debug-on-variable-change
> 5. open the test file with vim
> 6. modify the test file in vim and save it
> 7. Emacs enter debug with the following msg:
>
> Debugger entered--setting auto-revert-use-notify in buffer 1.c to nil:
>   debug--implement-debug-watch(auto-revert-use-notify nil set #<buffer
> 1.c>)
>   auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
>   file-notify--rm-descriptor(13)
>   file-notify-rm-watch(13)
>   #f(compiled-function (key value) #<bytecode 0x40a952e1>)(13
> (#<buffer 1.c>))
>   maphash(#f(compiled-function (key value) #<bytecode 0x40a952e1>)
> #<hash-table equal 7/65 0x40e7896d>)
>   auto-revert-notify-rm-watch()
>   auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
>   file-notify--rm-descriptor(13)
>   file-notify-rm-watch(13)
>   file-notify-callback((13 (rename delete) "/Users/jun/test/1.c"))
>   file-notify-handle-event((file-notify (13 (rename delete)
> "/Users/jun/test/1.c") file-notify-callback))
>   funcall-interactively(file-notify-handle-event (file-notify (13
> (rename delete) "/Users/jun/test/1.c") file-notify-callback))
>   call-interactively(file-notify-handle-event nil [(file-notify (13
> (rename delete) "/Users/jun/test/1.c") file-notify-callback)])
>   command-execute(file-notify-handle-event nil [(file-notify (13
> (rename delete) "/Users/jun/test/1.c") file-notify-callback)] t)

Well, this is not an error. The watchdog over "/Users/jun/test/1.c"
receives the `(rename delete)' events from writing the file. Due to
this, the watchdog is removed, as you see in the backtrace.

I could reproduce this behaviour on my GNU/Linux system. See the
following example, just from the shell:

--8<---------------cut here---------------start------------->8---
$ touch 1.c
$ ls -il 1.c*
3282165 -rw-r--r-- 1 albinus albinus 0 Dec 29 10:52 1.c
--8<---------------cut here---------------end--------------->8---

A zero length file 1.c has been created with inode 3282165.

--8<---------------cut here---------------start------------->8---
$ vim 1.c
$ ls -il 1.c*
3283516 -rw-r--r-- 1 albinus albinus 5 Dec 29 10:53 1.c
--8<---------------cut here---------------end--------------->8---

I have modified the file with vim, and saved. Now the inode is 3283516,
which means a *new* file with the same name. While saving the file, a
temporary file has been created, and renamed then to the original file
name. From Emacs' file-notify point of view, this is a new file.

If you want to keep the original file, you must apply backup-by-copy in
vim. Apply the following settings in ~/.vimrc, and rerun the test:

--8<---------------cut here---------------start------------->8---
$ cat <<EOF >~/.vimrc
set backup
set backupcopy=yes
EOF
$ vim 1.c
$ ls -il 1.c*
3283516 -rw-r--r-- 1 albinus albinus 9 Dec 29 10:58 1.c
3283482 -rw-r--r-- 1 albinus albinus 5 Dec 29 10:53 1.c~
--8<---------------cut here---------------end--------------->8---

You'll see that the inode 3283516 is kept.

Best regards, Michael.

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Date: Fri, 29 Dec 2017 11:02:10 +0100
> Cc: "emacs-devel@gnu.org" <emacs-devel@gnu.org>
> 
> > Emacs: 26.0.90 
> > OS: macOS 10.13.2
> >
> > 1. start Emacs with -Q
> > 2. open a test file (like 1.c)
> > 3. turn on auto-revert-mode by run global-auto-revert-mode
> > 4. add auto-revert-use-notify as a watcher variable by
> > debug-on-variable-change
> > 5. open the test file with vim
> > 6. modify the test file in vim and save it
> > 7. Emacs enter debug with the following msg:
> >
> > Debugger entered--setting auto-revert-use-notify in buffer 1.c to nil:
> >   debug--implement-debug-watch(auto-revert-use-notify nil set #<buffer
> > 1.c>)
> >   auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
> >   file-notify--rm-descriptor(13)
> >   file-notify-rm-watch(13)
> >   #f(compiled-function (key value) #<bytecode 0x40a952e1>)(13
> > (#<buffer 1.c>))
> >   maphash(#f(compiled-function (key value) #<bytecode 0x40a952e1>)
> > #<hash-table equal 7/65 0x40e7896d>)
> >   auto-revert-notify-rm-watch()
> >   auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
> >   file-notify--rm-descriptor(13)
> >   file-notify-rm-watch(13)
> >   file-notify-callback((13 (rename delete) "/Users/jun/test/1.c"))
> >   file-notify-handle-event((file-notify (13 (rename delete)
> > "/Users/jun/test/1.c") file-notify-callback))
> >   funcall-interactively(file-notify-handle-event (file-notify (13
> > (rename delete) "/Users/jun/test/1.c") file-notify-callback))
> >   call-interactively(file-notify-handle-event nil [(file-notify (13
> > (rename delete) "/Users/jun/test/1.c") file-notify-callback)])
> >   command-execute(file-notify-handle-event nil [(file-notify (13
> > (rename delete) "/Users/jun/test/1.c") file-notify-callback)] t)
> 
> Well, this is not an error. The watchdog over "/Users/jun/test/1.c"
> receives the `(rename delete)' events from writing the file. Due to
> this, the watchdog is removed, as you see in the backtrace.

Exactly, I think this is precisely the expected behavior: step 4
requests the debugger to be entered when auto-revert-use-notify is
modified, and auto-revert-notify-handler does modify it when the
watched file is deleted:

      (if (eq action 'stopped)
          ;; File notification has stopped.  Continue with polling.
          (cl-dolist (buffer
                      (if global-auto-revert-mode
                          (buffer-list) auto-revert-buffer-list))
            (with-current-buffer buffer
              (when (and (equal descriptor auto-revert-notify-watch-descriptor)
                         (or
                          ;; A buffer associated with a file.
                          (and (stringp buffer-file-name)
                               (string-equal
                                (file-name-nondirectory file)
                                (file-name-nondirectory buffer-file-name)))
                          ;; A buffer w/o a file, like dired.
                          (null buffer-file-name)))
                (auto-revert-notify-rm-watch)
                (setq-local auto-revert-use-notify nil))))  <<<<<<<<<<<<<

Re: auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 3342 bytes --]

It seems that this not a bug, but a user experience issue. It is not convenient to tweak vim and
other apps which can modify file.

What about the following logic:
When the auto-revert module known the file is renamed or deleted, delete the watch
and start a one shot short timer(about 100ms) to check the visiting file of the buffer. On timeout,
if the file exists, revert the file and add a new watch, otherwise, tell user the file doesn’t exist
and fallback to the default polling(5s).
Once the visiting file of the buffer can be accessed, go back to use file-notify again.

On 29 Dec 2017, 6:14 PM +0800, Eli Zaretskii <eliz@gnu.org>, wrote:
From: Michael Albinus <michael.albinus@gmx.de
Date: Fri, 29 Dec 2017 11:02:10 +0100
Cc: "emacs-devel@gnu.org" <emacs-devel@gnu.org

Emacs: 26.0.90
OS: macOS 10.13.2

1. start Emacs with -Q
2. open a test file (like 1.c)
3. turn on auto-revert-mode by run global-auto-revert-mode
4. add auto-revert-use-notify as a watcher variable by
debug-on-variable-change
5. open the test file with vim
6. modify the test file in vim and save it
7. Emacs enter debug with the following msg:

Debugger entered--setting auto-revert-use-notify in buffer 1.c to nil:
debug--implement-debug-watch(auto-revert-use-notify nil set #<buffer
1.c>)
auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
file-notify--rm-descriptor(13)
file-notify-rm-watch(13)
#f(compiled-function (key value) #<bytecode 0x40a952e1>)(13
(#<buffer 1.c>))
maphash(#f(compiled-function (key value) #<bytecode 0x40a952e1>)
#<hash-table equal 7/65 0x40e7896d>)
auto-revert-notify-rm-watch()
auto-revert-notify-handler((13 stopped "/Users/jun/test/1.c"))
file-notify--rm-descriptor(13)
file-notify-rm-watch(13)
file-notify-callback((13 (rename delete) "/Users/jun/test/1.c"))
file-notify-handle-event((file-notify (13 (rename delete)
"/Users/jun/test/1.c") file-notify-callback))
funcall-interactively(file-notify-handle-event (file-notify (13
(rename delete) "/Users/jun/test/1.c") file-notify-callback))
call-interactively(file-notify-handle-event nil [(file-notify (13
(rename delete) "/Users/jun/test/1.c") file-notify-callback)])
command-execute(file-notify-handle-event nil [(file-notify (13
(rename delete) "/Users/jun/test/1.c") file-notify-callback)] t)

Well, this is not an error. The watchdog over "/Users/jun/test/1.c"
receives the `(rename delete)' events from writing the file. Due to
this, the watchdog is removed, as you see in the backtrace.

Exactly, I think this is precisely the expected behavior: step 4
requests the debugger to be entered when auto-revert-use-notify is
modified, and auto-revert-notify-handler does modify it when the
watched file is deleted:

(if (eq action 'stopped)
;; File notification has stopped. Continue with polling.
(cl-dolist (buffer
(if global-auto-revert-mode
(buffer-list) auto-revert-buffer-list))
(with-current-buffer buffer
(when (and (equal descriptor auto-revert-notify-watch-descriptor)
(or
;; A buffer associated with a file.
(and (stringp buffer-file-name)
(string-equal
(file-name-nondirectory file)
(file-name-nondirectory buffer-file-name)))
;; A buffer w/o a file, like dired.
(null buffer-file-name)))
(auto-revert-notify-rm-watch)
(setq-local auto-revert-use-notify nil)))) <<<<<<<<<<<<<

[-- Attachment #2: Type: text/html, Size: 4716 bytes --]

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Michael Albinus]

zhang cc <ccsmile2008@outlook.com> writes:

Hi,

> What about the following logic:
> When the auto-revert module known the file is renamed or deleted,
> delete the watch 
> and start a one shot short timer(about 100ms) to check the visiting
> file of the buffer. On timeout, 
> if the file exists, revert the file and add a new watch, otherwise,
> tell user the file doesn’t exist 
> and fallback to the default polling(5s). 
> Once the visiting file of the buffer can be accessed, go back to use
> file-notify again.

Sounds possible. However, I would make it optional. Some people might
dislike this feature, invisible under the hood. And the timeout of 100ms
might vary depending on the filesystem the supervised file is located
on. In case of remote files, this will be too short I fear.

I will put it in my TODO. If time permits, I'll work on this, if nobody
beats me. Saying this, it might be better if you send this proposal via
"M-x report-emacs-bug". I will convert this into a wishlist item, and it
is much more likely to be found by other people than on my private TODO
list.

Best regards, Michael.

Re: auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 833 bytes --]


On 2 Jan 2018, 9:23 PM +0800, Michael Albinus <michael.albinus@gmx.de>, wrote:

Sounds possible. However, I would make it optional. Some people might
dislike this feature, invisible under the hood. And the timeout of 100ms
might vary depending on the filesystem the supervised file is located
on. In case of remote files, this will be too short I fear.

I will put it in my TODO. If time permits, I'll work on this, if nobody
beats me. Saying this, it might be better if you send this proposal via
"M-x report-emacs-bug". I will convert this into a wishlist item, and it
is much more likely to be found by other people than on my private TODO
list.

Best regards, Michael.

Thank you for your attention and your work.
My English is poor. I’m afraid I can’t discribe it clearly. Maybe someone else can do it?


[-- Attachment #2: Type: text/html, Size: 1395 bytes --]

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Michael Albinus]

zhang cc <ccsmile2008@outlook.com> writes:

Hi,

>     I will put it in my TODO. If time permits, I'll work on this, if
>     nobody beats me.
>
> Thank you for your attention and your work.
> My English is poor. I’m afraid I can’t discribe it clearly. Maybe
> someone else can do it?

I've pushed a patch to the master branch. It recreates a file
notification in autorevert, if a file was deleted and recreated
afterwards.

Since autorevert watches directories, the solution was simpler than
expected. The `create' event for the file from the directory is a
perfect trigger.

Could you, pls, check whether it works for you? I have extended the
`auto-revert-test02-auto-revert-deleted-file', which runs OK in my
environment. Testing on macOS (kqueue) is not possible for me.

Best regards, Michael.

Re: auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 1199 bytes --]


On 20 Jan 2018, 11:34 PM +0800, Michael Albinus <michael.albinus@gmx.de>, wrote:

I've pushed a patch to the master branch. It recreates a file
notification in autorevert, if a file was deleted and recreated
afterwards.

Yes. this seems OK. But there is a delay before auto-revert every 2 appending to the test file.

echo aaa >> test.c   (auto-revert ok)
echo aaa >> test.c   (delay about 4s, then auto-revert ok)
echo aaa >> test.c   (auto-revert ok)
echo aaa >> test.c   (delay about 4s, then auto-revert ok)
…

I added some debug log to two method (name in []):
[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)
[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)
Reverting buffer ‘1.c’.
[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)
[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)
[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)
[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)
[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)
[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)
Reverting buffer ‘1.c’.

3 write events but only one auto-revert.



[-- Attachment #2: Type: text/html, Size: 2167 bytes --]

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Alan Third]

On Sat, Jan 20, 2018 at 04:34:06PM +0100, Michael Albinus wrote:
> 
> I've pushed a patch to the master branch. It recreates a file
> notification in autorevert, if a file was deleted and recreated
> afterwards.
> 
> Since autorevert watches directories, the solution was simpler than
> expected. The `create' event for the file from the directory is a
> perfect trigger.
> 
> Could you, pls, check whether it works for you? I have extended the
> `auto-revert-test02-auto-revert-deleted-file', which runs OK in my
> environment. Testing on macOS (kqueue) is not possible for me.

Hi Michael,

The autorevert test fails on macOS for me:

Running 8 tests (2018-01-21 20:06:51+0000)
Library: `kqueue'
   passed  1/8  file-notify-test00-availability
   passed  2/8  file-notify-test01-add-watch
   passed  3/8  file-notify-test02-rm-watch
   passed  4/8  file-notify-test03-events
Reverting buffer `file-notify-test5Qh30O'.
Test file-notify-test04-autorevert backtrace:
  signal(ert-test-failed (((should-not auto-revert-use-notify) :form a
  ert-fail(((should-not auto-revert-use-notify) :form auto-revert-use-
  (if (not (unwind-protect (setq value-208 auto-revert-use-notify) (se
  (let (form-description-209) (if (not (unwind-protect (setq value-208
  (let ((value-208 (gensym "ert-form-evaluation-aborted-"))) (let (for
  (save-current-buffer (set-buffer buf) (let* ((fn-189 (function strin
  (progn (advice-add 'vc-refresh-state :around 'ignore) (setq file-not
  (unwind-protect (progn (advice-add 'vc-refresh-state :around 'ignore
  (let ((timeout (if (file-remote-p temporary-file-directory) 60 10)) 
  (closure (t) nil (let* ((fn-184 (function file-notify--test-local-en
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name file-notify-test04-autorevert :docume
  ert-run-or-rerun-test(#s(ert--stats :selector (not (or (tag :expensi
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable))) #f(co
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable)))
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/filenotify-tests.el"
  command-line()
  normal-top-level()
Test file-notify-test04-autorevert condition:
    (ert-test-failed
     ((should-not auto-revert-use-notify)
      :form auto-revert-use-notify :value t))
   FAILED  5/8  file-notify-test04-autorevert
   passed  6/8  file-notify-test05-file-validity
   passed  7/8  file-notify-test06-dir-validity
   passed  8/8  file-notify-test08-backup

Ran 8 tests, 7 results as expected, 1 unexpected (2018-01-21 20:07:14+0000)

1 unexpected results:
   FAILED  file-notify-test04-autorevert


-- 
Alan Third

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Michael Albinus]

Alan Third <alan@idiocy.org> writes:

Hi Alan,

> Hi Michael,

>> Could you, pls, check whether it works for you? I have extended the
>> `auto-revert-test02-auto-revert-deleted-file', which runs OK in my
>> environment. Testing on macOS (kqueue) is not possible for me.
>
> The autorevert test fails on macOS for me:
>
> 1 unexpected results:
>    FAILED  file-notify-test04-autorevert

Thanks for the heads up! I've updated autorevert-tests.el, but forgot
filenotify-tests.el. Should be fixed now in master.

Best regards, Michael.

Re: auto-revert error on macOS when auto-revert-use-notify is t

[Alan Third]

On Mon, Jan 22, 2018 at 09:17:33AM +0100, Michael Albinus wrote:
> 
> Thanks for the heads up! I've updated autorevert-tests.el, but forgot
> filenotify-tests.el. Should be fixed now in master.

Thanks, looks good now.
-- 
Alan Third

Re: auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 1254 bytes --]

Yes. this seems OK. But there is a delay before auto-revert every 2 appending to the test file.


echo aaa >> test.c   (auto-revert ok)

echo aaa >> test.c   (delay about 4s, then auto-revert ok)

echo aaa >> test.c   (auto-revert ok)

echo aaa >> test.c   (delay about 4s, then auto-revert ok)

…


I added some debug log to two method (name in []):

[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)

[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)

Reverting buffer ‘1.c’.

[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)

[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)

[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)

[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)

[file-notify-callback]: (9 (extend write) /Users/jun/test/1.c)

[auto-revert-notify-handler]: (9 changed /Users/jun/test/1.c)

Reverting buffer ‘1.c’.


3 write events but only one auto-revert.

There is a big delay before auto-reverting, not every one, about every two or three.
You can modify the test file with the following bash script:

#!/bin/bash

for (( i = 0; i < 100; i++ ));
do
        echo $i >> 1.c
        sleep 2
done



[-- Attachment #2: Type: text/html, Size: 10999 bytes --]

Re: auto-revert error on macOS when auto-revert-use-notify is t

[zhang cc]

[-- Attachment #1: Type: text/plain, Size: 338 bytes --]

I discribed the problem before, but may be not clear because of my poor English.


There is a big delay before auto-reverting, not every one, about every two or three.
You can modify the test file with the following bash script:

#!/bin/bash

for (( i = 0; i < 100; i++ ));
do
        echo $i >> 1.c
        sleep 2
done



[-- Attachment #2: Type: text/html, Size: 1674 bytes --]