Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

在 Openwrt procd init 脚本中设置 env RUST_BACKTRACE=1 ，在哪里看到 log？ #143

Closed
moxuanyuan opened this issue Mar 21, 2022 · 13 comments · Fixed by #147
Closed

在 Openwrt procd init 脚本中设置 env RUST_BACKTRACE=1 ，在哪里看到 log？ #143

moxuanyuan opened this issue Mar 21, 2022 · 13 comments · Fixed by #147

Comments

@moxuanyuan
Copy link

moxuanyuan commented Mar 21, 2022 •
edited
Loading

rathole 是安装在旁路由 openwrt 中。是从这里下载的 https://github.com/rapiz1/rathole/releases/download/v0.4.0/rathole-aarch64-unknown-linux-musl.zip

主路由每晚4点30分会自动重启，重启后，server 端( docker 0.4.0 版) 大约在 4点47分左右 显示下面这样的 log

Mar 21 04:47:43.964 ERROR connection{addr=xxx.xxx.197.12:56812}:handle{service=home_syncthing}:run: rathole::server: Failed to write control cmds: Operation timed out (os error 110)
Mar 21 04:47:43.965  INFO connection{addr=xxx.xxx.197.12:56812}:handle{service=home_syncthing}:run: rathole::server: Control channel shutdown

为了搞清什么问题，我在 openwrt 启动脚本 /etc/init.d/rathole 中 加了 RUST_BACKTRACE=1

#!/bin/sh /etc/rc.common

START=99 

USE_PROCD=1

PROG=/usr/sbin/rathole

CONFIG=/etc/rathole/config.toml

start_service() { 
    procd_open_instance
    procd_set_param env RUST_BACKTRACE=1
    procd_set_param command $PROG --client $CONFIG
    procd_set_param respawn 3600 10 50
    procd_close_instance
}

restart_service() {
 　　stop
 　　start
}

重启 op，rathole 能正常启动，但没找到地方看 log。。在 openwrt 的系统日志中也看不到
感觉是 env 没起作用，然后将脚本改成 procd_set_param command RUST_BACKTRACE=1 $PROG --client $CONFIG
结果 rathole 不能启动。。
我应该怎样 debug 呢？
@moxuanyuan
Copy link
Author

刚刚遇到一个问题，没断网，但 server 端显示其中一个端口 Shutdown，其它的正常。只能重启 client 端

@rapiz1
Copy link
Owner

rapiz1 commented Mar 21, 2022

rathole::server: Failed to write control cmds: Operation timed out (os error 110) 的原因我已经有了大概的推测，我会在近期尽快修复。

刚刚遇到一个问题，没断网，但 server 端显示其中一个端口 Shutdown，其它的正常。只能重启 client 端

连接偶尔断开是正常的，只要能自动重连就不影响使用。你可以提供复现环境和这个问题相关的日志吗？

@moxuanyuan
Copy link
Author

rathole::server: Failed to write control cmds: Operation timed out (os error 110) 的原因我已经有了大概的推测，我会在近期尽快修复。

刚刚遇到一个问题，没断网，但 server 端显示其中一个端口 Shutdown，其它的正常。只能重启 client 端

连接偶尔断开是正常的，只要能自动重连就不影响使用。你可以提供复现环境和这个问题相关的日志吗？

我就是不知那里看日志才发 issue

@rapiz1
Copy link
Owner

rapiz1 commented Mar 21, 2022

rathole 的日志输出在 stdout/stderr。你可以试试

         procd_set_param stdout 1 # forward stdout of the command to logd
         procd_set_param stderr 1 # same for stderr

参见 https://openwrt.org/docs/guide-developer/procd-init-scripts

@moxuanyuan
Copy link
Author

rathole 的日志输出在 stdout/stderr。你可以试试

         procd_set_param stdout 1 # forward stdout of the command to logd
         procd_set_param stderr 1 # same for stderr

参见 https://openwrt.org/docs/guide-developer/procd-init-scripts

谢谢，在系统日志中看到log了，我再观察一下，到时有什么情况再跟你反馈一下。

@moxuanyuan
Copy link
Author

moxuanyuan commented Mar 23, 2022 •
edited
Loading

看了 log ，client 端在路由器断网 ( 04:30 ) 后，不能自动重连 server 端吗？

下面是log

Wed Mar 23 04:30:23 2022 daemon.info rathole[2947]: Mar 23 04:30:23.644  WARN handle{service=home_syncthing}:run: rathole::client: Heartbeat timed out
Wed Mar 23 04:30:23 2022 daemon.info rathole[2947]: Mar 23 04:30:23.644  INFO handle{service=home_syncthing}:run: rathole::client: Control channel shutdown
Wed Mar 23 04:30:24 2022 daemon.info rathole[2947]: Mar 23 04:30:24.598  WARN handle{service=home_ssh}:run: rathole::client: Heartbeat timed out
Wed Mar 23 04:30:24 2022 daemon.info rathole[2947]: Mar 23 04:30:24.598  INFO handle{service=home_ssh}:run: rathole::client: Control channel shutdown
Wed Mar 23 04:30:36 2022 daemon.info rathole[2947]: Mar 23 04:30:36.921  WARN handle{service=home_docker}:run: rathole::client: Heartbeat timed out
Wed Mar 23 04:30:36 2022 daemon.info rathole[2947]: Mar 23 04:30:36.921  INFO handle{service=home_docker}:run: rathole::client: Control channel shutdown
Wed Mar 23 04:30:41 2022 daemon.info rathole[2947]: Mar 23 04:30:41.057  WARN handle{service=home_bypass}:run: rathole::client: Heartbeat timed out
Wed Mar 23 04:30:41 2022 daemon.info rathole[2947]: Mar 23 04:30:41.057  INFO handle{service=home_bypass}:run: rathole::client: Control channel shutdown
Wed Mar 23 04:31:02 2022 daemon.info rathole[2947]: Mar 23 04:31:02.843  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:02 2022 daemon.info rathole[2947]: Mar 23 04:31:02.843  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.057  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.057  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.057  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.270  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.270  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:03 2022 daemon.info rathole[2947]: Mar 23 04:31:03.910  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:04 2022 daemon.info rathole[2947]: Mar 23 04:31:04.337  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:04 2022 daemon.info rathole[2947]: Mar 23 04:31:04.550  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:04 2022 daemon.info rathole[2947]: Mar 23 04:31:04.763  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:04 2022 daemon.info rathole[2947]: Mar 23 04:31:04.764  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:04 2022 daemon.info rathole[2947]: Mar 23 04:31:04.764  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:06 2022 daemon.info rathole[2947]: Mar 23 04:31:06.845  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:07 2022 daemon.info rathole[2947]: Mar 23 04:31:07.272  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:07 2022 daemon.info rathole[2947]: Mar 23 04:31:07.274  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:07 2022 daemon.info rathole[2947]: Mar 23 04:31:07.280  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:08 2022 daemon.info rathole[2947]: Mar 23 04:31:08.553  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:08 2022 daemon.info rathole[2947]: Mar 23 04:31:08.763  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:08 2022 daemon.info rathole[2947]: Mar 23 04:31:08.764  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:08 2022 daemon.info rathole[2947]: Mar 23 04:31:08.766  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:08 2022 daemon.info rathole[2947]: Mar 23 04:31:08.978  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:09 2022 daemon.info rathole[2947]: Mar 23 04:31:09.193  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:09 2022 daemon.info rathole[2947]: Mar 23 04:31:09.832  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:09 2022 daemon.info rathole[2947]: Mar 23 04:31:09.833  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:13 2022 daemon.info rathole[2947]: Mar 23 04:31:13.246  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:13 2022 daemon.info rathole[2947]: Mar 23 04:31:13.461  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:13 2022 daemon.info rathole[2947]: Mar 23 04:31:13.461  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:13 2022 daemon.info rathole[2947]: Mar 23 04:31:13.674  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:14 2022 daemon.info rathole[2947]: Mar 23 04:31:14.101  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:14 2022 daemon.info rathole[2947]: Mar 23 04:31:14.312  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Wed Mar 23 04:31:14 2022 daemon.info rathole[2947]: Mar 23 04:31:14.526  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)

@moxuanyuan moxuanyuan mentioned this issue Mar 24, 2022
Closed
@rapiz1
Copy link
Owner

rapiz1 commented Mar 24, 2022

04:31:14 之后还有日志吗？

@moxuanyuan moxuanyuan mentioned this issue Mar 24, 2022
Closed
@moxuanyuan
Copy link
Author

04:31:14 之后还有日志吗？

没了，我早上10点多看的，进程还在，没其它日志，此时只能重启 client 。。前几天好似是重启 server 端也行（不确定）

@rapiz1
Copy link
Owner

rapiz1 commented Mar 24, 2022

可以麻烦你用 procd_set_param env RUST_LOG=debug 开启 debug 级别的 log 看看吗？
另外，v0.3.9 有没有问题？

@moxuanyuan
Copy link
Author

可以麻烦你用 procd_set_param env RUST_LOG=debug 开启 debug 级别的 log 看看吗？ 另外，v0.3.9 有没有问题？

我也是第一次用 rathole，直接上了 v0.4.0，我去设置一下 procd_set_param env RUST_LOG=debug，有新 log，再来反馈

@moxuanyuan
Copy link
Author

moxuanyuan commented Mar 25, 2022 •
edited
Loading

可以麻烦你用 procd_set_param env RUST_LOG=debug 开启 debug 级别的 log 看看吗？ 另外，v0.3.9 有没有问题？

下面是我重启 rathole 后，路由器系统日志

Fri Mar 25 11:22:09 我设了 procd_set_param env RUST_LOG=debug 然后 restart rathole
Fri Mar 25 11:23:51 我重启路由器
Fri Mar 25 11:24:01 路由器应该重启完成
Fri Mar 25 11:24:15 rathole 输出 log ，似乎跟没有开启 RUST_LOG=debug 前的 log 一样的，没有更多可参考的数据

Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.703 DEBUG rathole: Config { server: Some(ServerConfig { bind_addr: "0.0.0.0:2333", default_token: Some(MASKED), services: {"home_bypass": ServerServiceConfig { service_type: Tcp, name: "home_bypass", bind_addr: "0.0.0.0:8001", token: Some(MASKED), nodelay: None }, "home_docker": ServerServiceConfig { service_type: Tcp, name: "home_docker", bind_addr: "0.0.0.0:23751", token: Some(MASKED), nodelay: None }, "home_ssh": ServerServiceConfig { service_type: Tcp, name: "home_ssh", bind_addr: "0.0.0.0:2201", token: Some(MASKED), nodelay: None }, "home_syncthing": ServerServiceConfig { service_type: Tcp, name: "home_syncthing", bind_addr: "0.0.0.0:18384", token: Some(MASKED), nodelay: None }}, transport: TransportConfig { transport_type: Noise, tcp: TcpConfig { nodelay: false, keepalive_secs: 20, keepalive_interval: 8, proxy: None }, tls: None, noise: Some(NoiseConfig { pattern: "Noise_NK_25519_ChaChaPoly_BLAKE2s", local_private_key: Some(MASKED), remote_public_key:
Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.703  INFO config_watcher{path="/etc/rathole/config.toml"}: rathole::config_watcher: Start watching the config
Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.704  INFO handle{service=home_ssh}: rathole::client: Starting 835b7fe68ccba1910c458abe92273c3a6371e3b672d9c7b8a1dad13e4f4478ee
Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.704  INFO handle{service=home_bypass}: rathole::client: Starting 311764048e4434645b347e5c3020ec4ea392ce1a5c667c7550e50856d8fefac9
Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.704  INFO handle{service=home_docker}: rathole::client: Starting 28679bf89620a40e21026698075c23eae538c8bb007a22a6f17774e134bd32fd
Fri Mar 25 11:22:09 2022 daemon.info rathole[24364]: Mar 25 11:22:09.704  INFO handle{service=home_syncthing}: rathole::client: Starting 5eec12d8e3ab19a8ae66a064162c8d3f995ca4a9694efe38dfb8ca5cb8d7c24c
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.357 DEBUG handle{service=home_syncthing}:run: rathole::client: Sending hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.358 DEBUG handle{service=home_syncthing}:run: rathole::client: Reading hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.364 DEBUG handle{service=home_ssh}:run: rathole::client: Sending hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.364 DEBUG handle{service=home_docker}:run: rathole::client: Sending hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.365 DEBUG handle{service=home_ssh}:run: rathole::client: Reading hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.365 DEBUG handle{service=home_docker}:run: rathole::client: Reading hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.365 DEBUG handle{service=home_bypass}:run: rathole::client: Sending hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.365 DEBUG handle{service=home_bypass}:run: rathole::client: Reading hello
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.519 DEBUG handle{service=home_syncthing}:run: rathole::client: Sending auth
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.519 DEBUG handle{service=home_syncthing}:run: rathole::client: Reading ack
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.526 DEBUG handle{service=home_docker}:run: rathole::client: Sending auth
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.526 DEBUG handle{service=home_ssh}:run: rathole::client: Sending auth
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.526 DEBUG handle{service=home_docker}:run: rathole::client: Reading ack
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.527 DEBUG handle{service=home_ssh}:run: rathole::client: Reading ack
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.527 DEBUG handle{service=home_bypass}:run: rathole::client: Sending auth
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.528 DEBUG handle{service=home_bypass}:run: rathole::client: Reading ack
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.682  INFO handle{service=home_syncthing}:run: rathole::client: Control channel established
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.683 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.683 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.683 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.684 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.684 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.684 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.684 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.685 DEBUG handle{service=home_syncthing}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.693  INFO handle{service=home_docker}:run: rathole::client: Control channel established
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.693  INFO handle{service=home_ssh}:run: rathole::client: Control channel established
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.693 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.693 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.694 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.694 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.694 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.695 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.695 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.695  INFO handle{service=home_bypass}:run: rathole::client: Control channel established
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.695 DEBUG handle{service=home_docker}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.696 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.696 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.697 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.697 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.697 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.698 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.698 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.698 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.699 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.699 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.699 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.700 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.700 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.700 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.700 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:10 2022 daemon.info rathole[24364]: Mar 25 11:22:10.700 DEBUG handle{service=home_ssh}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:29 2022 daemon.info rathole[24364]: Mar 25 11:22:29.270 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:29 2022 daemon.info rathole[24364]: Mar 25 11:22:29.271 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:30 2022 daemon.info rathole[24364]: Mar 25 11:22:30.249 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:30 2022 daemon.info rathole[24364]: Mar 25 11:22:30.249 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.788 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.788 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.841 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.841 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.841 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.842 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.842 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.843 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.843 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.843 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.844 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:31 2022 daemon.info rathole[24364]: Mar 25 11:22:31.850 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:33 2022 daemon.info rathole[24364]: Mar 25 11:22:33.316 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:33 2022 daemon.info rathole[24364]: Mar 25 11:22:33.316 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:33 2022 daemon.info rathole[24364]: Mar 25 11:22:33.317 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:33 2022 daemon.info rathole[24364]: Mar 25 11:22:33.317 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:35 2022 daemon.info rathole[24364]: Mar 25 11:22:35.233 DEBUG handle{service=home_bypass}:run:run_data_channel_for_tcp{local_addr="127.0.0.1:80"}: rathole::client: New data channel starts forwarding
Fri Mar 25 11:22:35 2022 daemon.info rathole[24364]: Mar 25 11:22:35.235 DEBUG handle{service=home_bypass}:run: rathole::client: Received CreateDataChannel
Fri Mar 25 11:22:40 2022 daemon.info rathole[24364]: Mar 25 11:22:40.684 DEBUG handle{service=home_syncthing}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:22:40 2022 daemon.info rathole[24364]: Mar 25 11:22:40.695 DEBUG handle{service=home_docker}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:22:40 2022 daemon.info rathole[24364]: Mar 25 11:22:40.696 DEBUG handle{service=home_ssh}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:05 2022 daemon.info rathole[24364]: Mar 25 11:23:05.235 DEBUG handle{service=home_bypass}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:10 2022 daemon.info rathole[24364]: Mar 25 11:23:10.686 DEBUG handle{service=home_syncthing}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:10 2022 daemon.info rathole[24364]: Mar 25 11:23:10.697 DEBUG handle{service=home_docker}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:10 2022 daemon.info rathole[24364]: Mar 25 11:23:10.697 DEBUG handle{service=home_ssh}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:35 2022 daemon.info rathole[24364]: Mar 25 11:23:35.237 DEBUG handle{service=home_bypass}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:40 2022 daemon.info rathole[24364]: Mar 25 11:23:40.687 DEBUG handle{service=home_syncthing}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:40 2022 daemon.info rathole[24364]: Mar 25 11:23:40.698 DEBUG handle{service=home_ssh}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:40 2022 daemon.info rathole[24364]: Mar 25 11:23:40.698 DEBUG handle{service=home_docker}:run: rathole::client: Received HeartBeat
Fri Mar 25 11:23:51 2022 kern.info kernel: [346207.740788] meson8b-dwmac c9410000.ethernet eth0: Link is Down
Fri Mar 25 11:23:51 2022 daemon.notice netifd: Network device 'eth0' link is down
Fri Mar 25 11:23:51 2022 daemon.notice netifd: Interface 'lan' has link connectivity loss
Fri Mar 25 11:23:55 2022 daemon.notice netifd: Network device 'eth0' link is up
Fri Mar 25 11:23:55 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Fri Mar 25 11:23:55 2022 kern.info kernel: [346211.714671] meson8b-dwmac c9410000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Fri Mar 25 11:23:59 2022 daemon.notice netifd: Network device 'eth0' link is down
Fri Mar 25 11:23:59 2022 daemon.notice netifd: Interface 'lan' has link connectivity loss
Fri Mar 25 11:23:59 2022 kern.info kernel: [346215.747934] meson8b-dwmac c9410000.ethernet eth0: Link is Down
Fri Mar 25 11:24:01 2022 daemon.notice netifd: Network device 'eth0' link is up
Fri Mar 25 11:24:01 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Fri Mar 25 11:24:01 2022 kern.info kernel: [346218.464990] meson8b-dwmac c9410000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Fri Mar 25 11:24:15 2022 daemon.info rathole[24364]: Mar 25 11:24:15.238  WARN handle{service=home_bypass}:run: rathole::client: Heartbeat timed out
Fri Mar 25 11:24:15 2022 daemon.info rathole[24364]: Mar 25 11:24:15.238  INFO handle{service=home_bypass}:run: rathole::client: Control channel shutdown
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.688  WARN handle{service=home_syncthing}:run: rathole::client: Heartbeat timed out
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.688  INFO handle{service=home_syncthing}:run: rathole::client: Control channel shutdown
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.699  WARN handle{service=home_docker}:run: rathole::client: Heartbeat timed out
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.699  WARN handle{service=home_ssh}:run: rathole::client: Heartbeat timed out
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.700  INFO handle{service=home_docker}:run: rathole::client: Control channel shutdown
Fri Mar 25 11:24:20 2022 daemon.info rathole[24364]: Mar 25 11:24:20.700  INFO handle{service=home_ssh}:run: rathole::client: Control channel shutdown
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.865  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.865  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.867  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.867  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.867  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.867  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.867  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.868  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.866  WARN handle{service=home_docker}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.869  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.869  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.869  WARN handle{service=home_ssh}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:49 2022 daemon.info rathole[24364]: Mar 25 11:24:49.869  WARN handle{service=home_syncthing}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:50 2022 daemon.info rathole[24364]: Mar 25 11:24:50.505  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:50 2022 daemon.info rathole[24364]: Mar 25 11:24:50.505  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:50 2022 daemon.info rathole[24364]: Mar 25 11:24:50.506  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:50 2022 daemon.info rathole[24364]: Mar 25 11:24:50.507  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:50 2022 daemon.info rathole[24364]: Mar 25 11:24:50.507  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:51 2022 daemon.info rathole[24364]: Mar 25 11:24:51.787  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:51 2022 daemon.info rathole[24364]: Mar 25 11:24:51.788  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)
Fri Mar 25 11:24:53 2022 daemon.info rathole[24364]: Mar 25 11:24:53.706  WARN handle{service=home_bypass}:run: rathole::client: Failed to run the data channel: Failed to read cmd: Connection reset by peer (os error 104)

@rapiz1 rapiz1 mentioned this issue Mar 25, 2022
Merged
@rapiz1
Copy link
Owner

rapiz1 commented Mar 25, 2022

感谢你的反馈
https://github.com/rapiz1/rathole/actions/runs/2038127693 应该能够修复心跳超时后不会自动重连的问题，请测试一下有没有修复你遇到的问题

@rapiz1 rapiz1 mentioned this issue Mar 28, 2022
Closed
@rapiz1
Copy link
Owner

rapiz1 commented Apr 1, 2022

还有问题吗？

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix: restart when heartbeat times out rapiz1/rathole
2 participants
@moxuanyuan @rapiz1