reduce the log of Duplicate entry error

[zz-jason]

Reproduce Step

create table t(a bigint primary key, b bigint);
insert into t values(1, 1);
insert into t values(1, 1); -- returns: ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'

the log printed for the last insert statement:

[2020/08/06 08:52:21.984 +08:00] [WARN] [session.go:471] ["can not retry txn"] [conn=3] [label=general] [error="[kv:1062]Duplicate entry '1' for key 'PRIMARY'"] [IsBatchInsert=false] [IsPessimistic=false] [InRestrictedSQL=false] [tidb_retry_limit=10] [tidb_disable_txn_auto_retry=true]
[2020/08/06 08:52:21.984 +08:00] [WARN] [session.go:487] ["commit failed"] [conn=3] ["finished txn"="Txn{state=invalid}"] [error="[kv:1062]Duplicate entry '1' for key 'PRIMARY'"]
[2020/08/06 08:52:21.984 +08:00] [ERROR] [conn.go:744] ["command dispatched failed"] [conn=3] [connInfo="id:3, addr:127.0.0.1:55984 status:10, collation:utf8_general_ci, user:root"] [command=Query] [status="inTxn:0, autocommit:1"] [sql="insert into t values ( ... )"] [txn_mode=OPTIMISTIC] [err="[kv:1062]Duplicate entry '1' for key 'PRIMARY'"]
[2020/08/06 08:52:21.985 +08:00] [INFO] [2pc.go:739] ["2PC clean up done"] [conn=3] [txnStartTS=418558808419729408]

1 failed SQL (Duplicate entry) causes 2 warning, 1 error, 1 info log.

Goals

the goal of this task is to reduce the log when Duplicate entry error happens.

[ghost]

To me, this is a "client error". i.e. the server hasn't done anything wrong, the client has tried to do something that the server is designed to protect against.

It would be nice to track client errors / statistics in a way that does not pollute the server's log file. See #14433 for example.

[morgo]

Because client error tracking is now in information_schema, I am going to propose changing this to a debug level message. Here is a testcase showing the expected way to debug:

mysql> create table t(a bigint primary key, b bigint);
Query OK, 0 rows affected (0.01 sec)

mysql> insert into t values(1, 1);
Query OK, 1 row affected (0.00 sec)

mysql> insert into t values(1, 1);
ERROR 1062 (23000): Duplicate entry '1' for key 'PRIMARY'
mysql> select * from information_schema.CLIENT_ERRORS_SUMMARY_BY_USER;
+------+--------------+--------------------------------------------+-------------+---------------+---------------------+---------------------+
| USER | ERROR_NUMBER | ERROR_MESSAGE                              | ERROR_COUNT | WARNING_COUNT | FIRST_SEEN          | LAST_SEEN           |
+------+--------------+--------------------------------------------+-------------+---------------+---------------------+---------------------+
| root |         1062 | Duplicate entry '%-.64s' for key '%-.192s' |           1 |             0 | 2021-04-07 20:20:00 | 2021-04-07 20:20:00 |
+------+--------------+--------------------------------------------+-------------+---------------+---------------------+---------------------+
1 row in set (0.00 sec)