How to correlate log entries coming from CloudSql

[BSA]

I have enabled slow-logs ,long_query_time flags in Cloud-SQL for mysql instances to track the queries more than a threshold.  The log entries are emitted by this log from Cloud-SQL 

logs/cloudsql.googleapis.com%2Fmysql-slow.log

The Logentries are displayed in the stack-driver console individually like this

For each query 5 rows are displayed individually.   These queries are stored in a bigquery table through a sink created as the end-result.

Problem: I need to find individual queries  and co-relate them with the duration for each query. The 3rd row in the picture above contains the Query_time which is duration for running the query and the 5th row contains the actual query. I need to find a relation between the 2 rows as they are stored in different rows in the big-query for each of the log entries.

Also different servers may be sending these messages so when they are stored in bigquery i need to plot the queries against the correct servers.

I find a field for the 3rd row insertid: 2#272076179787#5485349422653289102#slow#1619605945744699000#00000000000015b9-0-0@a1

for the 5th row: 2#272076179787#5485349422653289102#slow#1619605945744699000#00000000000016ee-0-0@a1

I find the insertid same till this part #slow for  all the logs entries captured 

2#272076179787#5485349422653289102#slow

What follows after this is the timestamp value 1619605945744699000

but the last part containing #00000000000015b9-0-0@a1 is different for all the log entries.  Can anyone please tell me what is the insertid column and how it is separated by #? Also how can i make a relation between the 3rd Row which contains the query_time and the 5th_row which contains the query string? 

Note: If i try to match with time-stamp on the entries if timestamp matches for more than 1 query then it will not be correct.

Thanks a lot for your help and suggestions.

Regards

Bharath

[Igor Peshansky]

Bharath,

In general, the structure of the insertid is opaque — all you're guaranteed is that these values would correlate with the order of log entries (e.g., lines in an on-disk file) within the same resource. In this case, it looks like they are generated by the Cloud SQL infrastructure. The prefix you quoted ("2#272076179787#5485349422653289102#slow") seems to be "2#<project_id>#<instance_id>#slow", so you can identify logs coming in from a single MySQL instance. I would assume that the lines for a specific query in the MySQL slow log on one instance are grouped together, appearing as a contiguous chunk within the log file. So sorting the log entries by insertid in alphanumeric order should give you those groups of 5 lines per query, and you can extract the latency from that.

Also, have you seen https://cloud.google.com/community/tutorials/stackdriver-monitor-slow-query-mysql ?

Hope this helps,

        Igor

--
© 2021 Google Inc. 1600 Amphitheatre Parkway, Mountain View, CA 94043
 
Email preferences: You received this email because you signed up for the Google Stackdriver Discussion Google Group (google-stackdr...@googlegroups.com) to participate in discussions with other members of the GoogleStackdriver community.
---
You received this message because you are subscribed to the Google Groups "Google Stackdriver Discussion Forum" group.
To unsubscribe from this group and stop receiving emails from it, send an email to google-stackdriver-d...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/google-stackdriver-discussion/d4a77785-18fd-4f5b-9eda-31e6c0025112n%40googlegroups.com.

[BSA]

Thank you Igor. Can you please tell me why it is beginning with 2# and the last part which contains #00000000000015b9-0-0@a1?

Also will the timestamp after slow#1619605945744699000 will always be unique for each query?

Thanks

Bharath

[Igor Peshansky]

Sorry, as I said before, the insertId values are supposed to be opaque, and are not meant to be parsed. The only guarantee you get is that, for log entries from a given monitored resource, they reflect actual log ordering when put in alphanumeric order.

My suggestion is to continue treating them as opaque, and simply use them to order the logs. Also, the article I referenced may give you a way to do what you want without needing to rely on log ordering at all — have you tried that?

        Igor

To view this discussion on the web visit https://groups.google.com/d/msgid/google-stackdriver-discussion/c8d1a5a2-c83b-400a-950b-a989459012efn%40googlegroups.com.