Auth portion called twice

[jbaksta]

Implementing this to do some basic web-auth against a PAM stack, I'm seeing from my logs that there are two calls to the auth portion of the stack. I need to look at the code a little more to determine where it's at.

Using regular password authentication through PAM is sufficient here, but when implementing OTP-based authentication, there would be no way that it can work calling the auth portion twice due to the semantics of the OTP. Again, need to look at this a little closer, thought I'd at least bring it up that it does show running twice when looking at logs for authentication.

[adelton]

Are you sure some (internal) redirect isn't at play? What's the config and what's in the logs?

[jbaksta]

Fairly simple on all accords:

[root@authnz log]# cat /etc/pam.d/webapp
auth       required    pam_sss.so
account    required    pam_sss.so

Using pamtester to test authenticate:

[root@authnz log]# pamtester webapp alpha authenticate
Password:
pamtester: successfully authenticated

results in only one log message for authenticating as desired.

Jan  8 19:28:28 authnz pamtester: pam_sss(webapp:auth): authentication success; logname=root uid=0 euid=0 tty= ruser= rhost= user=alpha

However, through the Apache:

This is what I get in the logs (actually got three instances on this attempt):

Jan  8 19:30:35 authnz httpd: pam_sss(webapp:auth): authentication success; logname= uid=48 euid=48 tty= ruser= rhost=192.168.1.52 user=alpha
Jan  8 19:30:35 authnz httpd: pam_sss(webapp:auth): authentication success; logname= uid=48 euid=48 tty= ruser= rhost=192.168.1.52 user=alpha
Jan  8 19:30:35 authnz httpd: pam_sss(webapp:auth): authentication success; logname= uid=48 euid=48 tty= ruser= rhost=192.168.1.52 user=alpha

Apache area conf file :

<Location /protected>
 AuthType Basic
 AuthName "private area"
 AuthBasicProvider PAM
 AuthPAMService webapp
 Require valid-user
</Location>

[adelton]

What's the command that you run against the Apache and what's in the Apache logs? For me, running

curl -u alpha:Secret123 http://localhost/protected

results in single

Jan 09 05:42:33 server httpd[21938]: pam_sss(webapp:auth): authentication success; logname= uid=48 euid=48 tty= ruser= rhost=::1 user=alpha

record in journal and a single record in access_log

::1 - alpha [09/Jan/2020:05:42:33 -0500] "GET /protected HTTP/1.1" 404 196 "-" "curl/7.66.0"

(The 404 status is expected, the Location is not backed by any real directory.)

[jbaksta]

I'll try with a curl command later this evening / week. It occurred on Safari and Chrome as regular browsers. I hope it's not a client issue.

[pzirnik]

I have probably the same issue. I use auto_index and it looks like auth is called for each element, which makes apache horrible slow.

/srv/www/htdocs # ls -1 | wc -l 506

httpd-prefork: message repeated 500 times: [ pam_sss(webservice:auth): authentication success; logname= uid=30 euid=30 tty= ruser= rhost=x.x.x.x user=xxxxx

According to configuration i have socache active ... but no hint if it works or not

    <Location />
      AuthType Basic
      AuthName "Internal Download Area"
      AuthBasicProvider socache PAM
      AuthnCacheProvideFor PAM
      AuthPAMService webservice
      Require valid-user
    </Location>

pam-service-file

-----------
auth    required   pam_sss.so
account required   pam_sss.so
-----------

I used latest source to build the module. I guess i do something wrong, but would like to add already as i found this report while digging around.

[pzirnik]

Additional info: If i use a static "index.html" indeed i only get one log entry and apache is fast. So it looks like the module kicks already in while apache does generate the content to serve. Maybe some kind of bad security behavior to not lag any information in the auto generated index ?

[adelton]

Does the behaviour change if you use AuthnCacheContext server?

[pzirnik]

Yes, this did the trick :-)

Just one log entry now.

httpd-prefork: pam_sss(webservice:auth): authentication success; logname= u id=30 euid=30 tty= ruser= rhost=x.x.x.x user=xxxxx

Thanks

[adelton]

We seem to have lost the traction about the original issue reported by @jbaksta.