search cancel

Execution time exceeded threshold user=

book

Article ID: 213981

calendar_today

Updated On:

Products

SITEMINDER

Issue/Introduction

 

When running Policy Server, intermittently the Policy Server might
write log lines where the user variable has no value, ie. : user=.

To illustrate :

  [1646/140397614155520][Thu Apr 08 2021 13:01:31][SmAuthorization.cpp:2248][INFO]
  [sm-log-00000] Execution time exceeded threshold. (CSmAz::ProcessActiveExpression, 7295, 5000, 
  agent=myAgent client=10.0.0.1 server=http://myHost.myDomain.com 
  resource=/myApp action=GET user=)

Resolution

 

At first glance, the absence of user value might be caused of a
specific process hasn't finished yet. From the given snippet, the
value seems to be missing when the Policy Server is at the
Authorization phase.

To illustrate that, if the Policy Server takes too much time to
analyse the CRL cache for a given user, the Policy Server line will
reports no value for the user with similar line. Also, if the
processing of SAMLResponse takes too long, a similar log line with the
user without value can be shown (1)(2).

It's also possible the process ends the request correctly. Policy
Server writes this line because the process is not finished yet, but
takes more time than threshold value (5s). In the Policy Server
traces, you should see after that line if the process ends correctly
or with an error later. Mainly, when you see user= is because at the
stage the process is, the value is not yet known. Again, that doesn't
mean the authorization will fail.

 

Additional Information

 

(1)

    Policy Server :: Slow CRL Processing : Finding the CRL in the cache

      22 secs spend here :

      __[05/10/2019][08:58:50.486][2359943][140382136428288][ Finding the CRL in the cache]
      [08:58:50][CRLCache.cpp:180][CRLcache::isValid][][][][][][][][][][][][][][][][]
      [][][][][][][][][][][2B 68 03 BC 00 00 00 0B 25 50][][http://certserver.com/crl/CA.crl]
      [][][][][][][][][][][][][][][][][][][][][][][][][][][]

      __[05/10/2019][08:59:12.680][2359943][140382136428288][ Checking Validity of CRL]
      [08:59:12][CRLCache.cpp:260][isCRLValid][][][][][][][][][][][][][][][][][][][]
      [][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][]

      [05/10/2019][08:59:13.265][2359943][140382136428288][LogMessage:INFO:
      [sm-log-00000] Execution time exceeded threshold. (CServer::ProcessRequest, 
      322184, 5000, agent=myagent client=*10.0.0.1 server=https://myserver.mydomain.com 
      resource=/redirectSmartCard/ action=GET user=)][08:59:13][CServer.cpp:6372][][]
      [][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][]
      [][][][][][][][][][][][][][][][]

    https://knowledge.broadcom.com/external/article?articleId=133679
(2)
  
    AuthnResponse contains not SAML compliant Timestamp

      [12/28/2020][15:43:58.400][15:43:58][30735][140503237285632][CServer.cpp:6863]
      [][][][][][][][][][][][][][][][][][][][][][LogMessage:INFO:[sm-log-00000] 
      Execution time exceeded threshold. (CServer::Tunnel, 6098, 5000, 
      agent=sps-training-com client=*192.168.1.111 server=http://sps.training.com 
      resource=/affwebservices/public/saml2sso?SAMLRequest=fZHNbsMgEIRfxeIem6C4s
      VEcKW0OjZSqVuL00EuFATdINrgspD9PXxy3anrJBYllv52ZZQGsa3u68u6od%2FLNS3DRR9dqo
      OeHAnmrqWGggGrWSaCO0%2F3qYUtJjGlvjTPctOgCuU4wAGmdMhpFm3WBXmZcZPM8zQWWIpOpm
      OdZ0%2BR5OuOkzoQg%2BYzXImcYz1H0JC0EskBhUMABvNxocEy7UMIET6ZkQrJqmtIUU3zzjKJ
      1SKM0c2fq6FwPNEmgh9hZprTSrzE3XcKa5l3WwddJcQlJ7%2BtW8WTIQgDMoFQG2%2BokC%2BS
      slyha%2FYa4Mxp8J%2B1%2BZA%2B77Z9Mbb%2Fi7nM4Bw0%2BdqKo%2FFnZrdIiGLi%2BrXpsA
      npfVeWkfNxXaLkYjNFzersM4xfJZWG8%2Ff%2FP5Tc%3D action=GET user=)][][][][][]
      [][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][][]

    https://knowledge.broadcom.com/external/article?articleId=208775