Re: getting mysterious (to me) EINVAL from inotify_rm_watch

From: Felix von Leitner
Date: Wed May 11 2016 - 11:30:46 EST


Thus spake Peter Meerwald-Stadler (pmeerw@xxxxxxxxxx):
> > I am trying to add inotify support to my tail implementation (for -F).
> > This is what happens:
> >
> > inotify_init() = 4
> > inotify_add_watch(4, "/tmp/foo", IN_MODIFY) = 1
> > inotify_rm_watch(4, 1) = -1 EINVAL (Invalid argument)
> > inotify_add_watch(4, "/tmp/foo", IN_MODIFY) = 2
> >
> > There is also some polling, some reading and some statting going on here, but
> > those are on other descriptors than 4 so they should not matter).
> >
> > Can somebody explain the EINVAL I'm getting from inotify_rm_watch to me?
> > This is a stock kernel 4.5.0.

> #include <stdio.h>
> #include <sys/inotify.h>
> int main() {
> int fd, i, j;
> printf("init %d\n", fd=inotify_init()); // 3
> printf("add %d\n", i=inotify_add_watch(fd, "/tmp/foo", IN_MODIFY)); // 1
> printf("rm %d\n", inotify_rm_watch(fd, i)); // 0
> printf("add %d\n", j=inotify_add_watch(fd, "/tmp/foo", IN_MODIFY)); // 2
> return 0;
> }

> Ubuntu kernel x86_64 4.4.0-21, seems to work here
> so we have to guess what's going on between _add and _rm?

Wait!
It just occurred to me that this does not make any sense at all.
You use the name of the file with inotify_add_watch, not the descriptor
to the file. Why would closing the file matter?

My "load generator" test program is:

#include <unistd.h>
#include <assert.h>
#include <fcntl.h>
#include <stdio.h>

int main() {
int fd=open("/tmp/foo",O_WRONLY|O_CREAT|O_TRUNC,0600);
assert(fd>-1);
sleep(1);
write(fd,"1\n",2);
sleep(1);
write(fd,"2\n",2);
int fd2=open("/tmp/bar",O_WRONLY|O_CREAT|O_TRUNC,0600);
assert(fd>-1);
write(fd2,"3\n",2);
rename("/tmp/bar","/tmp/foo");
close(fd);
sleep(1);
write(fd2,"4\n",2);
close(fd2);
}

I touch /tmp/foo first, then I run my inotify tail -F on it, and I expect the
output to be

1\n2\n3\n4\n

It is. Then I press Ctrl-C.

Here is the strace of the tail:

execve("./bin-x86_64/tail", ["./bin-x86_64/tail", "-F", "/tmp/foo"], [/* 57 vars */]) = 0
arch_prctl(ARCH_SET_FS, 0x7fff1b1e2920) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_NODEFER, 0x4018d0}, {SIG_DFL, [], 0}, 8) = 0
open("/tmp/foo", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f251cf9f000
read(3, "", 32768) = 0
inotify_init() = 4
inotify_add_watch(4, "/tmp/foo", IN_MODIFY) = 1
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 0 (Timeout)
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\1\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0", 2048) = 16
fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\1\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0", 2048) = 16
fstat(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
read(3, "1\n", 8192) = 2
write(1, "1\n", 2) = 2
read(3, "", 8192) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\1\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0", 2048) = 16
fstat(3, {st_mode=S_IFREG|0644, st_size=4, ...}) = 0
read(3, "2\n", 8192) = 2
write(1, "2\n", 2) = 2
read(3, "", 8192) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 0 (Timeout)
fstat(3, {st_mode=S_IFREG|0644, st_size=4, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
close(3) = 0
inotify_rm_watch(4, 1) = -1 EINVAL (Invalid argument)
open("/tmp/foo", O_RDONLY) = 3
inotify_add_watch(4, "/tmp/foo", IN_MODIFY) = 2
open("/tmp", O_RDONLY) = 5
read(3, "3\n4\n", 8192) = 4
write(1, "3\n4\n", 4) = 4
read(3, "", 8192) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\1\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 2048) = 16
fstat(3, {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = 0 (Timeout)
fstat(3, {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
stat("/tmp/foo", {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
poll([{fd=4, events=POLLIN}], 1, 1000) = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
+++ killed by SIGINT +++

As you can see, I do close(3) and then inotify_rm_watch, and it returns EINVAL.
If I do the inotify_rm_watch first and then the close, then both returns 0.

What is going on here?!

Also, I was thrown off a bit because the next inotify_add_watch returns 2.
I somehow expected it to work like open, i.e. when you close fd 1 and then call
inotify_add_watch, you get 1 again as wd. But that is apparently not how it
works. This could maybe be clarified in the man page.

Regards,

Felix