TRM Server Logging - Advanced Topics

Applications
Applications covers the world of Teradata apps, including apps offered by Teradata (such as TRM or DCM), as well as best practices and methodologies for building your own Teradata-connected apps.
Teradata Employee

TRM Server Logging - Advanced Topics

In this post, we will cover some more advanced logging topics in TRM, including PE logging, SQL output, user clicks, authentication attempts, and startup logging.

PE Logging

PE logs, due to special requirements, are handled through custom log4j objects. These objects are based on log4j appenders and loggers, but are not configured in the log4j.xml file; they are essentially hard-wired in code. As such, the logging performed in the PE is not configurable.  The design of the PE logs includes two categories (general and detail level) of logs for each submitted PE job. The files are located and (usually) named with the convention:

<logpath-root>\<dated-logdir>\PE-<jobtype>-<id1>-<id2>-<time>.log and

<logpath-root>\<dated-logdir>\PE-<jobtype>-<id1>-<id2>-<time>-Detail.log

where:

  • logpath-root: root directory for all PE logs (see below for more details)
  • dated-logdi: the creation date, e.g. "2007.04.30" (YYYY-MM-DD)
  • jobtype: a descriptive name for job type, e.g. CommLeadGeneration or SegPlanRe-alize
  • id1, id2: run id and/or object id
  • time: created in HH:mm:ss format (HH = 24 hour clock)

logpath-root

The logpath root for the PE files defaults to different locations depending on the webserver:

• Tomcat is <tomcat install root>\webapps\trm\bin\dist

• WebSphere is <WAS root>\profiles\<AppSrv>\dist

To override this location, edit "trm.properties" (in the .\trm\WEB-INF\classes directory). The symbol trm-data specifies the root location:

trm-data=c:\my-trm-logs
trm-create=true

Config File Root

Most configuration files, including the log4j.xml, are located in the application's WEB-INF\classes directory, the path to which depends on the webserver:

  • Tomcat deployments will be structured like this: <tomcat root>\webapps\trm\WEB-INF\classes
  • WAS deploy structure looks like this:
    • <WAS root>\AppServer\profiles\<appsrv>\installedApps\<cell-server-name>\<trm-war>.ear\trm.war\WEB-INF\classes, where
      • <appsrv> is the application server sub-directory, probably AppSrv01 or similar
      • <cell-server-name> will combine the server nodename with the cell, e.g. WUSCS230003-B8LNode01Cell, and
      • <trm-war> will be the name you assigned to the installed apps in the WAS Admin console.

PE Log Purging

Due to their large size and marginal utility of archiving the PE logs in a test environment, a "purge" action was added which will automatically delete PE log files created in prior to given number of elapsed days. This elapsed time value is derived from "purgeWaitDays" which is set in the "processingEngineTemplate" Spring bean (see file "trm-modules/trm-processing-engine/config/common-pe-context.xml"). The minimum purge wait value is 1 (day). A value of 0 (or less) suppresses the purge action.

SQL Output

2008-12-16 07:47:08,226 DEBUG :pool-1-thread-229 [com.teradata.trm.common.qes.ioc.jdbc.advice.SqlTrace] sql(ms)=16 SQL TRACE: "insert into CR_RUN_COUNT (UPDATE_DTTM, UPDATE_USER, RUN_COUNT_ID) values (?, ?, ?)--parameters=[2008-12-16 07:47:08.163,trm-user,20003d420nmt],ver:6.1.0.0.85900.branches/stable/,
userId:kwells,pe_jobHistoryId:20003d420lmp,time:1229431627585,
pe_task:SegPeTask:10003d420lnp,thread:pool-d-229;"

This is an example log entry. It shows a query being executed to insert a record into CR_RUN_COUNT. It’s a parameterized query, and the parameters are reported in the com-ments of the query.

  • For all SQL activity:
    • the logger "com.teradata.trm.common.qes.ioc.jdbc.advice.SqlTrace" intercepts and displays essentially all SQL (from both Hibernate and direct from the ap-plication); currently set to DEBUG level. Set this logger level to TRACE to in-clude SQL issued from the Scheduler component (Quartz).
  • For Hibernate SQL generation
    • "hibernate.show_sql=true" only outputs to sysout. "show_sql" is configured in trm-modules\trm-common\src\config\hibernate.properties (currently set to true); only displays in console (apparently doesn't use log4j; it uses Sys-tem.out.println or similar).
    • logger "org.hibernate.SQL" also logs Hibernate SQL generation via for logging SQL generation via log4j; this is currently commented out since the QES log-ging will include this SQL as well as SQL generated and executed outside of Hibernate.

Logging User Clicks

2008-09-14 08:20:50,861 INFO ac210023:WebContainer : 4 [com.teradata.trm.common.web.struts.TRMRequestProcessor] --> 1 /trm/tablesAndFields.do create [1221292695038]

This is an example log entry. As with all log entries, it begins with the date/time, log level and the user name. These entries can be found by filtering (with logweb or similar tool) for mes-sages from the TRMRequestProcessor. You'll notice there is a --> which indicates the user has just clicked "into" this page. For each of these entries there is a corresponding <-- entry which indicates the log entry for when the server returns the page to the user. In this way you can identify all the log messages associated with each page, as the ones between these two log entries. After that, you see the url (/trm/tablesAndFields.do) and the dispatch action (create), which is to say the button that the user has clicked. So this log entry is when user ac210023 had clicked "create" on the tables and fields page.

2008-12-16 05:49:38,540 INFO kwells:WebContainer : 6 [com.teradata.trm.common.web.struts.TRMRequestProcessor] --> 1 /trm/extractFormat.do publish [1229424578540]
==================
method: POST
query string: &trm_currentBreadcrumb=0
parameters:
novalidate = true
url =
dispatch = publish
SAVE_FOLDERID = 20003d41rl9n
trm_currentBreadcrumb = 0
==================

This is another example. In this log entry you can see all the parameters that were passed on the request. So, in this case the user kwells was publishing an extract format into the folder with the id 20003d41r19n.

Logging Authentication Attempts

2008-12-16 11:09:22,608 WARN :WebContainer : 2 [org.acegisecurity.event.authentication.LoggerListener] Authentication event AuthenticationFailureBadCredentialsEvent: ac210023; details: org.acegisecurity.ui.WebAuthenticationDetails@380f4: RemoteIpAddress: 153.65.184.93; SessionId: ktmh6n_F_19ZsVrkWEhcAwG; exception: Bad cre-dentials

This is an example log entry. It shows an attempt by someone at IP address 153.65.184.93 to login with the userid ac210023. It reports that the login attempt failed because the credentials provided by the user (their username/password) were not correct. The user does not see this log message. They just see the message “Your login attempt was not successful, try again.”

2008-12-16 11:09:28,140 WARN :WebContainer : 2 [org.acegisecurity.event.authentication.LoggerListener] Authentication event AuthenticationSuccessEvent: ac210023; details: org.acegisecurity.ui.WebAuthenticationDetails@380f4: RemoteIpAddress: 153.65.184.93; SessionId: ktmh6n_F_19ZsVrkWEhcAwG

This is an example of a successful login event. It shows that someone at 153.65.184.93 logged in successfully with the userid ac210023. We never log the password used for either successful or failing login attempts.

Startup Logging

The following is an example log message captured in trm-system.log during the startup of TRM. It records all the settings from trm.properties, jdbc.properties and ldap.properties. Refer to the chapter on configuration settings to see the definition of each of these settings.

2008-12-10 09:41:07,765 -main: INFO  [TRMStartup]
********************************************************************************
TRM Startup properties

jdbc.properties :
base.db localtrm
dbcp.dataSource trmDataSource
dbcp.enablePreload false;
dbcp.fetchUpdatedSinceDaysAgo 365
dbcp.maxActive 50
dbcp.maxIdle 50
dbcp.maxWait 300
dbcp.tracing true
dbcp.validationQuery select current_timestamp dbcp.warehouseDataSource trmDataSource jdbc.driverClassName com.teradata.trm.common.qes.ioc.jdbc.QESDriver
jdbc.password *****
jdbc.url qes:jdbc:teradata://dbc/DATABASE=localtrm,TMODE=TERA
jdbc.username tduser
server dbc
trmrva.jdbc.driverClassName com.teradata.trm.common.qes.ioc.jdbc.QESDriver
trmrva.jdbc.password *****
trmrva.jdbc.url qes:jdbc:teradata://dbc/DATABASE=localtrm,TMODE=TERA
trmrva.jdbc.username tduser
trmva.jdbc.db localtrm

ldap.properties :
ldap.managerdn
ldap.managerpassword *****
ldap.searchBase
ldap.searchFilter
ldap.url ldap://continuum.sandiegoca.ncr.com:389/dc=teradata,dc=com
ldap.userdnpatterns uid={0},ou=Users

trm.properties :
segmentation.metadata.refreshInterval 600000
trm-create true
trm-data ./dist/trm
trm-help-link /trm-help/wwhelp.htm
trm-pe-cache-url
trm.allow-pe-jobs-to-run false
trm.external-validation-enabled true
trm.hostenv.webapp.base_url http://localhost:8080/trm
trm.query-banding-enabled false
trmrva.hostenv.webapp.base_url http://localhost:8080/trmrva
Tags (3)
1 REPLY

Re: TRM Server Logging - Advanced Topics

Hi Josh,

I do not know this is the right Place to ask this question or not.

I would love to hear approach to upgrade TCRM v5.2 batch (perl) to TRM v 6.0. (submit group).

Could you please inform me about Product manuals for TRM lastest version. I believe we have TRM 6.2 as latest.