search

SagerNet / sing-box

The universal proxy platform
https://sing-box.sagernet.org/
Other
20.01k stars 2.38k forks source link

sing-box server端运行一段时间后造成系统死机无响应 #247

Closed leeaash closed 1 year ago

leeaash commented 1 year ago

Welcome

Description of the problem

sing-box用docker形式跑在AWS lightsail 1 CPU 1G memeory VM上。 代理流量用shaowtls+ss的配置，基本一天内虚机就会死机，只能重启解决。 如果流量不切到sing-box上但容器仍旧运行，虚机超过一天也不会出现死机状态 怀疑 sing-box导致内存泄漏和cpu利用率高的情况，直至系统最终挂起无响应。 试了1.06，1.07，1.1beta17版本，情况相同

Version of sing-box

1.06，1.07，1.1beta17 ```console $ sing-box version # Paste output here ```

Server and client configuration file

```console # paste json here ``` server configuration { "log": { "disabled": false, "level": "debug", "timestamp": true }, "inbounds": [ { "type": "shadowtls", "listen": "::", "listen_port": 54443, "handshake": { "server": "www.bing.com", "server_port": 443 }, "detour": "ss-in" }, { "type": "shadowsocks", "tag": "ss-in", "listen": "127.0.0.1", "method": "2022-blake3-aes-128-gcm", "password": "password" }, { "type": "vmess", "tag": "vmess-in", "listen": "::", "listen_port": 10088, "users": [ { "name": "name", "uuid": "uuid", "alterId": 0 } ], "transport": { "type": "ws", "path": "/path", "max_early_data": 0, "early_data_header_name": "Sec-WebSocket-Protocol" } } ] } client configuration { "log": { "disabled": false, "level": "info", "timestamp": true }, "inbounds": [ { "type": "socks", "tag": "socks-in", "listen": "127.0.0.1", "listen_port": 10088 }, { "type": "socks", "tag": "socks-vmess", "listen": "127.0.0.1", "listen_port": 10188 } ], "outbounds": [ { "type": "shadowsocks", "tag": "ss-out", "method": "2022-blake3-aes-128-gcm", "password": "password", "detour": "shadowtls-out", "multiplex": { "enabled": true, "max_connections": 6, "min_streams": 6 } }, { "type": "shadowtls", "tag": "shadowtls-out", "server": "server_ip", "server_port": 443, "tls": { "enabled": true, "server_name": "www.bing.com" } }, { "type": "vmess", "tag": "vmess-out", "server": "server-name", "server_port": 443, "uuid": "uuid", "alter_id": 0, "security": "auto", "tls": { "enabled": true, "disable_sni": false, "server_name": "server-name", "insecure": false, "alpn": [] }, "transport": { "type": "ws", "path": "/path", "max_early_data": 0, "early_data_header_name": "Sec-WebSocket-Protocol" }, "multiplex": { "enabled": true, "max_connections": 6, "min_streams": 6 } } ], "route": { "rules": [ { "inbound": "socks-in", "outbound": "ss-out" }, { "inbound": "socks-vmess", "outbound": "vmess-out" } ] } }

Server and client log file

```console # paste log here 出现断连问题的时间点应该从日志的16:56分开始 ``` Nov 21 15:16:22 systemd-networkd[396]: message repeated 22 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 15:17:01 CRON[31438]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 21 15:17:30 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:30:12 systemd-networkd[396]: message repeated 11 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 15:31:22 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:32:25 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:33:42 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:34:49 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:36:02 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:39:22 systemd-networkd[396]: message repeated 3 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 15:39:22 systemd[1]: Starting Cleanup of Temporary Directories... Nov 21 15:39:22 systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Nov 21 15:39:22 systemd[1]: Finished Cleanup of Temporary Directories. Nov 21 15:40:32 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:44:02 systemd-networkd[396]: message repeated 3 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 15:45:12 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:46:22 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:47:32 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:48:37 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 15:54:22 systemd-networkd[396]: message repeated 5 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 15:55:32 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 16:16:21 systemd-networkd[396]: message repeated 18 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 16:17:01 CRON[31725]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 21 16:17:29 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 16:48:30 systemd-networkd[396]: message repeated 27 times: [ eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450] Nov 21 16:49:42 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 16:50:52 systemd-networkd[396]: eth0: DHCPv6 address da18:ac0:d741:29cb/128 timeout preferred 140 valid 450 Nov 21 16:56:03 systemd-networkd[396]: eth0: Could not set NDisc route or address: Connection timed out Nov 21 17:38:38 ss-server[458]: 2022-11-21 17:08:31 ERROR: remote_recv_send: Connection timed out Nov 21 17:49:31 ss-server[458]: 2022-11-21 17:09:44 ERROR: server recv: Connection timed out Nov 21 17:50:47 kernel: [268009.416075] systemd invoked oom-killer: gfp_mask=0x1100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0 Nov 21 17:50:47 kernel: [268009.416084] CPU: 0 PID: 1 Comm: systemd Not tainted 5.15.0-1023-aws #27~20.04.1-Ubuntu Nov 21 17:50:47 kernel: [268009.416087] Hardware name: Xen HVM domU, BIOS 4.11.amazon 08/24/2006 Nov 21 17:50:47 kernel: [268009.416088] Call Trace: Nov 21 17:50:47 kernel: [268009.416091] Nov 21 17:50:47 kernel: [268009.416093] dump_stack_lvl+0x4a/0x63 Nov 21 17:50:47 kernel: [268009.416100] dump_stack+0x10/0x16 Nov 21 17:50:47 kernel: [268009.416103] dump_header+0x53/0x225 Nov 21 17:50:47 kernel: [268009.416108] oom_kill_process.cold+0xb/0x10 Nov 21 17:50:47 kernel: [268009.416111] out_of_memory+0x1dc/0x530 Nov 21 17:50:47 kernel: [268009.416115] __alloc_pages_slowpath.constprop.0+0xcd4/0xde0 Nov 21 17:50:47 kernel: [268009.416119] ? __alloc_pages_slowpath.constprop.0+0xd88/0xde0 Nov 21 17:50:47 kernel: [268009.416123] __alloc_pages+0x2cc/0x310 Nov 21 17:50:47 kernel: [268009.416126] alloc_pages+0x90/0x120 Nov 21 17:50:47 kernel: [268009.416129] __page_cache_alloc+0x87/0xc0 Nov 21 17:50:47 kernel: [268009.416133] pagecache_get_page+0x150/0x530 Nov 21 17:50:47 kernel: [268009.416136] ? page_cache_ra_unbounded+0x16a/0x220 Nov 21 17:50:47 kernel: [268009.416145] filemap_fault+0x527/0xb60 Nov 21 17:50:47 kernel: [268009.416147] ? filemap_map_pages+0x138/0x640 Nov 21 17:50:47 kernel: [268009.416151] __do_fault+0x40/0x120 Nov 21 17:50:47 kernel: [268009.416156] do_fault+0x1f9/0x420 Nov 21 17:50:47 kernel: [268009.416159] __handle_mm_fault+0x62c/0x840 Nov 21 17:50:47 kernel: [268009.416161] handle_mm_fault+0xd8/0x2c0 Nov 21 17:50:47 kernel: [268009.416163] do_user_addr_fault+0x1c2/0x660 Nov 21 17:50:47 kernel: [268009.416167] exc_page_fault+0x77/0x170 Nov 21 17:50:47 kernel: [268009.416172] asm_exc_page_fault+0x27/0x30 Nov 21 17:50:47 kernel: [268009.416175] RIP: 0033:0x7fe9de36d6e5 Nov 21 17:50:47 kernel: [268009.416179] Code: 00 00 0f 1f 00 31 c0 c5 f8 77 c3 66 2e 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 89 f9 48 89 fa c5 f9 ef c0 83 e1 3f 83 f9 20 77 2b fd 74 0f c5 fd d7 c1 85 c0 0f 85 eb 00 00 00 48 83 c7 20 83 e1 Nov 21 17:50:47 kernel: [268009.416181] RSP: 002b:00007ffcf377ab98 EFLAGS: 00010283 Nov 21 17:50:47 kernel: [268009.416183] RAX: 00007fe9de04dc22 RBX: 0000000000000073 RCX: 000000000000001e Nov 21 17:50:47 kernel: [268009.416185] RDX: 000055e9f2028d5e RSI: 0000000000000073 RDI: 000055e9f2028d5e Nov 21 17:50:47 kernel: [268009.416186] RBP: 000055e9f22d5350 R08: 0000000000000000 R09: 0000000000000000 Nov 21 17:50:47 kernel: [268009.416188] R10: 0000000000000000 R11: 0000000000000002 R12: 000055e9f2028d5e Nov 21 17:50:47 kernel: [268009.416189] R13: 00007fe9de1613f8 R14: 0000000000000073 R15: 000055e9f2370b28 Nov 21 17:50:47 kernel: [268009.416191] Nov 21 17:50:47 kernel: [268009.416192] Mem-Info: Nov 21 17:50:47 kernel: [268009.416193] active_anon:597 inactive_anon:188071 isolated_anon:0 Nov 21 17:50:47 kernel: [268009.416193] active_file:7 inactive_file:404 isolated_file:0 Nov 21 17:50:47 kernel: [268009.416193] unevictable:5835 dirty:0 writeback:0 Nov 21 17:50:47 kernel: [268009.416193] slab_reclaimable:9328 slab_unreclaimable:17936 Nov 21 17:50:47 kernel: [268009.416193] mapped:2057 shmem:313 pagetables:2235 bounce:0 Nov 21 17:50:47 kernel: [268009.416193] kernel_misc_reclaimable:0 Nov 21 17:50:47 kernel: [268009.416193] free:12164 free_pcp:940 free_cma:0 Nov 21 17:50:47 kernel: [268009.416198] Node 0 active_anon:2388kB inactive_anon:752284kB active_file:28kB inactive_file:1616kB unevictable:23340kB isolated(anon):0kB isolated(file):0kB mapped:8228kB dirty:0kB writeback:0kB shmem:1252kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB kernel_stack:6400kB pagetables:8940kB all_unreclaimable? yes Nov 21 17:50:47 kernel: [268009.416202] Node 0 DMA free:4456kB min:708kB low:884kB high:1060kB reserved_highatomic:0KB active_anon:4kB inactive_anon:9956kB active_file:0kB inactive_file:8kB unevictable:0kB writepending:0kB present:15988kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:28kB local_pcp:28kB free_cma:0kB Nov 21 17:50:47 kernel: [268009.416207] lowmem_reserve[]: 0 937 937 937 937 Nov 21 17:50:47 kernel: [268009.416212] Node 0 DMA32 free:44200kB min:44344kB low:55428kB high:66512kB reserved_highatomic:0KB active_anon:2384kB inactive_anon:742328kB active_file:28kB inactive_file:1604kB unevictable:23340kB writepending:0kB present:1032192kB managed:974068kB mlocked:18404kB bounce:0kB free_pcp:3732kB local_pcp:3732kB free_cma:0kB Nov 21 17:50:47 kernel: [268009.416217] lowmem_reserve[]: 0 0 0 0 0 Nov 21 17:50:47 kernel: [268009.416221] Node 0 DMA: 6*4kB (UM) 22*8kB (UME) 24*16kB (UME) 21*32kB (UE) 10*64kB (UM) 4*128kB (UE) 2*256kB (UE) 1*512kB (E) 1*1024kB (E) 0*2048kB 0*4096kB = 4456kB Nov 21 17:50:47 kernel: [268009.416235] Node 0 DMA32: 244*4kB (ME) 99*8kB (UME) 238*16kB (UME) 99*32kB (ME) 80*64kB (ME) 81*128kB (UME) 28*256kB (UME) 17*512kB (UME) 4*1024kB (UM) 0*2048kB 0*4096kB = 44200kB Nov 21 17:50:47 kernel: [268009.416249] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB Nov 21 17:50:47 kernel: [268009.416251] 4013 total pagecache pages Nov 21 17:50:47 kernel: [268009.416252] 0 pages in swap cache Nov 21 17:50:47 kernel: [268009.416252] Swap cache stats: add 0, delete 0, find 0/0 Nov 21 17:50:47 kernel: [268009.416254] Free swap = 0kB Nov 21 17:50:47 kernel: [268009.416254] Total swap = 0kB Nov 21 17:50:47 kernel: [268009.416255] 262045 pages RAM Nov 21 17:50:47 kernel: [268009.416256] 0 pages HighMem/MovableOnly Nov 21 17:50:47 kernel: [268009.416256] 14688 pages reserved Nov 21 17:50:47 kernel: [268009.416257] 0 pages hwpoisoned Nov 21 17:50:47 kernel: [268009.416258] Tasks state (memory values in pages): Nov 21 17:50:47 kernel: [268009.416259] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name Nov 21 17:50:47 kernel: [268009.416261] [ 163] 0 163 24599 1078 208896 0 -250 systemd-journal Nov 21 17:50:47 kernel: [268009.416264] [ 191] 0 191 5087 931 61440 0 -1000 systemd-udevd Nov 21 17:50:47 kernel: [268009.416267] [ 331] 102 331 22721 845 77824 0 0 systemd-timesyn Nov 21 17:50:47 kernel: [268009.416269] [ 396] 100 396 6847 945 77824 0 0 systemd-network Nov 21 17:50:47 kernel: [268009.416271] [ 399] 101 399 6137 1746 94208 0 0 systemd-resolve Nov 21 17:50:47 kernel: [268009.416273] [ 433] 0 433 59418 534 98304 0 0 accounts-daemon Nov 21 17:50:47 kernel: [268009.416275] [ 434] 0 434 637 183 45056 0 0 acpid Nov 21 17:50:47 kernel: [268009.416277] [ 442] 0 442 2137 569 57344 0 0 cron Nov 21 17:50:47 kernel: [268009.416279] [ 444] 103 444 1919 905 53248 0 -900 dbus-daemon Nov 21 17:50:47 kernel: [268009.416281] [ 452] 0 452 7471 2558 94208 0 0 networkd-dispat Nov 21 17:50:47 kernel: [268009.416283] [ 453] 0 453 58181 553 94208 0 0 polkitd Nov 21 17:50:47 kernel: [268009.416285] [ 455] 104 455 56125 728 81920 0 0 rsyslogd Nov 21 17:50:47 kernel: [268009.416287] [ 458] 64677 458 4388 2435 73728 0 0 ss-server Nov 21 17:50:47 kernel: [268009.416289] [ 459] 0 459 307844 1353 176128 0 0 amazon-ssm-agen Nov 21 17:50:47 kernel: [268009.416291] [ 462] 0 462 181944 4309 262144 0 -900 snapd Nov 21 17:50:47 kernel: [268009.416293] [ 465] 0 465 4374 840 73728 0 0 systemd-logind Nov 21 17:50:47 kernel: [268009.416295] [ 467] 0 467 98258 1033 122880 0 0 udisksd Nov 21 17:50:47 kernel: [268009.416296] [ 471] 997 471 56864 1728 110592 0 0 zerotier-one Nov 21 17:50:47 kernel: [268009.416298] [ 472] 0 472 951 513 49152 0 0 atd Nov 21 17:50:47 kernel: [268009.416300] [ 473] 0 473 341155 5138 311296 0 -999 containerd Nov 21 17:50:47 kernel: [268009.416302] [ 500] 0 500 78768 792 114688 0 0 ModemManager Nov 21 17:50:47 kernel: [268009.416304] [ 503] 0 503 1840 436 53248 0 0 agetty Nov 21 17:50:47 kernel: [268009.416306] [ 524] 0 524 1459 387 45056 0 0 agetty Nov 21 17:50:47 kernel: [268009.416308] [ 604] 0 604 27034 2750 106496 0 0 unattended-upgr Nov 21 17:50:47 kernel: [268009.416310] [ 651] 0 651 376716 8657 454656 0 -500 dockerd Nov 21 17:50:47 kernel: [268009.416312] [ 686] 0 686 3046 872 61440 0 -1000 sshd Nov 21 17:50:47 kernel: [268009.416314] [ 724] 0 724 624 143 45056 0 0 bpfilter_umh Nov 21 17:50:47 kernel: [268009.416316] [ 915] 0 915 268723 506 131072 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416318] [ 925] 0 925 268723 493 135168 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416320] [ 928] 0 928 268723 510 126976 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416322] [ 935] 0 935 268723 506 135168 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416324] [ 979] 0 979 178100 656 106496 0 -998 containerd-shim Nov 21 17:50:47 kernel: [268009.416326] [ 1011] 0 1011 250290 488 126976 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416328] [ 1028] 0 1028 178164 644 106496 0 -998 containerd-shim Nov 21 17:50:47 kernel: [268009.416330] [ 1032] 0 1032 268723 534 122880 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416332] [ 1129] 0 1129 250290 336 126976 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416334] [ 1135] 0 1135 268723 519 131072 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416335] [ 1150] 0 1150 268437505 391 61440 0 0 wstunnel Nov 21 17:50:47 kernel: [268009.416337] [ 1238] 0 1238 178164 641 106496 0 -998 containerd-shim Nov 21 17:50:47 kernel: [268009.416339] [ 1345] 0 1345 186292 2545 192512 0 0 portainer Nov 21 17:50:47 kernel: [268009.416341] [ 1687] 0 1687 291771 1825 188416 0 0 ssm-agent-worke Nov 21 17:50:47 kernel: [268009.416343] [ 8999] 0 8999 53668 4501 94208 0 -1000 multipathd Nov 21 17:50:47 kernel: [268009.416346] [ 25787] 0 25787 178164 736 106496 0 -998 containerd-shim Nov 21 17:50:47 kernel: [268009.416348] [ 25817] 0 25817 319506 131013 1236992 0 0 sing-box Nov 21 17:50:47 kernel: [268009.416350] [ 26377] 0 26377 287156 513 151552 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416352] [ 26382] 0 26382 287156 493 143360 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416354] [ 26400] 0 26400 287156 526 139264 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416356] [ 26405] 0 26405 287156 307 143360 0 -500 docker-proxy Nov 21 17:50:47 kernel: [268009.416358] [ 26420] 0 26420 178164 649 102400 0 -998 containerd-shim Nov 21 17:50:47 kernel: [268009.416360] [ 26442] 0 26442 209692 5292 389120 0 0 traefik Nov 21 17:50:47 kernel: [268009.416361] [ 26779] 0 26779 428 36 45056 0 0 ash Nov 21 17:50:47 kernel: [268009.416364] [ 31871] 0 31871 3046 874 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416366] [ 31882] 0 31882 2993 696 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416367] [ 31884] 0 31884 2993 691 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416369] [ 31885] 0 31885 2993 703 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416371] [ 31886] 0 31886 2993 720 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416373] [ 31887] 0 31887 2993 702 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416374] [ 31888] 0 31888 2993 687 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416376] [ 31889] 0 31889 2993 713 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416378] [ 31890] 0 31890 2993 755 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416380] [ 31891] 0 31891 2993 726 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416381] [ 31892] 0 31892 2993 673 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416383] [ 31893] 0 31893 2993 718 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416385] [ 31894] 0 31894 2993 630 69632 0 0 sshd Nov 21 17:50:47 kernel: [268009.416387] [ 31895] 0 31895 2993 721 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416388] [ 31896] 0 31896 2993 746 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416390] [ 31900] 0 31900 2993 713 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416392] [ 31902] 0 31902 2993 696 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416393] [ 31904] 0 31904 2993 756 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416395] [ 31905] 0 31905 2993 666 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416397] [ 31906] 0 31906 2993 691 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416399] [ 31907] 0 31907 2993 685 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416400] [ 31908] 0 31908 2993 683 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416402] [ 31909] 0 31909 2993 661 65536 0 0 sshd Nov 21 17:50:47 kernel: [268009.416403] [ 31910] 0 31910 2993 673 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416405] [ 31911] 0 31911 2993 680 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416407] [ 31912] 0 31912 2993 714 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416409] [ 31923] 0 31923 2967 375 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416411] [ 31924] 0 31924 2967 367 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416412] [ 31926] 0 31926 2967 360 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416414] [ 31931] 0 31931 2967 373 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416416] [ 31933] 0 31933 2967 362 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416418] [ 31934] 0 31934 2967 357 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416420] [ 31935] 0 31935 2967 336 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416422] [ 31937] 0 31937 2967 345 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416423] [ 31939] 0 31939 2967 344 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416425] [ 31943] 0 31943 2967 356 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416427] [ 31944] 0 31944 2967 355 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416429] [ 31946] 0 31946 2967 363 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416430] [ 31948] 0 31948 2967 344 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416432] [ 31950] 0 31950 2967 310 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416434] [ 31951] 0 31951 2967 317 53248 0 0 sshd Nov 21 17:50:47 kernel: [268009.416436] [ 31952] 0 31952 2967 297 57344 0 0 sshd Nov 21 17:50:47 kernel: [268009.416438] [ 31954] 0 31954 2928 179 49152 0 0 sshd Nov 21 17:50:47 kernel: [268009.416439] [ 31963] 0 31963 3046 527 61440 0 0 sshd Nov 21 17:50:47 kernel: [268009.416441] [ 31965] 0 31965 1618 96 49152 0 0 modprobe Nov 21 17:50:47 kernel: [268009.416443] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/docker/19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8,task=sing-box,pid=25817,uid=0 Nov 21 17:50:47 kernel: [268009.416465] Out of memory: Killed process 25817 (sing-box) total-vm:1278024kB, anon-rss:524052kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:1208kB oom_score_adj:0 Nov 21 17:50:49 systemd-networkd[396]: eth0: Failed Nov 21 17:50:49 zerotier-one[471]: sendto: Network is unreachable Nov 21 17:50:49 zerotier-one[471]: message repeated 4 times: [ sendto: Network is unreachable] Nov 21 17:50:49 snapd[462]: SIGABRT: abort Nov 21 17:50:49 snapd[462]: PC=0x5565e4e2a791 m=0 sigcode=0 Nov 21 17:50:49 snapd[462]: goroutine 0 [idle]: Nov 21 17:50:49 snapd[462]: runtime.futex(0x5565e68f54e8, 0x80, 0x0, 0x0, 0xc000000000, 0x7ffd0980b640, 0x5565e4dfe0bc, 0x0, 0x7ffd0980b660, 0x5565e4dd3b83, ...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/sys_linux_amd64.s:535 +0x21 Nov 21 17:50:49 snapd[462]: runtime.futexsleep(0x5565e68f54e8, 0x7ffd00000000, 0xffffffffffffffff) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/os_linux.go:44 +0x46 Nov 21 17:50:49 snapd[462]: runtime.notesleep(0x5565e68f54e8) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/lock_futex.go:151 +0xa3 Nov 21 17:50:49 snapd[462]: runtime.stoplockedm() Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/proc.go:2068 +0x8c Nov 21 17:50:49 snapd[462]: runtime.schedule() Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/proc.go:2469 +0x489 Nov 21 17:50:49 snapd[462]: runtime.park_m(0xc000152c00) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/proc.go:2610 +0xa3 Nov 21 17:50:49 snapd[462]: runtime.mcall(0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/asm_amd64.s:318 +0x53 Nov 21 17:50:49 snapd[462]: goroutine 1 [select, 4466 minutes]: Nov 21 17:50:49 snapd[462]: main.run(0xc0001c3740, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/cmd/snapd/main.go:153 +0x4e5 Nov 21 17:50:49 snapd[462]: main.main() Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/cmd/snapd/main.go:64 +0x10e Nov 21 17:50:49 snapd[462]: goroutine 6 [syscall, 4466 minutes]: Nov 21 17:50:49 snapd[462]: os/signal.signal_recv(0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/sigqueue.go:147 +0x9e Nov 21 17:50:49 snapd[462]: os/signal.loop() Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/os/signal/signal_unix.go:23 +0x24 Nov 21 17:50:49 snapd[462]: created by os/signal.init.0 Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/os/signal/signal_unix.go:29 +0x43 Nov 21 17:50:49 snapd[462]: goroutine 31 [select, 62 minutes]: Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/overlord/standby.(*StandbyOpinions).Start.func1(0xc000424fa0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/overlord/standby/standby.go:105 +0x12b Nov 21 17:50:49 snapd[462]: created by github.com/snapcore/snapd/overlord/standby.(*StandbyOpinions).Start Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/overlord/standby/standby.go:96 +0xaa Nov 21 17:50:49 snapd[462]: goroutine 32 [select, 62 minutes]: Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/overlord.(*Overlord).Loop.func1(0x5565e4dcda75, 0xc00050eae0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/overlord/overlord.go:465 +0x17b Nov 21 17:50:49 snapd[462]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc000425090, 0xc000232aa0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d Nov 21 17:50:49 snapd[462]: created by gopkg.in/tomb%2ev2.(*Tomb).Go Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9 Nov 21 17:50:49 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:49 CRON[31958]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 21 17:50:49 snapd[462]: goroutine 33 [IO wait, 4466 minutes]: Nov 21 17:50:49 snapd[462]: internal/poll.runtime_pollWait(0x7f0dcc340e38, 0x72, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57 Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).wait(0xc000438598, 0x72, 0x0, 0x0, 0x5565e5864611) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47 Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).waitRead(...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92 Nov 21 17:50:49 snapd[462]: internal/poll.(*FD).Accept(0xc000438580, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:384 +0x1fa Nov 21 17:50:49 snapd[462]: net.(*netFD).accept(0xc000438580, 0x203000, 0xc000061cb0, 0x5565e4df78f3) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/fd_unix.go:238 +0x44 Nov 21 17:50:49 snapd[462]: net.(*UnixListener).accept(0xc000084cc0, 0x5565e6171bd0, 0xc000061ce8, 0xc000061cc0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:162 +0x34 Nov 21 17:50:49 snapd[462]: net.(*UnixListener).Accept(0xc000084cc0, 0xc00013a238, 0x8, 0xc000061cc0, 0x5565e584b7c5) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock.go:260 +0x49 Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/daemon.(*ucrednetListener).Accept(0xc000084de0, 0xc000061da8, 0x18, 0xc000126780, 0x5565e50c09f6) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/daemon/ucrednet.go:112 +0x4a Nov 21 17:50:49 snapd[462]: net/http.(*Server).Serve(0xc0001020e0, 0x5565e61acc60, 0xc000084de0, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/http/server.go:2896 +0x282 Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/daemon.(*Daemon).Start.func1(0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/daemon/daemon.go:378 +0x56 Nov 21 17:50:49 snapd[462]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc0001666e0, 0xc000032f20) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d Nov 21 17:50:49 snapd[462]: created by gopkg.in/tomb%2ev2.(*Tomb).Go Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9 Nov 21 17:50:49 snapd[462]: goroutine 34 [select]: Nov 21 17:50:49 snapd[462]: main.runWatchdog.func1(0xc0004250e0, 0xc000166690) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/cmd/snapd/main.go:93 +0xe5 Nov 21 17:50:49 snapd[462]: created by main.runWatchdog Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/cmd/snapd/main.go:91 +0x1e2 Nov 21 17:50:49 snapd[462]: goroutine 35 [IO wait, 4466 minutes]: Nov 21 17:50:49 snapd[462]: internal/poll.runtime_pollWait(0x7f0dcc340f08, 0x72, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57 Nov 21 17:50:49 systemd[1]: Starting Ubuntu Advantage Timer for running repeated jobs... Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).wait(0xc000438698, 0x72, 0x0, 0x0, 0x5565e5864611) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47 Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).waitRead(...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92 Nov 21 17:50:49 snapd[462]: internal/poll.(*FD).Accept(0xc000438680, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:384 +0x1fa Nov 21 17:50:49 snapd[462]: net.(*netFD).accept(0xc000438680, 0x203000, 0x7f0dcdbca700, 0x400) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/fd_unix.go:238 +0x44 Nov 21 17:50:49 snapd[462]: net.(*UnixListener).accept(0xc000084d50, 0xc0002ce870, 0x30, 0x30) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:162 +0x34 Nov 21 17:50:49 snapd[462]: net.(*UnixListener).Accept(0xc000084d50, 0xc0002ce870, 0x5565e6171bd0, 0xc00004dd28, 0xc000290380) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock.go:260 +0x49 Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/daemon.(*ucrednetListener).Accept(0xc000084e10, 0x5565e60d4c20, 0xc0002ce870, 0x5565e60055a0, 0x5565e6892030) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/daemon/ucrednet.go:112 +0x4a Nov 21 17:50:49 snapd[462]: net/http.(*Server).Serve(0xc0001020e0, 0x5565e61acc60, 0xc000084e10, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/http/server.go:2896 +0x282 Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/daemon.(*Daemon).Start.func1.1(0x5565e4dcda75, 0xc00050eae0) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/daemon/daemon.go:370 +0x4b Nov 21 17:50:49 snapd[462]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc0001666e0, 0xc000033380) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d Nov 21 17:50:49 snapd[462]: created by gopkg.in/tomb%2ev2.(*Tomb).Go Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9 Nov 21 17:50:49 snapd[462]: goroutine 36 [IO wait, 4466 minutes]: Nov 21 17:50:49 snapd[462]: internal/poll.runtime_pollWait(0x7f0dcc340d68, 0x72, 0x1000) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/runtime/netpoll.go:184 +0x57 Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).wait(0xc000438e98, 0x72, 0x0, 0x10, 0xc0000d7320) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:87 +0x47 Nov 21 17:50:49 snapd[462]: internal/poll.(*pollDesc).waitRead(...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_poll_runtime.go:92 Nov 21 17:50:49 snapd[462]: internal/poll.(*FD).ReadMsg(0xc000438e80, 0xc000463de0, 0x10, 0x10, 0xc0000d7320, 0x1000, 0x1000, 0x0, 0x0, 0x0, ...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/internal/poll/fd_unix.go:243 +0x230 Nov 21 17:50:49 systemd[1]: snapd.service: Watchdog timeout (limit 5min)! Nov 21 17:50:49 snapd[462]: net.(*netFD).readMsg(0xc000438e80, 0xc000463de0, 0x10, 0x10, 0xc0000d7320, 0x1000, 0x1000, 0xc000265d50, 0x5565e68b85d6, 0x1, ...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/fd_unix.go:214 +0x92 Nov 21 17:50:49 snapd[462]: net.(*UnixConn).readMsg(0xc00040af20, 0xc000463de0, 0x10, 0x10, 0xc0000d7320, 0x1000, 0x1000, 0xc000463c90, 0xc000463c8c, 0xc0004113a0, ...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock_posix.go:115 +0x93 Nov 21 17:50:49 snapd[462]: net.(*UnixConn).ReadMsgUnix(0xc00040af20, 0xc000463de0, 0x10, 0x10, 0xc0000d7320, 0x1000, 0x1000, 0xc000411a00, 0x20, 0x18, ...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/net/unixsock.go:143 +0x9a Nov 21 17:50:49 snapd[462]: github.com/godbus/dbus.(*oobReader).Read(0xc0000d7300, 0xc000463de0, 0x10, 0x10, 0xc000265df0, 0x5565e4dd590a, 0x20) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/github.com/godbus/dbus/transport_unix.go:21 +0x8f Nov 21 17:50:49 snapd[462]: io.ReadAtLeast(0x5565e6192a00, 0xc0000d7300, 0xc000463de0, 0x10, 0x10, 0x10, 0xc0004e03d0, 0x0, 0x0) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/io/io.go:310 +0x89 Nov 21 17:50:49 snapd[462]: io.ReadFull(...) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/io/io.go:329 Nov 21 17:50:49 snapd[462]: github.com/godbus/dbus.(*unixTransport).ReadMessage(0xc0002331c0, 0xc000000002, 0x2, 0xc0003c0b01) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/github.com/godbus/dbus/transport_unix.go:91 +0x11a Nov 21 17:50:49 snapd[462]: github.com/godbus/dbus.(*Conn).inWorker(0xc000432990) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/github.com/godbus/dbus/conn.go:294 +0x42 Nov 21 17:50:49 snapd[462]: created by github.com/godbus/dbus.(*Conn).Auth Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/github.com/godbus/dbus/auth.go:118 +0x623 Nov 21 17:50:49 snapd[462]: goroutine 54 [syscall, 857 minutes]: Nov 21 17:50:49 snapd[462]: syscall.Syscall6(0x17, 0xb, 0xc000100e28, 0x0, 0x0, 0x0, 0x0, 0xc000126f00, 0x200000003, 0xc000126f00) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/syscall/asm_linux_amd64.s:44 +0x5 Nov 21 17:50:49 snapd[462]: syscall.Select(0xb, 0xc000100e28, 0x0, 0x0, 0x0, 0x5565e4df78f3, 0x5565e61710f0, 0xc000100e48) Nov 21 17:50:49 snapd[462]: #011/usr/lib/go-1.13/src/syscall/zsyscall_linux_amd64.go:1320 +0xa2 Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/osutil/udev/netlink.stopperSelectReadable(0x5, 0xa, 0x0, 0xc00042f020, 0x1) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/osutil/udev/netlink/rawsockstop.go:57 +0x16c Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/osutil/udev/netlink.RawSockStopper.func1(0xc00007a720, 0xc00042f020, 0x6) Nov 21 17:50:49 systemd[1]: snapd.service: Killing process 462 (snapd) with signal SIGABRT. Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/osutil/udev/netlink/rawsockstop.go:31 +0x4e Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/osutil/udev/netlink.(*UEventConn).Monitor.func4(0xc0006a81c0, 0xc00007a780, 0xc00007a7e0, 0xc00007a840, 0xc00062a000, 0x5565e61b5f60, 0xc0006a81a0, 0xc00007a720) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/osutil/udev/netlink/conn.go:139 +0x46 Nov 21 17:50:49 snapd[462]: created by github.com/snapcore/snapd/osutil/udev/netlink.(*UEventConn).Monitor Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/osutil/udev/netlink/conn.go:136 +0x247 Nov 21 17:50:49 snapd[462]: goroutine 55 [select, 857 minutes]: Nov 21 17:50:49 snapd[462]: github.com/snapcore/snapd/overlord/ifacestate/udevmonitor.(*Monitor).Run.func1(0xc0003ee960, 0xc0001c3860) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/overlord/ifacestate/udevmonitor/udevmon.go:147 +0x329 Nov 21 17:50:49 snapd[462]: gopkg.in/tomb%2ev2.(*Tomb).run(0xc000432f30, 0xc000311940) Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2d Nov 21 17:50:49 snapd[462]: created by gopkg.in/tomb%2ev2.(*Tomb).Go Nov 21 17:50:49 snapd[462]: #011/build/snapd-D063sK/snapd-2.57.2/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc9 Nov 21 17:50:49 snapd[462]: rax 0xca Nov 21 17:50:49 snapd[462]: rbx 0x5565e68f53a0 Nov 21 17:50:49 snapd[462]: rcx 0x5565e4e2a793 Nov 21 17:50:49 snapd[462]: rdx 0x0 Nov 21 17:50:49 snapd[462]: rdi 0x5565e68f54e8 Nov 21 17:50:49 snapd[462]: rsi 0x80 Nov 21 17:50:49 snapd[462]: rbp 0x7ffd0980b628 Nov 21 17:50:49 snapd[462]: rsp 0x7ffd0980b5e0 Nov 21 17:50:49 snapd[462]: r8 0x0 Nov 21 17:50:49 snapd[462]: r9 0x0 Nov 21 17:50:49 snapd[462]: r10 0x0 Nov 21 17:50:49 snapd[462]: r11 0x286 Nov 21 17:50:49 snapd[462]: r12 0xf1 Nov 21 17:50:49 snapd[462]: r13 0x0 Nov 21 17:50:49 snapd[462]: r14 0x5565e5a89c30 Nov 21 17:50:49 snapd[462]: r15 0x0 Nov 21 17:50:49 snapd[462]: rip 0x5565e4e2a791 Nov 21 17:50:49 snapd[462]: rflags 0x286 Nov 21 17:50:49 snapd[462]: cs 0x33 Nov 21 17:50:49 snapd[462]: fs 0x0 Nov 21 17:50:49 snapd[462]: gs 0x0 Nov 21 17:50:49 systemd[1]: snapd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT Nov 21 17:50:49 systemd[1]: snapd.service: Failed with result 'watchdog'. Nov 21 17:50:49 dockerd[651]: time="2022-11-21T17:50:49.866269061Z" level=info msg="ignoring event" container=c704cb32aa163cf3bb78118db63dcf67e1b4af94b00c20a255a135d789a0ea7a module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete" Nov 21 17:50:49 systemd[1]: snapd.service: Scheduled restart job, restart counter is at 1. Nov 21 17:50:49 systemd[1]: Stopped Snap Daemon. Nov 21 17:50:49 systemd[1]: Starting Snap Daemon... Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.880260062Z" level=info msg="shim disconnected" id=19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8 Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.880888211Z" level=warning msg="cleaning up after shim disconnected" id=19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8 namespace=moby Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.880909867Z" level=info msg="cleaning up dead shim" Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.869412062Z" level=info msg="shim disconnected" id=c704cb32aa163cf3bb78118db63dcf67e1b4af94b00c20a255a135d789a0ea7a Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.883109471Z" level=warning msg="cleaning up after shim disconnected" id=c704cb32aa163cf3bb78118db63dcf67e1b4af94b00c20a255a135d789a0ea7a namespace=moby Nov 21 17:50:49 containerd[473]: time="2022-11-21T17:50:49.883469444Z" level=info msg="cleaning up dead shim" Nov 21 17:50:49 dockerd[651]: time="2022-11-21T17:50:49.922576006Z" level=info msg="ignoring event" container=19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete" Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.059231246Z" level=warning msg="cleanup warnings time=\"2022-11-21T17:50:50Z\" level=info msg=\"starting signal loop\" namespace=moby pid=32084 runtime=io.containerd.runc.v2\n" Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.060444283Z" level=warning msg="cleanup warnings time=\"2022-11-21T17:50:50Z\" level=info msg=\"starting signal loop\" namespace=moby pid=32085 runtime=io.containerd.runc.v2\n" Nov 21 17:50:50 kernel: [268012.372360] br-79e9ea37a0a1: port 2(vethb851790) entered disabled state Nov 21 17:50:50 kernel: [268012.374288] veth6b20014: renamed from eth0 Nov 21 17:50:50 systemd-networkd[396]: vethb851790: Lost carrier Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 networkd-dispatcher[452]: WARNING:Unknown index 23 seen, reloading interface list Nov 21 17:50:50 systemd[1]: var-lib-docker-overlay2-99e1181a596933a65eb6c641ba9a9b1bef4d6b55d27e51bb8cb792984bb83718-merged.mount: Succeeded. Nov 21 17:50:50 systemd-udevd[32115]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 21 17:50:50 systemd-udevd[32115]: Using default interface naming scheme 'v245'. Nov 21 17:50:50 systemd-networkd[396]: vethb851790: Link DOWN Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 kernel: [268012.475502] br-79e9ea37a0a1: port 2(vethb851790) entered disabled state Nov 21 17:50:50 systemd-timesyncd[331]: message repeated 2 times: [ Network configuration changed, trying to establish connection.] Nov 21 17:50:50 systemd-networkd[396]: rtnl: received neighbor for link '24' we don't know about, ignoring. Nov 21 17:50:50 kernel: [268012.478589] device vethb851790 left promiscuous mode Nov 21 17:50:50 kernel: [268012.478594] br-79e9ea37a0a1: port 2(vethb851790) entered disabled state Nov 21 17:50:50 systemd-networkd[396]: rtnl: received neighbor for link '24' we don't know about, ignoring. Nov 21 17:50:50 systemd[1]: run-docker-netns-d7951ead378f.mount: Succeeded. Nov 21 17:50:50 systemd[1]: var-lib-docker-overlay2-b71532ef8757e2ad4f957dec75d449aa5204b0b888aaba326819099801c5eb4f-merged.mount: Succeeded. Nov 21 17:50:50 networkd-dispatcher[452]: ERROR:Unknown interface index 23 seen even after reload Nov 21 17:50:50 networkd-dispatcher[452]: WARNING:Unknown index 23 seen, reloading interface list Nov 21 17:50:50 systemd-udevd[32119]: veth6b20014: Failed to get link config: No such device Nov 21 17:50:50 networkd-dispatcher[452]: ERROR:Unknown interface index 23 seen even after reload Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 networkd-dispatcher[452]: WARNING:Unknown index 33 seen, reloading interface list Nov 21 17:50:50 systemd-udevd[32115]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 21 17:50:50 systemd-udevd[32119]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable. Nov 21 17:50:50 systemd-udevd[32115]: vethf8e451c: Could not generate persistent MAC: No data available Nov 21 17:50:50 systemd-udevd[32119]: Using default interface naming scheme 'v245'. Nov 21 17:50:50 systemd-udevd[32119]: vethfeb8add: Could not generate persistent MAC: No data available Nov 21 17:50:50 kernel: [268012.740522] br-79e9ea37a0a1: port 2(vethf8e451c) entered blocking state Nov 21 17:50:50 kernel: [268012.740528] br-79e9ea37a0a1: port 2(vethf8e451c) entered disabled state Nov 21 17:50:50 kernel: [268012.741221] device vethf8e451c entered promiscuous mode Nov 21 17:50:50 systemd-networkd[396]: vethf8e451c: Link UP Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 kernel: [268012.760007] br-79e9ea37a0a1: port 2(vethf8e451c) entered blocking state Nov 21 17:50:50 kernel: [268012.760013] br-79e9ea37a0a1: port 2(vethf8e451c) entered forwarding state Nov 21 17:50:50 dockerd[651]: time="2022-11-21T17:50:50.696728505Z" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]" Nov 21 17:50:50 dockerd[651]: time="2022-11-21T17:50:50.697394691Z" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]" Nov 21 17:50:50 snapd[32083]: AppArmor status: apparmor is enabled and all features are available Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.809731173Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.810149989Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.810356676Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.811202240Z" level=info msg="starting signal loop" namespace=moby path=/run/containerd/io.containerd.runtime.v2.task/moby/c704cb32aa163cf3bb78118db63dcf67e1b4af94b00c20a255a135d789a0ea7a pid=32168 runtime=io.containerd.runc.v2 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.885968565Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.892278807Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.892496615Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 Nov 21 17:50:50 containerd[473]: time="2022-11-21T17:50:50.892970244Z" level=info msg="starting signal loop" namespace=moby path=/run/containerd/io.containerd.runtime.v2.task/moby/19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8 pid=32196 runtime=io.containerd.runc.v2 Nov 21 17:50:50 systemd[1]: run-docker-runtime\x2drunc-moby-c704cb32aa163cf3bb78118db63dcf67e1b4af94b00c20a255a135d789a0ea7a-runc.Y8gEza.mount: Succeeded. Nov 21 17:50:51 systemd[1]: run-docker-runtime\x2drunc-moby-19c865e392e15fe0733161e21fc52bc066e1178d6cfaa0823a67c590c667e2c8-runc.1fXAen.mount: Succeeded. Nov 21 17:50:51 kernel: [268013.393449] br-79e9ea37a0a1: port 2(vethf8e451c) entered disabled state Nov 21 17:50:52 systemd[1]: ua-timer.service: Succeeded. Nov 21 17:50:52 systemd[1]: Finished Ubuntu Advantage Timer for running repeated jobs. Nov 21 17:50:53 snapd[32083]: AppArmor status: apparmor is enabled and all features are available Nov 21 17:50:53 kernel: [268015.460671] eth0: renamed from vethfeb8add Nov 21 17:50:53 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:53 kernel: [268015.465093] IPv6: ADDRCONF(NETDEV_CHANGE): vethf8e451c: link becomes ready Nov 21 17:50:53 kernel: [268015.465135] br-79e9ea37a0a1: port 2(vethf8e451c) entered blocking state Nov 21 17:50:53 kernel: [268015.465138] br-79e9ea37a0a1: port 2(vethf8e451c) entered forwarding state Nov 21 17:50:53 systemd-networkd[396]: vethf8e451c: Gained carrier Nov 21 17:50:53 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:50:53 snapd[32083]: overlord.go:263: Acquiring state lock file Nov 21 17:50:53 snapd[32083]: overlord.go:268: Acquired state lock file Nov 21 17:50:53 snapd[32083]: daemon.go:247: started snapd/2.57.2 (series 16; classic) ubuntu/20.04 (amd64) linux/5.15.0-1023-aws. Nov 21 17:50:53 kernel: [268015.944459] loop10: detected capacity change from 0 to 8 Nov 21 17:50:53 systemd[1]: tmp-syscheck\x2dmountpoint\x2d252476785.mount: Succeeded. Nov 21 17:50:53 snapd[32083]: daemon.go:340: adjusting startup timeout by 55s (pessimistic estimate of 30s plus 5s per snap) Nov 21 17:50:54 systemd[1]: Started Snap Daemon. Nov 21 17:50:54 dbus-daemon[444]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.87' (uid=0 pid=32083 comm="/usr/lib/snapd/snapd " label="unconfined") Nov 21 17:50:54 systemd[1]: Starting Time & Date Service... Nov 21 17:50:54 dbus-daemon[444]: [system] Successfully activated service 'org.freedesktop.timedate1' Nov 21 17:50:54 systemd[1]: Started Time & Date Service. Nov 21 17:50:54 systemd-networkd[396]: vethf8e451c: Gained IPv6LL Nov 21 17:50:54 systemd-timesyncd[331]: Network configuration changed, trying to establish connection. Nov 21 17:51:24 systemd[1]: systemd-timedated.service: Succeeded. Nov 21 17:51:26 zerotier-one[471]: sendto: Network is unreachable Nov 21 18:16:51 zerotier-one[471]: message repeated 5 times: [ sendto: Network is unreachable] Nov 21 18:17:01 CRON[32738]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 21 18:21:56 zerotier-one[471]: sendto: Network is unreachable Nov 21 18:32:06 zerotier-one[471]: message repeated 2 times: [ sendto: Network is unreachable] Nov 21 18:36:32 systemd[1]: Starting Message of the Day... Nov 21 18:36:33 systemd[1]: motd-news.service: Succeeded. Nov 21 18:36:33 systemd[1]: Finished Message of the Day. Nov 21 18:37:11 zerotier-one[471]: sendto: Network is unreachable Nov 21 19:12:46 zerotier-one[471]: message repeated 7 times: [ sendto: Network is unreachable] Nov 21 19:13:22 systemd[1]: Starting Daily apt download activities... Nov 21 19:13:22 systemd[1]: apt-daily.service: Succeeded. Nov 21 19:13:22 systemd[1]: Finished Daily apt download activities. Nov 21 19:17:01 CRON[33760]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Nov 21 19:17:51 zerotier-one[471]: sendto: Network is unreachable Nov 21 20:13:46 zerotier-one[471]: message repeated 11 times: [ sendto: Network is unreachable]
70599 commented 1 year ago

我是512M的AWS lightsail，没有这种问题

leeaash commented 1 year ago

我是512M的AWS lightsail，没有这种问题

你跑的什么方式代理？

70599 commented 1 year ago

shadow-tls和naive

70599 commented 1 year ago

请参照这个链接调整你服务器上的服务以使CPU负载保持低于你套餐对应的CPU 利用率性能基准 https://lightsail.aws.amazon.com/ls/docs/zh_cn/articles/amazon-lightsail-viewing-instance-burst-capacity

70599 commented 1 year ago

只要你的代理可以正常通信，一般就不是本项目需要解决的问题

leeaash commented 1 year ago

只要你的代理可以正常通信，一般就不是本项目需要解决的问题

不跑sing-box之前没出过性能问题，用了sing-box，有流量就会出现问题

leeaash commented 1 year ago

请参照这个链接调整你服务器上的服务以使CPU负载保持低于你套餐对应的CPU 利用率性能基准 https://lightsail.aws.amazon.com/ls/docs/zh_cn/articles/amazon-lightsail-viewing-instance-burst-capacity 这是我的 cpu

70599 commented 1 year ago

AWS lightsail对CPU负载要求太严格 要么减少用量 要么更换其他套餐或者VPS吧

你也可以换v2ray什么的对比一下同样的使用场景有多大差异

leeaash commented 1 year ago

AWS lightsail对CPU负载要求太严格 要么减少用量 要么更换其他套餐或者VPS吧

你也可以换v2ray什么的对比一下同样的使用场景有多大差异

原来一直跑的ss, ss+v2ray plugin, wstunnel, udpraw, 各种套基本没死过，直到上了sing-box, 我先关了其他的再观察下吧

70599 commented 1 year ago

我一台设备连续播放4K流媒体，CPU负载稳定在5%左右。 在我的使用场景下，sing-box的性能表现够用了。

leeaash commented 1 year ago

cpu和实际流量没有相关性，我跑4k的时候不会必然导致问题，出问题的触发条件我目前还没有找到头绪，但基本上没有发生实际流量大的时候，通常在半夜时候也不会有流量压力的

70599 commented 1 year ago

cpu和实际流量没有相关性

由sing-box引发的CPU负载增高，肯定和流量、带宽有关。 我实际连续播放4K流媒体，也可以看到这个相关性。 从你给出的sing-box的配置来看，sing-box也没有在服务端提供代理以外的服务。

leeaash commented 1 year ago

cpu和实际流量没有相关性

由sing-box引发的CPU负载增高，肯定和流量、带宽有关。 我实际连续播放4K流媒体，也可以看到这个相关性。 从你给出的sing-box的配置来看，sing-box也没有在服务端提供代理以外的服务。

是的是的，我可能说的有点错误，当长时间播放4k并不会直接导致cpu持续的线性增加直至死机。出现问题的时候往往是没有什么太大流量的时候开始发生的。 我想说的是死机和流量没有直接相关性，或者说从我的观察看，并不是大流量导致的问题，但是服务开着，流量不走的话确实观察了一天多没事

70599 commented 1 year ago

还需要再好好排查一下，找到用sing-box稳定复现CPU满载的方法

leeaash commented 1 year ago

做了一个不同配置的对比， 1C1G lightsail主机，Debian 11， 只装了sing-box shadowtls+showsocks每天不定期出问题。shadowstls+vmess 跑了3，4天没出过问题

nekohasekai commented 1 year ago

请提供复现流程。

makaspacex commented 1 year ago

我这里也是同样的问题，使用的是shadowtls+showsocks，内存一直在持续升高，直到死机，发生大规模磁盘交换。

image

在这里清理的缓存

image

singbox的内存占用一直非常小

image
makaspacex commented 1 year ago 
做了一个不同配置的对比， 1C1G lightsail主机，Debian 11， 只装了sing-box
shadowtls+showsocks每天不定期出问题。shadowstls+vmess 跑了3，4天没出过问题

我是centos7，看来和系统没关系，应该和shadowdsocks有关系 希望开发者能注意到这个问题

makaspacex commented 1 year ago

目前加了定时任务 剩余内存小于150的时候 就自动释放 每分钟检查一次就好 下面是代码 请大家参考

#!/bin/bash
#该脚本用于清理buff/cache，释放内存

used=`free -m | awk 'NR==2' | awk '{print $3}'`
free=`free -m | awk 'NR==2' | awk '{print $4}'`
buff_cache=`free -m | awk 'NR==2' | awk '{print $6}'`
available=`free -m | awk 'NR==2' | awk '{print $7}'`

LOG_FILE=/var/log/mem.log

echo -n "$(date '+%Y-%m-%d %H:%M:%S') " >> $LOG_FILE
echo -n "used:${used}M free:${free}M buff_cache:${buff_cache}M available:${available}M " >> $LOG_FILE

#设置free小于150M时就开始进行清理
if [ $free -le 150 ] ; then
        sync && echo 1 > /proc/sys/vm/drop_caches
        sync && echo 2 > /proc/sys/vm/drop_caches
        sync && echo 3 > /proc/sys/vm/drop_caches
        echo -n "OK" >> $LOG_FILE
else
        echo -n "free >= 150, pass." >> $LOG_FILE
fi
echo "" >> $LOG_FILE

执行环境时centos7的bash，其他环境请自行测试

wx2020 commented 3 months ago

我这里也是同样的问题，使用的是shadowtls+showsocks，内存一直在持续升高，直到死机，发生大规模磁盘交换。

image

在这里清理的缓存 image

singbox的内存占用一直非常小

image

请问你这是什么面板

xinzhongyouhai commented 1 month ago

2024年10月7号~测试了好多次~感觉sing-box会疯狂占用CPU.用xray没问题~我用的AWS光帆~5刀的机器~一般能坚持个1天左右，VPS就出问题了~必须重启~