Forum Discussion

hui_37443's avatar
hui_37443
Icon for Nimbostratus rankNimbostratus
Feb 24, 2010

auth_result fired twice?

We have implemented an iRule to do OCSP check, based on the prize winner http://devcentral.f5.com/Default.aspx?tabid=108. When it encounters an error, it doesn't resume the suspended SSL::handshake.

 

when AUTH_RESULT {

 

if {[info exists tmm_auth_ssl_ocsp_sid] and $tmm_auth_ssl_ocsp_sid eq [AUTH::last_event_session_id]} {

 

set tmm_auth_status [AUTH::status]

 

 

log local0.debug "authentication status of round 1 $tmm_auth_status"

 

 

if {$tmm_auth_status eq 0} {

 

Success

 

log local0.debug "OCSP verfication succeeded"

 

SSL::handshake resume

 

lset ssl_array 1 "auth_success"

 

} elseif {$tmm_auth_status eq 1} {

 

Failure

 

log local0.debug "OCSP verfication failed"

 

SSL::handshake resume

 

lset ssl_array 1 "auth_failure"

 

} elseif {$tmm_auth_status eq -1} {

 

Error

 

log local0.debug "OCSP verfication error"

 

lset ssl_array 1 "auth_failure"

 

}

 

else {

 

Not authorised

 

log $tmm_auth_status

 

log local0.debug "OCSP verfication not authorised"

 

reject

 

}

 

 

session add ssl "$id any pool" $ssl_array 21600

 

}

 

}

 

 

From the client browser, we can see the error page shown promptly. However, in the log there is an TCL parsing error:

 

 

Feb 22 17:35:10 tmm tmm[1786]: 01220001:3: TCL error: cbz_ocsp_action - can't read "ssl_array": no such variable while executing "lset ssl_array 1 "auth_failure"

 

 

From the timestamp, it is more a couple of minutes later than the OCSP check. Looks like to me the event AUTH_RESULT is fired twice. Once right after the OCSP check, and the other a while later.

 

 

Not sure whether I need to resume the SSL::handshake?

12 Replies

  • Aaron, we are going to raise a case, and hope we can get the bottom of it. Craig, your tip gave us important hint on what's going on under the hood.

     

     

    We've generated several tcpmdump on traffic between F5 & OCSP server, with & without OneConnect profile. traffic without OneConnect profile is ten times heavier. That suggests that OCSP authentication is actually affected by OneConnect.
  • We've got a case with F5, C799711.

     

     

    Looks like it is the clash between idle timeout settings in OCSP profile & (TCP) protocol profile, and OneConnect profile simply makes things worse by extending the latter one.

     

     

    1.I’ve changed the OCSP profile idle timeout to 100 secs.

     

    2.I’ve also create a new TCP profile “tcp-shorttimeout”, which sets the idle timeout to 60 secs. The one we normally use is “tcp-lan-optimised”, which has default idle timeout value of 300 secs.

     

    3.If I use the tcp-shorttimeout as protocol profile, either in client side or server side field or both. The OCSP timeout issue goes away. It is a bit confusing here. I expected that one of the profiles affects OCSP, and the other doesn’t. However, my experiment suggests both have the same impact.

     

    4.If I use the normal profile, i.e. “tcp-lan-optimised”, the OCSP error pops up constantly.

     

    5.Put OneConnect profile in, the OCSP error shows up constantly, regardless which TCP profile I use. I’ve also noticed that much fewer OCSP calls are made with OneConnect profile in place.

     

     

    Definitely the idle timeout triggers another "auth_result" event. If the TCP session dies before, then OCSP session disappears with it. Otherwise, we can observe the symptom quite easily. Thinking about a quick fix. Putting the OCSP profile timeout to infinite will surely fix the issue. However, I can’t tell how much impact it may cause on the system.

     

     

    Cheers,