Error: ACS_IS_PROT_FAILED error code: -3 Web Agent Option pack (WAOP)
search cancel

Error: ACS_IS_PROT_FAILED error code: -3 Web Agent Option pack (WAOP)

book

Article ID: 203463

calendar_today

Updated On:

Products

CA Single Sign On Secure Proxy Server (SiteMinder) CA Single Sign On Agents (SiteMinder) CA Single Sign On Federation (SiteMinder) CA Single Sign On SOA Security Manager (SiteMinder) SITEMINDER

Issue/Introduction

 

When running Federation Services on Web Agent Option Pack and this one reports errors as such as:

  [sm-FedClient-01700] Sm_AgentApi_IsProtectedEx failed with error code: -3.

  [sm-FedClient-02890] Transaction with ID: 51122sd12s-3d34e837-1bec7db6-6ce236e3-62dda27e-d6 failed. Reason: ACS_IS_PROT_FAILED (, , )

and the browsers receive 500 errors.

 

Environment

 

Web Agent Option Pack 12.52SP1CR10 64bit on JBoss EAP 7.1.6.GA 64bit on RedHat 6; 
2 Policy Server 12.8SP2 on RedHat 6;

 

Cause

 

This issue happens as the Web Agent Option Pack tries to get a connection with the Policy Server, but it fails to get one. As such, each time the Web Agent Option Pack calls the Policy Server to get information about the protection of the target realm, it fails.

At the time of the issue, 1 out of 2 Policy Servers is down. The one Policy Server which is up and running has a problem communicating with the Policy Store when the Web Agent Option Pack starts. Policy Server needs to access the Policy Store data to find the trusted host and share secrets to connect with the Web Agent Option Pack.

With no connection established with the Policy Server, the Web Agent Option Pack cannot process any further protected calls.

The secondary Policy Server doesn't have access to the secondary Policy Store until 08:09:15. At 08:09:15 it seems to get one, but quickly after that, it lost connection access again, until 08:11:46. Again, it lost connection with the Policy Store to recover it finally at 08:15:00:

smps.log :

  [70152/140037444728576][Sun Nov 01 2020 08:00:01][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:00:31][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:01:01][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

[...omitted for brevity...]

  [70152/140037444728576][Sun Nov 01 2020 08:07:59][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:08:32][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140027398973184][Sun Nov 01 2020 08:09:15][smldaputils.cpp:1012][INFO]
  [sm-Server-04410] Failing back LDAP store type #0 to server 'primarypolicystore:389'.

  [70152/140037444728576][Sun Nov 01 2020 08:11:12][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:11:42][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140036985050880][Sun Nov 01 2020 08:11:46][smldaputils.cpp:1005][INFO]
  [sm-Server-04400] Failing over LDAP store type #0 to server 'secondarypolicystore:389'.

  [70152/140037444728576][Sun Nov 01 2020 08:12:14][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:12:46][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:13:19][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:13:52][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037444728576][Sun Nov 01 2020 08:14:25][SmObjLdapConnMgr.cpp:622][ERROR]
  [sm-Ldap-00350] SmObjLdapConnMgr Bind. Server primarypolicystore:389. Error 91 - Can't connect to the LDAP server

  [70152/140037712758528][Sun Nov 01 2020 08:15:00][smldaputils.cpp:1012][INFO]
  [sm-Server-04410] Failing back LDAP store type #0 to server 'primarypolicystore:389'.

[...omitted for brevity...]

Primary Policy Server is up and running only at 08:15:14 before it was down:

smps.log :

  [5650/140534854063904][Sun Nov 01 2020 08:15:14][CServer.cpp:4071][INFO]
  [sm-Server-03540] Product: SiteMinder Policy Server

  [5650/140534854063904][Sun Nov 01 2020 08:15:14][CServer.cpp:4072][INFO]
  [sm-Server-03550] Version: 12.80; Update: 02.00; Build: 1992; CR: 00;

  [5650/140534854063904][Sun Nov 01 2020 08:15:14][CServer.cpp:4075][INFO]
  [sm-Server-03570] Starting up Application: smpolicysrv.

[...omitted for brevity...]

The Web Agent Option Pack starts at the time the only secondary Policy Server has connection problems with the Policy Store, and thus threads 1709635328 and 1715951360 reports problem to get connection:

affwebserv.log

  [7048/1709635328][Sun Nov 01 2020 08:09:35][agentcommon][INFO]
  [sm-FedClient-00010] The SiteMinder Agent is initializing ..

  [7048/1709635328][Sun Nov 01 2020 08:09:35][agentcommon][INFO]
  [sm-FedClient-00010] SiteMinder Product Details: PRODUCT_UPDATE=0110 , PRODUCT_NAME=Federation Web Services, PRODUCT_LABEL=766, PRODUCT_VERSION=12.52.

It tries to connect to the Policy Server 08:09:39:

  [7048/1709635328][Sun Nov 01 2020 08:09:39][agentcommon][INFO]
  [sm-FedClient-00010] Registering the Configuration Manager with the Policy Server and after 60 seconds it reports it can't get a connection :

  [7048/1709635328][Sun Nov 01 2020 08:10:39][agentcommon][INFO]
  [sm-FedClient-00010] The doManagement Thread failed as the Policy Server could not be reached. Reason: Agent API Timed out

  [7048/1709635328][Sun Nov 01 2020 08:10:39][FWSAdministrationManager.java][ERROR]
  [sm-FedClient-00060] Federation Web services initialization FAILED. ()

and the transaction fails:

  [7048/1893447424][Sun Nov 01 2020 08:13:24][AssertionConsumer.java][ERROR]
  [sm-FedClient-01700]Sm_AgentApi_IsProtectedEx failed with error code: -3.

  [7048/1893447424][Sun Nov 01 2020 08:13:24][AssertionConsumer.java][ERROR]
  [sm-FedClient-02890] Transaction with ID: d4s411fd12-3d34e837-1bec7db6-6ce236e3-62dda27e-d6 failed. Reason: ACS_IS_PROT_FAILED (, , )

  [7048/1715951360][Sun Nov 01 2020 08:13:43][agentcommon][INFO]
  [sm-FedClient-00010] The doManagement Thread failed as the Policy Server could not be reached. Reason: Agent API No Connection

And this goes on for 64 threads from the Web Agent Option Pack:

  1613772544 1615877888 1616930560 1617983232 1619035904 1620088576 1621141248
  1622193920 1623246592 1624299264 1710688000 1711740672 1712793344 1714898688
  1717647104 1724970752 1760036608 1762141952 1763194624 1764247296 1765299968
  1766352640 1767405312 1768457984 1769510656 1770563328 1771616000 1772668672
  1773721344 1774774016 1775826688 1776879360 1777932032 1778984704 1780037376
  1781090048 1782142720 1788475136 1791633152 1792685824 1793738496 1794791168
  1808127744 1810306816 1811359488 1812412160 1813464832 1814517504 1815570176
  1816622848 1817675520 1818728192 1819780864 1820833536 1821886208 1822938880
  1823991552 1825044224 1826096896 1827149568 1828202240 1830307584 1887926016
  1893447424

To illustrate in detail: Thread 1613772544

The Web Agent Option Pack calls the function "getRealmForTarget" to get protection information about the target URL from the SAML Response it receives, and to get that, Web Agent Option Pack should have a connection with the Policy Server, so the following error:

  Sm_AgentApi_IsProtectedEx failed with error code: -3 ACS_IS_PROT_FAILED

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget]
  [Calling isProtected with resource: /myapp/login?SAML2IDPID=myidp.idp.com]

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget]
  [IsProtected call to policy server for target resource realm [CHECKPOINT = SSOSAML2_ISPROTECTEDCALLTOPS_REQ]]

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget]
  [Result code from Sm_AgentApi_IsProtectedEx: -3]

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget][Sm_AgentApi_IsProtectedEx failed with error code: -3]

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget]
  [Ending SAML2 AssertionConsumer Service request processing with HTTP error 500]

  [11/01/2020][08:50:54][7048][1613772544][552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea]
  [AssertionConsumer.java][getRealmForTarget]
  [Transaction with ID: 552sd11w2dsf-6484ea31-981fbfa2-83a2cf08-22025e06-aea failed. Reason: ACS_IS_PROT_FAILED]
  
--

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2]
  [AssertionConsumer.java][getRealmForTarget]
  [Calling isProtected with resource: /myapp/login?SAML2IDPID=myotheridp.otheridp.com]

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2]
  [AssertionConsumer.java][getRealmForTarget]
  [IsProtected call to policy server for target resource realm [CHECKPOINT = SSOSAML2_ISPROTECTEDCALLTOPS_REQ]]

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2]
  [AssertionConsumer.java][getRealmForTarget][Result code from Sm_AgentApi_IsProtectedEx: -3]

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2]
  [AssertionConsumer.java][getRealmForTarget][Sm_AgentApi_IsProtectedEx failed with error code: -3]

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2]
  [AssertionConsumer.java][getRealmForTarget]
  [Ending SAML2 AssertionConsumer Service request processing with HTTP error 500]

  [11/01/2020][09:00:17][7048][1613772544][22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2][AssertionConsumer.java][getRealmForTarget]
  [Transaction with ID: 22s33ds63-84865a57-8382a29e-d8d7b9f6-dec745b0-f2 failed. Reason: ACS_IS_PROT_FAILED]

 

Resolution

 

Restart the Web Agent Option Pack when the Policy Server and the Policy Store will be available to solve this issue.