Skip to content

Instantly share code, notes, and snippets.

@cosven

cosven/extract_sql.py

Created November 14, 2019 13:38
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save cosven/731f58ebbd0cb0ad6e725525b1da3b79 to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save cosven/731f58ebbd0cb0ad6e725525b1da3b79 to your computer and use it in GitHub Desktop.
Download ZIP
parse sql statements from general logs
Raw
extract_sql.py
#!/usr/bin/env python3
import re
def get_key_value(key, line):
"""get key's value in log line"""
p = re.compile(r'\[{}\='.format(key))
m = p.search(line)
if m is None:
raise SystemExit("get key({})'s value failed".format(key))
stack = []
start = m.end()
end = start
for i, c in enumerate(line[start:]):
if c == '[':
stack.append(c)
continue
if c == ']':
if stack:
stack.pop()
else:
end = start + i + 1
break
return line[start:end - 1]
def parse_line(line):
"""parse sql statement from line
:return: (conn_id, sql) tuple
"""
sql = get_key_value('sql', line)
conn = get_key_value('conn', line)
return conn, sql
def extract_lines(filepath):
"""extract lines from log file"""
# match log time prefix: [2019/11
line_start_p = re.compile(r'\[\d{4}\/\d{2}')
with open(filepath) as f:
line = None
for broken_line in f:
if line_start_p.match(broken_line) is None:
assert line is not None
line += broken_line
else: # brand new line arrived
# check if there exists old line
if line is not None:
yield line
line = broken_line
if __name__ == '__main__':
import sys
log_filename = sys.argv[1]
for line in extract_lines(log_filename):
if 'GENERAL_LOG' not in line:
continue
conn_id, sql = parse_line(line)
print(conn_id, sql)
@cosven
Copy link
Copy Markdown
Author

cosven commented Nov 14, 2019

测试用例

log

[2019/11/14 20:40:05.692 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=412545241755942915] [current_db=tidb] [sql=rollback]
[2019/11/14 20:40:05.692 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 20:40:05.692 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:24.489 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=0"]
[2019/11/14 20:42:24.490 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select   balance   from user_account   where account_id =   'user1'"]
[2019/11/14 20:42:24.498 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=] [sql="use `tidb`"]
[2019/11/14 20:42:24.498 +08:00] [INFO] [server.go:413] ["new connection"] [conn=27521] [remoteAddr=172.16.5.98:41692]
[2019/11/14 20:42:24.507 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="/* mysql-connector-java-5.1.47 ( Revision: fe1903b1ecb4a96a917f7ed3190d80c049b1de29 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server, @@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names, @@max_allowed_packet AS max_allowed_packet, @@net_buffer_length AS net_buffer_length, @@net_write_timeout AS net_write_timeout, @@query_cache_size AS query_cache_size, @@query_cache_type AS query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@transaction_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout"]
[2019/11/14 20:42:24.507 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET NAMES utf8mb4"]
[2019/11/14 20:42:24.507 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET character_set_results = NULL"]
[2019/11/14 20:42:24.507 +08:00] [INFO] [set.go:192] ["set session var"] [conn=27521] [name=character_set_results] [val=NULL]
[2019/11/14 20:42:24.508 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 20:42:24.509 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:24.509 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SELECT @@session.transaction_isolation"]
[2019/11/14 20:42:24.510 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=0"]
[2019/11/14 20:42:24.510 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:24.511 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="update user_account set balance = balance+1 where   account_id = 'user1'"]
[2019/11/14 20:42:24.514 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=412545278141530136] [current_db=tidb] [sql=commit]
[2019/11/14 20:42:24.517 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 20:42:24.517 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27521] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:24.518 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=412545278141530114] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:24.519 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=412545278141530114] [current_db=tidb] [sql="update user_account   set credit =credit+1 where   balance=10002.5 and account_id =   'user1'"]
[2019/11/14 20:42:24.539 +08:00] [INFO] [adapter.go:493] ["pessimistic write conflict, retry statement"] [conn=26101] [txn=412545278141530114] [forUpdateTS=412545278141530114] [conflictCommitTS=412545278141530137]
[2019/11/14 20:42:24.540 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=412545278141530114] [current_db=tidb] [sql=commit]
[2019/11/14 20:42:24.540 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 20:42:24.541 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select @@session.transaction_read_only"]
[2019/11/14 20:42:55.811 +08:00] [INFO] [client_batch.go:562] ["recycle idle connection"] [target=172.16.5.54:20171]
[2019/11/14 20:48:00.834 +08:00] [INFO] [region_cache.go:540] ["switch region leader to specific leader due to kv return NotLeader"] [regionID=31] [currIdx=1] [leaderStoreID=8]
[2019/11/14 20:48:20.350 +08:00] [INFO] [server.go:416] ["connection closed"] [conn=27521]
[2019/11/14 20:49:55.134 +08:00] [INFO] [region_cache.go:540] ["switch region leader to specific leader due to kv return NotLeader"] [regionID=19] [currIdx=0] [leaderStoreID=8]

sql

26101 rollback
26101 "SET autocommit=1"
26101 "select @@session.transaction_read_only"
26101 "SET autocommit=0"
26101 "select   balance   from user_account   where account_id =   'user1'"
27521 "use `tidb`"
27521 "/* mysql-connector-java-5.1.47 ( Revision: fe1903b1ecb4a96a917f7ed3190d80c049b1de29 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server, @@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names, @@max_allowed_packet AS max_allowed_packet, @@net_buffer_length AS net_buffer_length, @@net_write_timeout AS net_write_timeout, @@query_cache_size AS query_cache_size, @@query_cache_type AS query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@transaction_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout"
27521 "SET NAMES utf8mb4"
27521 "SET character_set_results = NULL"
27521 "SET autocommit=1"
27521 "select @@session.transaction_read_only"
27521 "SELECT @@session.transaction_isolation"
27521 "SET autocommit=0"
27521 "select @@session.transaction_read_only"
27521 "update user_account set balance = balance+1 where   account_id = 'user1'"
27521 commit
27521 "SET autocommit=1"
27521 "select @@session.transaction_read_only"
26101 "select @@session.transaction_read_only"
26101 "update user_account   set credit =credit+1 where   balance=10002.5 and account_id =   'user1'"
26101 commit
26101 "SET autocommit=1"
26101 "select @@session.transaction_read_only"

@cosven
Copy link
Copy Markdown
Author

cosven commented Nov 14, 2019

测试用例 2

[2019/11/14 21:23:31.207 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=0"]
[2019/11/14 21:23:31.209 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select
@@session.transaction_read_only"]
[2019/11/14 21:23:31.209 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="update user_account set balance
= balance+1 where   account_id = 'user1'"]
[2019/11/14 21:23:31.218 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=] [sql="use `tidb`"]
[2019/11/14 21:23:31.218 +08:00] [INFO] [server.go:413] ["new connection"] [conn=27604] [remoteAddr=172.16.5.98:54902]
[2019/11/14 21:23:31.226 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="/* mysql-connector-java-5.1.47 (
Revision: fe1903b1ecb4a96a917f7ed3190d80c049b1de29 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client,
@@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server,
@@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names,
@@max_allowed_packet AS max_allowed_packet, @@net_buffer_length AS net_buffer_length, @@net_write_timeout AS net_write_timeout, @@query_cache_size AS query_cache_size, @@query_cache_type AS
query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@transaction_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout"]
[2019/11/14 21:23:31.226 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET NAMES utf8mb4"]
[2019/11/14 21:23:31.227 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET character_set_results =
NULL"]
[2019/11/14 21:23:31.227 +08:00] [INFO] [set.go:192] ["set session var"] [conn=27604] [name=character_set_results] [val=NULL]
[2019/11/14 21:23:31.227 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 21:23:31.228 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select
@@session.transaction_read_only"]
[2019/11/14 21:23:31.228 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SELECT
@@session.transaction_isolation"]
[2019/11/14 21:23:31.229 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=0"]
[2019/11/14 21:23:31.229 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select
@@session.transaction_read_only"]
[2019/11/14 21:23:31.230 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="update user_account set balance
= balance+1 where   account_id = 'user1'"]
[2019/11/14 21:24:31.252 +08:00] [WARN] [expensivequery.go:160] [expensive_query] [cost_time=60.022316972s] [conn_id=27604] [user=root] [database=tidb] [txn_start_ts=412545924785242125] [mem_max="0
Bytes"] [sql="update user_account set balance = balance+1 where\n\t\taccount_id = 'user1'"]
[2019/11/14 21:33:41.213 +08:00] [INFO] [2pc.go:693] ["ttlManager live up to its lifetime"] [txnStartTS=412545924772134915]
[2019/11/14 21:33:51.976 +08:00] [WARN] [adapter.go:490] ["failed to extract conflictCommitTS from a conflict error"] [conn=27604]
[2019/11/14 21:33:51.976 +08:00] [INFO] [adapter.go:493] ["pessimistic write conflict, retry statement"] [conn=27604] [txn=412545924785242125] [forUpdateTS=412545924785242125] [conflictCommitTS=0]
[2019/11/14 21:33:51.979 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=412545924785242125] [current_db=tidb] [sql=commit]
[2019/11/14 21:33:51.980 +08:00] [WARN] [session.go:446] ["commit failed"] [conn=27604] ["finished txn"="Txn{state=invalid}"] [error="conn0 txn takes too much time, txnStartTS: 412545924785242125,
comm: 412546087511130114"] [errorVerbose="conn0 txn takes too much time, txnStartTS: 412545924785242125, comm:
412546087511130114\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).execute\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1101\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).executeAndWriteFinishBinlog\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1010\ngithub.com/pingcap/tidb/store/tikv.(*tikvTxn).Commit\n\tgithub.com/pingcap/tidb@/store/tikv/txn.go:298\ngithub.com/pingcap/tidb/session.(*TxnState).Commit\n\tgithub.com/pingcap/tidb@/session/txn.go:197\ngithub.com/pingcap/tidb/session.(*session).doCommit\n\tgithub.com/pingcap/tidb@/session/session.go:393\ngithub.com/pingcap/tidb/session.(*session).doCommitWithRetry\n\tgithub.com/pingcap/tidb@/session/session.go:403\ngithub.com/pingcap/tidb/session.(*session).CommitTxn\n\tgithub.com/pingcap/tidb@/session/session.go:468\ngithub.com/pingcap/tidb/session.finishStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:179\ngithub.com/pingcap/tidb/session.runStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:257\ngithub.com/pingcap/tidb/session.(*session).executeStatement\n\tgithub.com/pingcap/tidb@/session/session.go:961\ngithub.com/pingcap/tidb/session.(*session).execute\n\tgithub.com/pingcap/tidb@/session/session.go:1076\ngithub.com/pingcap/tidb/session.(*session).Execute\n\tgithub.com/pingcap/tidb@/session/session.go:999\ngithub.com/pingcap/tidb/server.(*TiDBContext).Execute\n\tgithub.com/pingcap/tidb@/server/driver_tidb.go:246\ngithub.com/pingcap/tidb/server.(*clientConn).handleQuery\n\tgithub.com/pingcap/tidb@/server/conn.go:1195\ngithub.com/pingcap/tidb/server.(*clientConn).dispatch\n\tgithub.com/pingcap/tidb@/server/conn.go:913\ngithub.com/pingcap/tidb/server.(*clientConn).Run\n\tgithub.com/pingcap/tidb@/server/conn.go:666\ngithub.com/pingcap/tidb/server.(*Server).onConn\n\tgithub.com/pingcap/tidb@/server/server.go:440\nruntime.goexit\n\truntime/asm_amd64.s:1357"]
[2019/11/14 21:33:51.980 +08:00] [WARN] [session.go:964] ["run statement error"] [conn=27604] [schemaVersion=206] [error="previous statement: update user_account set balance = balance+1 where
account_id = 'user1': conn0 txn takes too much time, txnStartTS: 412545924785242125, comm: 412546087511130114"] [errorVerbose="conn0 txn takes too much time, txnStartTS: 412545924785242125, comm:
412546087511130114\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).execute\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1101\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).executeAndWriteFinishBinlog\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1010\ngithub.com/pingcap/tidb/store/tikv.(*tikvTxn).Commit\n\tgithub.com/pingcap/tidb@/store/tikv/txn.go:298\ngithub.com/pingcap/tidb/session.(*TxnState).Commit\n\tgithub.com/pingcap/tidb@/session/txn.go:197\ngithub.com/pingcap/tidb/session.(*session).doCommit\n\tgithub.com/pingcap/tidb@/session/session.go:393\ngithub.com/pingcap/tidb/session.(*session).doCommitWithRetry\n\tgithub.com/pingcap/tidb@/session/session.go:403\ngithub.com/pingcap/tidb/session.(*session).CommitTxn\n\tgithub.com/pingcap/tidb@/session/session.go:468\ngithub.com/pingcap/tidb/session.finishStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:179\ngithub.com/pingcap/tidb/session.runStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:257\ngithub.com/pingcap/tidb/session.(*session).executeStatement\n\tgithub.com/pingcap/tidb@/session/session.go:961\ngithub.com/pingcap/tidb/session.(*session).execute\n\tgithub.com/pingcap/tidb@/session/session.go:1076\ngithub.com/pingcap/tidb/session.(*session).Execute\n\tgithub.com/pingcap/tidb@/session/session.go:999\ngithub.com/pingcap/tidb/server.(*TiDBContext).Execute\n\tgithub.com/pingcap/tidb@/server/driver_tidb.go:246\ngithub.com/pingcap/tidb/server.(*clientConn).handleQuery\n\tgithub.com/pingcap/tidb@/server/conn.go:1195\ngithub.com/pingcap/tidb/server.(*clientConn).dispatch\n\tgithub.com/pingcap/tidb@/server/conn.go:913\ngithub.com/pingcap/tidb/server.(*clientConn).Run\n\tgithub.com/pingcap/tidb@/server/conn.go:666\ngithub.com/pingcap/tidb/server.(*Server).onConn\n\tgithub.com/pingcap/tidb@/server/server.go:440\nruntime.goexit\n\truntime/asm_amd64.s:1357\nprevious
statement: update user_account set balance = balance+1 where   account_id = 'user1'"] [session="{\n  \"currDBName\": \"tidb\",\n  \"id\": 27604,\n  \"status\": 0,\n  \"strictMode\": true,\n  \"user\":
{\n    \"Username\": \"root\",\n    \"Hostname\": \"172.16.5.98\",\n    \"CurrentUser\": false,\n    \"AuthUsername\": \"root\",\n    \"AuthHostname\": \"%\"\n  }\n}"]
[2019/11/14 21:33:51.981 +08:00] [WARN] [conn.go:682] ["dispatch error"] [conn=27604] [connInfo="id:27604, addr:172.16.5.98:54902 status:0, collation:utf8_general_ci, user:root"] [command=Query]
[status="inTxn:0, autocommit:0"] [sql=commit] [err="conn0 txn takes too much time, txnStartTS: 412545924785242125, comm:
412546087511130114\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).execute\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1101\ngithub.com/pingcap/tidb/store/tikv.(*twoPhaseCommitter).executeAndWriteFinishBinlog\n\tgithub.com/pingcap/tidb@/store/tikv/2pc.go:1010\ngithub.com/pingcap/tidb/store/tikv.(*tikvTxn).Commit\n\tgithub.com/pingcap/tidb@/store/tikv/txn.go:298\ngithub.com/pingcap/tidb/session.(*TxnState).Commit\n\tgithub.com/pingcap/tidb@/session/txn.go:197\ngithub.com/pingcap/tidb/session.(*session).doCommit\n\tgithub.com/pingcap/tidb@/session/session.go:393\ngithub.com/pingcap/tidb/session.(*session).doCommitWithRetry\n\tgithub.com/pingcap/tidb@/session/session.go:403\ngithub.com/pingcap/tidb/session.(*session).CommitTxn\n\tgithub.com/pingcap/tidb@/session/session.go:468\ngithub.com/pingcap/tidb/session.finishStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:179\ngithub.com/pingcap/tidb/session.runStmt\n\tgithub.com/pingcap/tidb@/session/tidb.go:257\ngithub.com/pingcap/tidb/session.(*session).executeStatement\n\tgithub.com/pingcap/tidb@/session/session.go:961\ngithub.com/pingcap/tidb/session.(*session).execute\n\tgithub.com/pingcap/tidb@/session/session.go:1076\ngithub.com/pingcap/tidb/session.(*session).Execute\n\tgithub.com/pingcap/tidb@/session/session.go:999\ngithub.com/pingcap/tidb/server.(*TiDBContext).Execute\n\tgithub.com/pingcap/tidb@/server/driver_tidb.go:246\ngithub.com/pingcap/tidb/server.(*clientConn).handleQuery\n\tgithub.com/pingcap/tidb@/server/conn.go:1195\ngithub.com/pingcap/tidb/server.(*clientConn).dispatch\n\tgithub.com/pingcap/tidb@/server/conn.go:913\ngithub.com/pingcap/tidb/server.(*clientConn).Run\n\tgithub.com/pingcap/tidb@/server/conn.go:666\ngithub.com/pingcap/tidb/server.(*Server).onConn\n\tgithub.com/pingcap/tidb@/server/server.go:440\nruntime.goexit\n\truntime/asm_amd64.s:1357\nprevious
statement: update user_account set balance = balance+1 where   account_id = 'user1'"]
[2019/11/14 21:33:51.981 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 21:33:51.981 +08:00] [INFO] [2pc.go:1039] ["2PC clean up done"] [conn=27604] [txnStartTS=412545924785242125]
[2019/11/14 21:33:51.981 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=27604] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select
@@session.transaction_read_only"]
[2019/11/14 21:33:51.982 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=412545924772134915] [current_db=tidb] [sql=rollback]
[2019/11/14 21:33:51.982 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="SET autocommit=1"]
[2019/11/14 21:33:51.983 +08:00] [INFO] [session.go:1877] [GENERAL_LOG] [conn=26101] [[email protected]] [schemaVersion=206] [txnStartTS=0] [current_db=tidb] [sql="select
@@session.transaction_read_only"]

sql

26101 "SET autocommit=0"
26101 "select
@@session.transaction_read_only"
26101 "update user_account set balance
= balance+1 where   account_id = 'user1'"
27604 "use `tidb`"
27604 "/* mysql-connector-java-5.1.47 (
Revision: fe1903b1ecb4a96a917f7ed3190d80c049b1de29 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client,
@@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server,
@@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names,
@@max_allowed_packet AS max_allowed_packet, @@net_buffer_length AS net_buffer_length, @@net_write_timeout AS net_write_timeout, @@query_cache_size AS query_cache_size, @@query_cache_type AS
query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@transaction_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout"
27604 "SET NAMES utf8mb4"
27604 "SET character_set_results =
NULL"
27604 "SET autocommit=1"
27604 "select
@@session.transaction_read_only"
27604 "SELECT
@@session.transaction_isolation"
27604 "SET autocommit=0"
27604 "select
@@session.transaction_read_only"
27604 "update user_account set balance
= balance+1 where   account_id = 'user1'"
27604 commit
27604 "SET autocommit=1"
27604 "select
@@session.transaction_read_only"
26101 rollback
26101 "SET autocommit=1"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment