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.

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

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

Setting up SAML Trace to Debug

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

Collecting logs from RTMT

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

Reading the logs

Launch your favourite notepad editor, in our case we are using Notepad++
Open the logs in Notepad++
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.

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}

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

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

Login to AD FS Server and open power shell.
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
If you notice that “NotBeforeSkew” is set to 0 minute. Let’s modify this value to 1 minute.
Enter the following command
```
Set-AdfsRelyingPartyTrust -TargetIdentifier "CUCM-Pub-FQDN" -NotBeforeSkew 1
```
If you notice that “NotBeforeSkew” is set to 1 minute
Now try accessing the CUCM Publisher via SSO and your issue should be resolved.

Troubleshooting CUCM SAML Error video

Hope this helps

Avinash Karnani

I am working in an IT company and having 10+ years of experience into Cisco IP Telephony and Contact Center. I have worked on products like CUCM, CUC, UCCX, CME/CUE, IM&P, Voice Gateways, VG224, Gatekeepers, Attendant Console, Expressway, Mediasense, Asterisk, Microsoft Teams, Zoom etc. I am not an expert but i keep exploring whenever and wherever i can and share whatever i know. You can visit my LinkedIn profile by clicking on the icon below.

“Everyone you will ever meet knows something you don’t.” ― Bill Nye

How to troubleshoot “Error while processing SAML Response”?

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

Reproducing the Error

Setting up SAML Trace to Debug

Collecting logs from RTMT

Reading the logs

Modifying the SKEW value in AD FS Server

Troubleshooting CUCM SAML Error video

1 thought on “How to troubleshoot “Error while processing SAML Response”?”

Leave a Comment Cancel Reply

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

Reproducing the Error

Setting up SAML Trace to Debug

Collecting logs from RTMT

Reading the logs

Modifying the SKEW value in AD FS Server

Troubleshooting CUCM SAML Error video

Related Posts

1 thought on “How to troubleshoot “Error while processing SAML Response”?”

Leave a Comment Cancel Reply