Layer 7 Access Management

Expand all | Collapse all

Policy Server crashing with ASA restart

Jump to Best Answer
  • 1.  Policy Server crashing with ASA restart

    Posted 09-01-2016 04:33 PM

    Hello friends, Getting staright to the point.

    Policy Server: R1251FullVersion=12.51.1.972 (Cant be upgraded to 12.52 because of internal reasons)
    ASA: PRODUCT_VERSION=12.0 , PRODUCT_NAME=eTrust SiteMinder Agent for IBM WebSphere, PRODUCT_UPDATE=0200 , PRODUCT_LABEL=210.

    Both of them are running on Linux. Have been running fine for few years, until this happened today.

    Policy Store and Key store are running in different AD LDS Stores.

    While restarting application server(ASA) our Policy Server crashed, came back up by itself. ASA failed to start properly as it could not contact Policy Server. We restarted ASA again which crashed the policy server. When PS crashes and comes back up automatically, it comes back cleanly. There are no errors conencting to Policy store. It is able to communicate with other agents absolutely fine, however, during ASA start PS fails with 'Cant Connect to LDAP' error. It happened twice.

    Finally as a last resort and without any good reason I tried restarting policy server and then restart ASA again, fortunately everything came up normally. However it leaves me worried very much. I wonder if there is a difference between policy server crash and policy server restart using stop-all/start-all

    Could anyone suggest what could be happening here? did my PS try to open a new connection to the policy store and failed to create a new connection? is there something wrong with this particular thread? This very same thread is used for other transactions from webagent(not TAI) on the same box few seconds ago. Even if it, why would it fail twice?
    Appreciate any insight. I dont want to create a ticket as it would lead me to nowhere.

    smexec.log:

    Thu Sep 1 10:10:16 2016: Enter: HandleSignals(BLOCK_ALL)
    Thu Sep 1 10:10:16 2016: Enter: HandleSignals(UNBLOCK_ALL)
    Thu Sep 1 10:10:16 2016: Service smpolicysrv died - restart #0, pid: 11287

    Thu Sep 1 10:10:16 2016: Enter: HandleSignals(UNBLOCK_ALL)
    Thu Sep 1 11:25:53 2016: Enter: HandleSignals(BLOCK_ALL)
    Thu Sep 1 11:25:53 2016: Enter: HandleSignals(UNBLOCK_ALL)
    Thu Sep 1 11:25:53 2016: Service smpolicysrv died - restart #0, pid: 11913

     

    SMTRACE:
    [09/01/2016][10:10:12.187][10:10:12][15310][4002368368][CServer.cpp:3152][CAgentAcceptHandler::HandleInput][][][][][][][][][][][][][][][][][][][][][Received connection request]
    [09/01/2016][10:10:12.200][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Enqueuing a High Priority Message, from IP ::ffff: IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 1]
    [09/01/2016][10:10:12.200][10:10:12][15310][4138736496][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Dequeuing a High Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 0]
    [09/01/2016][10:10:12.200][10:10:12][15310][4138736496][CServer.cpp:2058][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][New connection attempt from client host]
    [09/01/2016][10:10:12.200][10:10:12][15310][4138736496][CServer.cpp:1842][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Getting current secret for the Agent portaltai8.5]
    [09/01/2016][10:10:12.200][10:10:12][15310][4138736496][CServer.cpp:1917][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Marking the shared secret as used for the Agent portaltai8.5]
    [09/01/2016][10:10:12.203][10:10:12][15310][4138736496][CServer.cpp:2073][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Starting new client session #659]
    [09/01/2016][10:10:12.206][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 1]
    [09/01/2016][10:10:12.206][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 0]
    [09/01/2016][10:10:12.206][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.206][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][104][][][][][][][][Leave function CServer::ProcessRequest]


    [09/01/2016][10:10:12.209][10:10:12][15310][4107266928][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19815][][][][][Dequeuing a High Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19815. Current count is 0]
    [09/01/2016][10:10:12.209][10:10:12][15310][4107266928][CServer.cpp:2058][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19815][][][][][New connection attempt from client host]
    [09/01/2016][10:10:12.209][10:10:12][15310][4107266928][CServer.cpp:1842][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Getting current secret for the Agent portaltai8.5]
    [09/01/2016][10:10:12.209][10:10:12][15310][4107266928][CServer.cpp:1917][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Marking the shared secret as used for the Agent portaltai8.5]
    [09/01/2016][10:10:12.210][10:10:12][15310][4107266928][CServer.cpp:2073][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19815][][][][][Starting new client session #660]
    [09/01/2016][10:10:12.210][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19815][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19815. Current count is 1]
    [09/01/2016][10:10:12.210][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19815][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19815. Current count is 0]
    [09/01/2016][10:10:12.210][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.210][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][104][][][][][][][][Leave function CServer::ProcessRequest]
    [09/01/2016][10:10:12.216][10:10:12][15310][

    [CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 1]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19813][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19813. Current count is 0]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][SmAuthUser.cpp:1372][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Enter function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][SmAuthUser.cpp:1417][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Leave function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][Sm_Az_Message.cpp:154][CSm_Az_Message::ProcessMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Az_Message::ProcessMessage]

    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s659/r2][][][][][][][][][][][][][][][][][][][host][Receive request attribute 143, data size is 4]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s659/r2][][][][][][][][][][][][][][][][][][][pld1][Receive request attribute 144, data size is 4]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][Sm_Az_Message.cpp:205][CSm_Az_Message::ProcessMessage][s659/r2][][][][][][][][][][][][][][][][][][][portaltai8.5][** Received agent request.]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][Sm_Az_Message.cpp:387][CSm_Az_Message::AnalyzeAzMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Az_Message::AnalyzeAzMessage]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][Sm_Az_Message.cpp:395][CSm_Az_Message::AnalyzeAzMessage][][][][][][][][][][][][][true][][][][][][][][Leave function CSm_Az_Message::AnalyzeAzMessage]
    [09/01/2016][10:10:12.216][10:10:12][15310][4012858224][GetConfig.cpp:81][CSm_Az_Message::GetConfig][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Az_Message::GetConfig]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][GetConfig.cpp:218][CSm_Az_Message::GetConfig][][][][][][][][][][][][][][][][][][][][][Request Timeout Value found in Host config object.]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][GetConfig.cpp:225][CSm_Az_Message::GetConfig][][portaltai8.5][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][][][][][][Overwriting Request timeout for Agent (portaltai8.5_::ffff:IP_ADDRESS_OF_ASA(TAI)) to 60]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:406][CSm_Az_Message::SendReply][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Az_Message::SendReply]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][MaxSocketsPerPort=600][Send response attribute 144, data size is 21]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][PolicyServer=HOSTNAME_OF_THE_POLICYSERVER,44441,44442,44443][Send response attribute 144, data size is 59]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][MinSocketsPerPort=2][Send response attribute 144, data size is 19]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][RequestTimeout=60][Send response attribute 144, data size is 17]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][NewSocketStep=2][Send response attribute 144, data size is 15]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][RequestTimeout=60][Send response attribute 144, data size is 17]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][NewSocketStep=2][Send response attribute 144, data size is 15]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][EnableFailOver=YES][Send response attribute 144, data size is 18]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][][Send response attribute 146, data size is 0]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:825][CSm_Az_Message::FormatAttribute][s659/r2][][][][][][][][][][][][][][][][][][][][Send response attribute 147, data size is 0]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:595][CSm_Az_Message::ProcessMessage][s659/r2][][][][][][][][][][][][][][][][][][][][** Status: GetConfig. ]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:599][CSm_Az_Message::SendReply][][][][][][][][][][][][][][][][][][][][][Leave function CSm_Az_Message::SendReply]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][GetConfig.cpp:273][CSm_Az_Message::GetConfig][][][][][][][][][][][][][ok][][][][][][][][Leave function CSm_Az_Message::GetConfig]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][Sm_Az_Message.cpp:377][CSm_Az_Message::ProcessMessage][][][][][][][][][][][][][809][][][][][][][][Leave function CSm_Az_Message::ProcessMessage]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][SmAuthUser.cpp:1422][CSmAuthUser::~CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Enter function CSmAuthUser::~CSmAuthUser]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][SmAuthUser.cpp:1474][CSmAuthUser::~CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Leave function CSmAuthUser::~CSmAuthUser]
    [09/01/2016][10:10:12.217][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][809][][][][][][][][Leave function CServer::ProcessRequest]
    [09/01/2016][10:10:12.219][10:10:12][15310][4002368368][CServer.cpp:3152][CAgentAcceptHandler::HandleInput][][][][][][][][][][][][][][][][][][][][][Received connection request]
    [09/01/2016][10:10:12.220][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Enqueuing a High Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 1]
    [09/01/2016][10:10:12.220][10:10:12][15310][4128246640][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Dequeuing a High Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 0]
    [09/01/2016][10:10:12.220][10:10:12][15310][4128246640][CServer.cpp:2058][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][New connection attempt from client host]
    [09/01/2016][10:10:12.220][10:10:12][15310][4128246640][CServer.cpp:1842][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Getting current secret for the Agent portaltai8.5]
    [09/01/2016][10:10:12.220][10:10:12][15310][4128246640][CServer.cpp:1917][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Marking the shared secret as used for the Agent portaltai8.5]
    [09/01/2016][10:10:12.221][10:10:12][15310][4128246640][CServer.cpp:2073][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Starting new client session #661]
    [09/01/2016][10:10:12.222][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 1]
    [09/01/2016][10:10:12.222][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 0]
    [09/01/2016][10:10:12.222][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.222][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][104][][][][][][][][Leave function CServer::ProcessRequest]
    [09/01/2016][10:10:12.223][10:10:12][15310][4002368368][CServer.cpp:3152][CAgentAcceptHandler::HandleInput][][][][][][][][][][][][][][][][][][][][][Received connection request]
    [09/01/2016][10:10:12.224][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Enqueuing a High Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19819. Current count is 1]
    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Dequeuing a High Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19819. Current count is 0]
    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:2058][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][New connection attempt from client host]



    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Dequeuing a High Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19819. Current count is 0]
    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:2058][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][New connection attempt from client host]
    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:1842][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Getting current secret for the Agent portaltai8.5]
    [09/01/2016][10:10:12.224][10:10:12][15310][4096777072][CServer.cpp:1917][GetSecretFunc][][][][][][][][][][][][][][][][][][][][][Marking the shared secret as used for the Agent portaltai8.5]
    [09/01/2016][10:10:12.225][10:10:12][15310][4096777072][CServer.cpp:2073][CAgentMessageHandler::DoWork][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Starting new client session #662]
    [09/01/2016][10:10:12.225][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19819. Current count is 1]
    [09/01/2016][10:10:12.225][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19819][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19819. Current count is 0]
    [09/01/2016][10:10:12.226][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.226][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][104][][][][][][][][Leave function CServer::ProcessRequest]
    [09/01/2016][10:10:12.228][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 1]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 0]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmAuthUser.cpp:1372][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Enter function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmAuthUser.cpp:1417][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Leave function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][Sm_Auth_Message.cpp:151][CSm_Auth_Message::ProcessMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::ProcessMessage]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][AgentAuth.cpp:36][CSm_Auth_Message::ProcessAgentMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::ProcessAgentMessage]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][0][Receive request attribute 199, data size is 1]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][1472742612][Receive request attribute 159, data size is 10]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][0][Receive request attribute 165, data size is 1]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][128][Receive request attribute 166, data size is 3]
    [09/01/2016][10:10:12.228][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][3][Receive request attribute 148, data size is 1]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r2][portaltai8.5][][][][][][][][][][][][][][][][][][PRODUCT_VERSION=12.0 , PRODUCT_NAME=eTrust SiteMinder Agent for IBM WebSphere, PRODUCT_UPDATE=0200 , PRODUCT_LABEL=210.][Receive request attribute 149, data size is 119]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][AgentAuth.cpp:312][CSm_Auth_Message::AnalyzeAgentAuthMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::AnalyzeAgentAuthMessage]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][AgentAuth.cpp:357][CSm_Auth_Message::AnalyzeAgentAuthMessage][][][][][][][][][][][][][true][][][][][][][][Leave function CSm_Auth_Message::AnalyzeAgentAuthMessage]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][DoManagement.cpp:462][CSm_Auth_Message::DoManagement][][][][][][][][][][][][][][][][][][][][PRODUCT_VERSION=12.0 , PRODUCT_NAME=eTrust SiteMinder Agent for IBM WebSphere, PRODUCT_UPDATE=0200 , PRODUCT_LABEL=210.,UTC=1472742612,TZ=0,Crypto=128][AgentTli SetAgentInfo command.]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][Sm_Auth_Message.cpp:3409][CSm_Auth_Message::SendReply][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::SendReply]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][DoManagement.cpp:462][CSm_Auth_Message::DoManagement][][][][][][][][][][][][][][][][][][][][PRODUCT_VERSION=12.0 , PRODUCT_NAME=eTrust SiteMinder Agent for IBM WebSphere, PRODUCT_UPDATE=0200 , PRODUCT_LABEL=210.,UTC=1472742612,TZ=0,Crypto=128][AgentTli SetAgentInfo command.]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][Sm_Auth_Message.cpp:3409][CSm_Auth_Message::SendReply][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::SendReply]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][Sm_Auth_Message.cpp:3734][CSm_Auth_Message::SendReply][][][][][][][][][][][][][][][][][][][][][Leave function CSm_Auth_Message::SendReply]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][AgentAuth.cpp:303][CSm_Auth_Message::ProcessAgentMessage][][][][][][][][][][][][][20][][][][][][][][Leave function CSm_Auth_Message::ProcessAgentMessage]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][Sm_Auth_Message.cpp:164][CSm_Auth_Message::ProcessMessage][][][][][][][][][][][][][20][][][][][][][][Leave function CSm_Auth_Message::ProcessMessage]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][SmAuthUser.cpp:1422][CSmAuthUser::~CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Enter function CSmAuthUser::~CSmAuthUser]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][SmAuthUser.cpp:1474][CSmAuthUser::~CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Leave function CSmAuthUser::~CSmAuthUser]
    [09/01/2016][10:10:12.229][10:10:12][15310][4012858224][CServer.cpp:5838][CServer::ProcessRequest][][][][][][][][][][][][][20][][][][][][][][Leave function CServer::ProcessRequest]
    [09/01/2016][10:10:12.230][10:10:12][15310][4002368368][CServer.cpp:1801][CAgentMessageHandler::HandleInput][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Enqueuing a Normal Priority Message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 1]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][CServer.cpp:1382][ThreadPool::Run][][][][][][][][][][][][][][][::ffff:IP_ADDRESS_OF_ASA(TAI)][19817][][][][][Dequeuing a Normal Priority message, from IP ::ffff:IP_ADDRESS_OF_ASA(TAI) with Port No 19817. Current count is 0]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][CServer.cpp:5662][CServer::ProcessRequest][][][][][][][][][][][][][][][][][][][][][Enter function CServer::ProcessRequest]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmAuthUser.cpp:1372][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Enter function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmAuthUser.cpp:1417][CSmAuthUser::CSmAuthUser][][][][][][][][][][][][][][][][][][][][][Leave function CSmAuthUser::CSmAuthUser]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][Sm_Auth_Message.cpp:151][CSm_Auth_Message::ProcessMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::ProcessMessage]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][AgentAuth.cpp:36][CSm_Auth_Message::ProcessAgentMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::ProcessAgentMessage]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][0][Receive request attribute 199, data size is 1]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][1472742612][Receive request attribute 159, data size is 10]
    [09/01/2016][10:10:12.230][10:10:12][15310][4 075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][0][Receive request attribute 165, data size is 1]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][128][Receive request attribute 166, data size is 3]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][1][Receive request attribute 148, data size is 1]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][SmMessage.cpp:513][CSmMessage::ParseAgentMessage][s661/r3][portaltai8.5][][][][][][][][][][][][][][][][][][][Receive request attribute 149, data size is 0]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][AgentAuth.cpp:312][CSm_Auth_Message::AnalyzeAgentAuthMessage][][][][][][][][][][][][][][][][][][][][][Enter function CSm_Auth_Message::AnalyzeAgentAuthMessage]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][AgentAuth.cpp:357][CSm_Auth_Message::AnalyzeAgentAuthMessage][][][][][][][][][][][][][true][][][][][][][][Leave function CSm_Auth_Message::AnalyzeAgentAuthMessage]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][smldaputils.cpp:1209][SmSearchLDAP][][][][][][][][][][][][][][][][][][][Handle='0x9b1a640', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=Company.com', Scope=1, Filter='(&(smAgentKeyOID4=1b-000bd9c6-be45-17bc-be3c-80740a98a05e)(objectcategory=smAgentKey4))', attrsonly=0][][Start of call ldap_search_st:Search LDAP.]
    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][smldaputils.cpp:1215][SmSearchLDAP][][][][][][][][][][][][][81][Can't contact LDAP server][][][][][Handle='0x9b1a640', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=Company.com', Scope=1, Filter='(&(smAgentKeyOID4=1b-000bd9c6-be45-17bc-be3c-80740a98a05e)(objectcategory=smAgentKey4))', attrsonly=0][][Return from call ldap_search_st]



  • 2.  Re: Policy Server crashing with ASA restart
    Best Answer

    Posted 09-02-2016 03:03 AM

    Hi SamWalker,

     

    The problem is that the Policy Server cannot reach the
    Key Store, to get the Agent keys and send them to the
    ASA Agent. Without these keys, the ASA Agent cannot
    work.

     

    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][smldaputils.cpp:1209]
    [SmSearchLDAP][][][][][][][][][][][][][][][][][][][Handle='0x9b1a640',
    Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=Company.com', Scope=1,
    Filter='(&(smAgentKeyOID4=1b-000bd9c6-be45-17bc-be3c-80740a98a05e)
    (objectcategory=smAgentKey4))', attrsonly=0][][Start of call ldap_search_st:Search LDAP.]

     

    [09/01/2016][10:10:12.230][10:10:12][15310][4075797360][smldaputils.cpp:1215]
    [SmSearchLDAP][][][][][][][][][][][][][81][Can't contact LDAP server][][][][]
    [Handle='0x9b1a640', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=Company.com',
    Scope=1, Filter='(&(smAgentKeyOID4=1b-000bd9c6-be45-17bc-be3c-80740a98a05e)
    (objectcategory=smAgentKey4))', attrsonly=0][][Return from call ldap_search_st]

     

    But if the Key Store isn't available, the Policy Server should report
    an error an not crash. Indeed, when I look into the readme for Policy
    Server 12.51CR08, I find some fixes that are near from what you describe.

     

    12.51CR08

     

    DE103154 Policy Server crashes during LDAP failover.


    DE106181 Policy Server terminates abruptly when policy store
      connection is lost.


    150154 When the key store is separate and multiple
       requests come from web agents to Policy Server,
       some agents fail to get agent keys with the
       following error message in the smps log:
       "Policy store failed operation 'MultipleSearch'
       for object type 'AgentKey'"


    120472 Policy Server terminates abnormally and does not
       recover when LDAP Directory Server hangs due to
       network connectivity issues.


    183017,183445 Policy Server terminates abruptly when the primary policy store in the failover configuration stops.

     

    http://downloads.ca.com/akdlm/CAproducts/SiteMinder/SMPLC/PolicyServer/12.51/CRs/cr08/ps-12.51-cr08-readme.txt

     

    You might consider to upgrade the Policy Server to the CR08.

     

    Also insure on the Policy Server OS that the /dev/random is symlinked to the /dev/urandom, or run rngd deamon.

     

    Hope that helps,

     

    Best Regards,
    Patrick



  • 3.  Re: Policy Server crashing with ASA restart

    Posted 09-02-2016 10:49 AM

    Thank You, Patrick. Appreciate the detailed insight. I will try to upgrade and hopefully it wont break anything.

     

    Can you confirm if the changes of this patch are limited to files on the physical policy server or will the Policy/key store be updated as part of this change?



  • 4.  Re: Policy Server crashing with ASA restart

    Posted 09-02-2016 02:32 PM

    Hi Anil,

     

    In most cases there are no changes to the policy store across CR. However, this is not necessarily true always.

     

    The best way to validate if the policy store needs upgrade is to compare if there is any changes in the .xdd files (SmMaster.xdd/SmObjects.xdd etc) between two verions.

     

    You will also need to compare if there are any changes in the default base policy objects (SmPolicy.xml) as well.

     

    Then, depending upon whether there are any differences in these files or not , you can make decisions whether or not the policy store needs upgrading.

     

    Regards,

     

    Ujwol Shrestha



  • 5.  Re: Policy Server crashing with ASA restart

    Posted 09-02-2016 10:59 AM

    Hi,

     

    Applying the CR will only affect physical policy server. You don't have to configure it over.

     

    Best Regards,

    Patrick



  • 6.  Re: Policy Server crashing with ASA restart

    Posted 09-02-2016 02:25 PM

    Hi Anil,

     

    So have you configured key store?

    Are you able to perform test connection from smconsole?

    Is the key store same as policy store?

    Are you able to perfrom key store export?

    smkeyexport -okeys.txt -dsiteminder -w<password> -c ?

     

    Do you see the smAgentKeyOID4 object that Policy server is trying to search for in the key export file?

     

    Regards,

    Ujwol Shrestha



  • 7.  Re: Policy Server crashing with ASA restart

    Posted 09-02-2016 05:06 PM

    Yes , I do have a seperate key store now as I have to co exist my r1251 and R1252 with the same key store.

     

    Both Policy store and Key store are running same physical server but on different instances(port numbers), with their own schema and services etc.

     

    I can export the keys to text file and I do see that missing key in that file. 

     

    objectclass: AgentKey
    Oid: 1b-000bd9c6-be45-17bc-be3c-80740a98a05e
    KeyMarker: 4
    Key: {RC2}IeSitpat3je6wngI/ufCwt7zz 

     

    What does the key marker: 4 indicate? The other 3 keys have 1,2,3  as markers.

     

    Are these keys change(or supposed to change) each time I restart my policy server or they are constant through out the life of Policy Server installation?  How often does policy server tries to send cookies to their webagents? Is it only during agent start up or during the processing as well?



  • 8.  Re: Policy Server crashing with ASA restart

    Posted 09-04-2016 10:19 PM

    You asked -" What does the key marker: 4 indicate? The other 3 keys have 1,2,3  as markers."

     

    Ujwol ->

    There should be only one set of agent keys comprising of 4 keys as :

    KEY_UPDATE_PERSISTENT

    KEY_UPDATE_LAST

    KEY_UPDATE_CURRENT

    KEY_UPDATE_NEXT

     

    The KeyMarker 1 to 4 indicates the type of the keys as above, but I am not sure which one is which.

     

    You asked -"Are these keys change(or supposed to change) each time I restart my policy server or they are constant through out the life of Policy Server installation?  How often does policy server tries to send cookies to their webagents? Is it only during agent start up or during the processing as well?"

     

    Ujwol -> Unless you have configured "dynamic agent key" rollover, the agent keys are constant/static.

    Policy server doesn't send "cookies" to the web agent. I guess you mean to say, the agent keys.

    It's not policy server who send the agent keys to the policy server, its the other way round, web agent regularly poll policy server to check if the agent keys  have changed. It does this once during the agent startup and then at regular interval as determined by PSPollInterval ACO parameter, the default is 30 seconds.

     

    Change How Often an Agent Checks for Policy or Key Updates - CA Single Sign-On - 12.52 SP1 - CA Technologies Documentati… 

    Change How Often an Agent Checks for Policy or Key Updates

    Last update January 9, 2015

    The Web Agent polls the Policy Server at regular intervals to check for the following items:

    • Updated management information
    • Updated policies
    • Dynamically updated agent keys

    Change this interval according to your needs with the following parameter:

    PSPollInterval

    Specifies how often (in seconds) the Web Agent contacts the Policy Server to retrieve information about policy changes or dynamically updated keys. Higher numbers (longer intervals) decrease network traffic. Lower numbers (shorter intervals) increase network traffic.

    Default: 30

    Limit: 1

    To change how often a Web Agent checks the Policy Server for updates, change the number of seconds in the PSPollInterval parameter.

    Important! Increasing the PSPollInterval parameter also affects how quickly the Agents enforce CA Single Sign-On policy changes. For example, suppose you change a Policy to revoke access for a terminated employee at 10:30, and your PSPollInterval parameter has a value of 3600 (the number of seconds in an hour). The Web Agents would not enforce the changed policy until as late as 11:30.


  • 9.  Re: Policy Server crashing with ASA restart

    Posted 09-06-2016 09:24 PM

    Thank Ujwol, That is helpful. I guess I should leave this topic although I have a bunch of questions since it is a bug in the product. Both Ujwol and Patrick, Thank You so much. Keep up the good work.