UC Collabing

Learning Never Ends!!

How to troubleshoot “Error while processing SAML Response”?

by · Published · Updated

Troubleshooting “Error while processing SAML Response” on your SSO enabled CUCM/CUC/CUPS/UCCX

You might have enabled CUCM with SSO and you might hit an SSO error on your CUCM when trying to login. No matter whether you use Firefox or Internet Explorer, the error keeps on appearing.

uccollabing.com

One thing to verify that time between the CUCM and IdP (Microsoft ADFS server) is in sync. You can download the logs from CUCM using RTMT and analyse if there is any issues in the time.  In order to do that, you can set the SSO trace to debug on your CUCM Publisher. To do this, following the below steps:

Reproducing the Error 

  1.  Launch Internet Explorer and enter CUCM FQDN and login via SSO
  2. Notice the time when you encounter the error

Setting up SAML Trace to Debug

  1.  Login to CUCM Publisher
  2. Enter the command “set samltrace level debug”

Collecting logs from RTMT

  1.  Launch RTMT and enter the Call Manager IP Address and credentials.
  2. Navigate to Trace & Log Central.
  3. Click on Collect Files.
  4. Click on Next (Do not select any option).uccollabing.com
  5. Checkbox “Cisco SSO” on your Call Manager Publisher.
  6. Click on Nextuccollabing.com
  7. Select the time range (when you did try to reproduce the issue) and download the file in your Desktop.
  8. Click on Finish

uccollabing.com

 

Reading the logs

  1. Launch your favourite notepad editor, in our case we are using Notepad++
  2. Open the logs in Notepad++uccollabing.com
  3.  Search for the logs as per the time when you tried to reproduce the issue. In our case we tried to reproduce the issue around 14:06.
  4.  If you notice around 2022-01-16 14:06:04,238 (time in IST) we initiated the connection and at the same time  2022-01-16T08:36:04Z (Time in UTC) SAML assertion was issued. It does not appear to show up any issue.2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger – SPSSOFederate: AuthnRequest:<samlp:AuthnRequest xmlns:samlp=”urn:oasis:names:tc:SAML:2.0:protocol” ID=”s23dc6703cb922c759eb5de29facfcc2870c262517″ Version=”2.0″ IssueInstant=”2022-01-16T08:36:04Z” Destination=”https://uccinwinad.uccollabing.com/adfs/ls/” ForceAuthn=”false” IsPassive=”false” ProtocolBinding=”urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST” AssertionConsumerServiceURL=”https://uccincucma.uccollabing.com:8443/ssosp/saml/SSO/alias/uccincucma.uccollabing.com”> 
    2022-01-16 14:06:04,237 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - getAttributeValueFromSSOConfig: values=null
2022-01-16 14:06:04,237 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - SAML2Utils.getSPAdapterClass: get SPAdapter class null
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - SPSSOFederate: AuthnRequest:<samlp:AuthnRequest  xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
ID="s23dc6703cb922c759eb5de29facfcc2870c262517" Version="2.0" IssueInstant="2022-01-16T08:36:04Z" Destination="https://uccinwinad.uccollabing.com/adfs/ls/" ForceAuthn="false" IsPassive="false" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" AssertionConsumerServiceURL="https://uccincucma.uccollabing.com:8443/ssosp/saml/SSO/alias/uccincucma.uccollabing.com">
<saml:Issuer xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">uccincucma.uccollabing.com</saml:Issuer>
<samlp:NameIDPolicy  xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" SPNameQualifier="uccincucma.uccollabing.com" AllowCreate="true"></samlp:NameIDPolicy>
</samlp:AuthnRequest>
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - PrefixResourceName:initialize(): delimiter = / wildcard = * oneLevelWildcard = -*- case = null
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - wildcardEmbedded,oneLevelWildcardEmbeddedtrue,false
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - SAML2MetaCache.getEntityConfig: cacheKey = ///uccincucma.uccollabing.com, found = true
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - SAML2MetaManager.getEntityConfig: got entity config from SAML2MetaCache: uccincucma.uccollabing.com
2022-01-16 14:06:04,238 DEBUG [http-bio-443-exec-5] fappend.SamlLogger - GOT_ENTITY_CONFIG
{uccincucma.uccollabing.com}

     

  5. Then you further dig into the logs, it will give you error stating that: (Missed to show this in the demo video)2022-01-16 14:06:11,187 ERROR [http-bio-443-exec-5] authentication.SAMLAuthenticator – Error while processing saml responseInvalid SAML Response. SAMLResponse is outside the validity window. com.sun.identity.saml2.common.SAML2Exception: Invalid SAML Response. SAMLResponse is outside the validity window. 
    2022-01-16 14:06:11,187 DEBUG [http-bio-443-exec-5] authentication.SAMLAuthenticator - SAML Authenticator:ProcessResponse. About to validate time
2022-01-16 14:06:11,187 DEBUG [http-bio-443-exec-5] authentication.SAMLAuthenticator - Time Valid?:false
2022-01-16 14:06:11,187 ERROR [http-bio-443-exec-5] authentication.SAMLAuthenticator - Failed validation for conditions tag. Throwing exception.
2022-01-16 14:06:11,187 ERROR [http-bio-443-exec-5] authentication.SAMLAuthenticator - Error while processing saml responseInvalid SAML Response. SAMLResponse is outside the validity window.
com.sun.identity.saml2.common.SAML2Exception: Invalid SAML Response. SAMLResponse is outside the validity window.
    at com.cisco.cpi.sso.saml.sp.security.authentication.SAMLAuthenticator.processResponse(SAMLAuthenticator.java:83)
    at com.cisco.cpi.sso.saml.sp.security.authentication.SAMLAuthenticator.process(SAMLAuthenticator.java:58)
    at com.cisco.cpi.sso.saml.sp.security.filter.SamlFilter.doFilter(SamlFilter.java:63)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
    at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:314)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1023)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)
2022-01-16 14:06:11,187 DEBUG [http-bio-443-exec-5] authentication.SAMLAuthenticator - error url is ::/ssosp/error?id=1000000
2022-01-16 14:06:45,750 DEBUG [Timer-6] util.FileMonitor$FileMonitorTask - newLastModified is ::1642282162000
2022-01-16 14:06:45,751 DEBUG [Timer-6] util.FileMonitor$FileMonitorTask - LastModified is    ::1642282162000
2022-01-16 14:06:45,799 DEBUG [Thread-62] changenotify.ChangeNotificationQueue - retrieveCNFromQueue :: Woke up after 60 seconds or notified to wake up.
2022-01-16 14:06:45,799 DEBUG [Thread-62] changenotify.ChangeNotificationQueue - retrieveCNFromQueue :: Waiting for 60 seconds or until interrupted
  6.  As we see that there was delay as per the logs, now let’s try to fix the issue by making some changes in AD FS server.

Modifying the SKEW value in AD FS Server

  1. Login to AD FS Server and open power shell.
  2. Enter the following command. 
    Get-AdfsRelyingPartyTrust -Identifier CUCM-Pub-FQDN | select *identifier*, *skew*

    NOTE: Modify CUCM-PUB-FQDN with the FQDN of your Call Manager

    uccollabing.com

  3. If you notice that  “NotBeforeSkew” is set to 0 minute. Let’s modify this value to 1 minute.
  4. Enter the following command 
    Set-AdfsRelyingPartyTrust -TargetIdentifier "CUCM-Pub-FQDN" -NotBeforeSkew 1

    uccollabing.com

  5.  If you notice that  “NotBeforeSkew” is set to 1 minute
  6. Now try accessing the CUCM Publisher via SSO and your issue should be resolved.

Troubleshooting CUCM SAML Error video

 

Hope this helps

Tags:

You may also like...

1 Response

  1. Adil says:
    July 14, 2022 at 11:42 am

    Hi Avinash,

    Thanks for your posting, it is very helpful.
    I just want to know that, i am receiving the SMAL response error on Cisco Jabber while login. Can you please help in that.

    Regards

    Reply

Leave a Reply

Your email address will not be published. Required fields are marked *