[TRAFODION-1488] Master exec log files do not have timestamps with the logged events

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.0-incubating
• Component/s: sql-exe
• Assignee: Roberta Marton
• Reporter: Weishiun Tsai
• Created: 09/Sep/15 18:46
• Updated: 16/Oct/15 22:53
• Resolved: 16/Oct/15 22:53

Description

Unlike the rest of the log files, master exec log files do not have any timestamps associated with the event logging in the file. This makes it really difficult to correlate the events with the timeline. This will particularly make customer support difficult if we get a set of log files from customers but can’t re-establish the event timeline. Since this problem does not exist in other types of log files generated using the same mechanism into the same directory. It’s assumed that it’s not a log4cpp problem in general, but how the master exec uses it instead.

To see this problem, issue a ‘cdl’ command on the shell prompt where your instance runs to go to the Trafodion log directory, and check the master exec log files with names like this: master_exec_*.log

Here is an example of a UDR log file, which has the proper timestamps:

[trafodion@nap001 logs]$ cat udr_0_19278.log
2015-08-17 16:22:52,679, INFO, SQL.UDR, Node Number: 0, CPU: 0, PIN: 37461, Process Name: $Z000VKB,,, A udrserver process is launched.
2015-08-17 16:22:52,679, INFO, SQL.UDR, Node Number: 0, CPU: 0, PIN: 37461, Process Name: $Z000VKB,,, A udrserver process is launched.
2015-08-17 16:24:19,579, INFO, SQL.UDR, Node Number: 0, CPU: 0, PIN: 38117, Process Name: $Z000W42,,, A udrserver process is launched.
2015-08-17 16:24:19,579, INFO, SQL.UDR, Node Number: 0, CPU: 0, PIN: 38117, Process Name: $Z000W42,,, A udrserver process is launched.

Here is an example of a master exec log file. It does not have any timestamps with the events.

[trafodion@nap001 logs]$ cat master_exec_0_14790.log
Node Number: 0, CPU: 0, PIN: 14790, Process Name: $Z000C2K,,, An executor process is launched.
Node Number: 0, CPU: 0, PIN: 14790, Process Name: $Z000C2K,,, An executor process is launched.
Node Number: 0, CPU: 0, PIN: 14790, Process Name: $Z000C2K, SQLCODE: 4082, QID: MXID11000014790212306885622799967000000000206U3333300_15__SQLCI_DML_LAST_, *** ERROR[4082] Object TRAFODION.SEABASE.DOESNOTEXIST does not exist or is inaccessible.
Node Number: 0, CPU: 0, PIN: 14790, Process Name: $Z000C2K, SQLCODE: 4082, QID: MXID11000014790212306885622799967000000000206U3333300_15__SQLCI_DML_LAST_, *** ERROR[4082] Object TRAFODION.SEABASE.DOESNOTEXIST does not exist or is inaccessible.

There is another JIRA report describing incorrect timestamps at https://issues.apache.org/jira/browse/TRAFODION-912 [^] ‘LP Bug: 1412806 - log4cpp : incorrect timestamp in logs for SQL info’. But the 2 problems are different. This bug report is created to track this particular missing timestamp issue.

---------------------------------------------------------------------------------

Here are the steps to see this problem:

(1) issue cdl from the shell prompt where your instance runs.
(2) Look at the master exec log files with names like master_exec_*.log