Skip to content

Silence QueryRunner startup logs in tests#10689

Merged
kokosing merged 1 commit intotrinodb:masterfrom
nineinchnick:reduce-test-query-runner-logging
Apr 1, 2022
Merged

Silence QueryRunner startup logs in tests#10689
kokosing merged 1 commit intotrinodb:masterfrom
nineinchnick:reduce-test-query-runner-logging

Conversation

@nineinchnick
Copy link
Copy Markdown
Member

@nineinchnick nineinchnick commented Jan 19, 2022

Silence QueryRunner startup logs to make it easier to browse logs in case of a failure. For example, the output of the TestCachingHiveMetastoreWithQueryRunner test from trino-hive-hadoop2 module goes down from 2348 to 172 lines. Silenced info should be repetitive across different CI runs and not convey information specific to tests. This includes non-default server configuration properties, which are passed explicitly in the QueryRunner builder.

Silenced logger examples:
org.glassfish.jersey.internal.inject.Providers and org.glassfish.jersey.internal.Errors:

2022-01-19T07:36:49.107-0600 WARNING A provider io.airlift.discovery.server.ServiceResource registered in SERVER runtime does not implement any provider interfaces applicable in the SERVER runtime. Due to constraint configuration problems the provider io.airlift.discovery.server.ServiceResource will be ignored. 

org.eclipse.jetty.server:

2022-01-19T07:36:49.233-0600 INFO Started o.e.j.s.ServletContextHandler@5e0edcd1{/,null,AVAILABLE,@http}
2022-01-19T07:36:49.240-0600 INFO Started http@106b1b81{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:56868}
2022-01-19T07:36:49.241-0600 INFO Started @5157ms

io.airlift.bootstrap, io.trino.server.PluginManager:

2022-01-19T07:36:49.345-0600 INFO Life cycle starting...
2022-01-19T07:36:49.346-0600 INFO Life cycle started
2022-01-19T07:36:53.748-0600 INFO Registering connector tpch
2022-01-19T07:36:53.750-0600 INFO Registering connector tpch
2022-01-19T07:36:53.751-0600 INFO Registering connector tpch
2022-01-19T07:36:53.787-0600 INFO Registering connector clickhouse
2022-01-19T07:36:53.787-0600 INFO Registering connector clickhouse
2022-01-19T07:36:53.788-0600 INFO Registering connector clickhouse

Bootstrap:

2022-01-19T07:36:53.862-0600 INFO PROPERTY                                                   DEFAULT      RUNTIME                             DESCRIPTION
2022-01-19T07:36:53.863-0600 INFO clickhouse.map-string-as-varchar                           false        true                                Map ClickHouse String and FixedString as varchar instead of varbinary

Previous failed attempts to reduce amount of logs:

@cla-bot cla-bot bot added the cla-signed label Jan 19, 2022
@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch from 38ffd6b to 88d2139 Compare January 19, 2022 17:03
@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch from 88d2139 to f25f62c Compare January 20, 2022 09:50
@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch 2 times, most recently from e08ff45 to da81659 Compare January 20, 2022 10:53
@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch 3 times, most recently from 4b42b87 to 9c6a227 Compare January 27, 2022 15:17
@nineinchnick nineinchnick requested a review from electrum January 27, 2022 15:39
Copy link
Copy Markdown
Member

@kokosing kokosing left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good. What improvement did we get?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is not needed. It is already logged.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR disables the regular Bootstrap logger that would log this. This has been added since the DB name is random. It gets logged as:

 2022-01-27T11:23:16.813-0600	INFO	pool-4-thread-1	io.trino.plugin.sqlserver.SqlServerQueryRunner	sqlserver catalog properties: {connection-*** connection-url=jdbc:sqlserver://localhost:49165;database=database_e6cbbe8278d54bd791b508e1ef187d3d;lockTimeout=60000, connection-user=sa, allow-drop-table=true}

You can see that there are no other occurrences of the db name in the CI log, except for failed query error messages.

@nineinchnick
Copy link
Copy Markdown
Member Author

nineinchnick commented Jan 31, 2022

Looks good. What improvement did we get?

See the PR description - some jobs go down from thousands to hundreds of log lines.

It should also make it a bit easier to search for keywords like "failure" or "failed" since configuration properties won't be matched.

@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch from 9c6a227 to 68e04bb Compare February 23, 2022 09:32
@nineinchnick
Copy link
Copy Markdown
Member Author

@electrum your requested changes have been applied, PTAL

@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch from 68e04bb to a631fc5 Compare March 29, 2022 13:18
Copy link
Copy Markdown
Member

@kokosing kokosing left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

% minor comments. Let me know once it is ready to merge.

@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch 2 times, most recently from fb5d613 to 5f5370f Compare March 31, 2022 13:48
@nineinchnick nineinchnick force-pushed the reduce-test-query-runner-logging branch from 5f5370f to 6a9aa57 Compare March 31, 2022 18:16
@kokosing kokosing merged commit 9092f0d into trinodb:master Apr 1, 2022
@github-actions github-actions bot added this to the 376 milestone Apr 1, 2022
@nineinchnick nineinchnick deleted the reduce-test-query-runner-logging branch April 4, 2022 09:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Development

Successfully merging this pull request may close these issues.

6 participants