search

pingcap / tidb

TiDB is an open-source, cloud-native, distributed, MySQL-Compatible database for elastic scale and real-time analytics. Try AI-powered Chat2Query free at : https://www.pingcap.com/tidb-serverless/
https://pingcap.com
Apache License 2.0
36.63k stars 5.77k forks source link

Sometimes TiDB does not raise the first error it received from TiFlash mpp #37792

Open windtalker opened 1 year ago

windtalker commented 1 year ago

Enhancement

[2022/09/13 21:37:57.990 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-0.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: From MPP<query:435965467766554652,task:10>: Code: 0, e.displayText() = DB::TiFlashException: Table 72 schema version 2596 newer than query schema version 2595, e.what() = DB::TiFlashException,"]
[2022/09/13 21:37:57.992 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-1.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:57.992 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-1.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:57.993 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-3.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:57.995 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-3.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:57.995 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-2.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:57.996 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-0.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: From MPP<query:435965467766554652,task:10>: Code: 0, e.displayText() = DB::TiFlashException: Table 72 schema version 2596 newer than query schema version 2595, e.what() = DB::TiFlashException,"]
[2022/09/13 21:37:57.996 +08:00] [WARN] [mpp.go:438] ["other error"] [txnStartTS=435965467766554652] [storeAddr=tc-tiflash-2.tc-tiflash-peer.endless-htap-zto-tps-1261360-1-131.svc:3930] [error="other error for mpp stream: Receive cancel request from TiDB"]
[2022/09/13 21:37:58.002 +08:00] [INFO] [coprocessor.go:870] ["[TIME_COP_PROCESS] resp_time:363.000187ms txnStartTS:435965464043847789 region_id:2634 store_addr:tc-tikv-3.tc-tikv-peer.endless-htap-zto-tps-1261360-1-131.svc:20160 kv_process_ms:347 kv_wait_ms:0 kv_read_ms:347 processed_versions:264819 total_versions:265050 rocksdb_delete_skipped_count:53 rocksdb_key_skipped_count:265058 rocksdb_cache_hit_count:762 rocksdb_read_count:0 rocksdb_read_byte:0"] [conn=5619032183516696081]
[2022/09/13 21:37:58.010 +08:00] [INFO] [conn.go:1137] ["command dispatched failed"] [conn=5619032183516696083] [connInfo="id:5619032183516696083, addr:10.233.99.234:35138 status:10, collation:utf8mb4_general_ci, user:root"] [command=Query] [status="inTxn:0, autocommit:1"] [sql="select\n  t.earliest_rec_site_id                    site_id,\n  DATE_FORMAT(t.earliest_rec_date,'%Y%m%d') site_date,\n  count(1)                         overtime_cnt,\n  1                                overtime_type\nfrom zto_ssmx_bill_detail t\nwhere t.earliest_rec_date>=DATE_FORMAT(DATE_ADD(now(),INTERVAL -7 DAY),'%Y-%m-%d 00:00:00')\nand t.earliest_rec_date<DATE_FORMAT(DATE_ADD(now(),INTERVAL 1 DAY),'%Y-%m-%d 00:00:00')\nand t.bill_state<21\ngroup by t.earliest_rec_site_id,DATE_FORMAT(t.earliest_rec_date,'%Y%m%d')\nunion all\nselect\n  t.forecast_disp_site_id                       site_id,\n  DATE_FORMAT(t.last_center_send_date,'%Y%m%d') site_date,\n  count(1)                                      overtime_cnt,\n  2                                             overtime_type\nfrom zto_ssmx_bill_detail  t\nwhere t.last_center_send_date>=DATE_FORMAT(DATE_ADD(now(),INTERVAL -7 DAY),'%Y-%m-%d 00:00:00')\nand t.last_center_send_date<DATE_FORMAT(DATE_ADD(now(),INTERVAL 1 DAY),'%Y-%m-%d 00:00:00')\nand t.bill_state<=32\ngroup by t.forecast_disp_site_id ,DATE_FORMAT(t.last_center_send_date,'%Y%m%d')"] [txn_mode=PESSIMISTIC] [timestamp=435965467766554652] [err="other error for mpp stream: Receive cancel request from TiDB\ngithub.com/pingcap/tidb/store/copr.(*mppIterator).handleMPPStreamResponse\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/store/copr/mpp.go:437\ngithub.com/pingcap/tidb/store/copr.(*mppIterator).establishMPPConns\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/store/copr/mpp.go:395\ngithub.com/pingcap/tidb/store/copr.(*mppIterator).handleDispatchReq\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/store/copr/mpp.go:318\ngithub.com/pingcap/tidb/store/copr.(*mppIterator).run.func2\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/store/copr/mpp.go:187\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1571"]

As the log shows, in [2022/09/13 21:37:57.990 +08:00], TiDB received the first error from TiFlash which is other error for mpp stream: From MPP<query:435965467766554652,task:10>: Code: 0, e.displayText() = DB::TiFlashException: Table 72 schema version 2596 newer than query schema version 2595, e.what() = DB::TiFlashException,, but in [2022/09/13 21:37:58.010 +08:00] [INFO] [conn.go:1137] ["command dispatched failed"], the error return to TiDB client is other error for mpp stream: Receive cancel request from TiDB

It should be improved so TiDB can always return the first error it received from TiFlash mpp.

windtalker commented 1 year ago

/label affects-6.2