1 minute wait before auth

[GoogleCodeExporter]

What steps will reproduce the problem?
1. use mod-auth-external

What is the expected output? What do you see instead?
I expect the dirindex to show right away .. but it doesn't .. I have to wait a 
whole minute ..

What version of the product are you using? On what operating system?
Gentoo 2.4.7, mod 3.3.1

Please provide any additional information below.

http://apaste.info/etlt
http://apaste.info/538w

Original issue reported on code.google.com by dex...@d3xt3r01.tk on 11 Dec 2013 at 10:33

[GoogleCodeExporter]

Ok, I think I know why .. it asks for each icon/image in the directory index :/
trying socache with memcache/shcmb but with no luck .. 

Original comment by dex...@d3xt3r01.tk on 11 Dec 2013 at 4:03

[GoogleCodeExporter]

This is what I've added at the end of my /etc/apache2/httpd.conf
LoadModule socache_shmcb_module modules/mod_socache_shmcb.so
LoadModule authn_socache_module  modules/mod_authn_socache.so
AuthnCacheSOCache shmcb
AuthnCacheEnable
# authncachenable by itself didn't allow apache to start, had to add 
authncachesocache ..

And this is what I have in my .htaccess ..

AuthType Basic
AuthName "Restricted Files"
AuthBasicProvider socache external
AuthExternalProvideCache On
AuthnCacheProvideFor external
AuthnCacheTimeout 60
AuthExternal apacheauth
GroupExternal apachegroup
Require external-group init def sh

But it doesn't work well .. Here's some output http://apaste.info/7xFv

Any ideas ?

I'm running gentoo with apache 2.4.7
Server version: Apache/2.4.7 (Unix)
Server built:   Dec 10 2013 18:46:55
Server's Module Magic Number: 20120211:27
Server loaded:  APR 1.5.0, APR-UTIL 1.5.2
Compiled using: APR 1.5.0, APR-UTIL 1.5.2
Architecture:   64-bit
Server MPM:     worker
  threaded:     yes (fixed thread count)
    forked:     yes (variable process count)
Server compiled with....
 -D APR_HAS_SENDFILE
 -D APR_HAS_MMAP
 -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
 -D APR_USE_SYSVSEM_SERIALIZE
 -D APR_USE_PTHREAD_SERIALIZE
 -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
 -D APR_HAS_OTHER_CHILD
 -D AP_HAVE_RELIABLE_PIPED_LOGS
 -D DYNAMIC_MODULE_LIMIT=256
 -D HTTPD_ROOT="/usr"
 -D SUEXEC_BIN="/usr/bin/suexec"
 -D DEFAULT_PIDLOG="/run/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="/etc/apache2/mime.types"
 -D SERVER_CONFIG_FILE="/etc/apache2/httpd.conf"

Original comment by dex...@d3xt3r01.tk on 11 Dec 2013 at 4:04

[GoogleCodeExporter]

First, the unhelpful response. To quote my comments on 
http://code.google.com/p/pwauth/wiki/Risks :

Don't Use Mod_Authn_Socache. This module, new in Apache 2.4, is very tempting. 
It caches login credentials so that you don't have to keep re-running the 
authenticator over and over again for the same user. That's a big performance 
gain. But the cache it maintains is essentially an Apache-readable copy of your 
system password file, containing the encrypted passwords of your active users. 
Having that sitting around is only slightly less of a problem than making your 
password file readable to Apache would have been in the first place.

It's been a while since I investigated mod_authn_socache, and maybe things have 
changed, but I think it inherently weakens your security if you are using 
mod_authnz_external to authenticate out of a database not directly readable to 
Apache.

But that's up to you. I'll look at this and try to see if I can come up with an 
actual helpful response.

Original comment by j...@unixpapa.com on 11 Dec 2013 at 4:48

[GoogleCodeExporter]

I understand .. I've actually read the wiki a couple of times today ..
It's trying to auth out of a mysql database .. the passwords are hashed .. I 
don't worry about that part .. 
I know there is a dbd module, I don't like the groups part .. auth-external 
does its job well, the only problem is the speed .. apache-mod-php...
Since there's no better way to make it faster .. in a directory index with 
thousands of directories, it's the only solution :/

Thanks in advance for the response !

Original comment by dex...@d3xt3r01.tk on 11 Dec 2013 at 4:53

[GoogleCodeExporter]

Directory indexes have always been a problem with mod_auth_external, just 
because they can branch out into an awful lot of requests. I can't think of any 
better solution than using authn_socache. At least you are using a shared 
memory cache. That's probably more secure than using a dbm cache. Possibly the 
additional security risks are not gigantic.

I also see that the last time I looked at authn_socache was while Apache 2.4 
was still in beta. Back then I studied it's source code pretty carefully, but 
I've long since forgotten everything I knew about it.

So...looking at your output

At 16:24:30.013465 authz_core sees the "Require init def sh" directive and 
discovers it can't resolve it because it hasn't authenticated a users. So it 
triggers an authentication. At 16:24:30.076883 authn_socache says it hasn't 
heard of the user "dex". At 16:24:30.076883 we hear that authn_socache has 
added "dex" to the cache. Presumably that means that authn_external was called 
and succeeded, but it doesn't log here. (Maybe it should - I should research 
that). At 16:24:30.136037 authz_core is happy about it's require directive.

I'm guessing the next line, at 16:24:30.136121 is the start of the next 
subrequest. Again, it starts with the Require failing because there is no 
identification. At 16:24:30.13697 authn_socache says it has found "dex" in 
cache and at 16:24:30.196576 the authentication has succeeded. That's all 
perfect.

But the next subrequest is bad. At 16:24:30.202281 authn_socache reports that 
it can't find any credentials for "dex". It looks like it then calls 
authn_external again, which succeeds, because at 16:24:30.261596 we again add 
"dex" to the cache.

And then the next request again fails to find "dex" in the cache.

So, returning to the domain of unhelpful responses, IT'S NOT MY FAULT. At least 
I can't think of any way it could be. Between the time that the cache lookup of 
"dex" succeeded, and the time it failed for the first time, no 
mod_authnz_external code would have been executed. It is only run AFTER 
failures to authenticate with socache. So I can't see how anything 
mod_authnz_external could possibly do would cause this behavior. It looks to me 
like flakiness in mod_authn_socache or mod_socache_shmcb.

I think I'd try using one of the other caching options, other than shmcb, and 
see if that make a difference. But I don't really believe that either module is 
going to be quite as buggy as all that, so this probably won't help.

One thing I'm thinking about is that there is probably more than one cache. 
After all, different directories might have different .htaccess files, so you'd 
need a separate authentication cache for each separate authentication domain. 
So one conceivable way that a cache lookup for "dex" would first succeed and 
then fail would be if they were being looked up in different caches. I don't 
know what request resulted in the log you posted, or what any of the 
subrequests were, but it seems possible that some were perceived as falling 
into different authentication domains.

The log file doesn't tell us the key that we tried to look up. It does tell us 
that all requests are on subcache 12, which is good. It appears "dex" is 
inserted into the cache three times, at index 130, 131, 132. This suggests that 
"dex" was never deleted from cache, but the key was somehow different each 
time. The keys are probably not just the user name. They may be something like 
"dex.domain1" "dex.domain2" or something. I'd have to read the source code for 
those two modules to have any chance of figuring out if something like that 
could possibly be going on.

Original comment by j...@unixpapa.com on 11 Dec 2013 at 6:38

[GoogleCodeExporter]

Thanks for taking your time to look at the logs .. 
I've tried memcache but with same luck and even less information :/

Maybe in a future version .. you'll have a built-in cache 

Original comment by dex...@d3xt3r01.tk on 11 Dec 2013 at 6:48

[GoogleCodeExporter]

Original comment by j...@unixpapa.com on 11 Dec 2013 at 7:24

• Changed state: Started

[GoogleCodeExporter]

After I've implemented some logging for the env variable I've noticed some 
strange behaviour ..:
The authenticator is called for each <a href="dir/index.php">...</a> element .. 
That's static content that doesn't require another call from the browser .. why 
is the authenticator called for a simple "link" ( not an image .. not a css / 
js .. )

Original comment by dex...@d3xt3r01.tk on 12 Dec 2013 at 6:19

[GoogleCodeExporter]

:-s Maybe it has something to do with the fact that apache "in the background" 
goes through each dir to see if it has a .htaccess with other requirements .. 
:/ That's still not good :-(

Original comment by dex...@d3xt3r01.tk on 12 Dec 2013 at 9:44