Queries are slow.

I use 50 threads for pressure testing, see query.log below.

/* Fri Jun 12 04:02:10.088 2020 conn 251301 real 0.045 wall 0.045 found 70166 */ SELECT id, pref, cref FROM oqsindex WHERE MATCH('@fullfields "3100171130F9223372036854775507S"') AND entity=100  ORDER BY id ASC OPTION max_matches=20, ranker=none, ranker=none;

The display latency is not very high.

+---------------+---------------------------------+
| Variable_name | Value                           |
+---------------+---------------------------------+
| total         | 20                              |
| total_found   | 70166                           |
| time          | 0.062                           |
| keyword[0]    | 3100171130f9223372036854775507s |
| docs[0]       | 70166                           |
| hits[0]       | 70166                           |
+---------------+---------------------------------+
mysql> show index oqsindex status;
+-------------------+-------------------------------------------------------------------------------------------------------------+
| Variable_name     | Value                                                                                                       |
+-------------------+-------------------------------------------------------------------------------------------------------------+
| index_type        | rt                                                                                                          |
| indexed_documents | 3449201                                                                                                     |
| indexed_bytes     | 2201412232                                                                                                  |
| ram_bytes         | 1565819887                                                                                                  |
| disk_bytes        | 2184867096                                                                                                  |
| ram_chunk         | 117193943                                                                                                   |
| ram_chunks_count  | 29                                                                                                          |
| disk_chunks       | 1                                                                                                           |
| mem_limit         | 2147483648                                                                                                  |
| ram_bytes_retired | 0                                                                                                           |
| tid               | 4350024                                                                                                     |
| tid_saved         | 4350024                                                                                                     |
| query_time_1min   | {"queries":72, "avg_sec":0.038, "min_sec":0.000, "max_sec":0.053, "pct95_sec":0.049, "pct99_sec":0.049}     |
| query_time_5min   | {"queries":26915, "avg_sec":0.052, "min_sec":0.000, "max_sec":0.098, "pct95_sec":0.062, "pct99_sec":0.067}  |
| query_time_15min  | {"queries":73715, "avg_sec":0.051, "min_sec":0.000, "max_sec":0.108, "pct95_sec":0.063, "pct99_sec":0.067}  |
| query_time_total  | {"queries":309369, "avg_sec":0.018, "min_sec":0.000, "max_sec":0.108, "pct95_sec":0.061, "pct99_sec":0.065} |
| found_rows_1min   | {"queries":72, "avg":54573, "min":0, "max":70166, "pct95":70166, "pct99":70166}                             |
| found_rows_5min   | {"queries":26915, "avg":66743, "min":0, "max":70166, "pct95":70166, "pct99":70166}                          |
| found_rows_15min  | {"queries":73715, "avg":67389, "min":0, "max":70166, "pct95":70166, "pct99":70166}                          |
| found_rows_total  | {"queries":309369, "avg":24106, "min":0, "max":70166, "pct95":70166, "pct99":70166}                         |
+-------------------+-------------------------------------------------------------------------------------------------------------+

Does it seem like time is spent on found_rows?

I used Jmeter 5.x to connect and send the SQL statement using mySQL8.x’s Driver.

summary +   1994 in 00:00:21 =   94.6/s Avg:   508 Min:    65 Max:  2432 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary +   3045 in 00:00:30 =  101.5/s Avg:   492 Min:   455 Max:   541 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =   5039 in 00:00:51 =   98.6/s Avg:   499 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3050 in 00:00:30 =  101.7/s Avg:   491 Min:   462 Max:   574 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =   8089 in 00:01:21 =   99.8/s Avg:   496 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3109 in 00:00:30 =  103.6/s Avg:   482 Min:   454 Max:   525 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  11198 in 00:01:51 =  100.8/s Avg:   492 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3113 in 00:00:30 =  103.8/s Avg:   482 Min:   458 Max:   572 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  14311 in 00:02:21 =  101.4/s Avg:   490 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3110 in 00:00:30 =  103.7/s Avg:   481 Min:   447 Max:   530 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  17421 in 00:02:51 =  101.8/s Avg:   488 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3134 in 00:00:30 =  104.5/s Avg:   478 Min:   440 Max:   524 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  20555 in 00:03:21 =  102.2/s Avg:   487 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3116 in 00:00:30 =  103.9/s Avg:   481 Min:   442 Max:   583 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  23671 in 00:03:51 =  102.4/s Avg:   486 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3121 in 00:00:30 =  104.0/s Avg:   480 Min:   452 Max:   524 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  26792 in 00:04:21 =  102.6/s Avg:   485 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3126 in 00:00:30 =  104.2/s Avg:   479 Min:   450 Max:   519 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  29918 in 00:04:51 =  102.8/s Avg:   485 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3131 in 00:00:30 =  104.4/s Avg:   479 Min:   451 Max:   520 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  33049 in 00:05:21 =  102.9/s Avg:   484 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3119 in 00:00:30 =  104.0/s Avg:   480 Min:   448 Max:   533 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  36168 in 00:05:51 =  103.0/s Avg:   484 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3118 in 00:00:30 =  103.9/s Avg:   481 Min:   452 Max:   521 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  39286 in 00:06:21 =  103.1/s Avg:   483 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3059 in 00:00:30 =  102.0/s Avg:   490 Min:   459 Max:   542 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  42345 in 00:06:51 =  103.0/s Avg:   484 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3066 in 00:00:30 =  102.2/s Avg:   489 Min:   459 Max:   567 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  45411 in 00:07:21 =  103.0/s Avg:   484 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3166 in 00:00:30 =  105.5/s Avg:   474 Min:   399 Max:   618 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  48577 in 00:07:51 =  103.1/s Avg:   484 Min:    65 Max:  2432 Err:     0 (0.00%)
summary +   3379 in 00:00:30 =  112.6/s Avg:   444 Min:   396 Max:   547 Err:     0 (0.00%) Active: 50 Started: 50 Finished: 0
summary =  51956 in 00:08:21 =  103.7/s Avg:   481 Min:    65 Max:  2432 Err:     0 (0.00%)

Which part takes up a lot of time? Any Suggestions for optimization?

Hi @dongbin

found_rows is not time, but just the number of found rows, for example:

MySQL [(none)]> create table t(f text);
MySQL [(none)]> insert into t values(0,'abc');
MySQL [(none)]> select * from t where match('abc');
+---------------------+------+
| id                  | f    |
+---------------------+------+
| 8215163023438905347 | abc  |
+---------------------+------+
MySQL [(none)]> show index t status;
+-------------------+--------------------------------------------------------------------------------------------------------+
| Variable_name     | Value                                                                                                  |
+-------------------+--------------------------------------------------------------------------------------------------------+
| index_type        | rt                                                                                                     |
| indexed_documents | 1                                                                                                      |
| indexed_bytes     | 3                                                                                                      |
| ram_bytes         | 6308                                                                                                   |
| disk_bytes        | 298                                                                                                    |
| ram_chunk         | 468                                                                                                    |
| ram_chunks_count  | 1                                                                                                      |
| disk_chunks       | 0                                                                                                      |
| mem_limit         | 134217728                                                                                              |
| ram_bytes_retired | 0                                                                                                      |
| tid               | 1                                                                                                      |
| tid_saved         | 0                                                                                                      |
| query_time_1min   | {"queries":1, "avg_sec":0.000, "min_sec":0.000, "max_sec":0.000, "pct95_sec":0.000, "pct99_sec":0.000} |
| query_time_5min   | {"queries":1, "avg_sec":0.000, "min_sec":0.000, "max_sec":0.000, "pct95_sec":0.000, "pct99_sec":0.000} |
| query_time_15min  | {"queries":1, "avg_sec":0.000, "min_sec":0.000, "max_sec":0.000, "pct95_sec":0.000, "pct99_sec":0.000} |
| query_time_total  | {"queries":1, "avg_sec":0.000, "min_sec":0.000, "max_sec":0.000, "pct95_sec":0.000, "pct99_sec":0.000} |
| found_rows_1min   | {"queries":1, "avg":1, "min":1, "max":1, "pct95":1, "pct99":1}                                         |
| found_rows_5min   | {"queries":1, "avg":1, "min":1, "max":1, "pct95":1, "pct99":1}                                         |
| found_rows_15min  | {"queries":1, "avg":1, "min":1, "max":1, "pct95":1, "pct99":1}                                         |
| found_rows_total  | {"queries":1, "avg":1, "min":1, "max":1, "pct95":1, "pct99":1}                                         |
+-------------------+--------------------------------------------------------------------------------------------------------+