I've been tearing my hair out for weeks trying to figure out why one of my Macs kept failing to Time Machine back up to my Gentoo box running netatalk. I could manually mount shares, but when TM decided to do an automatic backup, there would be an authentication failure. This was the failure message I would get in /var/log/messages: Jan 16 12:49:42 compute0 afpd: pam_unix(netatalk:auth): authentication failure; logname= uid=0 euid=0 tty=afpd ruser= rhost=laura-millers-imac user=millerti I exhausted every reasonable fix on the Mac side, to no avail, when I decided to enable debug logging (-setuplog "AFPDaemon LOG_DEBUG") on the server to see what was going on. Then the problem went away. I left debugging on, waiting for the problem to manifest again, but it never did. So I turned off debug logging in netatalk, and the authentication problem immediately returned. Sounds like a Catch 22. It appears that there's a bug in netatalk that is causing authentication to fail. The regular auth-fail message isn't informative, so I turn on more detailed logging, which makes the problem disappear. I'm sure you can imagine my frustration. Reproducible: Always # emerge --info Portage 2.1.9.31 (default/linux/amd64/10.0, gcc-4.4.5, glibc-2.12.2-r0, 2.6.37-gentoo x86_64) ================================================================= System uname: Linux-2.6.37-gentoo-x86_64-Intel-R-_Core-TM-2_Quad_CPU_Q9450_@_2.66GHz-with-gentoo-2.0.1 Timestamp of tree: Sun, 16 Jan 2011 08:00:01 +0000 app-shells/bash: 4.1_p9 dev-java/java-config: 2.1.11-r3 dev-lang/python: 2.6.6-r1, 2.7.1, 3.1.3 dev-util/cmake: 2.8.3-r1 sys-apps/baselayout: 2.0.1-r1 sys-apps/openrc: 0.7.0 sys-apps/sandbox: 2.4 sys-devel/autoconf: 2.13, 2.68 sys-devel/automake: 1.8.5-r4, 1.9.6-r3, 1.10.3, 1.11.1 sys-devel/binutils: 2.21 sys-devel/gcc: 4.4.5, 4.5.2 sys-devel/gcc-config: 1.4.1 sys-devel/libtool: 2.4-r1 sys-devel/make: 3.82 virtual/os-headers: 2.6.36.1 (sys-kernel/linux-headers) ACCEPT_KEYWORDS="amd64 ~amd64" ACCEPT_LICENSE="*" CBUILD="x86_64-pc-linux-gnu" CFLAGS="-O2 -march=core2 -ggdb -pipe" CHOST="x86_64-pc-linux-gnu" CONFIG_PROTECT="/etc /usr/share/config" CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5.3/ext-active/ /etc/php/cgi-php5.3/ext-active/ /etc/php/cli-php5.3/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo /etc/texmf/language.dat.d /etc/texmf/language.def.d /etc/texmf/updmap.d /etc/texmf/web2c" CXXFLAGS="-O2 -march=core2 -ggdb -pipe" DISTDIR="/usr/portage/distfiles" EMERGE_DEFAULT_OPTS="--jobs=2" FEATURES="assume-digests binpkg-logs distlocks fixlafiles fixpackages news parallel-fetch protect-owned sandbox sfperms splitdebug strict unknown-features-warn unmerge-logs unmerge-orphans userfetch" GENTOO_MIRRORS="http://gentoo.osuosl.org/ http://gentoo.netnitco.net http://mirror.csclub.uwaterloo.ca/gentoo-distfiles/ ftp://mirror.datapipe.net/gentoo ftp://mirror.csclub.uwaterloo.ca/gentoo-distfiles/ http://gentoo.mirrors.easynews.com/linux/gentoo/ ftp://ftp.free.fr/mirrors/ftp.gentoo.org/ ftp://gentoo.imj.fr/pub/gentoo/ ftp://distro.ibiblio.org/pub/linux/distributions/gentoo/" LANG="en_US.utf8" LDFLAGS="-Wl,-O1 -Wl,--as-needed" LINGUAS="en en_US" MAKEOPTS="--jobs=3 --load-average=7" PKGDIR="/usr/portage/packages" PORTAGE_CONFIGROOT="/" PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages" PORTAGE_TMPDIR="/var/tmp" PORTDIR="/usr/portage" PORTDIR_OVERLAY="/usr/local/portage" SYNC="rsync://rsync.gentoo.org/gentoo-portage" USE="X a52 aac aalib acl acpi alsa amd64 apache2 aspell autotrace bash-completion berkdb bidi bonjour bzip2 cairo cdda cdio cdr cli composite cracklib crypt ctype cups curl cxx dbus device-mapper dri dts dvd dvdr encode exif extras fbcon ffmpeg fftw filter flac fontconfig fortran freetype gcj gd gdbm git glib gmm gnutls gpm graphviz gs httpd iconv imagemagick ipp ipv6 ithreads jadetex java jpeg jpeg2k kde kde4 kerberos kpathsea kvm lame lapack latex lcms ldap live lm_sensors lzma mad matroska mdnsresponder-compat mjpeg mkl mmx mng modules mp3 mpeg mudflap multilib mysql mysqli ncurses nls nptl nptlonly ogg oggvorbis openexr opengl openmp openssl pam pcre pdf perl php plasma plotutils png ppds pppd python qemu qt3support qt4 quicktime readline reports rss ruby samba sasl secure-delete semantic-desktop session smp spl sql sse sse2 sse3 ssl stream subversion svg sysfs tcl tcpd theora threads thumbnail tiff tk tordns truetype unicode utempter vcd vlm vnc vorbis webkit wxwindows x264 xcomposite xml xorg xv xvid zeroconf zlib" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ubx" INPUT_DEVICES="evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LINGUAS="en en_US" PHP_TARGETS="php5-3" QEMU_SOFTMMU_TARGETS="i386 x86_64" QEMU_USER_TARGETS="i386 x86_64" RUBY_TARGETS="ruby18 ruby19" USERLAND="GNU" VIDEO_CARDS="radeon" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account" Unset: CPPFLAGS, CTARGET, FFLAGS, INSTALL_MASK, LC_ALL, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
Notes: Leaving debug logging on is not an acceptable work-around, because it floods my /var/log/messages with messages, rapidly using up disk space and drowning out other messages. This is a link to the netatalk bug I filed on sourceforge: https://sourceforge.net/tracker/index.php?func=detail&aid=3159355&group_id=8642&atid=108642#
could be a timing bug ... the debug logging could just be slowing things down just like changing the optimization
Yeah. Another thing that fixes the problem is leaving on PAM debug messages. Due to a bug in openrc (not logging stdout/stderr of daemons), the messages go nowhere, but nevertheless, authentication doesn't fail. So... why would changing timing cause auth to pass or fail?
I've found out a few other things. One is that there are others having this problem. For instance: http://ubuntuforums.org/showthread.php?p=10607522#post10607522 The other is that people using Kerberos only just don't seem to have this trouble. So, either PAM itself has a bug that we're exposing, or Netatalk has a PAM-related bug. This kinda narrows it down a bit, at least.
My suspicion is that Netatalk was never tested with the version of PAM that Gentoo has in ~amd64, so there's an incompatibility.
Is this with DHX1 or DHX2?
I'm not actually sure how to determine that. Can you give me a hint? Also, I've since upgraded to the latest netatalk, but I haven't actually tested it yet. I've been using alternative solutions that don't have the authentication problem.
Though the OP didn't mention what version of OSX is being used on the client side I think this bug is related to Apple having disabled the use of DHX (version 1) in OS X 10.7 (Lion). Netatalks' default -uamlist is 'uams_dhx.so,uams_dhx2.so' and I think whats happening is DHX (version 1) is tried but one side or other isn't waiting for the next authentication method. This might explain why LOG_DEBUG has the effect it does, it creates enough of a delay for the second authentication method to be negociated. Given that Apple has disabled DHX1 is might be a good idea to reverse the order of the -uamlist, with uams_dhx2.so being the first in the list. A recent post in the forums re net-fs/netatalk-2.2.3 seems to suggest that regardless of both DHX and DHX2 being listed in -uamlist if DHX fails, DHX2 is not tried, and authentication fails. It seems to me this is related to the report given in this bug. The post can be found here: http://forums.gentoo.org/viewtopic-p-7061882.html It'd be good to see this bug CLOSED, but as I'm no longer maintaing any netatalk servers, nor have any local (OSX) clients I could test with, I'm not able to provide more help than this, sorry. best regards ... khayyam
I was having this problem with Snow Leopard. I never tried it with Lion.
