#666 Missing volume paths are logged at debug level

[Joel Croteau]

Hello, running Netatalk 3.1.12 on Ubuntu 20.04. I had set up the server, which my MacBook was seeing, and was able to log into correctly, but was immediately saying "connection failed," with the Netatalk logs showing a successful login from my Mac, and the only log to indicate any problem was a dsi_stream_read: len:0, unexpected EOF message. I tried setting log level = default:note and didn't see anything else helpful. Finally I set log level = default:debug and got this:

Oct 20 21:36:24 Theseus netatalk[7372]: Set syslog logging to level: debug
Oct 20 21:36:24 Theseus netatalk[7372]: CNID Server: localhost:4700
Oct 20 21:36:24 Theseus netatalk[7372]: Global unix charset is UTF8
Oct 20 21:36:24 Theseus netatalk[7372]: Global vol charset is UTF8
Oct 20 21:36:24 Theseus netatalk[7372]: Global mac charset is MAC_ROMAN
Oct 20 21:36:24 Theseus netatalk[7372]: readextmap: loading "/etc/netatalk/extmap.conf"
Oct 20 21:36:24 Theseus netatalk[7372]: readextmap: done
Oct 20 21:36:24 Theseus netatalk[7372]: load_volumes: BEGIN
Oct 20 21:36:24 Theseus netatalk[7372]: load_volumes: no volumes yet
Oct 20 21:36:24 Theseus netatalk[7372]: load_volumes: loading: /etc/netatalk/afp.conf
Oct 20 21:36:24 Theseus netatalk[7372]: readvolfile: BEGIN
Oct 20 21:36:24 Theseus netatalk[7372]: readvolfile: sections: 2
Oct 20 21:36:24 Theseus netatalk[7372]: realpath() cannot resolve path ""/mnt/Conversation/Omikron""
Oct 20 21:36:24 Theseus netatalk[7372]: load_volumes: END
Oct 20 21:36:24 Theseus netatalk[7372]: Netatalk AFP server starting
Oct 20 21:36:24 Theseus netatalk[7372]: Attempting to register with mDNS using Avahi
Oct 20 21:36:24 Theseus netatalk[7372]: hostname: Theseus
Oct 20 21:36:24 Theseus netatalk[7372]: Registering server 'Theseus' with Bonjour
Oct 20 21:36:24 Theseus netatalk[7372]: Successfully started avahi loop.
Oct 20 21:36:24 Theseus netatalk[7372]: Registered with Zeroconf

Did you see it? The line realpath() cannot resolve path ""/mnt/Conversation/Omikron"". I had incorrectly specified the path name, and there was absolutely no indication of this elsewhere in the logs. I should say that I had already tried a few different path specifiers before this, and it was a little frustrating that there was nothing at all in the logs indicating success or failure for any of them. This was very frustrating and difficult to debug, and after I had corrected the path name, it worked perfectly. An error like this should really be logged at a higher level. Ideally, the logs should include a list of all successful mounts from afp.conf, what attributed they are read to have, and should raise an error for any issues resolving paths, any other problems, or any unrecognized config lines, as these are likely something the user would like to have that have just been mistyped. This would make solving problems with the config much easier.

[Daniel Markstedt]

Thanks for raising this issue. I agree that Netatalk's logging is all over the place, and can be frustrating to debug. With regards to the realpath() logging, this one actually used to be an error log until this change in 2014: https://sourceforge.net/p/netatalk/code/ci/5eb3b5ac51c8221009041928a5a08c101d2be743/tree/libatalk/util/unix.c?diff=a04d24be19aa000f89ee22d0197da4689cc487b2

Reverting this should be very straight forward, and it seems out of place in that changeset, so it might have been a mistake (residue from local testing) in the first place. I'll put up a PR right away over at the Github project.

As for the general request of adding logging for each successful mount: If you're up for it, don't hesitate to patch it yourself and submit a PR!

[Daniel Markstedt]

PR at https://github.com/Netatalk/Netatalk/pull/212

[Daniel Markstedt]

PR has been merged to the main development branch