The following steps will reproduce:

Configure site so that home page requires CAS login
New private browser window
Access site (get redirected to CAS) and halt on the CAS login page
Open a new tab
Access site in the new tab and complete login process (so you're now in the site)
Go back to first tab and complete login process (you're now at the site; note the ST in the URL)
Go back to the second tab and logout (you will end up at the CAS server logout page)
Go back to the first tab and hit refresh

This will result in a nasty 500 error and an exception being thrown by phpCAS. What's happening here is that if you submit the CAS login form when you have a Drupal session, you end up in Drupal with the service ticket appended to the URL. If you close your Drupal session and request the URL with the service ticket present (basically by hitting refresh), your browser requests the URL with the service ticket, which phpCAS then tries to validate. Since the service ticket has expired, it throws an exception, which results in a 500 error.

If you think this scenario sounds crazy, it happened "in the wild" on our setup here this morning (we caught the 500 error in the logs and investigated).

A solution is simple: simply check at the beginning of the hook_init process for a logged in user with $_GET['ticket'] set, and redirect them.

I will post a patch in my first comment.

CommentFileSizeAuthor
#14 Logged In users with service tickets in URL-2223329-14.patch2.52 KBtherainmakor
#13 Logged In users with service tickets in URL-2223329-13.patch589 bytestherainmakor
#1 2223329-1-loggedInUsersWithServiceTickets.patch650 bytesyalet

Comments

yalet’s picture

yalet commented
Status: Active » Needs review
StatusFileSize
new 2223329-1-loggedInUsersWithServiceTickets.patch650 bytes

patch.

Status: Needs review » Needs work

The last submitted patch, 1: 2223329-1-loggedInUsersWithServiceTickets.patch, failed testing.

vinmassaro’s picture

vinmassaro commented

Are you seeing errors similar to these? I opened #2170801 because we're seeing a lot in our logs but are not sure what's causing it to happen.

CAS_AuthenticationException: in CAS_Client->validateCAS20() (line 2839 of /d7/sites/all/libraries/CAS/CAS/Client.php).

PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'ST-387962-qlkzAsN5G245o9VSQL6M-cas' for key 'PRIMARY': INSERT INTO {cas_login_data} (cas_session_id, uid) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1); Array ( [:db_insert_placeholder_0] => ST-387962-qlkzAsN5G245o9VSQL6M-cas [:db_insert_placeholder_1] => 24963 ) in _cas_single_sign_out_save_token() (line 1123 of /d7/sites/all/modules/contrib/cas/cas.module).
yalet’s picture

yalet commented

Well, to be clear, the first error (the CAS authentication exception) covers a large swath of errors that can be generated by the CAS server response.

I have seen the second error, but I am not 100% sure that it is correlated with this particular issue. In most cases, the second service ticket has expired, which causes the exception.

The second case looks to be a second session with the same service ticket, which indicates a different problem.

vinmassaro’s picture

vinmassaro commented

I looked closer and noticed the first error seems to correlate with a database deadlock.

Do you have any idea how the second case happens? We see them a lot and I'm not sure how to debug.

yalet’s picture

yalet commented

The first error is correlated with a database deadlock? It seems at first glance like the second would be more likely to correlate with a database deadlock. Are the two errors correlated with each other?

vinmassaro’s picture

vinmassaro commented

Actually, I don't think my suspicion was true. The database deadlocks appear to be separate and not connected to these other CAS errors, since they occur on the users table.

These errors:

CAS_AuthenticationException: in CAS_Client->validateCAS20() (line 2839 of /data01/d7/sites/all/libraries/CAS/CAS/Client.php).

Always report a location like:
http://mysite.com/cas?destination=&ticket=ST-437362-SFmaeYjmzibhL4kinczM-cas

I assume this happens because a CAS ticket is being sent that does not exist in Drupal, therefore fails validation? The issue is I don't know how these requests originate. I agree with you that this is totally crazy - it always returns a 500 error and the user is never correctly authenticated into the site and left in a broken state.

These errors:

PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'ST-283554-1II5pOCyUknH04VvoBd3-cas' for key 'PRIMARY': INSERT INTO {cas_login_data} (cas_session_id, uid) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1); Array ( [:db_insert_placeholder_0] => ST-283554-1II5pOCyUknH04VvoBd3-cas [:db_insert_placeholder_1] => 15449 ) in _cas_single_sign_out_save_token() (line 1123 of /data01/d7/sites/all/modules/contrib/cas/cas.module).

Don't appear to be connected to the previous error, since they are from different hostnames, indicating a different user. I'm unsure what the impact is on the user experience with these.

yalet’s picture

yalet commented

Always report a location like:
http://mysite.com/cas?destination=&ticket=ST-437362-SFmaeYjmzibhL4kinczM...

I assume this happens because a CAS ticket is being sent that does not exist in Drupal, therefore fails validation? The issue is I don't know how these requests originate. I agree with you that this is totally crazy - it always returns a 500 error and the user is never correctly authenticated into the site and left in a broken state.

Actually, what happens is that a user's browser requests a page with the ST in their URL (as shown above). Then phpCAS takes the ST out of the browser and calls back to the CAS server with the ST to validate it. The CAS server then responds with some xml (assuming you're using CAS protocol >= 2) which tells phpCAS the name of the user and the released attributes if validation succeeded, or a failure message if it did not. Those exception messages get generated whenever a failed ticket validation occurs. This can happen for several reasons, including ST timeout. You can turn on debugging and dump the debug output (attached as a file, please) to see why validation is failing.

Don't appear to be connected to the previous error, since they are from different hostnames, indicating a different user. I'm unsure what the impact is on the user experience with these.

Stepping through the code, this occurs only when, during the login process for a user (and the ticket has already been validated), CAS tries to store the service ticket in the database but it is already there. So you have a situation where a browser has supplied a valid service ticket after that service ticket has already been used to log in to Drupal. Since the log in process won't run if the user is already logged in, I don't see how this could happen "by accident". Do you know how long your service tickets are valid before they expire?

yalet’s picture

yalet commented
Status: Needs work » Needs review

1: 2223329-1-loggedInUsersWithServiceTickets.patch queued for re-testing.

vinmassaro’s picture

vinmassaro commented

@yalet: I just received this error again with CAS 7.x-1.4:

PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry 'ST-1030275-xdWTlA0qGjDJ1hAnjnsW-cas' for key 'PRIMARY': INSERT INTO {cas_login_data} (cas_session_id, uid) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1); Array ( [:db_insert_placeholder_0] => ST-1030275-xdWTlA0qGjDJ1hAnjnsW-cas [:db_insert_placeholder_1] => 2 ) in _cas_single_sign_out_save_token() (line 1132 of /data01/d7/sites/all/modules/contrib/cas/cas.module).

What I did was I logged into a production site with CAS. I then refreshed the production site to our dev environment (drush archive-dump, drush archive-restore), and then attempted to log into the dev site via /cas.

yalet’s picture

yalet commented

I just saw behavior today in person that produces the SQL integrity constraint error:

A user clicked on a link to a service that had gateway mode enabled, and he had a CAS session. After he clicked the link, he got impatient with the loading time, and clicked the link again. The CAS server, aware that he had a valid ST, passed him along to Drupal again, which at this point had two requests that contained the same ST. Since the user hadn't actually reached the point where he had been signed into Drupal (and gotten his cookies for identifying his session), but had reached the point where his ST was saved, the second request triggered the error.

I'm not sure what other behavior can cause the same error, but this pattern will.

therainmakor’s picture

therainmakor commented

I see this occuring quite a bit when an organization has multiple sites that the user can log out of CAS from, which does not trigger _cas_single_sign_out_check() to be called to delete a user's records from the cas_login_data table. So what happens is a build up of CAS tickets and the db_insert() fails due to a duplicate primary key.

There are two options that can be done, an easy way and a more difficult way:

#1 (the easy way) - use db_merge() on line 1127 instead of db_insert(). See comment #13
#2 (the harder way) - clear old tickets on cron based on session.timstamp for each user. This could match your organization's CAS ticket expiration rules by way of a configuration field on admin/config/people/cas. See comment #14

Or a mixture of the two, which might be the safest way.

therainmakor’s picture

therainmakor commented
StatusFileSize
new Logged In users with service tickets in URL-2223329-13.patch589 bytes

Patch for easy way from comment #12

therainmakor’s picture

therainmakor commented
StatusFileSize
new Logged In users with service tickets in URL-2223329-14.patch2.52 KB

Patch for harder way from comment #12

vinmassaro’s picture

vinmassaro commented

@therainmakor: can you provide steps on how to reproduce the error so I can test the patch? I've only seen this happen randomly and was not able to reproduce it easily. I saw it again today on a site. Thanks.

therainmakor’s picture

therainmakor commented

@vinmassaro,

This is how it usually happens at my organization, which is a large public university with many different Drupal sites that use CAS login, along with other non-Drupal sites that use CAS login (mainly our student portal).

  1. Log into site A with CAS.
  2. Wait the CAS ticket expiration time (that's dependent on your organization's CAS server settings).
  3. Log into site B with CAS.
  4. Visit site A (this is when the error usually occurs).

Just to let everyone know, I've been using the patch from #13 on multiple sites within our organization without any issues. I think this is probably the best way to handle this.

vinmassaro’s picture

vinmassaro commented

@therainmakor: wasn't able to reproduce the issue with your description in #16, unfortunately. Had reports of it again today on one of our sites :\

vinmassaro’s picture

vinmassaro commented

Came back to this issue today after a user experienced the behavior in #10. After discussing with @yalet on IRC, it's clear there are two separate issues in this thread, one being the error reported in #1 and the other in #10. The patch in #1 works for the issue in the original post. The patch in #13 is sensible because you wouldn't want to attempt to insert the same value again, but this scenario is hard to test because the error is difficult to reproduce.

therainmakor’s picture

therainmakor commented

Yes, #13 is hard to test because it happens sporadically, but since I have put that patch in I have not seen the 500 error since on the four sites I manage. I especially haven't seen it happen when I refresh a DEV or QA environment with our production environment, which usually caused the error to occur for some reason.

metzlerd’s picture

metzlerd commented

I don't know where we are on strategies with this, but the issue summary suggests we are going to eliminate the ability to process a cas login for a currently logged in user. I realize this is somewhat of an edge case, but this will break our two factor auth implementation of cas because it only demands two-factor auth if it hits specific pages that require it. Can you tell me wehter the current solutions is still relying on the need to eleminate tokens when a user is logged in?

yalet’s picture

yalet commented

@metzlerd Patch 1 would certainly break that, I hadn't thought that through. The patch in 13 would not. However, as this issue has gotten a bit muddled, they are not attempting to solve all aspects of the same problem.

  • yalet committed 59892f6 on 7.x-1.x authored by therainmakor 
    Issue #2223329, 2737897 by therainmakor, yalet, joegraduate, vinmassaro...
yalet’s picture

yalet commented

I've committed #13 to deal with this issue (tracked primarily now in https://www.drupal.org/node/2737897).

bkosborne’s picture

bkosborne
Primary language English
Location New Jersey, USA
commented
Status: Needs review » Closed (outdated)

The root cause of the 500 errors has been addressed in #2737897: Intermittent fatal MySQL errors upon login and #2925151: Old CAS login data is never cleared.

Hiding the exception pages from being shown to users is being addressed in #2232805: Visiting login URL containing expired or invalid service ticket results in 500 error

bkosborne’s picture

bkosborne
Primary language English
Location New Jersey, USA
commented
Title: Logged In users with service tickets in URL » Logged In users end up with service tickets in current URL