I have been able to do more digging into this and I think I have located the point of error. I believe faulty data is being written into the cache file.
Looking at the debug log entries, we can see that the username is successfully validated. [Wed Nov 15 15:01:59 2006] [notice] -> successful primary authentication for : 'testusertest' Then we go through the steps of creating and sending the ticket. Next we store the information in the Cache and sent the cookie back to the client. [Wed Nov 15 15:01:59 2006] [notice] MODCASIDS=IWkXielWCWqFZDXsGzUJ0xPCKRVhX;Secure;Path=/ After that, when the user reloads the page or visits the site again, we see that it has a valid cookie, and pull the data from the Cache. That is where we get the extra infomation on the user. [Wed Nov 15 15:02:02 2006] [notice] in do_cas() [Wed Nov 15 15:02:02 2006] [notice] in check_individual_cookie() [Wed Nov 15 15:02:02 2006] [notice] in cache_get() [Wed Nov 15 15:02:02 2006] [notice] -> check_individual_cookie succeeded; found- [Wed Nov 15 15:02:02 2006] [notice] testusertestW![E If I check the Cache file using strings, I can verify that the username is stored in there as testusertestW. Of course any other non-printables could be masked by using strings: IWkXielWCWqFZDXsGzUJ0xPCKRVhX testusertestW So, I'm trudging along right now looking at the cache_put sections to see if I can find out where things have gone wrong. Un/fortunately, I am a sysadmin and not a coder so it is a new learning experience for me. If anyone has pointers, I'll gladly take them. Dallas (It's always fun to follow up on your own post.) On Wed, 8 Nov 2006, Dallas Wisehaupt wrote: > Hello all, > > We are seeing something odd with authenticating usernames that are 12 > characters long. If we connect to one of the resources using mod_cas, we > see one of two behaviors. > 1) Extra data shows up for the username on the second access attempt > 2) The httpd process segfaults > > We see case #1 with our twiki server (Apache/2.0.46) and with a simple > script that echoes the REMOTE_USER variable. On the first access, we are > prompted to auth, auth sucessfully and then are presented with the > proper username. On the second access or a reload and we get presented > with the username with extra characters. Here is an example from the > Apache error log: > > [Tue Nov 07 12:17:56 2006] [notice] in do_cas() > [Tue Nov 07 12:17:56 2006] [notice] portstr:- > [Tue Nov 07 12:17:56 2006] [notice] 443 > [Tue Nov 07 12:17:56 2006] [notice] ! > [Tue Nov 07 12:17:56 2006] [notice] service = > 'https://embarcadero.scranton.edu/twiki/bin/whoami'; ticket = '(null)' > [Tue Nov 07 12:17:56 2006] [notice] about to call CAS_validate() > [Tue Nov 07 12:18:04 2006] [notice] in do_cas() > [Tue Nov 07 12:18:04 2006] [notice] portstr:- > [Tue Nov 07 12:18:04 2006] [notice] 443 > [Tue Nov 07 12:18:04 2006] [notice] ! > [Tue Nov 07 12:18:04 2006] [notice] service = > 'https://embarcadero.scranton.edu/twiki/bin/whoami'; ticket = > 'ST-42-7ttGMOkic5EBmn35kaXD' > [Tue Nov 07 12:18:04 2006] [notice] about to call CAS_validate() > [Tue Nov 07 12:18:04 2006] [notice] -> successful primary authentication for > : 'testusertest' > [Tue Nov 07 12:18:04 2006] [notice] in create_and_send_new_ticket() > [Tue Nov 07 12:18:04 2006] [notice] in random_ticket() > [Tue Nov 07 12:18:04 2006] [notice] using /dev/urandom > [Tue Nov 07 12:18:04 2006] [notice] processing randomness... > [Tue Nov 07 12:18:04 2006] [notice] got random ticket:- > [Tue Nov 07 12:18:04 2006] [notice] HLGcDDLAgCucm158XaZsXlKO0DRed > [Tue Nov 07 12:18:04 2006] [notice]- > [Tue Nov 07 12:18:04 2006] [notice] random_ticket successful: ticket =- > [Tue Nov 07 12:18:04 2006] [notice] HLGcDDLAgCucm158XaZsXlKO0DRed > [Tue Nov 07 12:18:04 2006] [notice]- > [Tue Nov 07 12:18:04 2006] [notice] in cache_put() > [Tue Nov 07 12:18:04 2006] [notice] -> got lock > [Tue Nov 07 12:18:04 2006] [notice] -> first memcpy() done > [Tue Nov 07 12:18:04 2006] [notice] -> second memcpy() done > [Tue Nov 07 12:18:04 2006] [notice] -> released lock > [Tue Nov 07 12:18:04 2006] [notice] in send_cookie() > [Tue Nov 07 12:18:04 2006] [notice] -> sending cookie ' > [Tue Nov 07 12:18:04 2006] [notice] > MODCASIDS=HLGcDDLAgCucm158XaZsXlKO0DRed;Secure;Path=/ > [Tue Nov 07 12:18:04 2006] [notice] ' > [Tue Nov 07 12:18:06 2006] [notice] in do_cas() > [Tue Nov 07 12:18:06 2006] [notice] in check_individual_cookie() > [Tue Nov 07 12:18:06 2006] [notice] in cache_get() > [Tue Nov 07 12:18:06 2006] [notice] -> check_individual_cookie succeeded; > found- > [Tue Nov 07 12:18:06 2006] [notice] testusertest!!PE > [Tue Nov 07 12:18:06 2006] [notice]- > [Tue Nov 07 12:18:06 2006] [notice] -> authenticated from cookie! > > We see case #2 on our mod_cas protected Oracle Calendar server > (Apache/2.0.52). When acessing the resource, we are redirected, auth, > get passed back, and then see a "cannot contact the server" error. This is > what shows up in the error log on that machine: > > [Wed Nov 08 10:56:38 2006] [notice] in do_cas() > [Wed Nov 08 10:56:38 2006] [notice] in check_individual_cookie() > [Wed Nov 08 10:56:38 2006] [notice] portstr: > [Wed Nov 08 10:56:38 2006] [notice] 443 > [Wed Nov 08 10:56:38 2006] [notice] \n > [Wed Nov 08 10:56:38 2006] [notice] service = > 'https://salt.ssr.scranton.edu/ocas-bin/ocas.fcgi%3Fsub%3Dweb'; ticket = > '(null)' > [Wed Nov 08 10:56:38 2006] [notice] about to call CAS_validate() > [Wed Nov 08 10:56:48 2006] [notice] in do_cas() > [Wed Nov 08 10:56:48 2006] [notice] in check_individual_cookie() > [Wed Nov 08 10:56:48 2006] [notice] portstr: > [Wed Nov 08 10:56:48 2006] [notice] 443 > [Wed Nov 08 10:56:48 2006] [notice] \n > [Wed Nov 08 10:56:48 2006] [notice] service = > 'https://salt.ssr.scranton.edu/ocas-bin/ocas.fcgi%3Fsub%3Dweb'; ticket = > 'ST-12-MQpHXqIVj6XKdP9rh2uR' > [Wed Nov 08 10:56:48 2006] [notice] about to call CAS_validate() > [Wed Nov 08 10:56:48 2006] [notice] -> successful primary authentication for > : 'christiansd1' > [Wed Nov 08 10:56:48 2006] [notice] in create_and_send_new_ticket() > [Wed Nov 08 10:56:48 2006] [notice] in random_ticket() > [Wed Nov 08 10:56:48 2006] [notice] using /dev/urandom > [Wed Nov 08 10:56:48 2006] [notice] processing randomness... > [Wed Nov 08 10:56:48 2006] [notice] got random ticket: > [Wed Nov 08 10:56:48 2006] [notice] Gl3tPOAC4HOEjBrPXALWv2akhFrJ1 > [Wed Nov 08 10:56:48 2006] [notice] > [Wed Nov 08 10:56:48 2006] [notice] random_ticket successful: ticket = > [Wed Nov 08 10:56:48 2006] [notice] Gl3tPOAC4HOEjBrPXALWv2akhFrJ1 > [Wed Nov 08 10:56:48 2006] [notice] > [Wed Nov 08 10:56:48 2006] [notice] in cache_put() > [Wed Nov 08 10:56:48 2006] [notice] -> got lock > [Wed Nov 08 10:56:48 2006] [notice] -> first memcpy() done > [Wed Nov 08 10:56:48 2006] [notice] -> second memcpy() done > [Wed Nov 08 10:56:48 2006] [notice] -> released lock > [Wed Nov 08 10:56:48 2006] [notice] in send_cookie() > [Wed Nov 08 10:56:48 2006] [notice] -> sending cookie ' > [Wed Nov 08 10:56:48 2006] [notice] > MODCASIDS=Gl3tPOAC4HOEjBrPXALWv2akhFrJ1;Secure;Path=/ > [Wed Nov 08 10:56:48 2006] [notice] ' > [Wed Nov 08 10:56:48 2006] [notice] in do_cas() > [Wed Nov 08 10:56:48 2006] [notice] in check_individual_cookie() > [Wed Nov 08 10:56:48 2006] [notice] in cache_get() > [Wed Nov 08 10:56:49 2006] [notice] child pid 10106 exit signal Segmentation > fault (11) > > What adds to the oddity is that the "whoami" script which echoes the > REMOTE_USER variable shows segfaults in the error log, but returns the a > page with variable properly displayed with no additional characters. > > In both cases, I have tested going to other CAS protected resources > (EZProxy and our Luminis based portal) and am passed in as a sucessfully > validated user with the proper username. > > For both of these mod_cas based servers, we are using the mod_cas module > hosted by Case Western. I have tried adjusting the USERBUFSIZE from 20 > to 30 in the hope that there would be a change, but it gave no change in > behavior. > > In addition, the TWiki instance is pointing against the production CAS > server and the Calendar instance points at our test CAS server. However, > they are both running the same server software so I wouldn't expect a > difference there. > > Has anyone seen this before? We're kinda stumped by this one. > > Dallas > -- Dallas Wisehaupt Systems Administrator [EMAIL PROTECTED] The University of Scranton _______________________________________________ Yale CAS mailing list [email protected] http://tp.its.yale.edu/mailman/listinfo/cas
