search

apache / doris

Apache Doris is an easy-to-use, high performance and unified analytics database.
https://doris.apache.org
Apache License 2.0
12.67k stars 3.27k forks source link

[Bug] ConnectProcessor Null packet received from network #34711

Open ddsr-ops opened 6 months ago

ddsr-ops commented 6 months ago

Search before asking

Version

2.0.7

What's Wrong?

2024-05-11 14:05:15,138 INFO (replayer|102) [Env.replayJournal():2539] replayed journal id is 40594948, replay to journal id is 40594949
2024-05-11 14:05:15,422 INFO (replayer|102) [Env.replayJournal():2539] replayed journal id is 40594949, replay to journal id is 40594950
2024-05-11 14:05:15,666 INFO (mysql-nio-pool-1469|65282) [QeProcessorImpl.unregisterQuery():149] not found query ccd79d6357e74c3a-bf4979cdf92c9ea4 when unregisterQuery
2024-05-11 14:05:15,668 INFO (mysql-nio-pool-1469|65282) [MasterOpExecutor.forward():127] forward to master FE TNetworkAddress(hostname:10.50.253.104, port:9021), statement id: 81565
2024-05-11 14:05:16,593 INFO (replayer|102) [Env.replayJournal():2539] replayed journal id is 40594950, replay to journal id is 40594951
2024-05-11 14:05:16,593 INFO (replayer|102) [DatabaseTransactionMgr.replayUpsertTransactionState():1974] replay a committed transaction TransactionState. transaction id: 11932426, label: insert_bad46b0a2749408e_80c68aa11d296bbc, db id: 160996, table id list: 6224461, callback id: -1, coordinator: FE: 10.50.253.104, transaction status: COMMITTED, error replicas num: 0, replica ids: , prepare time: 1715407515668, commit time: 1715407516587, finish time: -1, reason:
2024-05-11 14:05:16,603 INFO (replayer|102) [Env.replayJournal():2539] replayed journal id is 40594951, replay to journal id is 40594952
2024-05-11 14:05:16,603 INFO (replayer|102) [DatabaseTransactionMgr.replayUpsertTransactionState():1977] replay a visible transaction TransactionState. transaction id: 11932426, label: insert_bad46b0a2749408e_80c68aa11d296bbc, db id: 160996, table id list: 6224461, callback id: -1, coordinator: FE: 10.50.253.104, transaction status: VISIBLE, error replicas num: 0, replica ids: , prepare time: 1715407515668, commit time: 1715407516587, finish time: 1715407516599, reason:
2024-05-11 14:05:16,607 INFO (replayer|102) [Env.replayJournal():2539] replayed journal id is 40594952, replay to journal id is 40594955
2024-05-11 14:05:16,607 INFO (replayer|102) [LoadManager.replayCreateLoadJob():186] LOAD_JOB=6280774, msg={replay create load job}
2024-05-11 14:05:16,609 INFO (mysql-nio-pool-1469|65282) [MasterOpExecutor.waitOnReplaying():103] forwarding to master get result max journal id: 40594955
2024-05-11 14:05:16,609 INFO (mysql-nio-pool-1469|65282) [JournalObservable.waitOn():50] waiting for the observer to replay journal to 40594955 with timeout: 17280000 ms
2024-05-11 14:05:17,047 WARN (mysql-nio-pool-1469|65282) [ConnectProcessor.processOnce():839] Null packet received from network. remote: 10.50.253.9:50228
2024-05-11 14:05:17,048 WARN (mysql-nio-pool-1469|65282) [ReadListener.lambda$handleEvent$0():60] Exception happened in one session(org.apache.doris.qe.ConnectContext@7947541d).
java.io.IOException: Error happened when receiving packet.
        at org.apache.doris.qe.ConnectProcessor.processOnce(ConnectProcessor.java:840) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_144]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_144]
        at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_144]

What You Expected?

Remove the WARN info, it is too much.

How to Reproduce?

No response

Anything Else?

FE nodes were restart in scroll way, non-master nodes first , then master node.

Are you willing to submit PR?

Code of Conduct

raulos-chan commented 3 months ago 
2024-07-24 14:24:54,846 WARN (mysql-nio-pool-459|121040) [ConnectProcessor.processOnce():843] Null packet received from network. remote: 172.16.16.86:62743
2024-07-24 14:24:54,846 WARN (mysql-nio-pool-459|121040) [ReadListener.lambda$handleEvent$0():60] Exception happened in one session(org.apache.doris.qe.ConnectContext@227f16cf).
java.io.IOException: Error happened when receiving packet.
    at org.apache.doris.qe.ConnectProcessor.processOnce(ConnectProcessor.java:844) ~[doris-fe.jar:1.2-SNAPSHOT]
    at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_351]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_351]
    at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_351]

Version 2.0.13

navicat打开连接时出现同样的错误，DBeaver就没有问题