afpd[13648]: pam_systemd(netatalk:session): Failed to release session: Access denied

[jdfalk]

afpd[13648]: PAM audit_log_acct_message() failed: Operation not permitted
afpd[13648]: pam_systemd(netatalk:session): Failed to release session: Access denied

I am just seeing these randomly in the log figured I should report a bug.

ProblemType: Bug
DistroRelease: Ubuntu 15.10
Package: netatalk 2.2.5-1
ProcVersionSignature: Ubuntu 4.2.0-25.30-generic 4.2.6
Uname: Linux 4.2.0-25-generic x86_64
ApportVersion: 2.19.1-0ubuntu5
Architecture: amd64
Date: Mon Jan 25 22:38:46 2016
InstallationDate: Installed on 2015-05-10 (261 days ago)
InstallationMedia: Ubuntu-Server 15.04 "Vivid Vervet" - Release amd64 (20150422)
ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: netatalk
UpgradeStatus: Upgraded to wily on 2015-10-26 (92 days ago)
mtime.conffile..etc.netatalk.AppleVolumes.default: 2015-11-02T17:03:11.847318

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Dan Smith (danms)]

This bug seems to be preventing me from using afpd at all. It seems like a dbus/systemd policy issue. Here are my logs when trying to log into afpd remotely:

Mar 12 08:28:11 challenger systemd-logind[5961]: New session c684 of user dan.
Mar 12 08:28:11 challenger systemd[1]: Started Session c684 of user dan.
Mar 12 08:28:11 challenger afpd[23024]: Login by dan (AFP3.4)
Mar 12 08:28:12 challenger collectd[29229]: smart plugin: unable to get temperature for /dev/sda.
Mar 12 08:28:13 challenger afpd[23024]: AFP logout by dan
Mar 12 08:28:13 challenger afpd[23024]: dsi_stream_read: len:0, unexpected EOF
Mar 12 08:28:13 challenger afpd[23024]: afp_over_dsi: client logged out, terminating DSI session
Mar 12 08:28:13 challenger afpd[23024]: pam_unix(netatalk:session): session closed for user dan
Mar 12 08:28:13 challenger dbus[6025]: [system] Rejected send message, 2 matched rules; type="method_call", sender=":1.1615" (uid=1000 pid=23024 comm="/usr/sbin/afpd -d -F /etc/netatalk/afp.conf ") interface="org.freedesktop.login1.Manager" member="ReleaseSession" error name="(unset)" requested_reply="0" destination="org.freedesktop.login1" (uid=0 pid=5961 comm="/lib/systemd/systemd-logind ")
Mar 12 08:28:13 challenger afpd[23024]: pam_systemd(netatalk:session): Failed to release session: Access denied
Mar 12 08:28:13 challenger afpd[23024]: PAM audit_log_acct_message() failed: Operation not permitted
Mar 12 08:28:13 challenger afpd[23024]: AFP statistics: 0.58 KB read, 0.44 KB written
Mar 12 08:28:13 challenger systemd-logind[5961]: Removed session c684.

Maybe related to this upstream systemd bug?

https://github.com/systemd/systemd/issues/6375

[Dan Smith (danms)]

Also note I'm seeing this on Xenial

[Atsuko Ito (yottatsa)]

It happens because pam_systemd can no longer connect to the systemd after privileges have been dropped. pam_systemd is enabled in /etc/pam.d/common-session, so changing a line in /etc/pam.d/netatalk from

@include common-session

to

@include common-session-noninteractive

removes the message.

[dmarks (markstedt)]

This is being addressed in upstream netatalk in https://github.com/Netatalk/netatalk/issues/361

A fix has been merged to main and will be part of the next stable netatalk release.