594 views

How to increase debug logging for the Edge Encryption proxy



Goal


There are currently three options for increasing debug logging on the Edge Encryption Proxy. You might want to increase the level of logging to debug issues with the proxy and interpret the logs yourself, or you might want to have technical support look into the issue with the benefit of more verbose log statements.

How to


Depending on the issue being debugged, set up debug logging in one of three ways:

  • Debugging issues with SSL connectivity between the Edge Encryption Proxy and the instance
  • Debugging issues other than SSL connectivity
  • Logging for processing times for browser requests through the proxy and Edge Encryption Rule execution time

For all debug cases, you may view and interpret the logs on your own or open an incident to get interpretation from ServiceNow technical support providing the description of the issue and how it is reproduced.

Debugging issues with SSL connectivity between the Edge Encryption Proxy and the instance

Use this method if you want to debug issues with SSL connectivity between the Edge Encryption Proxy and the instance (for example, you go to the URL of the proxy but access to the instance fails via the proxy). These steps increase logging and help find the verbose log statements.

  1. Stop the proxy.

  2. Add the following line to the file $proxy_installation_location/conf/wrapper.conf, which is a Java startup property:

    wrapper.java.additional.<next available number in sequence> = -Djavax.net.debug=all

    For example: wrapper.java.additional.4 = -Djavax.net.debug=all

  3. Save the change and restart the proxy.

  4. Reproduce the issue.

  5. Debug log statements related to the SSL exchange can be found in the $proxy_installation_location/logs/wrapper_<current date>.log file.

  6. When debugging is complete, stop the proxy and edit the file $proxy_installation_location/conf/wrapper.conf again, removing or commenting out (adding a # at the beginning of the line) the following line:

    wrapper.java.additional.<next available number in sequence> = -Djavax.net.debug=all

  7. Save the change and restart the proxy.

Debugging issues with the Edge Encryption application other than SSL-related issues

Use this method if you want to debug issues with the Edge Encryption application aside from SSL-related issues. These steps increase logging and help find the verbose log statements.

  1. Stop the proxy.

  2. In the $proxy_installation_location/conf/log4j.properties file, change the setting of the log from info to debug.

    Change this:
    log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=info
    to this:
    log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=debug

  3. Save the change and restart the proxy.

  4. Reproduce the issue.

  5. Check for debug log statements related to the application in the $proxy_installation_location/logs/edgeencryption.log file.

  6. When debugging is complete, stop the proxy and restore the original log setting.

    Change from:
    log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=debug
    back to:
    log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=info

  7. Save the change and restart the proxy. 

Logging for processing times for browser requests through the proxy and Edge Encryption Rule execution time

Additional logging has been introduced to the Edge Proxies. The additional logging settings are added to the <proxy_installation_location>/conf/log4j.properties file. Changes made are taken up by the proxy dynamically within about a minute after the changes to the file are made, so you do not have to restart the proxies.

  1. Modify the <proxy_installation_location>/conf/log4j.properties file by adding the following line under the line containing log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=info, FileLog:

    log4j.logger.com.snc.edgeencryption.metrics.EdgeEncryptionTimingMetricCache=info, TimingLog

    In this example, the log level is set to info; however, you can set the level to other values such as warn or debug. The level values are as follows:

    • info – More than 5 seconds or more to serve the request
    • warn – 10 seconds or more to serve the request
    • debug – Log all requests
  2. Add the following lines into the file anywhere under another log4j.appender. block:

    log4j.appender.TimingLog=org.apache.log4j.RollingFileAppender
    log4j.appender.TimingLog.File=../logs/edgenetwork.log
    log4j.appender.TimingLog.MaxFileSize=500MB
    log4j.appender.TimingLog.MaxBackupIndex=4
    log4j.appender.TimingLog.layout=org.apache.log4j.PatternLayout
    log4j.appender.TimingLog.layout.ConversionPattern=%d %-5p %m%n

    Values that you might want to change (note that the debug log level will be very verbose):

    • log4j.appender.NetworkLog.MaxFileSize – Set this value depending on how large you want the files to be

    • log4j.appender.NetworkLog.MaxBackupIndex – The number of MaxFileSize files you want to keep

  3. After the log4j.properties file is saved, the following types of messages will be in the edgenetwork.log log file for network times:

    2017-04-27 08:22:44,876 DEBUG 1307988484 request_uri=/api/now/ui/presencesysparm_auto_request=true&cd=1493306564548 request_method=POST
    client_request_received="2017-04-27 08:22:44,044" proxy_request_processing_time=4
    all_rules_processing_time=1 rule_executed="REST JSON" rule_execution_time=0
    proxy_instance_round_trip=219 proxy_response_processing_time=103 total_time_from_proxy=326
    response_code=201 glide_user=SCv2:XjK/JWWrfN/dbMoo1ZllcvcsAvoYheBd jsessionid_suffix=A396BC

    The values in the log messages are as follows:

    • request_uri: The URI being requested

    • request_method: The HTTP method being used, for example, GET, POST, PUT, PATCH, DELETE

    • client_request_received: The timestamp noting when the HTTP client request arrived at the Edge proxy

    • proxy_request_processing_time: How long the Edge proxy took to process the request in milliseconds

    • all_rules_processing_time: Total time it took to execute all of the Edge Encryption rules for the request in milliseconds

    • rule_executed: The name of the Edge proxy rule that was executed

    • rule_execution_time: How long it took to execute listed rule_executed in milliseconds

    • proxy_instance_round_trip: The time from when the Edge proxy sent the request to the instance until the instance sent the response and was received by the edge proxy in milliseconds

    • proxy_response_processing_time: How long the Edge proxy took to process the response in milliseconds

    • total_time_from_proxy: The total time from when the Edge proxy received the request from the client and returned the response to the client in milliseconds

    • response_code: HTTP response code glide_user: The glide_user cookie value

    • jsessionid_suffix: The JSession cookie suffix associated with the request

 

Logging for the Jetty Application Server Client

 

Jetty is the application server that hosts the Edge Encryption application.  Turning on this logger can give valuable information about the Jetty/Edge Encryption interactions.  

Additional logging has been introduced to the Edge Proxies. The additional logging settings are added to the <proxy_installation_location>/conf/log4j.properties file. Changes made are taken up by the proxy dynamically within about a minute after the changes to the file are made, so you do not have to restart the proxies.

  1. Modify the <proxy_installation_location>/conf/log4j.properties file by adding the following line under the line containing log4j.logger.com.snc.edgeencryption.EdgeEncryptionLog=info, FileLog:

 

log4j.logger.org.eclipse.jetty.client=debug, jettyClient

 

debug is the only logger level; it is recommended that this logger be kept on for a short a period as possible to collect the needed data as it creates a lot of logging.

  1. Add the following lines into the file anywhere under another log4j.appender. block:

 

log4j.appender.jettyClient=org.apache.log4j.RollingFileAppender
log4j.appender.jettyClient.File=../logs/jettyClient.log
log4j.appender.jettyClient.MaxFileSize=500MB
log4j.appender.jettyClient.MaxBackupIndex=4
log4j.appender.jettyClient.layout=org.apache.log4j.PatternLayout
log4j.appender.jettyClient.layout.ConversionPattern=%d %-5p %m%n

 

Values that you might want to change (note again that the debug log level will be very verbose):

    • log4j.appender.jettyClient.MaxFileSize – Set this value depending on how large you want the files to be
    • log4j.appender.jettyClient.MaxBackupIndex – The number of MaxFileSize files you want to keep
  1. After the log4j.properties file is saved, the following types of messages will be in the jettyClient.log log file:

 

2017-09-25 10:34:05,491 DEBUG -WrapperSimpleAppMain Created HttpDestination[https://instance.service-now.com]@5c50a7d5,queue=0,pool=DuplexConnectionPool[c=0/64,a=0,i=0]

2017-09-25 10:34:05,494 DEBUG -WrapperSimpleAppMain Queued HttpRequest[POST /sn_edge_encryption_edge_encryption.do HTTP/1.1]@423cddba for HttpDestination[https://instance.service-now.com]@5c50a7d5,queue=1,pool=DuplexConnectionPool[c=0/64,a=0,i=0]

Article Information

Last Updated:2017-09-26 06:55:36
Published:2017-02-17