feisty avahi-autoipd fails on fopen()

[C de-Avillez]

Binary package hint: avahi-autoipd

Feb 5 21:31:16 xango avahi-autoipd(eth1)[9617]: Successfully called chroot().
Feb 5 21:31:16 xango avahi-autoipd(eth1)[9617]: Successfully dropped root privileges.
Feb 5 21:31:16 xango avahi-autoipd(eth1)[9617]: fopen() failed: Permission denied
Feb 5 21:31:16 xango avahi-autoipd(eth1)[9617]: Starting with address 169.254.7.96
Feb 5 21:31:24 xango avahi-autoipd(eth1)[9617]: Callout BIND, address 169.254.7.96 on interface eth1
Feb 5 21:31:28 xango avahi-autoipd(eth1)[9617]: Successfully claimed IP address 169.254.7.96
Feb 5 21:31:28 xango avahi-autoipd(eth1)[9617]: fopen() failed: Permission denied
Feb 5 21:32:08 xango avahi-autoipd(eth1)[9617]: Got SIGTERM, quitting.
Feb 5 21:32:08 xango avahi-autoipd(eth1)[9617]: Callout STOP, address 169.254.7.96 on interface eth1
Feb 5 21:32:08 xango avahi-autoipd(eth1)[9618]: client: RTNETLINK answers: No such device
Feb 5 21:32:08 xango avahi-autoipd(eth1)[9618]: Script execution failed with return value 2
hggdh@xango:/usr/src/src/avahi-autoipd/avahi-0.6.17/avahi-autoipd$

[C de-Avillez (hggdh2)]

strace output at the fopen() error:

write(2, "Found user \'avahi-autoipd\' (UID "..., 73) = 73
write(2, "\n", 1) = 1
umask(0) = 022
mkdir("/var/lib/avahi-autoipd", 0755) = -1 EEXIST (File exists)
umask(022) = 0
chown("/var/lib/avahi-autoipd", 107, 113) = 0
stat("/var/lib/avahi-autoipd", {st_dev=makedev(253, 17), st_ino=7509, st_mode=S_IFDIR|0755, st_nlink=2, st_uid=107, st_gid=113, st_blksize=4096, st_bl
ocks=0, st_size=128, st_atime=2007/02/06-07:40:25, st_mtime=2007/01/20-10:57:43, st_ctime=2007/02/06-07:47:08}) = 0
chroot("/var/lib/avahi-autoipd") = 0
write(2, "Successfully called chroot().", 29) = 29
write(2, "\n", 1) = 1
chdir("/") = 0
open("/proc/sys/kernel/ngroups_max", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/group", O_RDONLY) = -1 ENOENT (No such file or directory)
setgroups(1, [113]) = 0
setresgid(113, 113, 113) = 0
setresuid(107, 107, 107) = 0
write(2, "Successfully dropped root privil"..., 37) = 37
write(2, "\n", 1) = 1
sendto(7, "\x20\x00\x00\x00\x12\x00\x05\x02\x00\x00\x00\x00\x00\x00"..., 32, 0, NULL, 0) = 32
recvfrom(7, "\xf8\x00\x00\x00\x10\x00\x02\x00\x00\x00\x00\x00\x91\x18"..., 2048, 0, NULL, NULL) = 1272
recvfrom(7, "\x14\x00\x00\x00\x03\x00\x02\x00\x00\x00\x00\x00\x91\x18"..., 2048, 0, NULL, NULL) = 20
sendto(7, "\x18\x00\x00\x00\x16\x00\x05\x02\x01\x00\x00\x00\x00\x00"..., 24, 0, NULL, 0) = 24
recvfrom(7, "\x30\x00\x00\x00\x14\x00\x02\x00\x01\x00\x00\x00\x91\x18"..., 2048, 0, NULL, NULL) = 228
recvfrom(7, "\x14\x00\x00\x00\x03\x00\x02\x00\x01\x00\x00\x00\x91\x18"..., 2048, 0, NULL, NULL) = 20
open("/00:03:25:1b:d1:ac", O_RDONLY) = -1 EACCES (Permission denied)
write(2, "fopen() failed: Permission denie"..., 33) = 33
write(2, "\n", 1) = 1

[C de-Avillez (hggdh2)]

well, this seems to have been a fluke, perhaps caused by a previous version of avahi-autoipd.

After I stopped avahi-autoipd, deleted the /var/lib/avahi-autoipd directory, and restarted it, it went without any glitches.

I will keep on trying but, right now, I am considering it as a fluke.

[C de-Avillez (hggdh2)]

nope, not a fluke. I rebooted and, after the reboot I get this:

Feb 6 11:51:10 xango avahi-autoipd(eth1)[25328]: Found user 'avahi-autoipd' (UID 107) and group 'avahi-autoipd' (G
ID 113).
Feb 6 11:51:10 xango avahi-autoipd(eth1)[25328]: Successfully called chroot().
Feb 6 11:51:10 xango avahi-autoipd(eth1)[25328]: Successfully dropped root privileges.
Feb 6 11:51:10 xango avahi-autoipd(eth1)[25328]: Starting with address 169.254.7.96
Feb 6 11:51:10 xango avahi-autoipd(eth1)[25328]: SIOCSIFFLAGS failed: Permission denied
Feb 6 11:51:25 xango avahi-autoipd(eth0)[25568]: Found user 'avahi-autoipd' (UID 107) and group 'avahi-autoipd' (G
ID 113).
Feb 6 11:51:25 xango avahi-autoipd(eth0)[25568]: Successfully called chroot().
Feb 6 11:51:25 xango avahi-autoipd(eth0)[25568]: Successfully dropped root privileges.
Feb 6 11:51:25 xango avahi-autoipd(eth0)[25568]: Starting with address 169.254.7.63
Feb 6 11:51:30 xango avahi-autoipd(eth0)[25568]: Callout BIND, address 169.254.7.63 on interface eth0
Feb 6 11:51:34 xango avahi-autoipd(eth0)[25568]: Successfully claimed IP address 169.254.7.63
Feb 6 11:56:31 xango avahi-autoipd(eth1)[4614]: client: RTNETLINK answers: No such device
Feb 6 11:56:31 xango avahi-autoipd(eth1)[4614]: Script execution failed with return value 2
Feb 6 12:00:14 xango avahi-autoipd(eth0)[9818]: Found user 'avahi-autoipd' (UID 107) and group 'avahi-autoipd' (GI
D 113).
Feb 6 12:00:14 xango avahi-autoipd(eth0)[9818]: Successfully called chroot().
Feb 6 12:00:14 xango avahi-autoipd(eth0)[9818]: Successfully dropped root privileges.
Feb 6 12:00:14 xango avahi-autoipd(eth0)[9818]: fopen() failed: Permission denied
Feb 6 12:00:14 xango avahi-autoipd(eth0)[9818]: Starting with address 169.254.7.63
Feb 6 12:00:19 xango avahi-autoipd(eth0)[9818]: Callout BIND, address 169.254.7.63 on interface eth0
Feb 6 12:00:23 xango avahi-autoipd(eth0)[9818]: Successfully claimed IP address 169.254.7.63
Feb 6 12:00:23 xango avahi-autoipd(eth0)[9818]: fopen() failed: Permission denied
(END)

so there is indeed something wrong going on here.

[Trent Lloyd (lathiat)]

Can you run

ls -la /var/lib/avahi-autoipd

and paste the output? (when this problem is occuring)

[C de-Avillez (hggdh2)]

Sure. It is happening right now. In fact, it happens every time, unless I remove /var/lib/avahi-autoipd. Then, on the first run, no problems.

hggdh@xango:/var/lib$ ls -la avahi-autoipd/
total 10
drwxr-xr-x 2 avahi-autoipd avahi-autoipd 128 2007-02-06 11:53 .
drwxr-xr-x 72 root root 1928 2007-02-06 15:36 ..
---------- 1 avahi-autoipd avahi-autoipd 13 2007-02-06 11:51 00:03:25:1b:d1:ac
---------- 1 avahi-autoipd avahi-autoipd 13 2007-02-06 11:53 00:90:4b:ff:c5:08
hggdh@xango:/var/lib$ sudo cat avahi-autoipd/00\:03\:25\:1b\:d1\:ac
169.254.7.63
hggdh@xango:/var/lib$ sudo cat avahi-autoipd/00\:90\:4b\:ff\:c5\:08
169.254.7.96
hggdh@xango:/var/lib$

Last reboot produced the following messages in /var/lob/syslog:

Feb 6 17:39:31 xango avahi-autoipd(eth1)[5828]: Found user 'avahi-autoipd' (UID 107) and group 'avahi-autoipd' (GID 113).
Feb 6 17:39:31 xango avahi-autoipd(eth1)[5828]: Successfully called chroot().
Feb 6 17:39:31 xango avahi-autoipd(eth1)[5828]: Successfully dropped root privileges.
Feb 6 17:39:31 xango avahi-autoipd(eth1)[5828]: fopen() failed: Permission denied
Feb 6 17:39:31 xango avahi-autoipd(eth1)[5828]: Starting with address 169.254.7.96
Feb 6 17:39:37 xango avahi-autoipd(eth1)[5828]: Callout BIND, address 169.254.7.96 on interface eth1
Feb 6 17:39:41 xango avahi-autoipd(eth1)[5828]: Successfully claimed IP address 169.254.7.96
Feb 6 17:39:41 xango avahi-autoipd(eth1)[5828]: fopen() failed: Permission denied
Feb 6 17:46:19 xango avahi-autoipd(eth0)[9746]: Found user 'avahi-autoipd' (UID 107) and group 'avahi-autoipd' (GID 113).
Feb 6 17:46:19 xango avahi-autoipd(eth0)[9746]: Successfully called chroot().
Feb 6 17:46:19 xango avahi-autoipd(eth0)[9746]: Successfully dropped root privileges.
Feb 6 17:46:19 xango avahi-autoipd(eth0)[9746]: fopen() failed: Permission denied
Feb 6 17:46:19 xango avahi-autoipd(eth0)[9746]: Starting with address 169.254.7.63
Feb 6 17:46:24 xango avahi-autoipd(eth0)[9746]: Callout BIND, address 169.254.7.63 on interface eth0
Feb 6 17:46:28 xango avahi-autoipd(eth0)[9746]: Successfully claimed IP address 169.254.7.63
Feb 6 17:46:28 xango avahi-autoipd(eth0)[9746]: fopen() failed: Permission denied

So, indeed, there is a reason for the fopen() error...

[C de-Avillez (hggdh2)]

And, looking at both the source code and at the strace output above, we see the reason for the file permissions... umask (0000) would do that.

Additionally, *after* chrooting to /var/lib/avahi-autoipd, we see two failed open() calls:

open("/proc/sys/kernel/ngroups_max", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/group", O_RDONLY) = -1 ENOENT (No such file or directory)

Of course they will fail.

Yes, there is at least one bug here, probably two. Or more.

[C de-Avillez (hggdh2)]

I have attached two runs of avahi-autoipd, done as follows:

1. sudo avahi-autoipd -k eth0
2. sudo rm -rf /var/lib/avahi-autoipd
3. sudo strace -ff -v -x -o avahi-autoipd-strace avahi-autoipd -D eth0

(on another terminal, after avahi got stable)

4. sudo avahi-autoipd -k eth0

The collected strace output in in avahi-initial-run.tar, in the attachment

5. sudo strace -ff -v -x -o avahi-autoipd-strace avahi-autoipd -D eth0

(on another terminal, after avahi-autoipd got stable)

6. sudo avahi-autoipd -k eth0

The collected strace output is in avahi-second-run.tar, in the attachment.

First run produced no error, second run got the fopen() failure.

[dchristm77 (derekchristman)]

My wireless connection is failing with the same symptoms. If I take off all encryption, deleting the /var/lib/avahi-autoipd directory works, however if using WPA personal I can't get a connection. This problem started occurring after updating from edgy to the feisty fawn release.

[Juan Pablo Salazar Bertín (snifer)]

Confirmed in feisty, avahi-daemon version 0.6.17-0ubuntu3.

Attached my last boot daemon.log.

[Johnathon (kirrus)]

This report appears to be remarkably similar to bug #78078.

[C de-Avillez (hggdh2)]

Yes, except that I did not experience any network connection issue like there. So... I am not sure.

Anyway, since then I purged Avahi from my laptop -- given that I float around on cellular, hotel, and public wireless, I really do not want Avahi broadcast/discover... so it is gone , and I cannot check for the bug 78078 issues.

[borzo (semgeb)]

I am having similar problems with avahi permissions on 7.10 avahi version 0.6.20

[Robert Ancell (robert-ancell)]

Thanks for the report. Is this still occurring for anyone in a recent release of Ubuntu?

[Przemek K. (azrael)]

We are closing this bug report because it lacks the information we need to investigate the problem, as described in the previous comments. Please reopen it if you can give us the missing information, and don't hesitate to submit bug reports in the future. To reopen the bug report you can click on the current status, under the Status column, and change the Status back to "New". Thanks again!