REST Logging/Tracing

Products

• CA Service Desk Manager
• CA Service Management - Service Desk Manager

Issue/Introduction

When working with REST API calls in Service Desk Manager, it may not be obvious where the logging is recorded or how to turn up logging for purposes of troubleshooting.

This article discusses a recommended means to debug and troubleshoot REST API calls within CA Service Desk.

Environment

CA Service Desk Manager 17.1 and higher

Resolution

The log of interest for REST API calls is the "jrest.log".  This log is contained in the Service Desk Manager install directory's log directory.

One can review this log via a text editor to review REST related activity.  Turning up logging can be done with the following command, executed in an Admin Command Prompt:

pdm_log4j_config -f REST -l DEBUG -a -s 30MB

The above changes the default logging from INFO to DEBUG and increases the jrest log file size up to 30 MB from the default 3MB.  One can turn off the logging back down to default levels by running:

pdm_log4j_config -f REST -l INFO -a -s 3MB

One does not need to cycle services when turning up logging, but it is recommended to wait a few minutes after running the above commands before leveraging the extended logging.

Example of log materials of interest:

11/06 09:51:17.487 [http-nio-8050-exec-4] DEBUG BOPSessionToken 59 New BOPSessionToken created: persID=[cnt:4F89491F9F21EE43A84A6BACF002F2A0]; licensed=[1]; sessionID=[1582237011]; domSession=[Domsession:9dJAAA] 

11/06 09:51:17.508 [http-nio-8050-exec-4] DEBUG SDMCRUDServiceImpl 282 Query for creating new resource: INSERT INTO rest_access (access_key,contact) VALUES (1582237011,'4F89491F9F21EE43A84A6BACF002F2A0') 

11/06 09:51:17.934 [http-nio-8050-exec-4] INFO  DAL_JDBC 132 Statement.executeUpdate (426ms): INSERT INTO rest_access (access_key,contact) VALUES (1582237011,'4F89491F9F21EE43A84A6BACF002F2A0') 

The above entries indicate that an access key was generated and saved into table rest_access.  This entry is key to indicate that a successful login took place via REST and that an access key was permitted.  Note:  Only the INFO entry displayed would be obligated to appear in the jrest.log.  The other two entries depicted above are DEBUG entries that are only exposed if extra logging was turned on:

Leveraging the same access key "1582237011" in a REST GET call, we see with logging turned up:

11/06 10:12:11.256 [http-nio-8050-exec-8] DEBUG DAL_JDBC 129 Statement.executeQuery (12ms): SELECT contact FROM rest_access WHERE access_key = 1582237011 
...
11/06 10:12:11.302 [http-nio-8050-exec-8] DEBUG DalUtilities 866 getObjectsCountQuery return: SELECT COUNT(*) FROM cr 
...
11/06 10:12:11.782 [http-nio-8050-exec-8] DEBUG DalUtilities 2740 For (cr) working on Majic attribute: id 

11/06 10:12:11.783 [http-nio-8050-exec-8] DEBUG DalUtilities 3199 Object class type: java.lang.Integer 

11/06 10:12:11.784 [http-nio-8050-exec-8] DEBUG DalUtilities 2878 Self URI: http://SDM-SERVER:8050/caisd-rest/cr/2800 

The above indicates on [http-nio-8050-exec-8] that access_key 1582237011 was used to do a query of call request entries.

Examples of errors that may be encountered in jrest.log

11/01 15:58:11.485 [http-bio-8050-exec-1] ERROR BasicAuthenticator 113 BPMessagingException error on authentication validation for userid(testuser1). com.ca.sdm.bop.BPMessagingException: AHD04020:Login failed for userid (testuser1); no default role found for session type (10) 

The above indicates that login had failed due to a problem with contact id testuser1 lacking a default role configuration.

Later logging also denotes for attempts to access change orders via REST while using access key 596316253 (scanning for entries on [http-bio-8050-exec-3])

11/05 09:57:33.003 [http-bio-8050-exec-3] INFO DAL_JDBC 132 Statement.executeQuery (250ms): SELECT contact FROM rest_access WHERE access_key = 596316253 

11/05 09:57:33.003 [http-bio-8050-exec-3] ERROR DalUtilities 2090 No record found for the following query: SELECT contact FROM rest_access WHERE access_key = 596316253 

11/05 09:57:33.003 [http-bio-8050-exec-3] ERROR DalUtilities 207 Contact UUID not found for REST Access Key (596316253) provided via X-AccessKey header. 

11/05 09:57:33.019 [http-bio-8050-exec-3] ERROR SDMCRUDServiceImpl 473 Error creating new 'chg' resource. Invalid REST Access Key (596316253) provided via X-AccessKey header. {http://SDM-SERVER:8050/caisd-rest/chg}

As the access key query for 596316253 failed (was not found at all in the rest_access table), this results in the change query request failing.

Additional Information

To check current logging levels, please run:

pdm_log4j_config -f REST -d

Additional logging one may expect to find in the SDM install's log directory as a result of activating logging in debug mode:

• jrest.log
• pdm_tomcat_REST.log
• RestWSJavadocErrors.log
• RestWSJavadocNotices.log
• RestWSJavadocWarnings.log

The above can also be used to track activity when one is redeploying REST web services, ie pdm_rest_util -undeploy / pdm_rest_util -deploy.  The following is a partial log excerpt from the jrest.log illustrating such activity:

02/16 18:41:42.576 [deploy_thread] DEBUG Pdm_rest_util 590 In RestWarDeployThread.run method
02/16 18:41:42.577 [deploy_thread] DEBUG ToolsFactory 120 Returning CXF Deployer (CXFServiceDeployerImpl) instance.
02/16 18:41:42.578 [main] DEBUG Pdm_rest_util 456 deploy_thread is running
02/16 18:41:42.594 [deploy_thread] INFO  Pdm_rest_util 569 Deploying WAR file to C:/PROGRA~2/CA/SERVIC~1\bopcfg\www\CATALINA_BASE_REST\webapps\
02/16 18:41:42.598 [deploy_thread] DEBUG CXFServiceDeployerImpl 188 Generating 'C:/PROGRA~2/CA/SERVIC~1\temp\SDM-REST\WEB-INF\beans.xml' from 'C:/PROGRA~2/CA/SERVIC~1\temp\SDM-REST'
02/16 18:41:42.910 [deploy_thread] DEBUG beansXmlGenerator 133 generation of 'C:\PROGRA~2\CA\SERVIC~1\temp\SDM-REST\WEB-INF\beans.xml' completed
02/16 18:41:42.911 [deploy_thread] DEBUG CXFServiceDeployerImpl 588 Copying file 'C:\PROGRA~2\CA\SERVIC~1\site\rest\web.xml' to 'C:\PROGRA~2\CA\SERVIC~1\temp\SDM-REST\WEB-INF\web.xml'
02/16 18:41:42.916 [deploy_thread] DEBUG FileUtilities -1 copyFile; source => C:\PROGRA~2\CA\SERVIC~1\site\rest\web.xml ; dest => C:\PROGRA~2\CA\SERVIC~1\temp\SDM-REST\WEB-INF\web.xml
02/16 18:41:42.916 [deploy_thread] DEBUG FileUtilities -1 FileUtilities#copyFile: Copied 1266 bytes (1266 bytes total)
02/16 18:41:42.917 [deploy_thread] DEBUG CXFServiceDeployerImpl 203 Archiving and deploying 'C:\PROGRA~2\CA\SERVIC~1\temp\SDM-REST' to 'C:\PROGRA~2\CA\SERVIC~1\site\rest\caisd-rest.war'

For SOAP Logging/Tracing, please see KB Article 137240