[Bug]: Cannot query statement_info record after CN restart #10090

DanielZhangQD · 2023-06-16T03:24:18Z

Is there an existing issue for the same bug?

I have checked the existing issues.

Environment

- Version or commit-id (e.g. v0.1.0 or 8b23a93): nightly-9207b269
- Hardware parameters:
- OS type:
- Others:

Actual Behavior

Delete the cache dir in the CN Pod
Delete the CN Pod
Run query after CN is started
Query the statement_info record but get empty record

企业微信截图_adf318b2-11d1-4200-bc1b-ed6249a895ca

an

Expected Behavior

Get the statement_info record successfully

Steps to Reproduce

See detail in `Actual Behavior`

Additional information

No response

gavinyue · 2023-06-16T03:25:04Z

测试aggr的时候，一并测试这个问题。

gavinyue · 2023-06-21T15:25:20Z

Still pending

gavinyue · 2023-06-26T06:18:24Z

Pending for the stmt_aggr pr merge. Stuck on dn oom

gavinyue · 2023-06-28T05:02:54Z

Looking into this issue.

gavinyue · 2023-06-30T01:04:49Z

Tried this on eks.
Delete the pod

Then run the query against the new pod. Can find the query in the statementinfo table

gavinyue · 2023-06-30T04:35:47Z

@DanielZhangQD Could you re-check after #10302 merge?

Thanks.

DanielZhangQD · 2023-07-03T02:09:34Z

OK

DanielZhangQD · 2023-07-03T08:23:51Z

@DanielZhangQD Could you re-check after #10302 merge?

Thanks.

@gavinyue It does not work:

MySQL [(none)]> pager cat > /dev/null;SELECT `statement_id`,`stats`,`duration`,`sql_source_type`,`account`,`response_at` FROM `system`.`statement_info` where status != 'Running' and account != 'sys' and account != 'mocloud_mo_ob' and response_at >= '2023-06-12 06:30:00' and response_at < '2023-06-12 06:35:00';pager;select last_query_id(-1);
PAGER set to 'cat > /dev/null'

Empty set (12.47 sec)

Default pager wasn't set, using stdout.
+--------------------------------------+
| last_query_id(-1)                    |
+--------------------------------------+
| 9a943a5a-1979-11ee-abfe-56c9384c6f1f |
+--------------------------------------+
1 row in set (0.01 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';

Empty set (8.20 sec)

MySQL [(none)]>
MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';
Empty set (1.03 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';
Empty set (0.68 sec)

MySQL [(none)]> pager cat > /dev/null;SELECT `statement_id`,`stats`,`duration`,`sql_source_type`,`account`,`response_at` FROM `system`.`statement_info` where status != 'Running' and account != 'sys' and account != 'mocloud_mo_ob' and response_at >= '2023-06-20 01:30:00' and response_at < '2023-06-20 02:30:00';pager;select last_query_id(-1);
PAGER set to 'cat > /dev/null'

6101126 rows in set (54.05 sec)

Default pager wasn't set, using stdout.
+--------------------------------------+
| last_query_id(-1)                    |
+--------------------------------------+
| 1996622d-197a-11ee-abfe-56c9384c6f1f |
+--------------------------------------+
1 row in set (0.00 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '1996622d-197a-11ee-abfe-56c9384c6f1f';
Empty set (1.54 sec)

gavinyue · 2023-07-06T13:22:15Z

Follow this today.

gavinyue · 2023-07-11T15:27:50Z

Pending

gavinyue · 2023-07-12T17:41:55Z

@DanielZhangQD It has a 15+second latentcy for the statement being inserted in the statementinfo table. Did you wait for 15 seconds before running the select query?

gavinyue · 2023-07-18T14:43:21Z

Discussed with the Daniel.

Need to confirm with him again whether this is still an issue.

gavinyue · 2023-07-21T15:27:30Z

Will follow with Daniel to see whether to close this issue or not.

gavinyue · 2023-07-26T15:26:15Z

Pending

gavinyue · 2023-07-31T14:52:31Z

Pending

gavinyue · 2023-08-03T14:33:37Z

Need to discuss with author whether this is still an issue.

gavinyue · 2023-08-08T15:09:28Z

Pending

gavinyue · 2023-08-11T15:23:44Z

Pending

gavinyue · 2023-08-16T15:26:18Z

需要和author 沟通

gavinyue · 2023-08-22T07:00:54Z

又测了一下，暂时还是无法复现这个问题

gavinyue · 2023-08-27T16:29:42Z

暂时还没找到合适的办法

gavinyue · 2023-11-21T15:08:22Z

Pending

gavinyue · 2023-11-25T18:06:02Z

pending

gavinyue · 2023-11-30T14:38:34Z

Pending

gavinyue · 2023-12-05T14:59:16Z

Pending

gavinyue · 2023-12-08T15:08:32Z

暂时没有解决

gavinyue · 2023-12-13T14:47:18Z

Pending

gavinyue · 2023-12-20T12:59:51Z

Pending.

gavinyue · 2023-12-25T15:04:32Z

Pending

gavinyue · 2023-12-29T14:39:06Z

Pending

gavinyue · 2024-01-04T13:29:07Z

Pending

gavinyue · 2024-01-10T15:09:06Z

Pending

gavinyue · 2024-01-15T11:45:54Z

Pending

gavinyue · 2024-01-19T15:18:43Z

Pending

xzxiong · 2024-01-24T10:43:51Z

明天统一梳理一下

xzxiong · 2024-01-25T12:36:36Z

从目前方案来说，本身无法保证时延。但目前对于这个模块的可观测性来说，太差了。dup #14298
Next: 优化整体的可观测性

sql 写入的延迟；
csv写入延迟；
csv回写mo的延迟
哪些文件回写过mo
...

xzxiong · 2024-01-30T10:09:28Z

pending

xzxiong · 2024-02-02T10:09:17Z

pending

xzxiong · 2024-02-08T02:13:15Z

pending

xzxiong · 2024-02-21T10:29:01Z

pending

xzxiong · 2024-02-26T10:17:15Z

pending

xzxiong · 2024-02-29T10:10:49Z

pending

xzxiong · 2024-03-01T07:49:45Z

@DanielZhangQD Could you re-check after #10302 merge?
Thanks.

@gavinyue It does not work:

MySQL [(none)]> pager cat > /dev/null;SELECT `statement_id`,`stats`,`duration`,`sql_source_type`,`account`,`response_at` FROM `system`.`statement_info` where status != 'Running' and account != 'sys' and account != 'mocloud_mo_ob' and response_at >= '2023-06-12 06:30:00' and response_at < '2023-06-12 06:35:00';pager;select last_query_id(-1);
PAGER set to 'cat > /dev/null'

Empty set (12.47 sec)

Default pager wasn't set, using stdout.
+--------------------------------------+
| last_query_id(-1)                    |
+--------------------------------------+
| 9a943a5a-1979-11ee-abfe-56c9384c6f1f |
+--------------------------------------+
1 row in set (0.01 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';

Empty set (8.20 sec)

MySQL [(none)]>
MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';
Empty set (1.03 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '9a943a5a-1979-11ee-abfe-56c9384c6f1f';
Empty set (0.68 sec)

MySQL [(none)]> pager cat > /dev/null;SELECT `statement_id`,`stats`,`duration`,`sql_source_type`,`account`,`response_at` FROM `system`.`statement_info` where status != 'Running' and account != 'sys' and account != 'mocloud_mo_ob' and response_at >= '2023-06-20 01:30:00' and response_at < '2023-06-20 02:30:00';pager;select last_query_id(-1);
PAGER set to 'cat > /dev/null'

6101126 rows in set (54.05 sec)

Default pager wasn't set, using stdout.
+--------------------------------------+
| last_query_id(-1)                    |
+--------------------------------------+
| 1996622d-197a-11ee-abfe-56c9384c6f1f |
+--------------------------------------+
1 row in set (0.00 sec)

MySQL [(none)]> select statement,stats,duration from system.statement_info where statement_id = '1996622d-197a-11ee-abfe-56c9384c6f1f';
Empty set (1.54 sec)

@DanielZhangQD 现在看是 OK的，目前新版本上未复现。
env: aliyun / new-dev
version: 1.1-dev

mysql> pager cat > /tmp/pager_20240301.txt;
PAGER set to 'cat > /tmp/pager_20240301.txt'
mysql> select * from system.statement_info where request_at > '2024-03-01 07:40:14.410045' and request_at < '2024-03-01 07:46:18.706256' and statement_id = '018df8f6-fcb6-72ea-b5d1-6ec8d1addacc'; pager; select last_query_id(-1); select sleep(15); select now();
1 row in set (0.16 sec)

Default pager wasn't set, using stdout.
+--------------------------------------+
| last_query_id(-1)                    |
+--------------------------------------+
| 018df8fc-2f17-72a0-a06d-ea51eba87e2e |
+--------------------------------------+
1 row in set (0.03 sec)

+-----------+
| sleep(15) |
+-----------+
|         0 |
+-----------+
1 row in set (15.03 sec)

+----------------------------+
| now()                      |
+----------------------------+
| 2024-03-01 07:48:28.444927 |
+----------------------------+
1 row in set (0.04 sec)

mysql> select statement_id, request_at, response_at, status, duration / 1e6 ms, stats from system.statement_info where request_at > '2024-03-01 07:48:00.444927' and reque
+--------------------------------------+----------------------------+----------------------------+---------+------------+--------------------------------------+
| statement_id                         | request_at                 | response_at                | status  | ms         | stats                                |
+--------------------------------------+----------------------------+----------------------------+---------+------------+--------------------------------------+
| 018df8fc-2f17-72a0-a06d-ea51eba87e2e | 2024-03-01 07:48:10.000000 | 2024-03-01 07:48:15.000000 | Success | 129.438229 | [3,15133034,11366772.319,0,1,6505,2] |
+--------------------------------------+----------------------------+----------------------------+---------+------------+--------------------------------------+
1 row in set (0.04 sec)

DanielZhangQD added kind/bug Something isn't working needs-triage severity/s0 Extreme impact: Cause the application to break down and seriously affect the use labels Jun 16, 2023

DanielZhangQD assigned gavinyue and matrix-meow Jun 16, 2023

gavinyue mentioned this issue Jun 16, 2023

[Bug]: eks bvt regression： the same sql and statement_id log records in statement_info are greater than 1 #9891

Closed

1 task

xzxiong unassigned matrix-meow Jun 19, 2023

gavinyue assigned DanielZhangQD Jun 30, 2023

DanielZhangQD removed their assignment Jul 3, 2023

sukki37 removed the needs-triage label Dec 23, 2023

fengttt assigned xzxiong and gavinyue and unassigned gavinyue Jan 23, 2024

gavinyue removed their assignment Jan 23, 2024

xzxiong added duplicate This issue or pull request already exists to-next-release labels Jan 25, 2024

DanielZhangQD closed this as completed Mar 1, 2024

[Bug]: Cannot query statement_info record after CN restart #10090

[Bug]: Cannot query statement_info record after CN restart #10090

Comments

DanielZhangQD commented Jun 16, 2023

Is there an existing issue for the same bug?

Environment

Actual Behavior

Expected Behavior

Steps to Reproduce

Additional information

gavinyue commented Jun 16, 2023

gavinyue commented Jun 21, 2023

gavinyue commented Jun 26, 2023

gavinyue commented Jun 28, 2023

gavinyue commented Jun 30, 2023

gavinyue commented Jun 30, 2023

DanielZhangQD commented Jul 3, 2023

DanielZhangQD commented Jul 3, 2023

gavinyue commented Jul 6, 2023

gavinyue commented Jul 11, 2023

gavinyue commented Jul 12, 2023

gavinyue commented Jul 18, 2023

gavinyue commented Jul 21, 2023

gavinyue commented Jul 26, 2023

gavinyue commented Jul 31, 2023

gavinyue commented Aug 3, 2023

gavinyue commented Aug 8, 2023

gavinyue commented Aug 11, 2023

gavinyue commented Aug 16, 2023

gavinyue commented Aug 22, 2023

gavinyue commented Aug 27, 2023

gavinyue commented Nov 21, 2023

gavinyue commented Nov 25, 2023

gavinyue commented Nov 30, 2023

gavinyue commented Dec 5, 2023

gavinyue commented Dec 8, 2023

gavinyue commented Dec 13, 2023

gavinyue commented Dec 20, 2023

gavinyue commented Dec 25, 2023

gavinyue commented Dec 29, 2023

gavinyue commented Jan 4, 2024

gavinyue commented Jan 10, 2024

gavinyue commented Jan 15, 2024

gavinyue commented Jan 19, 2024

xzxiong commented Jan 24, 2024

xzxiong commented Jan 25, 2024 • edited Loading

xzxiong commented Jan 30, 2024

xzxiong commented Feb 2, 2024

xzxiong commented Feb 8, 2024

xzxiong commented Feb 21, 2024

xzxiong commented Feb 26, 2024

xzxiong commented Feb 29, 2024

xzxiong commented Mar 1, 2024 • edited Loading

xzxiong commented Jan 25, 2024 •

edited

Loading

xzxiong commented Mar 1, 2024 •

edited

Loading