Print processed_rows in expensive query logs

[ekexium]

Enhancement

For expensive queries, we often care about its progress and ETA.
By printing the number of processed rows (affected rows) in expensive query logs, it's easier to have an estimate of the progress.
The value might be the AffectedRows in StmtCtx.

[jayendrapawar]

@ekexium anticipating the types of changes indicated below

[2024-02-23 10:15:00] Expensive Query: SELECT * FROM some_table WHERE some_condition;
[2024-02-23 10:15:05] Progress: Affected Rows - 10000
[2024-02-23 10:15:10] Progress: Affected Rows - 25000
[2024-02-23 10:15:15] Progress: Affected Rows - 50000
[2024-02-23 10:15:20] Progress: Affected Rows - 75000
[2024-02-23 10:15:25] Progress: Affected Rows - 100000

[ekexium]

@jayendrapawar I assume the enhancement should be extra fields to the existing expensive query logs. Now it looks like

[2020/02/05 15:32:25.096 +08:00] [WARN] [expensivequery.go:167] [expensive_query] [cost_time=60.008338935s] [wait_time=0s] [request_count=1] [total_keys=70] [process_keys=65] [num_cop_tasks=1] [process_avg_time=0s] [process_p90_time=0s] [process_max_time=0s] [process_max_addr=10.0.1.9:20160] [wait_avg_time=0.002s] [wait_p90_time=0.002s] [wait_max_time=0.002s] [wait_max_addr=10.0.1.9:20160] [stats=t:pseudo] [conn_id=60026] [user=root] [database=test] [table_ids="[122]"] [txn_start_ts=414420273735139329] [mem_max="1035 Bytes (1.0107421875 KB)"] [sql="insert into t select sleep(1) from t"]

[jayendrapawar]

Expected Changes : [affected_rows=<Numbers of Rows Affected] in addition to existing logs.

Expected Result:
[2020/02/05 15:32:25.096 +08:00] [WARN] [expensivequery.go:167] [expensive_query] [cost_time=60.008338935s] [wait_time=0s] [request_count=1] [total_keys=70] [process_keys=65] [num_cop_tasks=1] [process_avg_time=0s] [process_p90_time=0s] [process_max_time=0s] [process_max_addr=10.0.1.9:20160] [wait_avg_time=0.002s] [wait_p90_time=0.002s] [wait_max_time=0.002s] [wait_max_addr=10.0.1.9:20160] [stats=t:pseudo] [conn_id=60026] [user=root] [database=test] [table_ids="[122]"] [txn_start_ts=414420273735139329] [mem_max="1035 Bytes (1.0107421875 KB)"] [sql="insert into t select sleep(1) from t"] [affected_rows=1000]

I'd like to work on this fix. Please assign me @ekexium

[ekexium]

@jayendrapawar Hi do you still have time for this?

[jayendrapawar]

Having issue with local setup to test, I'll pick it up later

…

On Tue, Mar 19, 2024 at 1:09 PM ekexium ***@***.***> wrote: @jayendrapawar <https://github.com/jayendrapawar> Hi do you still have time for this? — Reply to this email directly, view it on GitHub <#51240 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AOVBJDMXRYDV5A3AESKLRTLYY7TRRAVCNFSM6AAAAABDUNMDHKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDAMBWGEZDEOBZG4> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[ekexium]

Hey @jayendrapawar, thank you for your interest in this issue.
Given the time-sensitive nature of this feature, I'll go ahead and work on it to ensure we meet our project deadlines. Your efforts in our community are still highly valued, and I look forward to your future contributions. Please feel free to pick up any other open issues!