traces.txt   [plain text]



                      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