Retrieve Job log information from SQL – IBM i

Job log

Job log provides information about the job including any errors and is extremely helpful to analyze what has happened. 

Sometimes, it becomes difficult to check all the messages in the job log (especially when the job is running for longer or if there are many messages in the job log) just by using DSPJOB/WRKJOB. 

SQL table function JOBLOG_INFO provides another way of accessing job log from SQL session. Each message from the job log is returned in a new row. This gives the flexibility to query and select the messages as required (E.g.: Requests, Diagnostic Informational etc). 

This table function requires one mandatory parameter Job name and one optional parameter Ignore errors. 

Job Name (JOB_NAME) – Qualified job name (job number/user/job name). For the job log of current job, ‘*’ can be specified. 

Ignore Errors (IGNORE_ERRORS) – This parameter accepts either ‘YES’ or ‘NO’. This determines what needs to be done in case of any error in Query execution. 
NO (default) – An error is returned. YES – A warning is returned. No rows are returned when an error is encountered. 

Let’s have a quick look at a query to retrieve the job log of current session. 

1

2

3

4

5

6

7

8

SELECT ORDINAL_POSITION,

       MESSAGE_TYPE, 

       MESSAGE_TIMESTAMP, 

       FROM_LIBRARY, 

       FROM_PROGRAM, 

       MESSAGE_TEXT, 

       MESSAGE_SECOND_LEVEL_TEXT 

FROM TABLE(QSYS2/JOBLOG_INFO(JOB_NAME => ‘*’))

In the above query, 
Lines 1 – 7: Few columns from the table function JOBLOG_INFO. More info on each of these columns can be found below. Line – 8: JOB_NAME parameter is being passed with ‘*’ to retrieve the job log of current job. 

Below are the few columns used in the above query. 

ORDINAL_POSITION – A unique number of each row in the job log. First message in the job log would contain ‘1’ and incremented by ‘1’ for the next message. 

MESSAGE_TYPE – Type of message from the job log. Below are the valid values for this column. 
COMMANDCOMPLETIONDIAGNOSTICESCAPEINFORMATIONALINQUIRYNOTIFYREPLYREQUESTSCOPESENDER
MESSAGE_TIMESTAMP – Timestamp when the message was written to Job log. 

FROM_LIBRARY – The library containing the program or service program that sent the message.

FROM_PROGRAM – The program or service program that sent the message.

MESSAGE_TEXT – First level of text message. 

MESSAGE_SECOND_LEVEL_TEXT – Second level of text message. 

There are many other useful columns present in this table function. Full list of columns can be found here.  

Above query returns all the messages in the job log. We can also select the records based on the message type or any other columns as required.

1

2

3

4

5

6

7

8

9

SELECT ORDINAL_POSITION,

       MESSAGE_TYPE, 

       MESSAGE_TIMESTAMP, 

       FROM_LIBRARY, 

       FROM_PROGRAM, 

       MESSAGE_TEXT, 

       MESSAGE_SECOND_LEVEL_TEXT 

FROM TABLE(QSYS2/JOBLOG_INFO(JOB_NAME => ‘*’))

WHERE  MESSAGE_TYPE = ‘DIAGNOSTIC’ ;

In the above query, 
Line – 9: We are only retrieving the diagnostic messages by adding condition on MESSAGE_TYPE. 

This query would only return the diagnostic messages along with it’s position in the job log (ORDINAL_POSITION) and timestamp the message was sent to job log (MESSAGE_TIMESTAMP).


In both the queries mentioned above, we are only retrieving the job log of the current job by passing ‘*’ against the job name. 

Let’s have a look at retrieving the job log of other job. 

1

2

3

4

5

6

7

8

SELECT ORDINAL_POSITION,

       MESSAGE_TYPE, 

       MESSAGE_TIMESTAMP, 

       FROM_LIBRARY, 

       FROM_PROGRAM, 

       MESSAGE_TEXT, 

       MESSAGE_SECOND_LEVEL_TEXT 

FROM TABLE(QSYS2/JOBLOG_INFO(JOB_NAME => ‘730621/REDDYP/QPAD202846’))

In the above query, 
Lines 1 – 7: Columns from the table function as required. Line – 8: We are passing qualified job name with job number, user and job name. 

By adding condition on the columns we can extract the specific information required. 

E.g.: List of commands executed in an interactive session. 

This can be achieved by adding condition on MESSAGE_TYPE. 

1

2

3

4

5

6

7

8

SELECT MESSAGE_TYPE, 

       MESSAGE_TIMESTAMP, 

       FROM_LIBRARY, 

       FROM_PROGRAM, 

       MESSAGE_TEXT, 

       MESSAGE_SECOND_LEVEL_TEXT 

FROM TABLE(QSYS2/JOBLOG_INFO(JOB_NAME => ‘730621/REDDYP/QPAD202846’))

WHERE  MESSAGE_TYPE = ‘REQUEST’ 

Above query can be amended to fetch the first command or last command etc. 

For some reason, if the job doesn’t present in the system or any other errors occurs while running the above query, an error is returned. This may cause an issue when running these query as part of procedures or function.

To avoid this, we could consider using optional parameter IGNORE_ERRORS (YES). By passing this parameter, JOBLOG_INFO would only return a warning and no records are returned. 

1

2

3

4

5

6

7

8

9

SELECT MESSAGE_TYPE, 

       MESSAGE_TIMESTAMP, 

       FROM_LIBRARY, 

       FROM_PROGRAM, 

       MESSAGE_TEXT, 

       MESSAGE_SECOND_LEVEL_TEXT 

FROM TABLE(QSYS2/JOBLOG_INFO(JOB_NAME => ‘730621/REDDYP/QPAD202846’, IGNORE_ERRORS => ‘YES’))

WHERE  MESSAGE_TYPE = ‘REQUEST’ 

If this parameter (IGNORE_ERRORS) is not passed, default value ‘NO’ is considered and an error is returned for any error while running the query. 

If you have any Suggestions or Feedback, Please leave a comment below or use Contact Form. 

Node.js Reference Architecture: Logging in Node.js

Understanding what tools to use for logging in your Node.js applications and deployments is a critical step to ensuring they run well in production. This article discusses why the Node.js Reference Architecture recommends Pino as a great tool for logging in your Node.js application. The article concludes by walking you through an example of logging in a Node.js application in production.

Because the Node.js ecosystem offers so many packages in the npm registry, the Node contributors at Red Hat and IBM collaborated to create a reference architecture for Node.js where we highlight our recommendations based on our use. Read our intro Welcome to the Node.js Reference Architecture. It’s important that we stress that this recommendation is only meant to be a starting point for teams who want an opinion. There are other good logging options, and we don’t think teams need to change what they are already using in production and understand there can be good reasons to use something else.

Defining requirements for a logging tool

Before we could decide on what tool to recommend, we had to define the requirements for a good logging tool. We quickly agreed that the logger we chose should be:

Able to support structured logging/JSON format
Simple. With the availability of modern log repositories and viewers, we wanted to select a simple logger and recommend doing any complex filtering/handling outside of the Node.js process itself.
Actively maintained. This might seem obvious, but in this process, we realized that one team was using a logger that was no longer maintained. That’s certainly a reminder to keep an eye on your dependencies!

Why we chose Pino for logging

When we looked at the loggers the team members had experience with, there were a number of good options. We agreed on Pino for the following reasons:

Large-scale deployment success. Some of our production Node.js deployments already used Pino, so we have seen it succeed in real-world, large-scale deployments.
Sample and starter kit support. We already used Pino in a number of our samples and starters, so we were confident in its use for other teams.
Ease of use. Of the choices which supported Structured/JSON logging, Pino was the easiest for developers to start with. Although other options had fuller features, our belief that the logging option should be simple made us choose Pino instead of tools that might have features that aren’t needed.

Logging guidance

Our team decided on these basic guidance for logging errors in Node.js.

Send logs to standard out (Stdout). Use log aggregation tools to collect logs across processes, containers, and applications. All log processing should be done in a separate process.
Plan for a final resting place for log data. After 7 days, migrate log data to a lower cost storage. Manual retrieval is likely okay.
Add code to your application that allows logger.level to be set through an environment variable so that can be easily changed in container environments.
Use the redaction option to ensure sensitive data is not logged.
Limit the use of warn, error, and fatal levels to information which must always be logged.
Limit the use of info level to important information which can always be logged without introducing significant overhead. Customer-usage REST response logs (status/duration/URL) are recommended at this level for security auditing purposes.
Don’t throw and catch multiple errors. Throw once and catch/log at the highest level.

Real-world implementation of logging guidance

How do all these recommendations translate to real-world implementation? While the reference architecture sticks to concise recommendation, in this series, we want to expand a bit on the “why” behind our decision and to offer real-world examples of Node.js usage key concepts. This section details an IBM team’s implementation of these logging principles.

At this point Jim will share some of his more detailed experience from the IBM team that he is part of. Hopefully you’ll see how this perspective (along with others) results in the guidance and recommendation above.

Structured logging

A good logging strategy ensures that your logs are structured as carriage-return separated JSON blocks. This makes it easy for modern log repositories and viewers like LogDNA, Kibana, and Loggly to sort and filter various keywords in the JSON block. Even though modern logging repositories will turn string-based logs into JSON logs internally, providing JSON logs allows your applications to define their own custom keywords to sort/search with. It’s still common for shell scripts at the startup of a container to not use JSON logs, but to have a Node.js process in the same container use JSON logging after startup.

Development team sometimes push back against this because logs become harder to read when looking at them in a log file. A workaround we use is to use a log formatting method to sort specific fields to come in the same order as the non-JSON format. For example, first in the serialized JSON block is the timestamp, level, then message, with the rest of the keywords following them in any order.

Modern logging repositories handle the storage, filtering, and visualization of the logs that are generated by your application. This is an example of viewing logs that have been fed by the IBM Log Analysis service into LogDNA:

Note the graphql_call and transaction_id fields you can see here will be discussed in the section on using Logging formatters and thread-local variables

Static and dynamic log-level management

Early on, you should define a standard set of log levels that application developers should use. These may differ based on the logging tool that you use, but having them well defined helps ensure you have consistent use across your team.

Your team should review all the spots an application will generate an error log to confirm that the different variables needed to debug that error path are logged. Doing so helps you avoid needing to recreate the problem later with more detailed logging. Your goal should be “First Failure Data Capture”, so that you don’t have to recreate problems in order to debug customer issues. If additional data is required to debug a customer issue, a separate issue should be created to track adding additional logging to cover the additional data that was needed in that error path.

As mentioned in the guidance above, the initial application logging level is determined by environment variable setting. However, we found certain “corrupted state” cases where we wanted to change the logging level to be more verbose without having to redeploy or restart the application. This happened when we started to have occasional database or queuing-service errors. We used a hidden REST endpoint that was not exposed publicly, but we could still invoke it using admin-routing tools like “kubectl proxy. The REST endpoint could communicate with the logging library to change the logging level dynamically.

Logging formatters and thread-local variables

Logging formatters are customizable methods that allow applications to add or transform data into the outputted JSON logs. Using formatters to export specific thread-local variables into the logs is a powerful technique for getting useful data that your support teams will want in all your logs.

For example, your support team may want the ability to filter logs to a specific failing REST call. Generating and storing a REST call’s trace-guid as a specific thread-local variable early in the REST processing (i.e. one of the first express middleware layers) allows anyone following logs in that REST call to then share that same trace-guid.

Customer error messages that provide that trace-guid make it simple for your support team to help the customer by filtering on that trace-guid to know exactly what the customer was doing. Otherwise, your support team has to hunt through logs for errors with similar timestamps, which is time-consuming. There are other ways to get cross-transaction information including distributed tracing, but it’s often still useful to include this kind of information in logs.

While Node.js doesn’t have obvious thread-local variable support like Python and Ruby, it does have that functionality exposed through its async-hooks library. Specifically, in the latest Node.js versions, you can access AsyncLocalStorage. These APIs are still experimental, but have been relatively stable over time. Otherwise, if you are still using older Node.js versions, you can use the cls-hooked library even back to Node v8 to get equivalent functionality.

Good thread-local variables to set in a common authentication-validation layer are things like user-guid (as opposed to an email address for GDPR compliance), organization-id, and if the user is an application admin. Those allow security auditors to trace what actions a specific user or organization has done, and validate your own admins have not taken inappropriate actions.

If your application uses GraphQL, you will notice that since all the GraphQL calls share the same entry endpoint, traditional REST trace logs are not very helpful as they won’t indicate which GraphQL call was invoked. We updated our GraphQL entry methods to set the method name in a thread-local variable so that we could include the name in the REST trace logs.

Logging the real IP

In most Kubernetes-based deployments, the source IP address that the applications see is just that of the ingress router and not from the caller. If you use a security firewall in front of your Kubernetes cluster (like this CloudFlare service offered in the IBM Cloud, the caller’s IP address will be stored in a ‘X-Forwarded-For’ header. The application endpoint handler can then extract and log the header instead of the REST request’s IP address. If you are not using a frontend like that, you may have to do specific configuration of your load-balancer and ingress to ensure the public IP is carried into the Kubernetes ingress and then into your application.

Configuration logging at startup

Dumping the application configuration settings at startup can help developers quickly identify and understand configuration problems, as opposed to guessing what the configuration “should be.” This provides key information that will save you time when investigating issues while limiting the potential for sensitive information in subsequent logs.

However, doing that can sometimes expose values like passwords or API keys that should normally remain secret. A common example of that is where a developer adds a “printenv” at the startup of the application to dump all the environment variables and inadvertently exposes the DB passwords also passed in as environment variables.

Node.js libraries like convict make it easy to define how configuration settings are imported. They allow the app to determine if the settings should be imported from mounted config-files or environment-variables or both. They also determine what elements in a configuration are optional, what default settings should be, and if a field’s value should be treated as sensitive (i.e. value is a password or apikey). As long as developers mark the password and apikey fields as sensitive in the definition of the configuration, then the configuration object can be safely logged at startup as the sensitive field values will be converted into asterisks.

Since we mentioned sensitive information, as outlined in the Reference Architecture, it’s also important to consider the information your application is gathering and use redaction to remove sensitive fields when you are logging that gathered information.

Summary

We hope this article has given you a bit more insight and background on the recommendations and guidance in the logging section of the Node.js Reference Architecture along with a deeper dive into some of the team’s experience and what they’ve found useful. We hope you join us for the next installment in the series.

In the meantime, if you’d like to catch up on what IBM and Red Hat are doing on the Node.js front you can check out these landing pages:

IBM Developer Node.js development
Red Hat Developer Node.js development

Verified by MonsterInsights