Bug 7203 - PAM conversation takes very long when trying to login with a user that doesn't exist
Summary: PAM conversation takes very long when trying to login with a user that doesn'...
Status: CLOSED FIXED
Alias: None
Product: ThinLinc
Classification: Unclassified
Component: Web Access (show other bugs)
Version: trunk
Hardware: PC Unknown
: P2 Normal
Target Milestone: 4.10.0
Assignee: Pierre Ossman
URL:
Keywords: relnotes, samuel_tester
Depends on:
Blocks:
 
Reported: 2018-06-27 12:20 CEST by Samuel Mannehed
Modified: 2019-02-15 11:06 CET (History)
1 user (show)

See Also:
Acceptance Criteria:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Description Samuel Mannehed cendio 2018-06-27 12:20:37 CEST 
When trying to login using WebAccess with a user that doesn't exist on the server you get a delay of ~50 seconds before it says authentication failed.

It seems to be selinux related since `setenforce 0` fixes the problem. The audit log says:

==> /var/log/audit/audit.log <==
type=USER_AVC msg=audit(1530090502.684:1025): pid=776 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied  { send_msg } for msgtype=error error_name=org.freedesktop.systemd1.NoSuchDynamicUser dest=:1.248 spid=1 tpid=14879 scontext=system_u:system_r:init_t:s0 tcontext=system_u:system_r:thinlinc_webaccess_t:s0 tclass=dbus permissive=0  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'

The delay problem does not exist when logging in to the same system using the same non-existing user with SSH. You get a different AVC in the audit log:

==> /var/log/audit/audit.log <==
type=USER_AVC msg=audit(1530089623.012:952): pid=776 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied  { send_msg } for msgtype=method_call interface=org.freedesktop.systemd1.Manager member=LookupDynamicUserByName dest=org.freedesktop.systemd1 spid=13483 tpid=1 scontext=system_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=system_u:system_r:init_t:s0 tclass=dbus permissive=0  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'

Problem was first encountered on Fedora 27, can reproduce on a different Fedora 28 system as well. Can not reproduce on eudemo or tl.cendio.se.
Comment 1 Samuel Mannehed cendio 2018-06-27 12:21:14 CEST 
This might be related:

https://bugzilla.redhat.com/show_bug.cgi?id=1460244
Comment 2 Samuel Mannehed cendio 2018-06-29 14:09:06 CEST 
Before bug 5086:

We always (on these systems) had a very long (~75 seconds) delay after trying to login with a user that didn't exist. Then we eventually get a "Authentication failure" error in the GUI. Logs a normal auth-fail, no hints to why it took so long, eg. no timeout reached due to 120 secs login grace time.

After bug 5086:

We properly handle errors in PAM conversation and get a timeout after 10 seconds and a "Internal error" in the GUI. Logs say that a timeout was reached in the PAM conversation.

--

The difference is now that the admin gets a hint that something is wrong with his system.
Comment 3 Samuel Mannehed cendio 2018-11-08 15:52:35 CET 
Also see bug 7277
Comment 4 Pierre Ossman cendio 2019-01-09 14:29:32 CET 
The root cause was found in bug 7277. The SELinux policy is a bit broken and doesn't allow things to send dbus replies back to our unconfined processes. And nss_systemd uses dbus to work, so whenever that module was used we get a hang until dbus times out.

The reason it only happens on invalid users is because nss_systemd is the last module in most configurations, so valid users will be found by one of the earlier modules.

This will be fixed as a side effect of bug 7277 being fixed.
Comment 6 Samuel Mannehed cendio 2019-02-15 11:06:30 CET 
Works well now, tested with build 6040 on Fedora 29.

Release note look good as well.
Note You need to log in before you can comment on or make changes to this bug.