Question: How to record the execution time of sql?

[loktarjugg]

RT

[hedwigz]

Hey @loktarjugg :)
sqlcomment adds tracing data to your SQL query but it doesn't provide the monitoring capabilities such as recording time.
If you use something like Google Cloud SQL then they will provide you with the execution time.
What DB do you use and where is it hosted?

[loktarjugg]

Hey @loktarjugg :) sqlcomment adds tracing data to your SQL query but it doesn't provide the monitoring capabilities such as recording time. If you use something like Google Cloud SQL then they will provide you with the execution time. What DB do you use and where is it hosted?

thanks for your reply, i`m using Alibaba Cloud based MYSQL, and i want to decide whether to print the log based on the execution time of sql

[hedwigz]

@loktarjugg The easiest and most "dirty" way to accomplish this is by measuring the time before the query and after the query. Of course, this includes a full roundtrip to the DB and it isn't the actual query time but it is easiest to implement and can cover most use-cases.
In most use cases when troubleshooting SQL performance you should be utilizing the monitoring capabilities of your cloud provider. see https://www.alibabacloud.com/help/en/apsaradb-for-rds/latest/use-the-sql-explorer-feature-on-an-apsaradb-rds-for-mysql-instance for example.

[loktarjugg]

@loktarjugg The easiest and most "dirty" way to accomplish this is by measuring the time before the query and after the query. Of course, this includes a full roundtrip to the DB and it isn't the actual query time but it is easiest to implement and can cover most use-cases. In most use cases when troubleshooting SQL performance you should be utilizing the monitoring capabilities of your cloud provider. see https://www.alibabacloud.com/help/en/apsaradb-for-rds/latest/use-the-sql-explorer-feature-on-an-apsaradb-rds-for-mysql-instance for example.

Actually, I am using this capability provided by Alibaba Cloud, but it can't do the associated trace i can't trace the complete call chain very well

[hedwigz]

@loktarjugg oh cool !
Does Alibaba cloud support SQL comments?

[loktarjugg]

@loktarjugg oh cool ! Does Alibaba cloud support SQL comments?

yes, alibaba cloud support it by the way, the SQL exporter provided by Alibaba Cloud will be truncated when the characters are larger than 2000

[hedwigz]

Great! @loktarjugg
Could you provide a link to their docs?
And any details on what you did that didn't work?
How does the query you output looks like? (you can use client.Debug() see example)

[loktarjugg]

Great! @loktarjugg Could you provide a link to their docs? And any details on what you did that didn't work? How does the query you output looks like? (you can use client.Debug() see example)

ok, but the docs is written in chinese, In the screenshot below, I'll translate the key sentences

it means: SQL statements greater than 2000 will be truncated

I'm implementing it in"dirty" way

sqlcomment.NewDriver(dialect.DebugWithContext(drv, func(ctx context.Context, i ...interface{}) {
        start := time.Now()
        defer func() {
            logx.WithContext(ctx).Infof("the sql exec time %s", time.Since(start))
        }()
        logx.WithContext(ctx).Infov(i)
    }),
        sqlcomment.WithDriverVerTag(),
        sqlcomment.WithTags(sqlcomment.Tags{
            sqlcomment.KeyApplication: "test",
            sqlcomment.KeyFramework:   "net/http",
        }))

output:

{"@timestamp":"2022-04-19T22:48:58.953+08:00","level":"info","content":["driver.Query: query=SELECT DISTINCT `project`.`xy_project_user`.`id`, `project`.`xy_project_user`.`project_id` FROM `project`.`xy_project_user` WHERE (`project`.`xy_project_user`.`user_id` = ? AND `project`.`xy_project_user`.`status` = ?) AND `project`.`xy_project_user`.`deleted_at` IS NULL /*application='project.rpc',db_driver='ent:v0.10.2-0.20220321093754-edd968490ea2',framework='net/http'*/ args=[340632127 1]"],"trace":"e5e95c3961705d1f6806cb08a41ccd3f","span":"d39b8fde88d426b2"}
{"@timestamp":"2022-04-19T22:48:58.953+08:00","level":"info","content":"the sql exec time 227.375µs","trace":"e5e95c3961705d1f6806cb08a41ccd3f","span":"d39b8fde88d426b2"}

Thanks again for your reply

[hedwigz]

it means: SQL statements greater than 2000 will be truncated

Yes, but that only means that if your query statement is huge it won't be logged in fully in the audit logs. Why is that an issue?

I'm implementing it in"dirty" way

Looks great. Looks like you are using a tracer (which one?) but you haven't integrated it with sqlcomment so the tracing info cannot be consumed by Alibaba.
There's an example here for integrating with OpenTelemetry but OpenCensus is also supported

[loktarjugg]

Yes, but that only means that if your query statement is huge it won't be logged in fully in the audit logs. Why is that an issue?

As you said, this is not an issue, I want to express that it has this limitation

Looks great. Looks like you are using a tracer (which one?) but you haven't integrated it with sqlcomment so the tracing info cannot be consumed by Alibaba.

I'm using jeager to track, and i can be confident that my trace is correct because I wrap logx

As there is no better way to print the execution time, I think we can close this issue. thank you very much for your patient reply.

[hedwigz]

@loktarjugg happy to help :)