Yong Li

How to troubleshoot Secure Cloud SMS OTP delivery problem

Blog Post created by Yong Li Employee on Oct 12, 2015

The Issue

Secure Cloud 1.5x could report the following error when it's trying to deliver a Security Code over Text Message (SMS OTP)

Error: An error has occurred while sending the Security Code. Please try again later

image25.png

 

Background

Secure Cloud 1.5x uses Arcot Common Data Service to deliver SMS OTP, the service is running on the Advanced Authentication server.

 

Troubleshoot SMS OTP Delivery Problem

  1. Confirm 'Security Code' is enabled on Configure Credential Types: Credential Type
    image_thumb12.png
  2. Confirm Security Code is enable on the current Advanced Authentication Flow.
    For example, the following is a typical setting for ArcotID OTP with Risk flow which can easily trigger Security Code on a RiskMinder Advised Increased Authentication scenario.
    image14.png
    image_thumb20.png

  3. Confirm 'Security Code over SMS' is Enabled and configured properly
    image_thumb13.png
    Note:
    • OOTB Secure Cloud only supports Clickatell as the SMS Provider, if you need to use other SMS Provider, you may contact CA Service who will be able to do the integration, otherwise you can build your own SMS gateway proxy to handle the HTTP POST request from the Advanced Authentication server. I'll detail how to use tcpdump to explore the format of the HTTP request.
    • If you are using Clickatell for SMS delivery, please ensure the Advanced Authentication server machine can directly connect to api.clickatell.com port 80 and 443

  4. Check if other alternative OTP delivery approach works.
    For example, if Security Code over Email is enabled on 'ArcotID OTP with Risk' Flow, you may check if Email OTP can be sent to the end user by using 'Forgot my PIN' function on a new machine whereon the end user didn't pass Risk evaluation before.
    This will trigger a Increased Authentication scenario.
    • Visit 'Forgot my PIN' link on a new machine
      image10.png
      image_thumb16.png
    • RiskMinder triggers a Increased Authentication scenario.
      image_thumb17.png
    • By selecting 'Receive Security Code over Email', an Email OTP will be sent out.
      image13.png
  5. Verify the end user mobile can receive SMS messages from other sources.
  6. Check if the issue only happen on certain user's Mobile number.
    KNOWN ISSUE:  For customers in certain countries which have a phone number which was  issued by one phone carrier but which was later moved to another carrier may not be able to receive SMS messages from the Clickatell SMS delivery service .
  7. Ensure the end user mobile number containing the country code if the SMS Provider is Clickatell, i.e +61432100000.
  8. On Advance Authentication server, adjust logger settings in /opt/CA/AdvancedAuth/Tomcat/lib/log4j.properties
    log4j.logger.com.ca=ALL
    log4j.logger.com.arcot=ALL
    log4j.logger.com.arcot.integrations.toksvr.client.SimpleTSClientImpl=INFO

    log4j.appender.LOGHANDLE.File=/opt/CA/AdvancedAuth/Tomcat/logs/cm-aads.log

    Note: Please bounce the servers after the change
  9. Logs to check
    • On Advance Authentication Server, please review /opt/CA/AdvancedAuth/Tomcat/logs/cm-aads.log
      Search SMSSender in cm-aads.log to find details about SMS delivery probem, i.e. the SMSSender can not connect to Clickatell

      2015-10-08 13:46:16,718 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:90) - Received Clickatel Integation URL: http://api.clickatell.com/http/sendmsg?
      2015-10-08 13:46:16,756 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:114) - Message received: [Security Code for TEST001 is 96543]
      2015-10-08 13:46:16,756 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:115) - OTPData for Clickatell:: [user=theuser&password=thepassword&api_id=0123210&to=0123443210&from=54321&mo=1&text=Security+Code+for+TEST001+is+96543]
      2015-10-08 13:46:17,537 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:126) - Processing URL response
      2015-10-08 13:46:17,538 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:138) - strReturn::ID: 3aa6f965640efedf9d6d57ce24e61498
      2015-10-08 13:46:17,538 [http-bio-9090-exec-5] DEBUG SMSSender,(http-bio-9090-exec-5:159) - SMS sent

    • On SiteMinder SecureProxy Server, please review /opt/CA/secure-proxy/proxy-engine/logs/cm-aa.log
      Search ProvideOTPAndDeliver in cm-aa.log to find additional details about the communication to Common Data Service on Advance Authentication Server

      2015-10-01 21:17:49,165 [ajp-bio-8009-exec-8] DEBUG ProvideOTPAndDeliver,(ajp-bio-8009-exec-8:98) - OTP successfully generated for user TEST001
      2015-10-01 21:17:49,165 [ajp-bio-8009-exec-8] DEBUG ProvideOTPAndDeliver,(ajp-bio-8009-exec-8:103) - otp delivery channel is sms
      ...
      2015-10-01 21:17:50,251 [ajp-bio-8009-exec-8] DEBUG ProvideOTPAndDeliver,(ajp-bio-8009-exec-8:244) - SMS OTP sent


  10. Use tcpdump for troubleshooting

    tcpdump can be used to capture the http traffic between the Advanced Authentication server and the SMS delivery server, command line:
    tcpdump -s 0 -i eth1 -A host api.clickatell.com and tcp port http

A typical scenario that I ran on Advanced Authentication server machine:

[root@yongscaa~]# tcpdump -s 0 -i eth1 -A host api.clickatell.com and tcp port http
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth1, link-type EN10MB (Ethernet), capture size 65535 bytes
00:31:49.724243 IP cm151b.10986 > api.clickatell.com.http: Flags [S], seq 2643595182, win 5840, options [mss 1460,sackOK,TS val 955958669 ecr 0,nop,wscale 7], length 0
E..<.#@.@.y..#.}....*..P............b..........
8...........
00:31:49.743188 IP api.clickatell.com.http > cm151b.10986: Flags [S.], seq 3563331, ack 2643595183, win 65535, options [mss 1436,nop,wscale 5,sackOK,TS val 1258856570 ecr 955958669], length 0
E..<..@.8........#.}.P*..6_C.......................
K..z8...
00:31:49.743215 IP cm151b.10986 > api.clickatell.com.http: Flags [.], ack 1, win 46, options [nop,nop,TS val 955958688 ecr 1258856570], length 0
E..4.$@.@.y..#.}....*..P.....6_D....\......
8...K..z
00:31:49.744291 IP cm151b.10986 > api.clickatell.com.http: Flags [P.], seq 1:285, ack 1, win 46, options [nop,nop,TS val 955958689 ecr 1258856570], length 284
E..P.%@.@.x..#.}....*..P.....6_D...........
8...K..zPOST /http/sendmsg? HTTP/1.1
Content-Type: application/x-www-form-urlencoded
Cache-Control: no-cache
Pragma: no-cache
User-Agent: Java/1.7.0_67
Host: api.clickatell.com
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive
Content-Length: 126


00:31:49.744319 IP cm151b.10986 > api.clickatell.com.http: Flags [P.], seq 285:411, ack 1, win 46, options [nop,nop,TS val 955958689 ecr 1258856570], length 126
E....&@.@.x..#.}....*..P.....6_D.....%.....
8...K..zuser=xxxxxxx&password=xxxxxxxx&api_id=xxxxxxx&to=614300xxxxx&from=xxxxx&mo=1&text=Demo+Env0+Security+Code+for+TEST001+is+93957
00:31:49.765072 IP api.clickatell.com.http > cm151b.10986: Flags [.], ack 411, win 2087, options [nop,nop,TS val 1258856572 ecr 955958689], length 0
E..4.&@.8........#.}.P*..6_D...I...'Sd.....
K..|8...
00:31:50.553150 IP api.clickatell.com.http > cm151b.10986: Flags [P.], seq 1:229, ack 411, win 2091, options [nop,nop,TS val 1258856661 ecr 955958689], length 228
E.....@.8........#.}.P*..6_D...I...+.......
K...8...
HTTP/1.1 200 OK
Date: Mon, 19 Oct 2015 07:31:50 GMT
Server: Apache
Keep-Alive: timeout=10, max=50
Connection: Keep-Alive
Transfer-Encoding: chunked
Content-Type: text/html

24
ID: 6cd6f6dccfc89d0c8935636faa8e94ec
0

Outcomes