4 Replies Latest reply: Feb 3, 2011 11:36 PM by 836548 RSS

    Agent 2.2 with OpenSSO

    804089
      I have setup IIS agent 2.2 with OpenSSO 8. I occasionally get a blank page after login when I try to access the protected application. I see the following in the agent log. Any ideas on what might be wrong?
      2010-10-06 14:14:48.079 Debug 2288:18ee7b8 all: Log::pSetLevelsFromString(): setting log level for module 0 to 5, old level 1.
      2010-10-06 14:14:48.079 -1 2288:18ee7b8 all: =======================================
      2010-10-06 14:14:48.079 -1 2288:18ee7b8 all: Version: 2.2-02
      2010-10-06 14:14:48.079 -1 2288:18ee7b8 all: Build Date: Wed Nov 12 08:37:44 PST 2008
      2010-10-06 14:14:48.079 -1 2288:18ee7b8 all: Build Machine: WOOKIE
      2010-10-06 14:14:48.079 -1 2288:18ee7b8 all: =======================================
      2010-10-06 14:14:48.079 Debug 2288:18ee7b8 all: Connection::initialize() calling NSS_Initialize() with directory = "D:/Sun/Access_Manager/Agents/2.2/iis6/cert" and prefix = ""
      2010-10-06 14:14:48.079 Debug 2288:18ee7b8 all: Connection::initialize() Connection timeout wen receiving data = 0 milliseconds
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.remote.log.buffer.size, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: load_agent_properties() : Property com.sun.am.cookie.secure is set to false.
      2010-10-06 14:14:48.094 Warning 2288:18ee7b8 PolicyAgent: Invalid URL () for property (com.sun.am.policy.agents.config.errorpage.url) specified
      2010-10-06 14:14:48.094 Warning 2288:18ee7b8 PolicyAgent: Setting error_page_url to null
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.deny_on_log_failure, using default value.
      2010-10-06 14:14:48.094 Debug 2288:18ee7b8 PolicyAgent: parse_url(https://services.domain2.ca:443/amagent): Normalized URL: https://services.domain2.ca:443/amagent
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: load_agent_properties(): com.sun.am.policy.agents.config.agenturi.prefix : Value => https://services.domain2.ca:443/amagent
      2010-10-06 14:14:48.094 Debug 2288:18ee7b8 PolicyAgent: parse_url(https://services.domain2.ca/opensso/UI/Login): Normalized URL: https://services.domain2.ca:443/opensso/UI/Login
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: calling parseIPAddresses(): not_enforced_ipstr: 127.0.0.1 10.226.10.92 10.226.10.52
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: parseIPAddresses(): add ipAddr: 127.0.0.1
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: parseIPAddresses(): add ipAddr: 10.226.10.92
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: parseIPAddresses(): add ipAddr: 10.226.10.52
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: parseIPAddresses(): exit.
      2010-10-06 14:14:48.094 Debug 2288:18ee7b8 PolicyAgent: parse_url(https://services.domain2.ca:443/applicationmvc/* http://host.domain.com:80/applicationmvc/* https://services.domain2.ca/landingapp/*): Normalized URL: https://services.domain2.ca:443/applicationmvc/*
      2010-10-06 14:14:48.094 Debug 2288:18ee7b8 PolicyAgent: parse_url(http://host.domain.com:80/applicationmvc/* https://services.domain2.ca/landingapp/*): Normalized URL: http://host.domain.com:80/applicationmvc/*
      2010-10-06 14:14:48.094 Debug 2288:18ee7b8 PolicyAgent: parse_url(https://services.domain2.ca/landingapp/*): Normalized URL: https://services.domain2.ca:443/landingapp/*
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.ignore_policy_evaluation_if_notenforced, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 PolicyAgent: am_web_init(): Logout URL is .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 PolicyAgent: no cookies to be reset on logout.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 PolicyAgent: load_agent_properties(): cookie reset enabled property com.sun.am.policy.agents.config.cookie.reset.enable is false
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.ignore_server_check, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.iis.Use_Basic_Auth, using default value.
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 PolicyAgent: Default priority => DEFAULT : Actual priority => HIGH
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.iis.owa_enabled, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.iis.owa_enabled_change_protocol, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.proxy.override_host_port, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.policy.agents.config.no_child_thread_activation_delay, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.ignore.naming_service, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.ignore.preferred_naming_url, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.sso.default_session.url, using default value .
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.sso.hash_bucket.size, using default value.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.sso.hash_bucket.size, using default value.
      2010-10-06 14:14:48.094 Info 2288:18ee7b8 AM_SSO_SERVICE: SSOTokenService::SSOTokenService(): SSOTokenService notification enabled, URL = https://services.domain2.ca:443/amagent/UpdateAgentCacheServlet?shortcircuit=false.
      2010-10-06 14:14:48.094MaxDebug 2288:18ee7b8 all: No value specified for key com.sun.am.sso.max_threads, using default value.
      2010-10-06 14:14:48.094 Info 2288:191e560 ThreadPool: ::spin() : New Thread entered loop. Active threads = 0 : Work queue : 0.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 ThreadPool: ThreadPool::dispatch(): Calling PR_Lock() after this line thread_pool.cpp:186.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 ThreadPool: ThreadPool::dispatch(): Successfully dispatched the work.
      2010-10-06 14:14:49.110 Debug 2288:191e560 ThreadPool: spin() : Thread awakened: activeThreads = 1 ; maxThreads = 11 ; workQueueSize = 1
      2010-10-06 14:14:49.110 Info 2288:18ee7b8 AM_SSO_SERVICE: SSOTokenService::initialize(): dispatched hash table cleanup.
      2010-10-06 14:14:49.110 Info 2288:18ee7b8 AM_SSO_SERVICE: SSOTokenService::initialize(): SSOTokenService cache initialized.
      2010-10-06 14:14:49.110 Debug 2288:191e560 ThreadPool: ::spin() : Thread Function calling 0x1e1b650.
      2010-10-06 14:14:49.110 Info 2288:18ee7b8 AM_SSO_SERVICE: SSOTokenService::SSOTokenService(): SSOTokenService created.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyEngine: Policy engine initalized.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyEngine: policy_engine.cpp:94 In createService
      2010-10-06 14:14:49.110 Info 2288:18ee7b8 PolicyEngine: iPlanetAMWebAgentService creation attempted.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.am.hash_bucket.size, using default value.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.auth.org.name, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.certdb.password, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.auth.certificate.alias, using default value .
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.ignore.naming_service, using default value.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.ignore.preferred_naming_url, using default value.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.ordinal, using default value.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.am.userid.param.type, using default value Session.
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: Service::Service() Profile Attribute=emplid
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: Service::Service() Profile Attribute=entrydn
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: Service::Service() Profile Attribute=uid
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.agents.config.attribute.multi_value_separator, using default value |.
      2010-10-06 14:14:49.110 Info 2288:18ee7b8 ServiceEngine: Service() notification enabled, URL = https://services.domain2.ca:443/amagent/UpdateAgentCacheServlet?shortcircuit=false
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyAgent: FqdnHandler::FqdnHandler() fqdnMap size => 2
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyAgent: FqdnHandler::FqdnHandler() Fqdn Default => services.domain2.ca
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: FqdnHandler::FqdnHandler() [10.226.45.177] => {services.domain2.ca}
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: FqdnHandler::FqdnHandler() [hosttest.domain.com] => {services.domain2.ca}
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: am_web_init: Using cookie prefix HTTP_.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: am_web_init: Using cookie max-age 300.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): requestProtocolType = off
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): HEADER_Host = hosttest.domain.com
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): SERVER_PORT = 80
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): URL = /myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): PATH_INFO = /myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): SCRIPT_NAME = /myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): Reconstructed path info =
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: get_request_url(): Constructed request url = http://hosttest.domain.com:80/myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyAgent: am_web_is_notification(), https://services.domain2.ca:443/myapplicationLife/Home.aspx is not notification url https://services.domain2.ca:443/amagent/UpdateAgentCacheServlet?shortcircuit=false.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): requestMethod = GET
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): SSO token found in cookie header.
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): SSO token = AQIC5wM2LY4SfcyYx+wf/9JKLz1KP7GqoqKy62euCX9NCPM=@AAJTSQACMDE=#
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): requestClientIP = 10.226.45.41
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): status after am_map_create = success (0)
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 PolicyAgent: am_web_is_access_allowed(): processing url https://services.domain2.ca:443/myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: am_web_is_access_allowed(): client_ip 10.226.45.41 not found in client ip not enforced list
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 AM_POLICY_SERVICE: am_policy_compare_urls(): compare usePatterns=false returned 3
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: Matching https://services.domain2.ca:443/myapplicationLife/Home.aspx with access_denied_url https://services.domain2.ca/applicationmvc/Account/DOBVerify.aspx: FALSE
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 AM_POLICY_SERVICE: am_policy_compare_urls(): compare usePatterns=true returned 3
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 AM_POLICY_SERVICE: am_policy_compare_urls(): compare usePatterns=true returned 3
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 AM_POLICY_SERVICE: am_policy_compare_urls(): compare usePatterns=true returned 3
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 AM_POLICY_SERVICE: am_policy_compare_urls(): compare usePatterns=true returned 3
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: in_not_enforced_list: enforcing access control for https://services.domain2.ca:443/myapplicationLife/Home.aspx
      2010-10-06 14:14:49.110 Debug 2288:18ee7b8 PolicyAgent: set_host_ip_in_env_map: map_insert: client_ip=10.226.45.41
      2010-10-06 14:14:49.110MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.am.max_threads, using default value.
      2010-10-06 14:14:49.110 Info 2288:1920b18 ThreadPool: ::spin() : New Thread entered loop. Active threads = 0 : Work queue : 0.
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 ThreadPool: ThreadPool::dispatch(): Calling PR_Lock() after this line thread_pool.cpp:186.
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 ThreadPool: ThreadPool::dispatch(): Successfully dispatched the work.
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 ServiceEngine: Service communication with server started.
      2010-10-06 14:14:50.126 Debug 2288:1920b18 ThreadPool: spin() : Thread awakened: activeThreads = 1 ; maxThreads = 10 ; workQueueSize = 1
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.am.org.name, using default value /.
      2010-10-06 14:14:50.126 Debug 2288:1920b18 ThreadPool: ::spin() : Thread Function calling 0x1f413b8.
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 ServiceEngine: No value specified for key com.sun.am.policy.am.auth_module, using default value Application.
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 AuthService: Number of servers in service:1, 'https://services.domain2.ca/opensso/authservice'.
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 AuthService: BaseService::doRequest(): Using server: https://services.domain2.ca/opensso/authservice.
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <RequestSet vers="1.0" svcid="auth" reqid="0">
      <Request><![CDATA[<?xml version="1.0" encoding="UTF-8"?><AuthContext version="1.0">
      <Request authIdentifier="0"><NewAuthContext orgName="/"/></Request></AuthContext>]]></Request>
      </RequestSet>
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest Request line: POST /opensso/authservice HTTP/1.0
      2010-10-06 14:14:50.126 Info 2288:18ee7b8 all: Successfully completed SSL handshake.
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Cookie and Headers =Host: services.domain2.ca
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Content-Length =Content-Length: 296
      .
      2010-10-06 14:14:50.126 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Header Suffix =Accept: text/xml
      Content-Type: text/xml; charset=UTF-8
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Total chunks: 9.
      2010-10-06 14:14:50.126MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Sent 9 chunks.
      2010-10-06 14:14:50.391 Debug 2288:18ee7b8 AuthService: HTTP Status = 200 (OK)
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Reading headers.
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: Date: Wed, 06 Oct 2010 18:14:50 GMT
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: set-cookie: JSESSIONID=B0833A971A1CEB46FF22825B154CEA97; Path=/opensso
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: set-cookie: amlbcookie=01; Domain=.domain2.ca; Path=/
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: set-cookie: amlbcookie=01; Domain=.domain.com; Path=/
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: Connection: close
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: Content-Type: text/plain
      2010-10-06 14:14:50.391 Debug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): No content length in response.
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 all: Connection::waitForReply(): returns with status success.
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Completed processing the response with status: success
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <ResponseSet vers="1.0" svcid="auth" reqid="0">
      <Response><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><LoginStatus status="in_progress"></LoginStatus></Response></AuthContext>]]></Response>
      </ResponseSet>
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><LoginStatus status="in_progress"></LoginStatus></Response></AuthContext>
      2010-10-06 14:14:50.391 Debug 2288:18ee7b8 AuthService: AuthService::processLoginStatus() Login is in progress.
      2010-10-06 14:14:50.391 Info 2288:18ee7b8 AuthService: AuthService::processLoginStatus() Auth Identifier =AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#
      2010-10-06 14:14:50.391 Debug 2288:18ee7b8 AuthService: BaseService::doRequest(): Using server: https://services.domain2.ca/opensso/authservice.
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <RequestSet vers="1.0" svcid="auth" reqid="1">
      <Request><![CDATA[<?xml version="1.0" encoding="UTF-8"?><AuthContext version="1.0">
      <Request authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><Login><IndexTypeNamePair indexType="moduleInstance"><IndexName>Application</IndexName></IndexTypeNamePair></Login></Request></AuthContext>]]></Request>
      </RequestSet>
      2010-10-06 14:14:50.391MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest Request line: POST /opensso/authservice HTTP/1.0
      2010-10-06 14:14:50.407 Info 2288:18ee7b8 all: Successfully completed SSL handshake.
      2010-10-06 14:14:50.407 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Cookie and Headers =Host: services.domain2.ca
      Cookie: JSESSIONID=B0833A971A1CEB46FF22825B154CEA97;amlbcookie=01;amlbcookie=01
      2010-10-06 14:14:50.407 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Content-Length =Content-Length: 443
      .
      2010-10-06 14:14:50.407 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Header Suffix =Accept: text/xml
      Content-Type: text/xml; charset=UTF-8
      2010-10-06 14:14:50.407MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Total chunks: 14.
      2010-10-06 14:14:50.407MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Sent 14 chunks.
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: HTTP Status = 200 (OK)
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Reading headers.
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: Date: Wed, 06 Oct 2010 18:14:50 GMT
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: Connection: close
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: Content-Type: text/plain
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): No content length in response.
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 all: Connection::waitForReply(): returns with status success.
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Completed processing the response with status: success
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <ResponseSet vers="1.0" svcid="auth" reqid="1">
      <Response><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><GetRequirements><Callbacks length="2"><NameCallback><Prompt>Enter application name.</Prompt></NameCallback><PasswordCallback echoPassword="true"><Prompt>Enter secret string.</Prompt></PasswordCallback></Callbacks></GetRequirements></Response></AuthContext>]]></Response>
      </ResponseSet>
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><GetRequirements><Callbacks length="2"><NameCallback><Prompt>Enter application name.</Prompt></NameCallback><PasswordCallback echoPassword="true"><Prompt>Enter secret string.</Prompt></PasswordCallback></Callbacks></GetRequirements></Response></AuthContext>
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 ServiceEngine: Service::do_agent_auth_login(): Setting password callback.
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 ServiceEngine: Service::do_agent_auth_login(): Setting name callback to 'UrlAccessAgent'.
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: BaseService::doRequest(): Using server: https://services.domain2.ca/opensso/authservice.
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <RequestSet vers="1.0" svcid="auth" reqid="2">
      <Request><![CDATA[<?xml version="1.0" encoding="UTF-8"?><AuthContext version="1.0">
      <Request authIdentifier="AQIC5wM2LY4SfczArJpBFrSCg2eHw/b2mrG39uCvmA+bzdI=@AAJTSQACMDE=#"><SubmitRequirements><Callbacks length="2"><NameCallback><Prompt>Enter application name.</Prompt><Value>UrlAccessAgent</Value></NameCallback><PasswordCallback echoPassword="true"><Prompt>Enter secret string.</Prompt><Value><secure data></Value></PasswordCallback></Callbacks></SubmitRequirements></Request></AuthContext>]]></Request>
      </RequestSet>
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest Request line: POST /opensso/authservice HTTP/1.0
      2010-10-06 14:14:50.673 Info 2288:18ee7b8 all: Successfully completed SSL handshake.
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Cookie and Headers =Host: services.domain2.ca
      Cookie: JSESSIONID=B0833A971A1CEB46FF22825B154CEA97;amlbcookie=01;amlbcookie=01
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Content-Length =Content-Length: 618
      .
      2010-10-06 14:14:50.673 Debug 2288:18ee7b8 AuthService: BaseService::sendRequest Header Suffix =Accept: text/xml
      Content-Type: text/xml; charset=UTF-8
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Total chunks: 30.
      2010-10-06 14:14:50.673MaxDebug 2288:18ee7b8 AuthService: BaseService::sendRequest(): Sent 30 chunks.
      2010-10-06 14:14:50.798 Debug 2288:18ee7b8 AuthService: HTTP Status = 502 (Proxy Error)
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Reading headers.
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Date: Wed, 06 Oct 2010 18:14:46 GMT
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Connection: close
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Content-Type: text/html; charset=iso-8859-1
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Reading body content of length: 70904979434504610
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 all: Connection::waitForReply(): returns with status success.
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: Http::Response::readAndParse(): Completed processing the response with status: success
      2010-10-06 14:14:50.798MaxDebug 2288:18ee7b8 AuthService: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
      <html><head>
      <title>502 Proxy Error</title>
      </head><body>
      <h1>Proxy Error</h1>
      <p>The proxy server received an invalid response from an upstream server.
      The proxy server could not handle the request <em>POST /opensso/authservice</em>.<p>
      Reason: <strong>Error reading from remote server</strong></p></p>
      </body></html>
      2010-10-06 14:14:50.798 Warning 2288:18ee7b8 AuthService: BaseService::doHttpPost() failed, HTTP error = 502
      2010-10-06 14:14:50.798 Error 2288:18ee7b8 PolicyEngine: am_policy_evaluate: InternalException in AuthService::submitRequirements() with error message:Error sending client submitted requirements to server. and code:21
      2010-10-06 14:14:50.798 Warning 2288:18ee7b8 PolicyAgent: am_web_is_access_allowed()(https://services.domain2.ca:443/myapplicationLife/Home.aspx, GET) denying access: status = HTTP error
      2010-10-06 14:14:50.798 Debug 2288:18ee7b8 PolicyAgent: am_web_is_access_allowed(): Successfully logged to remote server for GET action by user unknown user to resource https://services.domain2.ca:443/myapplicationLife/Home.aspx.
      2010-10-06 14:14:50.798 Info 2288:18ee7b8 PolicyAgent: am_web_is_access_allowed()(https://services.domain2.ca:443/myapplicationLife/Home.aspx, GET) returning status: HTTP error.
      2010-10-06 14:14:50.798 Debug 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): status after am_web_is_access_allowed = HTTP error (21)
      2010-10-06 14:14:50.798 Error 2288:18ee7b8 PolicyAgent: HttpExtensionProc(): status: HTTP error (21)
        • 1. Re: Agent 2.2 with OpenSSO
          handat
          Two things:

          1. You can configure an error page in the agent so when you get an error you get to see the error page instead of a blank page.

          2. It appears to be a problem with your proxy server. Does the agent or opensso go through a proxy server or a reverse proxy server? It looks like it is causing a problem and not the agent or opensso themselves. Your proxy server may have a client connection limit which has been reached by the agent/opensso.
          • 2. Re: Agent 2.2 with OpenSSO
            804089
            There is only a firewall in front of opensso. There is a reverse proxy server configured for the agent. I do not have access to review that configuration...
            Is there a reason opensso may become unavailable to the agent server in spite of being online? I have successfully used the admin console on OpenSSO when the agent logs these errors.
            • 3. Re: Agent 2.2 with OpenSSO
              handat
              You will need to get access to that reverse proxy and check its logs and configs because it is the root of your problems.
              • 4. Re: Agent 2.2 with OpenSSO
                836548
                If reverse proxy is done for both OpenSSO and agent url, the you have to mention the reverse proxy url while createing J2EE agent in OpenSSO. And make the sure the agent username/password is correct in AMConfig.properties file.