Traces of the ApacheDBI modules The traces are supposed to serve as a reference, to check the local setup. They also serve as specification for regression testing of the modules. Note: - in order to see the traces in the error_log, you need to enable full debug output by setting $Apache::DBI::DEBUG = 2 and $Apache::AuthDBI::DEBUG = 2. - make sure, that the output of the same server is observed (check process id !) unless AuthDBI is tested and the usage of shared memory is configured. - here we show only the traces of one specific module, in reality the traces are a mix of all used modules and of all servers - in all auth-traces the REQUEST has been deleted - $; appears as '{' 1. Apache::DBI -------------- 1.1. normal persistent database connection new connect: 1150 Apache::DBI need ping: yes 1150 Apache::DBI new connect to 'dbname=template1{{{AutoCommit=1{PrintError=1' 1150 Apache::DBI disconnect (overloaded) re-use of connection: 1151 Apache::DBI need ping: yes 1151 Apache::DBI already connected to 'dbname=template1{{{AutoCommit=1{PrintError=1' 1151 Apache::DBI disconnect (overloaded) 1.2. PerlCleanupHandler: check if a rollback is initiated when using a connection with AutoCommit = 0 (data_source: dbi:Pg(AutoCommit=>0):dbname=template1): 1150 Apache::DBI push PerlCleanupHandler 1150 Apache::DBI need ping: yes 1150 Apache::DBI new connect to 'dbname=template1{{{AutoCommit=0{PrintError=1' 1150 Apache::DBI disconnect (overloaded) 1150 Apache::DBI PerlCleanupHandler 1150 Apache::DBI PerlCleanupHandler rollback for dbname=template1{{{AutoCommit=0{PrintError=1 1.3. PerlChildInitHandler: check if a pre-configured connection in startup.pl is initiated. the following entries are supposed to appear in the error_log once for every server: 1033 Apache::DBI PerlChildInitHandler 1033 Apache::DBI need ping: yes 1033 Apache::DBI new connect to 'dbname=template1{httpd{www{AutoCommit=1{PrintError=1' 1.4. timeout for ping: set PingTimeOut > 0 and verify, that the first database access shows 'need ping: yes' (unless a database handle has been created upon server startup). The second access immediately afterwards shows 'need ping: no' and the third access after timeout seconds again shows 'need ping: yes'. Always watch the same server ! De-activate ping with setting timeout = -1 and check for 'need ping: no'. 1.5. After having initiated a persistent connection check the perl-status menu-item 'DBI connections' ( http://localhost/perl-status?DBI ). Be sure, to check a server, which has a database handle ! Datasource Username dbname=test_auth ------------------------------------------------------------------- 2. Apache::AuthDBI::authen -------------------------- 2.1. normal authentication, setCacheTime(60), no cleanup handler ========== 25362 Apache::AuthDBI::authen request type = >initial main< 25362 Apache::AuthDBI::authen get_basic_auth_pw: res = >401<, password sent = >< -------------- here the password requester of the browser pops up -------- ========== 25364 Apache::AuthDBI::authen request type = >initial main< 25364 Apache::AuthDBI::authen get_basic_auth_pw: res = >0<, password sent = >support< 25364 Apache::AuthDBI::authen user sent = >support< 25364 Apache::AuthDBI::authen Config{ pwdcasesensitive } = on 25364 Apache::AuthDBI::authen Config{ pwd_whereclause } = 25364 Apache::AuthDBI::authen Config{ placeholder } = off 25364 Apache::AuthDBI::authen Config{ log_field } = 25364 Apache::AuthDBI::authen Config{ uid_field } = userid 25364 Apache::AuthDBI::authen Config{ authoritative } = on 25364 Apache::AuthDBI::authen Config{ data_source } = dbi:Pg:dbname=test_auth 25364 Apache::AuthDBI::authen Config{ grp_field } = groupid 25364 Apache::AuthDBI::authen Config{ encrypted } = on 25364 Apache::AuthDBI::authen Config{ pwd_field } = passwd 25364 Apache::AuthDBI::authen Config{ nopasswd } = off 25364 Apache::AuthDBI::authen Config{ grp_table } = groups 25364 Apache::AuthDBI::authen Config{ pwd_table } = users 25364 Apache::AuthDBI::authen Config{ password } = 25364 Apache::AuthDBI::authen Config{ log_string } = 25364 Apache::AuthDBI::authen Config{ uidcasesensitive } = on 25364 Apache::AuthDBI::authen Config{ username } = 25364 Apache::AuthDBI::authen Config{ grp_whereclause } = 25364 Apache::AuthDBI::authen passwd not found in cache 25364 Apache::AuthDBI::authen statement: SELECT passwd FROM users WHERE userid = 'support' 25364 Apache::AuthDBI::authen passwd = >su7/poGcpDQWY< 25364 Apache::AuthDBI::authen user support: password match for >su7/poGcpDQWY< 25364 Apache::AuthDBI::authen return OK 2.2. normal authentication as above, check if cached password is used discard all traces up to the Config section 25519 Apache::AuthDBI::authen cache: found >support,dbi:Pg:dbname=test_auth,users,userid< >935176023< >su7/poGcpDQWY< 25519 Apache::AuthDBI::authen passwd found in cache 25519 Apache::AuthDBI::authen passwd = >su7/poGcpDQWY< 25519 Apache::AuthDBI::authen user support: password match for >su7/poGcpDQWY< 25519 Apache::AuthDBI::authen secs since last CleanupHandler: 164, CleanupTime: 60 25519 Apache::AuthDBI::authen return OK 2.3. after successful authentication change password in database. Restart browser and check if password is looked up in the database again. 2.4. check normal authentication with several users, who share the same userid, but who have different passwords. 2.5. check normal authentication with more than one data_source parameter (and corresponding usernames and passwords), where the first connect fails and the second succeeds. Expect to see a warning about the failure. ------------------------------------------------------------------- 3. Apache::AuthDBI::authz ------------------------- 3.1. normal group authorization, setCacheTime(60) discard authentication traces ========== 25560 Apache::AuthDBI::authz request type = >initial main< 25560 Apache::AuthDBI::authz user sent = >support< 25560 Apache::AuthDBI::authz requirements: valid-user=>< user=>w3master< group=>group-a group-b group-support group-customer< 25560 Apache::AuthDBI::authz groups not found in cache 25560 Apache::AuthDBI::authz statement: SELECT groupid FROM groups WHERE userid = 'support' 25560 Apache::AuthDBI::authz groups = >group-support< 25560 Apache::AuthDBI::authz user support: group_result = OK for >group-support< 25560 Apache::AuthDBI::authz return OK ========== 25560 Apache::AuthDBI::authz request type = >< ========== 25560 Apache::AuthDBI::authz request type = >main< 3.2. normal authorization as above, check if cached password is used ========== 25560 Apache::AuthDBI::authz request type = >initial main< 25560 Apache::AuthDBI::authz user sent = >support< 25560 Apache::AuthDBI::authz requirements: valid-user=>< user=>w3master< group=>group-a group-b group-support group-customer< 25560 Apache::AuthDBI::authz cache: found >support,dbi:Pg:dbname=test_auth,users,userid< >935176510< >group-support< 25560 Apache::AuthDBI::authz groups found in cache 25560 Apache::AuthDBI::authz groups = >group-support< 25560 Apache::AuthDBI::authz user support: group_result = OK for >group-support< 25560 Apache::AuthDBI::authz return OK ========== 25560 Apache::AuthDBI::authz request type = >< ========== 25560 Apache::AuthDBI::authz request type = >main< 3.3. after successful authorization change group in database and .htaccess. Check if group is looked up in the database again. 3.4. check normal authorization with a specific required user. Expect to see no database access. 3.5. check normal group authorization with more than one data_source parameter, where the first connect fails and the second succeeds. Expect to see a warning about the failure. ------------------------------------------------------------------- 4. Apache::AuthDBI using the cleanup handler -------------------------------------------- 4.1. PerlCleanupHandler: configure setCleanupTime(60) and check that the first request does not create a PerlCleanupHandler: ... 1682 Apache::AuthDBI::authen secs since last CleanupHandler: 9, CleanupTime: 60 1682 Apache::AuthDBI::authen return OK ========== 1682 Apache::AuthDBI::authen request type = >< ========== 1682 Apache::AuthDBI::authen request type = >main< 4.2. PerlCleanupHandler: configure setCleanupTime(60) and check that a request after the configured time shows the following entries: ... 1682 Apache::AuthDBI::authen secs since last CleanupHandler: 244, CleanupTime: 60 1682 Apache::AuthDBI::authen push PerlCleanupHandler 1682 Apache::AuthDBI::authen return OK ========== 1682 Apache::AuthDBI::authen request type = >< ========== 1682 Apache::AuthDBI::authen request type = >main< 1682 Apache::AuthDBI PerlCleanupHandler 1682 Apache::AuthDBI PerlCleanupHandler keep >support,dbi:Pg:dbname=test_auth,users,userid< 4.3. Authentication: check if a previously used userid/password is deleted from cache, after the CacheTime has expired. For this, re-start the browser, re-authenticate with another userid and wait, until CacheTime and CleanupTime have expired. 1760 Apache::AuthDBI PerlCleanupHandler delete >w3master,dbi:Pg:dbname=test_auth,users,userid<, last access 157 s before 4.4. Authorization: check if a previously used userid/group is deleted from cache, after the CacheTime has expired. For this, re-start the browser, re-authenticate with another userid and wait, until CacheTime and CleanupTime have expired. 1760 Apache::AuthDBI PerlCleanupHandler delete >support,dbi:Pg:dbname=test_auth,users,userid<, last access 157 s before 5. Apache::AuthDBI using shared memory -------------------------------------- 5.1. PerlChildInitHandler: initIPC(10000) the following entries are supposed to appear in the error_log during server startup once for every server with increasing child count: 1479 Apache::AuthDBI PerlChildInitHandler child count = 1 1478 Apache::AuthDBI PerlChildInitHandler child count = 2 ... 5.2. using normal authentication, check if shared memory is used: expect to see the following entry just before the Config section: 1669 Apache::AuthDBI::authen cache in shared memory, shmid 2821, shmsize 10000, semid 642 using a command like ipcs should also show the IPC resources: ------ Shared Memory Segments -------- key shmid owner perms bytes nattch status 0x0103c80c 2821 httpd 600 10000 0 ------ Semaphore Arrays -------- key semid owner perms nsems status 0x0103c80c 642 httpd 600 1 5.3. PerlChildExitHandler: check if IPC resources are removed upon server shutdown. the following entries are supposed to appear in the error_log during server shutdown once for every server with decreasing child count: ... 1595 Apache::AuthDBI PerlChildExitHandler child count = 2 1596 Apache::AuthDBI PerlChildExitHandler child count = 1, remove shared memory 2309 and semaphore 386 # EOF