Hi Theo,

Not sure if the SQL Logger is relevant here. In my experience you've to turn the root logger at least to WARN level to get an output of long running SQL statements.

cheers
Johann

As Johann said, the root logger is what is used to log long running queries. Since we log long running queries as a warning, you need the root logger at least at WARN. It is set to INFO out of the box which is what I would recommend most customers leave it at. To configure the root logger, in the Logging application you use the "Manage Maximo Root Logger" action. 

The SQL logger set to INFO means most queries should get logged but would not include execution times (just the query). 

I would also check the appender. Some customers disable the Console appender (which causes it to write to the SystemOut logs) in 7.6 because they want the Maximo logs to get written to other locations but that is needed for logging purposes in MAS. You can see the Appenders associated with the root logger in the same Manage Maximo Root Logger dialog. 

Finally, unrelated to your topic but I would avoid using 10 ms as the threshold. I assume you did that when you were not seeing any logs but if not, that would cause a lot of noise and slow down the application trying to write to the log file. We don't log queries based on query execution time on the database server but time it takes Maximo to complete the query. This is normally pretty close to the query execution times of the database server but in cases of high CPU for example (like hung threads), you'll see a lot of queries that look like they took a lot longer than they actually did on the database server. When your threshold is this low, you're likely going to see some false positives. And you're likely not going to be able to optimize these queries much further even if the time is accurate.

Utilities like Instana are best to analyze low execution time queries that run frequently. For example, in a REST API request you could have a child table get queried thousands of times which collectively adds up to a significant impact even though individual queries may complete quickly. Those help you see the true impact of a single request rather than trying to correlate thousands of log entries. Then you can look at ways that you could potentially address that impact, such as utilizing the REST API caching mechanisms. 

Hi Theo,

Not sure if the SQL Logger is relevant here. In my experience you've to turn the root logger at least to WARN level to get an output of long running SQL statements.

cheers
Johann

Johann/Steven,

The root logger level was the issue. In the 7.6.1.3 environment, it was set to INFO, and in the MAS 9 environment, it was set to ERROR. I set it to WARN in the MAS environment, and the execution times started appearing in the logs. Is it better to leave it at WARN or INFO for extended troubleshooting, where the logs will be left that way for hours or days (this is a non-production environment)?

Thanks,

-Theo Pozzy

As Johann said, the root logger is what is used to log long running queries. Since we log long running queries as a warning, you need the root logger at least at WARN. It is set to INFO out of the box which is what I would recommend most customers leave it at. To configure the root logger, in the Logging application you use the "Manage Maximo Root Logger" action. 

The SQL logger set to INFO means most queries should get logged but would not include execution times (just the query). 

I would also check the appender. Some customers disable the Console appender (which causes it to write to the SystemOut logs) in 7.6 because they want the Maximo logs to get written to other locations but that is needed for logging purposes in MAS. You can see the Appenders associated with the root logger in the same Manage Maximo Root Logger dialog. 

Finally, unrelated to your topic but I would avoid using 10 ms as the threshold. I assume you did that when you were not seeing any logs but if not, that would cause a lot of noise and slow down the application trying to write to the log file. We don't log queries based on query execution time on the database server but time it takes Maximo to complete the query. This is normally pretty close to the query execution times of the database server but in cases of high CPU for example (like hung threads), you'll see a lot of queries that look like they took a lot longer than they actually did on the database server. When your threshold is this low, you're likely going to see some false positives. And you're likely not going to be able to optimize these queries much further even if the time is accurate.

Utilities like Instana are best to analyze low execution time queries that run frequently. For example, in a REST API request you could have a child table get queried thousands of times which collectively adds up to a significant impact even though individual queries may complete quickly. Those help you see the true impact of a single request rather than trying to correlate thousands of log entries. Then you can look at ways that you could potentially address that impact, such as utilizing the REST API caching mechanisms. 

Hi Theo,

Not sure if the SQL Logger is relevant here. In my experience you've to turn the root logger at least to WARN level to get an output of long running SQL statements.

cheers
Johann

Hi Theo,

Not sure if the SQL Logger is relevant here. In my experience you've to turn the root logger at least to WARN level to get an output of long running SQL statements.

cheers
Johann