rustdesk-server
rustdesk-server copied to clipboard
hbbs keeps crashing frequently after upgrade to 1.1.12
Describe the bug Multiple crashes of the rendezvous server hbbs container occur per day since I upgraded the docker image to version 1.1.12 on 2024-12-29. The crashes increased from once every few days to now multiple times per day. I cannot really make something out of the container log error message:
Describe the environment
- Install environment: Running in a Docker container on a Synology DS220+ with DSM 7.2.2-72806 Update 2 and Docker Container Manager 20.10.23-1437
- Using the image rustdesk/rustdesk-server:latest
- Execution Command: hbbs -r [myserver].synology.me
How to Reproduce the bug Steps to reproduce the behavior:
- For me this started with the upgrade to the 1.1.12 docker image (not sure which my previous version was, but i guess 1.1.11-1)
- nothing else was changed
Expected behavior hbbs should run without crashing, as it has done for more than 2 years by now.
Additional context
An excerpt of the console log from the hbbs container, notice the ERROR lines at [2025-01-13 19:14:56.293679 +00:00] and [2025-01-13 15:55:40.878880 +00:00]
2025/01/13 20:18:02 stdout [2025-01-13 19:18:02.513564 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 20:18:02 stdout [2025-01-13 19:18:02.464885 +00:00] INFO [src/peer.rs:102] update_pk 1576124680 [::ffff:109.250.91.84]:53937 b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f" b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f"
2025/01/13 20:18:02 stdout [2025-01-13 19:18:02.453626 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1576124680 from [::ffff:176.3.9.1]:60782 to [::ffff:109.250.91.84]:53937
2025/01/13 20:15:34 stdout [2025-01-13 19:15:34.852542 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 20:15:34 stdout [2025-01-13 19:15:34.825776 +00:00] INFO [src/peer.rs:102] update_pk 1576124680 [::ffff:176.3.9.1]:60782 b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f" b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f"
2025/01/13 20:15:34 stdout [2025-01-13 19:15:34.743863 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1576124680 from ::ffff:109.250.91.84 to [::ffff:176.3.9.1]:60782
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.566129 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp [::]:0: Ok(212992)
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.566004 +00:00] INFO [src/rendezvous_server.rs:185] Start
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.565985 +00:00] INFO [src/rendezvous_server.rs:153] ALWAYS_USE_RELAY=N
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.565901 +00:00] INFO [src/common.rs:46] relay-servers=["xxx.synology.me"]
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563908 +00:00] INFO [src/rendezvous_server.rs:139] local-ip: ""
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563904 +00:00] INFO [src/rendezvous_server.rs:138] mask: None
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563872 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp [::]:21116: Ok(212992)
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563848 +00:00] INFO [src/rendezvous_server.rs:103] Listening on websocket :21118
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563846 +00:00] INFO [src/rendezvous_server.rs:102] Listening on tcp :21115, extra port for NAT test
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563844 +00:00] INFO [src/rendezvous_server.rs:101] Listening on tcp/udp :21116
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563839 +00:00] INFO [src/common.rs:46] rendezvous-servers=[]
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.563814 +00:00] INFO [src/rendezvous_server.rs:99] serial=0
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.559334 +00:00] INFO [src/peer.rs:84] DB_URL=./db_v2.sqlite3
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.559329 +00:00] INFO [src/rendezvous_server.rs:1205] Key: TBCxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx=
2025/01/13 20:15:09 stdout [2025-01-13 19:15:09.559315 +00:00] INFO [src/common.rs:122] Private key comes from id_ed25519
2025/01/13 20:14:56 stdout [2025-01-13 19:14:56.293679 +00:00] ERROR [src/rendezvous_server.rs:173] Failed to run hbbs test with 0.0.0.0:21116: Timeout of test_hbbs
2025/01/13 20:14:42 stdout [2025-01-13 19:14:42.570243 +00:00] INFO [src/peer.rs:102] update_pk 1576124680 [::ffff:109.250.91.84]:49724 b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f" b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f"
2025/01/13 20:14:42 stdout [2025-01-13 19:14:42.551265 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1576124680 from [::ffff:176.3.9.1]:60858 to [::ffff:109.250.91.84]:49724
2025/01/13 19:52:31 stdout [2025-01-13 18:52:31.271513 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 19:52:31 stdout [2025-01-13 18:52:31.239157 +00:00] INFO [src/peer.rs:102] update_pk 1576124680 [::ffff:176.3.9.1]:60986 b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f" b"9W\x1dyKv\x92^:\xf5WJM\xbc\x05Q\xf5\xcd\xa06S\xb0m#\xf6/\x96\xb4\xac\xa5\x10\x0f"
2025/01/13 19:52:30 stdout [2025-01-13 18:52:30.808158 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1576124680 from [::ffff:176.3.40.117]:58507 to [::ffff:176.3.9.1]:60986
2025/01/13 18:32:22 stdout [2025-01-13 17:32:22.597032 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 18:32:22 stdout [2025-01-13 17:32:22.565098 +00:00] INFO [src/peer.rs:102] update_pk 28817767 [::ffff:89.244.85.6]:20144 b"e393a8b5-cc6f-4e2e-a33a-43ab5e53fd7d" b"L\x03JI\xb3\x99R;\xd09\xe9\xa3\x80\xca\0\xc4A&i#\xb0\x91\xf7\xb6\xa7\xa8\xaez\xcdM\x9fA"
2025/01/13 18:32:22 stdout [2025-01-13 17:32:22.551106 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 28817767 from [::ffff:176.3.71.185]:14471 to [::ffff:89.244.85.6]:20144
2025/01/13 18:31:25 stdout [2025-01-13 17:31:25.529232 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 18:31:25 stdout
2025/01/13 18:31:25 stdout guid = ?
2025/01/13 18:31:25 stdout where
2025/01/13 18:31:25 stdout info = ?
2025/01/13 18:31:25 stdout pk = ?,
2025/01/13 18:31:25 stdout id = ?,
2025/01/13 18:31:25 stdout set
2025/01/13 18:31:25 stdout peer
2025/01/13 18:31:25 stdout update
2025/01/13 18:31:25 stdout
2025/01/13 18:31:25 stdout [2025-01-13 17:31:25.529148 +00:00] WARN [<unnamed>:0] update peer set id=?, …; rows affected: 1, rows returned: 0, elapsed: 24.856s
2025/01/13 18:31:25 stdout [2025-01-13 17:31:14.292179 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp 0.0.0.0:0: Ok(212992)
2025/01/13 18:31:00 stdout [2025-01-13 17:31:00.668218 +00:00] INFO [src/peer.rs:102] update_pk 28817767 [::ffff:176.3.71.185]:14568 b"e393a8b5-cc6f-4e2e-a33a-43ab5e53fd7d" b"L\x03JI\xb3\x99R;\xd09\xe9\xa3\x80\xca\0\xc4A&i#\xb0\x91\xf7\xb6\xa7\xa8\xaez\xcdM\x9fA"
2025/01/13 18:31:00 stdout [2025-01-13 17:31:00.096112 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 28817767 from [::ffff:89.244.85.6]:20083 to [::ffff:176.3.71.185]:14568
2025/01/13 16:57:01 stdout [2025-01-13 15:57:01.336584 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 16:57:01 stdout [2025-01-13 15:57:01.311618 +00:00] INFO [src/peer.rs:102] update_pk 1439711627 [::ffff:77.179.25.102]:37821 b"\xb7\xf4\xf0\xf19\xc06!\x04g\xcf\xdcR\x1f\x0cO\xa1g\xe1/\xa5^s\x03\x18Z\x88\xf8\xf4\x02\0e" b"\xb7\xf4\xf0\xf19\xc06!\x04g\xcf\xdcR\x1f\x0cO\xa1g\xe1/\xa5^s\x03\x18Z\x88\xf8\xf4\x02\0e"
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.290833 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp [::]:0: Ok(212992)
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.290660 +00:00] INFO [src/rendezvous_server.rs:185] Start
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.290488 +00:00] INFO [src/rendezvous_server.rs:153] ALWAYS_USE_RELAY=N
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.290312 +00:00] INFO [src/common.rs:46] relay-servers=["xxx.synology.me"]
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.288726 +00:00] INFO [src/rendezvous_server.rs:139] local-ip: ""
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.288721 +00:00] INFO [src/rendezvous_server.rs:138] mask: None
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.288656 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp [::]:21116: Ok(212992)
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.287553 +00:00] INFO [src/rendezvous_server.rs:103] Listening on websocket :21118
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.287550 +00:00] INFO [src/rendezvous_server.rs:102] Listening on tcp :21115, extra port for NAT test
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.287548 +00:00] INFO [src/rendezvous_server.rs:101] Listening on tcp/udp :21116
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.287543 +00:00] INFO [src/common.rs:46] rendezvous-servers=[]
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.287461 +00:00] INFO [src/rendezvous_server.rs:99] serial=0
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.284416 +00:00] INFO [src/peer.rs:84] DB_URL=./db_v2.sqlite3
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.284411 +00:00] INFO [src/rendezvous_server.rs:1205] Key: TBCxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx=
2025/01/13 16:55:56 stdout [2025-01-13 15:55:56.284386 +00:00] INFO [src/common.rs:122] Private key comes from id_ed25519
2025/01/13 16:55:40 stdout [2025-01-13 15:55:40.878880 +00:00] ERROR [src/rendezvous_server.rs:173] Failed to run hbbs test with 0.0.0.0:21116: Timeout of test_hbbs
2025/01/13 16:55:28 stdout [2025-01-13 15:55:28.152265 +00:00] INFO [src/peer.rs:102] update_pk 1619586320 [::ffff:77.179.25.102]:59560 b"/j\x10\xc0\xd6K\xa8\xac\x07\x82\x8c\x8c\xa3\xadN\x11\x17\xb5:\x10\x155\xfe\xe9oS\xae\\\xc0S\xab&" b"/j\x10\xc0\xd6K\xa8\xac\x07\x82\x8c\x8c\xa3\xadN\x11\x17\xb5:\x10\x155\xfe\xe9oS\xae\\\xc0S\xab&"
2025/01/13 16:55:28 stdout [2025-01-13 15:55:28.105795 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1619586320 from [::ffff:77.187.19.73]:59560 to [::ffff:77.179.25.102]:59560
2025/01/13 15:40:28 stdout [2025-01-13 14:40:28.918105 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 15:40:28 stdout [2025-01-13 14:40:28.878355 +00:00] INFO [src/peer.rs:102] update_pk 1619586320 [::ffff:77.187.19.73]:59560 b"/j\x10\xc0\xd6K\xa8\xac\x07\x82\x8c\x8c\xa3\xadN\x11\x17\xb5:\x10\x155\xfe\xe9oS\xae\\\xc0S\xab&" b"/j\x10\xc0\xd6K\xa8\xac\x07\x82\x8c\x8c\xa3\xadN\x11\x17\xb5:\x10\x155\xfe\xe9oS\xae\\\xc0S\xab&"
2025/01/13 15:40:28 stdout [2025-01-13 14:40:28.843871 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1619586320 from [::ffff:61.8.129.200]:6400 to [::ffff:77.187.19.73]:59560
2025/01/13 15:39:24 stdout [2025-01-13 14:39:24.761504 +00:00] INFO [src/peer.rs:130] pk updated instead of insert
2025/01/13 15:39:24 stdout
2025/01/13 15:39:24 stdout guid = ?
2025/01/13 15:39:24 stdout where
2025/01/13 15:39:24 stdout info = ?
2025/01/13 15:39:24 stdout pk = ?,
2025/01/13 15:39:24 stdout id = ?,
2025/01/13 15:39:24 stdout set
2025/01/13 15:39:24 stdout peer
2025/01/13 15:39:24 stdout update
2025/01/13 15:39:24 stdout
2025/01/13 15:39:24 stdout [2025-01-13 14:39:24.761414 +00:00] WARN [<unnamed>:0] update peer set id=?, …; rows affected: 1, rows returned: 0, elapsed: 25.263s
2025/01/13 15:39:12 stdout [2025-01-13 14:39:12.873060 +00:00] INFO [libs/hbb_common/src/udp.rs:36] Receive buf size of udp 0.0.0.0:0: Ok(212992)
2025/01/13 15:38:59 stdout [2025-01-13 14:38:59.497810 +00:00] INFO [src/peer.rs:102] update_pk 1439711627 [::ffff:77.187.19.73]:42143 b"\xb7\xf4\xf0\xf19\xc06!\x04g\xcf\xdcR\x1f\x0cO\xa1g\xe1/\xa5^s\x03\x18Z\x88\xf8\xf4\x02\0e" b"\xb7\xf4\xf0\xf19\xc06!\x04g\xcf\xdcR\x1f\x0cO\xa1g\xe1/\xa5^s\x03\x18Z\x88\xf8\xf4\x02\0e"
2025/01/13 15:38:59 stdout [2025-01-13 14:38:59.470987 +00:00] INFO [src/rendezvous_server.rs:597] IP change of 1439711627 from [::ffff:61.8.129.79]:3779 to [::ffff:77.187.19.73]:42143
same here, used for month without problems, now it keeps shutting itself down...
2025-03-04 16:19:53.478179 +01:00] ERROR [src/rendezvous_server.rs:173] Failed to run hbbs test with 0.0.0.0:21116: Timeout of test_hbbs
but im using ich777/rustdesk-server-aio
so its a widespread problem...
For most of February I had not a single hbbs crash, without me changing anything about the configuration. I hope it would stay like this, alas it went back to crashing in March and keeps on doing so multiple times a day. If I could provide any more useful data, please let me know.
yeah still "Failed to run hbbs test with" every some hours, i just set it to auto restart every hour
I disabled HDD hibernation on NAS and problem disappears.