morytyann / OpenWrt-mihomo

Transparent Proxy with Mihomo on OpenWrt.
MIT License
1.21k stars 140 forks source link

[BUG]插件会不定时重载 #144

Closed Joee-D closed 2 months ago

Joee-D commented 2 months ago

自查步骤

确认

系统

OpenWrt

系统版本

OpenWrt 23.05-SNAPSHOT r24041-a07a531329

插件版本

1.7.6

硬件架构

x86_64

BUG 描述

插件会不定时重载 8.29晚启动后无任何操作,查看插件日志发现有8.30中午启动的记录 由于本插件日志不会记录之前的日志,所以只能看到最近一次的日志

查看系统日志,发现有多次定时器操作记录。

预期行为

未设置定期重启的情况,不应该重载

复现步骤

正常启动后不定时出现

插件配置

未勾选定时重启,未勾选定时更新GeoX文件

启用√

定时重启

选择配置文件
文件:Joee.yaml
▾
上传配置文件
文件 /etc/mihomo/profiles/Joee.yaml (2.28 KB)
混入√

检查配置文件√

快速重载√
定时更新GeoX文件 

配置文件

log-level: error mode: rule find-process-mode: off unified-delay: true tcp-concurrent: true keep-alive-interval: 600 ipv6: true external-ui: ui external-ui-name: metacubexd external-ui-url: https://mirror.ghproxy.com/https://github.com/MetaCubeX/metacubexd/archive/refs/heads/gh-pages.zip external-controller: 0.0.0.0:9090 secret: **** profile: store-selected: true store-fake-ip: true allow-lan: true port: 8080 socks-port: 1080 mixed-port: 7890 redir-port: 7891 tproxy-port: 7892 tun: stack: mixed device: tun mtu: 9000 gso: true gso-max-size: 65536 endpoint-independent-nat: false enable: false dns: enable: true listen: 0.0.0.0:1053 enhanced-mode: fake-ip fake-ip-range: 198.18.0.1/16 ipv6: true use-system-hosts: true use-hosts: false fake-ip-filter:

插件日志

[2024-08-30 12:10:57] App is enabled. [2024-08-30 12:10:57] Starting... [2024-08-30 12:10:57] Use Profile: Joee.yaml [2024-08-30 12:10:57] Mixin is enabled, mixin all config. [2024-08-30 12:10:57] Profile testing... [2024-08-30 12:11:00] Profile test passed! [2024-08-30 12:11:00] Start Core [2024-08-30 12:11:00] Transparent Proxy is enabled. [2024-08-30 12:11:00] Transparent Proxy: Start hijack. [2024-08-30 12:11:00] Transparent Proxy: Using TPROXY mode. [2024-08-30 12:11:00] Transparent Proxy: IPv4 DNS Hijack is enabled, IPv4 dns request will redirect to the core. [2024-08-30 12:11:01] Transparent Proxy: IPv6 DNS Hijack is enabled, IPv6 dns request will redirect to the core. [2024-08-30 12:11:01] Transparent Proxy: IPv4 Proxy is enabled, set proxy for IPv4 traffic. [2024-08-30 12:11:01] Transparent Proxy: IPv6 Proxy is enabled, set proxy for IPv6 traffic. [2024-08-30 12:11:01] Transparent Proxy: Destination TCP Port to Proxy: 1-65535. [2024-08-30 12:11:01] Transparent Proxy: Destination UDP Port to Proxy: 1-65535. [2024-08-30 12:11:01] Transparent Proxy: Add exclusions. [2024-08-30 12:11:01] Transparent Proxy: Router Proxy is enabled, set proxy for router. [2024-08-30 12:11:01] Transparent Proxy: Lan Proxy is enabled, set proxy for lan. [2024-08-30 12:11:01] Transparent Proxy: Access Control is using allow mode, set proxy for client which is in acl. [2024-08-30 12:11:01] Start Successful!

核心日志

No response

附加信息

系统中未设置其他定时配置,但是可以看到系统日志中有多个crontab记录,应该是本插件cleanup过程触发的删除动作,查看系统日志无其他明显日志。 Fri Aug 30 02:30:22 2024 cron.err crond[17635]: crond (busybox 1.36.1) started, log level 8 Fri Aug 30 03:06:27 2024 cron.err crond[21345]: crond (busybox 1.36.1) started, log level 8 Fri Aug 30 03:26:37 2024 cron.err crond[23593]: crond (busybox 1.36.1) started, log level 8 Fri Aug 30 11:50:47 2024 cron.err crond[2618]: crond (busybox 1.36.1) started, log level 8 Fri Aug 30 12:10:57 2024 cron.err crond[4919]: crond (busybox 1.36.1) started, log level 8

liumingan commented 2 months ago

看日志确实是重启过了

morytyann commented 2 months ago

应该是reload_trigger导致的

morytyann commented 2 months ago

你看下有没有firewall重启/重新加载的日志

Joee-D commented 2 months ago

你看下有没有firewall重启/重新加载的日志

系统日志中没有,系统日志设置的是调试级别

Fri Aug 30 02:30:22 2024 cron.err crond[17635]: crond (busybox 1.36.1) started, log level 8
Fri Aug 30 03:06:27 2024 cron.err crond[21345]: crond (busybox 1.36.1) started, log level 8
Fri Aug 30 03:26:37 2024 cron.err crond[23593]: crond (busybox 1.36.1) started, log level 8
Fri Aug 30 11:50:47 2024 cron.err crond[2618]: crond (busybox 1.36.1) started, log level 8
Fri Aug 30 12:10:57 2024 cron.err crond[4919]: crond (busybox 1.36.1) started, log level 8
Fri Aug 30 14:24:25 2024 daemon.err uhttpd[2152]: [info] luci: accepted login on /admin/services/mihomo/log for root from 127.0.0.1
Fri Aug 30 15:32:49 2024 daemon.err uhttpd[2152]: [info] luci: accepted login on /admin/services/mihomo/config for root from 127.0.0.1
Fri Aug 30 16:41:07 2024 daemon.err uhttpd[2152]: [info] luci: accepted login on /admin/services/mihomo/config for root from 127.0.0.1
Fri Aug 30 20:41:44 2024 daemon.err uhttpd[2152]: [info] luci: accepted login on /admin/status/overview for root from 192.168.1.208

reload_trigge会被什么外部变化触发呢?

morytyann commented 2 months ago

@Joee-D wan接口pppoe重播,或者dhcp获取新的lease时会触发

Joee-D commented 2 months ago

@Joee-D wan接口pppoe重播,或者dhcp获取新的lease时会触发

哦,这个我理解,本机是pppoe拨号的,确认过程没有pppoe重播(重播会有系统日志)。 那几次异常的crond 记录是连在一起的,也就是连续发生多次,中间没有其他日志,是完整的系统日志。

morytyann commented 2 months ago

@Joee-D crond的日志是因为插件会重启它,说实话我没有遇到过,也没复现过,还需要更多信息才能解决

Joee-D commented 2 months ago

@Joee-D crond的日志是因为插件会重启它,说实话我没有遇到过,也没复现过,还需要更多信息才能解决

当前确实无法收集到更多信息。 issue建议暂时先开一段时间,我重启下系统再观察几天,无法复现或无更多信息后关闭。

PKC278 commented 2 months ago

我也遇到了这个问题,昨天22:10:52自动重启,今天09:44:23自动重启,使用pppoe拨号上网,接口没有重启,系统日志中也没有找到更多有用信息,继续观察中

Joee-D commented 2 months ago

重启后一晚上还是出现了

Sat Aug 31 03:59:58 2024 cron.err crond[10127]: crond (busybox 1.36.1) started, log level 8
Sat Aug 31 04:20:07 2024 cron.err crond[12490]: crond (busybox 1.36.1) started, log level 8

看了一下代码,打算编个版本,做如下尝试:

1. 删除启动删除历史log的操作,保留多次log

https://github.com/morytyann/OpenWrt-mihomo/blob/b9f76872077ed90ddfebbb0649e2b695af39382d/mihomo/files/mihomo.init#L12

2.在reload_service增加记录log

https://github.com/morytyann/OpenWrt-mihomo/blob/b9f76872077ed90ddfebbb0649e2b695af39382d/mihomo/files/mihomo.init#L396 当前看只有两个会触发reload 一个是配置变更触发 https://github.com/morytyann/OpenWrt-mihomo/blob/b9f76872077ed90ddfebbb0649e2b695af39382d/mihomo/files/mihomo.init#L402 另外一个是端口变化触发 https://github.com/morytyann/OpenWrt-mihomo/blob/b9f76872077ed90ddfebbb0649e2b695af39382d/mihomo/files/mihomo.init#L409 感觉还是端口变化触发的可能大

3.尝试不监听wan6接口,怀疑是否是wan6的问题

https://github.com/morytyann/OpenWrt-mihomo/blob/b9f76872077ed90ddfebbb0649e2b695af39382d/mihomo/files/mihomo.init#L406

morytyann commented 2 months ago

应该是wan6的问题

morytyann commented 2 months ago

已经处理了,不再绕过IP,改成绕过接口,这样就不用添加接口的reload_trigger了。

Joee-D commented 2 months ago

已经处理了,不再绕过IP,改成绕过接口,这样就不用添加接口的reload_trigger了。

image

已经编译了这个分支&安装了,继续观察下

morytyann commented 2 months ago

理论上不会出现了,因为已经没有接口的reload_trigger了,我先关闭了,如果问题复现再Reopen吧

Joee-D commented 2 months ago

理论上不会出现了,因为已经没有接口的reload_trigger了,我先关闭了,如果问题复现再Reopen吧

1.7.7使用了两天,没有重启记录,也暂无遇到新的问题。 现在wan口pppoe重播也不会触发重载了。由于绕过了wan_device而不是wan ip,也没有问题。