Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log JdbcClient invocations #1274

Merged

Conversation

kokosing
Copy link
Member

@kokosing kokosing commented Aug 10, 2019

INFO	dispatcher-query-36	io.prestosql.event.QueryMonitor	TIMELINE: Query 20190810_204626_01200_jd4ta :: Transaction:[3311da6d-3e21-418f-af97-2237f2096afd] :: elapsed 14ms :: planning 3ms :: waiting 3ms :: scheduling 4ms :: running 6ms :: finishing 1ms :: begin 2019-08-10T15:46:26.967-05:00 :: end 2019-08-10T15:46:26.981-05:00
2019-08-10T15:46:27.023-0500	DEBUG	Query-20190810_204627_01201_jd4ta-710	io.prestosql.plugin.jdbc.JdbcClient	Invocation of getTableHandle(identity=JdbcIdentity{user=user, extraCredentials=[]}, schemaTableName=tpch.orders) succeeded in 455.84us
2019-08-10T15:46:27.025-0500	DEBUG	Query-20190810_204627_01201_jd4ta-710	io.prestosql.plugin.jdbc.JdbcClient	Invocation of getColumns(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, tableHandle=tpch.orders TEST-7768427258835813315.TPCH.ORDERS) succeeded in 1.89ms
2019-08-10T15:46:27.028-0500	DEBUG	Query-20190810_204627_01201_jd4ta-638	io.prestosql.plugin.jdbc.JdbcClient	Invocation of getTableStatistics(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, handle=tpch.orders TEST-7768427258835813315.TPCH.ORDERS, tupleDomain=TupleDomain{ALL}) succeeded in 8.73us
2019-08-10T15:46:27.029-0500	DEBUG	Query-20190810_204627_01201_jd4ta-638	io.prestosql.plugin.jdbc.JdbcClient	Invocation of getSplits(identity=JdbcIdentity{user=user, extraCredentials=[]}, tableHandle=tpch.orders TEST-7768427258835813315.TPCH.ORDERS) succeeded in 9.14us
2019-08-10T15:46:27.030-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of getConnection(identity=JdbcIdentity{user=user, extraCredentials=[]}, split=io.prestosql.plugin.jdbc.JdbcSplit@69792765) succeeded in 83.35us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=-5, jdbcTypeName=BIGINT, columnSize=19, decimalDigits=0}) succeeded in 19.76us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=-5, jdbcTypeName=BIGINT, columnSize=19, decimalDigits=0}) succeeded in 6.33us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=12, jdbcTypeName=VARCHAR, columnSize=1, decimalDigits=0}) succeeded in 7.27us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=8, jdbcTypeName=DOUBLE, columnSize=17, decimalDigits=0}) succeeded in 5.05us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=91, jdbcTypeName=DATE, columnSize=10, decimalDigits=0}) succeeded in 3.33us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=12, jdbcTypeName=VARCHAR, columnSize=15, decimalDigits=0}) succeeded in 6.84us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=12, jdbcTypeName=VARCHAR, columnSize=15, decimalDigits=0}) succeeded in 4.17us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=4, jdbcTypeName=INTEGER, columnSize=10, decimalDigits=0}) succeeded in 2.95us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of toPrestoType(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, typeHandle=JdbcTypeHandle{jdbcType=12, jdbcTypeName=VARCHAR, columnSize=79, decimalDigits=0}) succeeded in 3.35us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of buildSql(session=FullConnectorSession{queryId=20190810_204627_01201_jd4ta, user=user, source=test, timeZoneKey=Pacific/Apia, locale=en, startTime=1565469987022, properties={}}, connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=, split=io.prestosql.plugin.jdbc.JdbcSplit@69792765, table=tpch.orders TEST-7768427258835813315.TPCH.ORDERS, columns=[ORDERKEY:bigint:Optional[BIGINT], CUSTKEY:bigint:Optional[BIGINT], ORDERSTATUS:varchar(1):Optional[VARCHAR], TOTALPRICE:double:Optional[DOUBLE], ORDERDATE:date:Optional[DATE], ORDERPRIORITY:varchar(15):Optional[VARCHAR], CLERK:varchar(15):Optional[VARCHAR], SHIPPRIORITY:integer:Optional[INTEGER], COMMENT:varchar(79):Optional[VARCHAR]]) succeeded in 49.28us
2019-08-10T15:46:27.031-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcRecordCursor	Executing: prep4600: SELECT "ORDERKEY", "CUSTKEY", "ORDERSTATUS", "TOTALPRICE", "ORDERDATE", "ORDERPRIORITY", "CLERK", "SHIPPRIORITY", "COMMENT" FROM "TEST-7768427258835813315"."TPCH"."ORDERS"
2019-08-10T15:46:27.065-0500	DEBUG	20190810_204627_01201_jd4ta.1.0-0-582	io.prestosql.plugin.jdbc.JdbcClient	Invocation of abortReadConnection(connection=conn2649: url=jdbc:h2:mem:test-7768427258835813315 user=) succeeded in 7.12us
2019-08-10T15:46:27.072-0500	I

@cla-bot cla-bot bot added the cla-signed label Aug 10, 2019
@kokosing kokosing requested review from findepi, chancez and sopel39 and removed request for chancez August 10, 2019 05:51
This is useful class, that could also be used in other connectors.
@kokosing kokosing force-pushed the origin/master/152_logging_invocations branch from 0b99a2f to 00c7445 Compare August 10, 2019 20:58
@kokosing kokosing changed the title Move LoggingInvocationHandler to presto-plugin-toolkit Log JdbcClient invocations Aug 10, 2019
@kokosing kokosing merged commit 0d02779 into trinodb:master Aug 12, 2019
@kokosing kokosing deleted the origin/master/152_logging_invocations branch August 12, 2019 11:06
@kokosing kokosing mentioned this pull request Aug 12, 2019
7 tasks
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.

None yet

2 participants