add troubleshooting-writeconflict (#3209)

* add troubleshooting-writeconflict

* fix syntax

* fix snytax again

* adjust

* fix format

* refine format and wording

Co-authored-by: yikeke <yikeke@pingcap.com>
Co-authored-by: Keke Yi <40977455+yikeke@users.noreply.github.com>

Author: 3 people

media/troubleshooting-write-conflict-kv-backoff-ops.png

@@ -0,0 +1,93 @@
+---
+title: 乐观事务模型下写写冲突问题排查
+summary: 介绍 TiDB 中乐观锁下写写冲突出现的原因以及解决方案。
+category: troubleshooting
+---
+
+# 乐观事务模型下写写冲突问题排查
+
+本文介绍 TiDB 中乐观锁下写写冲突出现的原因以及解决方案。
+
+在 v3.0.8 版本之前，TiDB 默认采用乐观事务模型，在事务执行过程中并不会做冲突检测，而是在事务最终 COMMIT 提交时触发两阶段提交，并检测是否存在写写冲突。当出现写写冲突，并且开启了事务重试机制，则 TiDB 会在限定次数内进行重试，最终重试成功或者达到重试次数上限后，会给客户端返回结果。因此，如果 TiDB 集群中存在大量的写写冲突情况，容易导致集群的 Duration 比较高。
+
+## 出现写写冲突的原因
+
+TiDB 中使用 [Percolator](https://www.usenix.org/legacy/event/osdi10/tech/full_papers/Peng.pdf) 事务模型来实现 TiDB 中的事务。Percolator 总体上就是一个二阶段提交的实现。具体的二阶段提交过程可参考[乐观事务文档](/optimistic-transaction.md)。
+
+当客户端发起 `COMMIT` 请求的时候，TiDB 开始两阶段提交：
+
+1. TiDB 从所有要写入的 Key 中选择一个作为当前事务的 Primary Key
+2. TiDB 向所有的本次提交涉及到的 TiKV 发起 prewrite 请求，TiKV 判断是否所有 Key 都可以 prewrite 成功
+3. TiDB 收到所有 Key 都 prewrite 成功的消息
+4. TiDB 向 PD 请求 commit_ts
+5. TiDB 向 Primary Key 发起第二阶段提交。Primary Key 所在的 TiKV 收到 commit 操作后，检查数据合法性，清理 prewrite 阶段留下的锁
+6. TiDB 收到两阶段提交成功的信息
+
+写写冲突发生在 prewrite 阶段，当发现有其他的事务在写当前 Key (data.commit_ts > txn.start_ts)，则会发生写写冲突。
+
+TiDB 会根据 `tidb_disable_txn_auto_retry` 和 `tidb_retry_limit` 参数设置的情况决定是否进行重试，如果设置了不重试，或者重试次数达到上限后还是没有 prewrite 成功，则向 TiDB 返回 `Write Conflict` 错误。
+
+## 如何判断当前集群存在写写冲突
+
+可以通过 Grafana 监控查看集群写写冲突的情况：
+
+* 通过 TiDB 监控面板中 KV Errors 监控栏中 KV Backoff OPS 监控指标项，查看 TiKV 中返回错误信息的数量
+
+    ![kv-backoff-ops](/media/troubleshooting-write-conflict-kv-backoff-ops.png)
+
+    txnlock 表示集群中存在写写冲突，txnLockFast 表示集群中存在读写冲突。
+
+* 通过 TiDB 监控面板中 KV Errors 监控栏中 Lock Resolve OPS 监控指标项，查看事务冲突相关的数量
+
+    ![lock-resolve-ops](/media/troubleshooting-write-conflict-lock-resolve-ops.png)
+
+    expired、not_expired、wait_expired 表示对应的 lock 状态
+
+* 通过 TiDB 监控面板中 KV Errors 监控栏中 KV Retry Duration 监控指标项，查看 KV 重试请求的时间
+
+    ![kv-retry-duration](/media/troubleshooting-write-conflict-kv-retry-duration.png)
+
+也可以通过 TiDB 日志查看是否有 `[kv:9007]Write conflict` 关键字，如果搜索到对应关键字，则可以表明集群中存在写写冲突。
+
+## 如何解决写写冲突问题
+
+如果通过以上方式判断出集群中存在大量的写写冲突，建议找到冲突的数据，以及写写冲突的原因，看是否能从应用程序修改逻辑，加上重试的逻辑。当出现写写冲突的时候，可以在 TiDB 日志中看到类似的日志：
+
+```log
+[2020/05/12 15:17:01.568 +08:00] [WARN] [session.go:446] ["commit failed"] [conn=3] ["finished txn"="Txn{state=invalid}"] [error="[kv:9007]Write conflict, txnStartTS=416617006551793665, conflictStartTS=416617018650001409, conflictCommitTS=416617023093080065, key={tableID=47, indexID=1, indexValues={string, }} primary={tableID=47, indexID=1, indexValues={string, }} [try again later]"]
+```
+
+关于日志的解释如下：
+
+* `[kv:9007]Write conflict`：表示出现了写写冲突
+* `txnStartTS=416617006551793665`：表示当前事务的 start_ts 时间戳，可以通过 pd-ctl 工具将时间戳转换为具体时间
+* `conflictStartTS=416617018650001409`：表示冲突事务的 start_ts 时间戳，可以通过 pd-ctl 工具将时间戳转换为具体时间
+* `conflictCommitTS=416617023093080065`：表示冲突事务的 commit_ts 时间戳，可以通过 pd-ctl 工具将时间戳转换为具体时间
+* `key={tableID=47, indexID=1, indexValues={string, }}`：表示当前事务中冲突的数据，tableID 表示发生冲突的表的 ID，indexID 表示是索引数据发生了冲突。如果是数据发生了冲突，会打印 `handle=x` 表示对应哪行数据发生了冲突，indexValues 表示发生冲突的索引数据
+* `primary={tableID=47, indexID=1, indexValues={string, }}`：表示当前事务中的 Primary Key 信息
+
+通过 pd-ctl 将时间戳转换为可读时间：
+
+{{< copyable "" >}}
+
+```shell
+./pd-ctl -u https://127.0.0.1:2379 tso {TIMESTAMP}
+```
+
+通过 tableID 查找具体的表名：
+
+{{< copyable "" >}}
+
+```shell
+curl http://{TiDBIP}:10080/db-table/{tableID}
+```
+
+通过 indexID 查找具体的索引名：
+
+{{< copyable "sql" >}}
+
+```sql
+SELECT * FROM INFORMATION_SCHEMA.TIDB_INDEXES WHERE TABLE_SCHEMA='{table_name}' AND TABLE_NAME='{table_name}' AND INDEX_ID={indexID};
+```
+
+另外在 v3.0.8 及之后版本默认使用悲观事务模式，从而避免在事务提交的时候因为冲突而导致失败，无需修改应用程序。悲观事务模式下会在每个 DML 语句执行的时候，加上悲观锁，用于防止其他事务修改相同 Key，从而保证在最后提交的 prewrite 阶段不会出现写写冲突的情况。