Logging (NTC)

NoTouch Center logging has been carefully engineered to supply exactly the right amount of information. In some cases, users may need more fine-grain control on NoTouch Center logging. For instance, it could be necessary to

  • increase logging (debug) in case of troubleshooting
  • disable annoying but harmless log messages
  • specially treat log messages that emanate from your own scripts using the Scripting interface

Every log message knows its originating module (e.g. com.ncomputing.center.msrv.MServer), a log level (e. g. DEBUG, INFO, ERROR) and the actual log message. The logging system distributes these log messages into certain appenders. There are two appenders configured by default, one logs to the system console (=standard output), the other one into the database, the APPLOG table; this is what you then find in the "Log" view in NoTouch Center.

The standard output will be redirected to a file named center.log - i.e. the center.log file is the main and most important log file:

  • On Windows systems, it resides in the log subdirectory of the NoTouch Center installation folder
  • On a NComputing Virtual Appliance the file is /var/log/center.log

Contents

Log configuration file

The master log configuration file is log4j2.xml - NoTouch Center uses the well-established Log4J2 toolkit [1] for logging. The file resides in the main NoTouch Center installation directory. Use a regular text editor to edit this file. If you edit this file, please restart NoTouch Center afterwards for the changes to become effective.

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="ERROR" package="com.ncomputing.center">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{ISO8601} %-5p [%t] %c: %m%n"/>
    </Console>
    <TorqueDBAppender name="TorqueDBAppender">
    </TorqueDBAppender>
  </Appenders>
  <Loggers>
          <Logger name="com.ncomputing" level="INFO">
                  <AppenderRef ref="TorqueDBAppender"/>
          </Logger>
          <Logger name="scripts" level="INFO">
                  <AppenderRef ref="TorqueDBAppender"/>
          </Logger>
          <Logger name="org.apache.commons.httpclient" level="ERROR"/>
          <Logger name="org.apache.commons.httpclient" level="ERROR"/>
          <Logger name="org.apache.struts" level="ERROR"/>
          <Logger name="net.sf.jasperreports" level="ERROR"/>
          <Root level="ERROR">
                <AppenderRef ref="Console"/>
          </Root>
  </Loggers>
</Configuration>

The easiest thing to add more verbosity is to add an additional line right before the <Root level="ERROR"> line.

    <Logger name="com.ncomputing.msrv.MServer" level="DEBUG"/>

This example would enable debug-level logging for the MServer, the component that deals with clients.

Another example: Let's assume you are writing scripts using the Scripting interface. You frequently use logger.debug() statements in your code and you want this visible. So change the log level of the "scripts" namespace to DEBUG:

        <Logger name="scripts" level="DEBUG">
                 <AppenderRef ref="TorqueDBAppender"/>
         </Logger>

Log output format

Each line in the log file has the following fields:

  • Exact timestamp (date and time including microseconds)
  • Log level
  • Thread ID
  • Originating module
  • Actual message

Take this example:

2015-06-14T01:13:33,896 INFO  [main] com.ncomputing.center.Start: Product version: 4.1.404
2015-06-14T01:13:33,898 INFO  [main] com.ncomputing.center.Start: Instance UUID: 5d842478-9012-47e4-XXXX-XXXXee0f602f
2015-06-14T01:13:33,900 INFO  [main] com.ncomputing.center.LicenseManager: Local Address:ncomputingva (IP(s): 192.168.21.10)
2015-06-14T01:13:34,778 INFO  [main] com.ncomputing.center.DatabaseNG: Database configured and connected
2015-06-14T01:13:34,868 INFO  [main] com.ncomputing.center.DatabaseNG: Upgrading database from older product version 4.1.384
2015-06-14T01:13:34,886 INFO  [main] com.ncomputing.center.web.UpdateManager: system imported release information 
2015-06-14T01:19:20,677 INFO  [main] com.ncomputing.center.web.UpdateManager: system imported lang information 
2015-06-14T01:19:20,736 INFO  [main] com.ncomputing.center.LicenseManager: License present: 30x LMD for NComputing Test Environment (6XYZ7250)
2015-06-14T01:19:20,737 INFO  [main] com.ncomputing.center.LicenseManager: License present: 50x MCLI for NComputing Test Environment (6XYZ7251)
2015-06-14T01:23:29,780 INFO  [main] com.ncomputing.center.Start: System ready
2015-06-14T02:57:15,293 INFO  [qtp664996488-36] com.ncomputing.center.LoginService: User 'admin' (System Administrator) logged in from 127.0.0.1
2015-06-14T02:58:58,034 INFO  [qtp664996488-38] com.ncomputing.center.actions.logon.LogoffAction: User 'admin' logged off

Exceptions and stack traces

An "exception" denotes a state of a software program that is "unusual". Using exceptions allows to write cleaner and more efficient code, as multiple "if (ok) then - else" constructs are eliminated and replaced by a 'mainstream' execution path and unusual states like "disk drive full" etc. An exception does not necessarily mean a catastrophic failure of some component and it does not mean there is a software bug - not all! It only means something is "exceptional".

Sometimes exceptions are logged with a "stack trace" that allows the programmer to know exactly where in the program code the exception happened. This can be helpful for improving the software, sometimes it has no value whatsoever. Imagine a situation when suddenly the database server (Oracle, MS SQL, MySQL) crashes and NoTouch Center can not fulfill a query.

org.apache.torque.TorqueException: com.mysql.jdbc.exceptions.jdbc4.MySQLQueryInterruptedException: Query execution was interrupted
        at org.apache.torque.util.BasePeer.throwTorqueException(BasePeer.java:105)
        at org.apache.torque.util.BasePeer.executeQuery(BasePeer.java:945)
        at org.apache.torque.util.BasePeer.doSelect(BasePeer.java:783)
        at org.apache.torque.util.BasePeer.doSelect(BasePeer.java:756)

Even though the system logs a nice stack trace and we know exactly where in the code the exception occured, it is still not really helpful because we are not dealing with a software but instead the failure of an external component.

What this means is, if you try to debug a problem, look into the log files, check it for exceptions, but keep the "big picture" in mind - an exception is not necessarily the problem, most likely it is a symptom, but not the cause!

Logging to syslog

Of course you can direct log messages to a syslog server instead of the default log file. The underlying logging framework supports the SyslogAppender, so you

  1. register the SyslogAppender in the Appenders section
  2. reference it in the Loggers section depending on your actual logging desires

An example - look for both occurrences of the "bsd" logger:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="ERROR" package="com.ncomputing.center">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{ISO8601} %-5p [%t] %c: %m%n"/>
    </Console>
    <TorqueDBAppender name="TorqueDBAppender">
    </TorqueDBAppender>
    <Syslog name="bsd" host="localhost" port="514" protocol="TCP"/>
  </Appenders>
  <Loggers>
          <Logger name="com.ncomputing" level="INFO">
                  <AppenderRef ref="TorqueDBAppender"/>
          </Logger>
          <Logger name="scripts" level="INFO">
                  <AppenderRef ref="TorqueDBAppender"/>
          </Logger>
          <Logger name="org.apache.commons.httpclient" level="ERROR"/>
          <Logger name="org.apache.commons.httpclient" level="ERROR"/>
          <Logger name="org.apache.struts" level="ERROR"/>
          <Logger name="net.sf.jasperreports" level="ERROR"/>
          <Root level="ERROR">
                <AppenderRef ref="bsd"/>
          </Root>
  </Loggers>
</Configuration>

The SyslogAppender can do much more than just old-school syslog - please see log4j2 SyslogAppender for a complete overview.