下記の環境でSoftEtherを運用しています。
SoftEther バージョン：4.42.9798
OS： AlmaLinux 9.3
カスケード接続：別サーバー（CentOS 7.9）で稼働するバージョン 4.29.9680のSoftEtherからカスケード接続があり、4.42.9798のサーバーではカスケード経由のVPN接続とサーバーに直接接続したVPN接続が混在しています。どちらもVPN内ではSecureNatでローカルのネットワーク上のAPサーバーと通信しています。
構成概要は下記のようになります。
(CentOS 7.9 / 4.29.9680) ----カスケード接続---> (AlmaLinux 9.3 / 4.42.9798) -----ローカルLAN---- (APサーバー)
/\ /\
| |
VPN端末 VPN端末
VPN端末台数は合計で約360台で、10分おきにAPサーバーに向けて一斉にデータ送信します。
当初は 4.29.9680 の方にのみVPN端末が接続されており、APサーバーと通信していましたが、4.42.9798の方に
VPN端末を接続し始めたころから4.42.9798のvpnserverプロセスがSIGABRTで断続的にクラッシュするようになりました。
コアダンプは残っていないです。
4.29.9680からのカスケード接続を停止して、4.42.9798を単独で動作させるように変更してから数日経っていますが、
安定しているようでクラッシュはまだ発生していないです。
もう一つ、当初の 4.29.9680のみにVPN端末があったときは、クラッシュは起きていないですが、4.42.9798の方の
vpnserverプロセスの固有メモリ使用量が増加する一方で約1GiBまでになりました。4.42.9798の単独動作ではメモリ
増加はしますがずっと増え続けることはなくなりました。
上記のような現象について何かご存じでしたら情報共有お願いします。
SoftEther VPNのクラッシュについて
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
VPN サーバーの処理能力を超えて送受信を行った場合、一時的にデータを貯めておくためにメモリの消費量が増えることがあります。
SecureNAT も、メモリ消費が増えやすいので、可能であればAPサーバーも直接仮想 HUB に繋いでしまったほうが安定するかも知れません。
SecureNAT も、メモリ消費が増えやすいので、可能であればAPサーバーも直接仮想 HUB に繋いでしまったほうが安定するかも知れません。
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
ご回答ありがとうございます。
現象が発生していたときの 4.42.9798 のVPNサーバーのCPU使用率は約20%、ピークでも40%で、100～150本のスレッドが常に
実行されていました。但しサーバースペックはCPUが2コア、メモリが4GiBでした。
CPU使用率だけみるとまだ余裕があるように見えますが、別の容認で処理制限がかかることはあり得るでしょうか。またこれが
クラッシュに繋がることは考えられますか。シスログからみると頻度は少ない（数回）ですが、１分未満の間隔で発生する
こともありました。
因みに現在はサーバースペックを上げて4コア、8GiBのメモリで動作させています。
現象が発生していたときの 4.42.9798 のVPNサーバーのCPU使用率は約20%、ピークでも40%で、100～150本のスレッドが常に
実行されていました。但しサーバースペックはCPUが2コア、メモリが4GiBでした。
CPU使用率だけみるとまだ余裕があるように見えますが、別の容認で処理制限がかかることはあり得るでしょうか。またこれが
クラッシュに繋がることは考えられますか。シスログからみると頻度は少ない（数回）ですが、１分未満の間隔で発生する
こともありました。
因みに現在はサーバースペックを上げて4コア、8GiBのメモリで動作させています。
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
実はクラッシュ(SIGABRT)については、高負荷の場合でも経験がなく原因は見当がつきません。
コアダンプが出せるようであれば、クラッシュが起きている場所を特定できるかも知れません。
コアダンプが出せるようであれば、クラッシュが起きている場所を特定できるかも知れません。
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
SoftEtherをsystemdで動かしており、コアダンプの出力設定を有効にしましたがやはりコアが出力されません。
シスログの/var/log/messagesには次のログが記録されます。
systemd-coredump[2256399]: Resource limits disable core dumping for process 2231098 (vpnserver).
systemd-coredump[2256399]: Process 2231098 (vpnserver) of user 0 dumped core.
そこでv4.42-9798のソースを確認しましたが、次の2カ所でコアダンプを無効にしていました。
Mayaqua/Kernel.c：
void AbortExit()
void AbortExitEx(char *msg)
もしここを通っていればコアダンプが出ないとは思いますが、後者の方は abort_error_log.txt ファイルを
作成するようになっており、このファイルもない様なので前者が候補になりますが、これが発生する
可能性は何があるでしょうか。VPNセッションを頻繁に切断、接続すると発生しやすいようです。
今回使っているのは下記からダウンロードしたバイナリです。
https://jp.softether-download.com/files ... bit.tar.gz
ダウンロードしたバイナリをAlmaLinux 9.3でビルド（リンク）して使っています。もし可能でしたら
このバイナリをビルドした条件（コンパイラ及び使用したライブラリのバージョン等）を教えて頂けない
でしょうか。確認でコアダンプの無効化なしで動作させてみたいと思います。
シスログの/var/log/messagesには次のログが記録されます。
systemd-coredump[2256399]: Resource limits disable core dumping for process 2231098 (vpnserver).
systemd-coredump[2256399]: Process 2231098 (vpnserver) of user 0 dumped core.
そこでv4.42-9798のソースを確認しましたが、次の2カ所でコアダンプを無効にしていました。
Mayaqua/Kernel.c：
void AbortExit()
void AbortExitEx(char *msg)
もしここを通っていればコアダンプが出ないとは思いますが、後者の方は abort_error_log.txt ファイルを
作成するようになっており、このファイルもない様なので前者が候補になりますが、これが発生する
可能性は何があるでしょうか。VPNセッションを頻繁に切断、接続すると発生しやすいようです。
今回使っているのは下記からダウンロードしたバイナリです。
https://jp.softether-download.com/files ... bit.tar.gz
ダウンロードしたバイナリをAlmaLinux 9.3でビルド（リンク）して使っています。もし可能でしたら
このバイナリをビルドした条件（コンパイラ及び使用したライブラリのバージョン等）を教えて頂けない
でしょうか。確認でコアダンプの無効化なしで動作させてみたいと思います。
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
デバッグビルドを作成されるのであれば、バイナリ版ではなくソース版を使用するのが良いかと思います。
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
デバッグビルドしてコアダンプが取得できました。クラッシュが起きている箇所はいくつかありますが、いずれもFree()関数の中で「CheckMemTag2: tag2->Magic != canary_memtag_magic2」のエラーです。下記はクラッシュ時のスタックトレースです。
１）このパターンが一番多いです。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc80a86c88) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc80a86c70) at src/Mayaqua/Memory.c:4814
#6 0x0000000000410216 in FreeBuf (b=0x7efc80a86c70) at src/Mayaqua/Memory.c:4133
#7 0x000000000047c209 in OvsSendControlPacketWithAutoSplit (c=0x7efc8c88b9f0, opcode=4 '\004', data=0x7efc8cd31360 "\027\003\003", data_size=56) at src/Cedar/Interop_OpenVPN.c:1265
#8 0x000000000047e428 in OvsRecvPacket (s=0x7efc8cf6ff70, recv_packet_list=0x7efc8cfdcb70, protocol=1) at src/Cedar/Interop_OpenVPN.c:2245
#9 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc7510a4f0) at src/Cedar/Interop_OpenVPN.c:2926
#10 0x0000000000467bba in ConnectionAccept (c=0x7efc8c885990) at src/Cedar/Connection.c:3121
#11 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc74eb6e50, param=0x7efc7555bb20) at src/Cedar/Listener.c:267
#12 0x0000000000515f87 in ThreadPoolProc (t=0x7efc64aee320, param=0x7efc643127e0) at src/Mayaqua/Kernel.c:1062
#13 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc64343210) at src/Mayaqua/Unix.c:1723
#14 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#15 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
２）もう一つのパターンです。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc98d1b7a8) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc98d1b790) at src/Mayaqua/Memory.c:4814
#6 0x0000000000433f27 in FreeUdpPacket (p=0x7efc7ca3b6d0) at src/Mayaqua/Network.c:21541
#7 0x000000000047f8b2 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc68e71d20) at src/Cedar/Interop_OpenVPN.c:2933
#8 0x0000000000467bba in ConnectionAccept (c=0x7efc7d4f6dc0) at src/Cedar/Connection.c:3121
#9 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc68c40fd0, param=0x7efc68279740) at src/Cedar/Listener.c:267
#10 0x0000000000515f87 in ThreadPoolProc (t=0x7efc9443d020, param=0x7efc94427ae0) at src/Mayaqua/Kernel.c:1062
#11 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc9443f430) at src/Mayaqua/Unix.c:1723
#12 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#13 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
３）ここでも発生しています。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc7c1caa88) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc7c1caa70) at src/Mayaqua/Memory.c:4814
#6 0x000000000047ecd0 in OvsSendPacketNow (s=0x7efc7c034370, se=0x7efc7c8bfda0, p=0x7efc7c187840) at src/Cedar/Interop_OpenVPN.c:2476
#7 0x000000000047e5aa in OvsRecvPacket (s=0x7efc7c034370, recv_packet_list=0x7efc7c84d1b0, protocol=1) at src/Cedar/Interop_OpenVPN.c:2278
#8 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc683a99d0) at src/Cedar/Interop_OpenVPN.c:2926
#9 0x0000000000467bba in ConnectionAccept (c=0x7efc7d0b1a60) at src/Cedar/Connection.c:3121
#10 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc6877ddb0, param=0x7efc696d6820) at src/Cedar/Listener.c:267
#11 0x0000000000515f87 in ThreadPoolProc (t=0x7efc98123e60, param=0x7efc981228f0) at src/Mayaqua/Kernel.c:1062
#12 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc980ea7b0) at src/Mayaqua/Unix.c:1723
#13 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#14 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
４）
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc8c709258) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc8c709240) at src/Mayaqua/Memory.c:4814
#6 0x000000000047ca51 in OvsSendDataPacket (c=0x7efc7131c930, key_id=0 '\000', data_packet_id=1, data=0x63bab0 <ping_signature>, data_size=16) at src/Cedar/Interop_OpenVPN.c:1516
#7 0x000000000047ea17 in OvsRecvPacket (s=0x7efc70c2f070, recv_packet_list=0x7efc710ef400, protocol=1) at src/Cedar/Interop_OpenVPN.c:2399
#8 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc74c52360) at src/Cedar/Interop_OpenVPN.c:2926
#9 0x0000000000467bba in ConnectionAccept (c=0x7efc711ee3e0) at src/Cedar/Connection.c:3121
#10 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc7516d160, param=0x7efc74b65ec0) at src/Cedar/Listener.c:267
#11 0x0000000000515f87 in ThreadPoolProc (t=0x3008580, param=0x3008100) at src/Mayaqua/Kernel.c:1062
#12 0x000000000045c176 in UnixDefaultThreadProc (param=0x2ffd2b0) at src/Mayaqua/Unix.c:1723
#13 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#14 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
５）
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc64ea6218) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc64ea6200) at src/Mayaqua/Memory.c:4814
#6 0x00000000004226f3 in UnixSelectInner (num_read=3, reads=0x7efc9e6d0d60, num_write=0, writes=0x7efc9e6d0c60, timeout=256) at src/Mayaqua/Network.c:9485
#7 0x0000000000421ebe in UnixSelect (set=0x7efc9e6d0f50, timeout=256, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Mayaqua/Network.c:9166
#8 0x0000000000425778 in Select (set=0x7efc9e6d0f50, timeout=256, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Mayaqua/Network.c:12843
#9 0x0000000000464b1d in ConnectionReceive (c=0x7efc642a16d0, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Cedar/Connection.c:1782
#10 0x00000000004d7a96 in SessionMain (s=0x7efc649d3790) at src/Cedar/Session.c:353
#11 0x00000000004a7273 in ServerAccept (c=0x7efc642a16d0) at src/Cedar/Protocol.c:4223
#12 0x0000000000467e39 in ConnectionAccept (c=0x7efc642a16d0) at src/Cedar/Connection.c:3173
#13 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc98829a50, param=0x7efc98814330) at src/Cedar/Listener.c:267
#14 0x0000000000515f87 in ThreadPoolProc (t=0x7efc980efc00, param=0x7efc980de6b0) at src/Mayaqua/Kernel.c:1062
#15 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc980efee0) at src/Mayaqua/Unix.c:1723
#16 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#17 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
発生条件は下記です。
・VPNセッションはOpenVPNで300本
・vpnserverのスレッド数は約950本
・VPNセッションは5分周期で切断、接続を繰り返す
・VPN接続後、SecureNat経由でAPサーバーにデータ送信（平均して約1MB/sのデータ量）
１）このパターンが一番多いです。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc80a86c88) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc80a86c70) at src/Mayaqua/Memory.c:4814
#6 0x0000000000410216 in FreeBuf (b=0x7efc80a86c70) at src/Mayaqua/Memory.c:4133
#7 0x000000000047c209 in OvsSendControlPacketWithAutoSplit (c=0x7efc8c88b9f0, opcode=4 '\004', data=0x7efc8cd31360 "\027\003\003", data_size=56) at src/Cedar/Interop_OpenVPN.c:1265
#8 0x000000000047e428 in OvsRecvPacket (s=0x7efc8cf6ff70, recv_packet_list=0x7efc8cfdcb70, protocol=1) at src/Cedar/Interop_OpenVPN.c:2245
#9 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc7510a4f0) at src/Cedar/Interop_OpenVPN.c:2926
#10 0x0000000000467bba in ConnectionAccept (c=0x7efc8c885990) at src/Cedar/Connection.c:3121
#11 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc74eb6e50, param=0x7efc7555bb20) at src/Cedar/Listener.c:267
#12 0x0000000000515f87 in ThreadPoolProc (t=0x7efc64aee320, param=0x7efc643127e0) at src/Mayaqua/Kernel.c:1062
#13 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc64343210) at src/Mayaqua/Unix.c:1723
#14 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#15 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
２）もう一つのパターンです。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc98d1b7a8) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc98d1b790) at src/Mayaqua/Memory.c:4814
#6 0x0000000000433f27 in FreeUdpPacket (p=0x7efc7ca3b6d0) at src/Mayaqua/Network.c:21541
#7 0x000000000047f8b2 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc68e71d20) at src/Cedar/Interop_OpenVPN.c:2933
#8 0x0000000000467bba in ConnectionAccept (c=0x7efc7d4f6dc0) at src/Cedar/Connection.c:3121
#9 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc68c40fd0, param=0x7efc68279740) at src/Cedar/Listener.c:267
#10 0x0000000000515f87 in ThreadPoolProc (t=0x7efc9443d020, param=0x7efc94427ae0) at src/Mayaqua/Kernel.c:1062
#11 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc9443f430) at src/Mayaqua/Unix.c:1723
#12 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#13 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
３）ここでも発生しています。
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc7c1caa88) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc7c1caa70) at src/Mayaqua/Memory.c:4814
#6 0x000000000047ecd0 in OvsSendPacketNow (s=0x7efc7c034370, se=0x7efc7c8bfda0, p=0x7efc7c187840) at src/Cedar/Interop_OpenVPN.c:2476
#7 0x000000000047e5aa in OvsRecvPacket (s=0x7efc7c034370, recv_packet_list=0x7efc7c84d1b0, protocol=1) at src/Cedar/Interop_OpenVPN.c:2278
#8 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc683a99d0) at src/Cedar/Interop_OpenVPN.c:2926
#9 0x0000000000467bba in ConnectionAccept (c=0x7efc7d0b1a60) at src/Cedar/Connection.c:3121
#10 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc6877ddb0, param=0x7efc696d6820) at src/Cedar/Listener.c:267
#11 0x0000000000515f87 in ThreadPoolProc (t=0x7efc98123e60, param=0x7efc981228f0) at src/Mayaqua/Kernel.c:1062
#12 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc980ea7b0) at src/Mayaqua/Unix.c:1723
#13 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#14 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
４）
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc8c709258) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc8c709240) at src/Mayaqua/Memory.c:4814
#6 0x000000000047ca51 in OvsSendDataPacket (c=0x7efc7131c930, key_id=0 '\000', data_packet_id=1, data=0x63bab0 <ping_signature>, data_size=16) at src/Cedar/Interop_OpenVPN.c:1516
#7 0x000000000047ea17 in OvsRecvPacket (s=0x7efc70c2f070, recv_packet_list=0x7efc710ef400, protocol=1) at src/Cedar/Interop_OpenVPN.c:2399
#8 0x000000000047f870 in OvsPerformTcpServer (cedar=0x24af2a0, sock=0x7efc74c52360) at src/Cedar/Interop_OpenVPN.c:2926
#9 0x0000000000467bba in ConnectionAccept (c=0x7efc711ee3e0) at src/Cedar/Connection.c:3121
#10 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc7516d160, param=0x7efc74b65ec0) at src/Cedar/Listener.c:267
#11 0x0000000000515f87 in ThreadPoolProc (t=0x3008580, param=0x3008100) at src/Mayaqua/Kernel.c:1062
#12 0x000000000045c176 in UnixDefaultThreadProc (param=0x2ffd2b0) at src/Mayaqua/Unix.c:1723
#13 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#14 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
５）
#0 0x00007efca02a154c in __pthread_kill_implementation () from /lib64/libc.so.6
#1 0x00007efca0254d06 in raise () from /lib64/libc.so.6
#2 0x00007efca02287f3 in abort () from /lib64/libc.so.6
#3 0x0000000000519700 in AbortExitEx (msg=0x5c59c8 "CheckMemTag2: tag2->Magic != canary_memtag_magic2") at src/Mayaqua/Kernel.c:2505
#4 0x00000000004112b3 in CheckMemTag2 (tag=0x7efc64ea6218) at src/Mayaqua/Memory.c:4857
#5 0x00000000004111c7 in Free (addr=0x7efc64ea6200) at src/Mayaqua/Memory.c:4814
#6 0x00000000004226f3 in UnixSelectInner (num_read=3, reads=0x7efc9e6d0d60, num_write=0, writes=0x7efc9e6d0c60, timeout=256) at src/Mayaqua/Network.c:9485
#7 0x0000000000421ebe in UnixSelect (set=0x7efc9e6d0f50, timeout=256, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Mayaqua/Network.c:9166
#8 0x0000000000425778 in Select (set=0x7efc9e6d0f50, timeout=256, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Mayaqua/Network.c:12843
#9 0x0000000000464b1d in ConnectionReceive (c=0x7efc642a16d0, c1=0x7efc64c54b60, c2=0x7efc64229c50) at src/Cedar/Connection.c:1782
#10 0x00000000004d7a96 in SessionMain (s=0x7efc649d3790) at src/Cedar/Session.c:353
#11 0x00000000004a7273 in ServerAccept (c=0x7efc642a16d0) at src/Cedar/Protocol.c:4223
#12 0x0000000000467e39 in ConnectionAccept (c=0x7efc642a16d0) at src/Cedar/Connection.c:3173
#13 0x000000000048f1ac in TCPAcceptedThread (t=0x7efc98829a50, param=0x7efc98814330) at src/Cedar/Listener.c:267
#14 0x0000000000515f87 in ThreadPoolProc (t=0x7efc980efc00, param=0x7efc980de6b0) at src/Mayaqua/Kernel.c:1062
#15 0x000000000045c176 in UnixDefaultThreadProc (param=0x7efc980efee0) at src/Mayaqua/Unix.c:1723
#16 0x00007efca029f802 in start_thread () from /lib64/libc.so.6
#17 0x00007efca023f450 in clone3 () from /lib64/libc.so.6
発生条件は下記です。
・VPNセッションはOpenVPNで300本
・vpnserverのスレッド数は約950本
・VPNセッションは5分周期で切断、接続を繰り返す
・VPN接続後、SecureNat経由でAPサーバーにデータ送信（平均して約1MB/sのデータ量）
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
いずれもメモリ開放時の領域破壊チェックで引っかかっているように見えます。
バッファオーバーランの可能性が高いですが、メモリの故障の可能性も若干あります。
バッファオーバーランの可能性が高いですが、メモリの故障の可能性も若干あります。
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
新たに分かったことを共有します。偶然かもしれませんがメモリの壊れ方に特徴があります。CheckMemTag2()でエラーになっているのはバッファー解放時に、バッファーの後ろに設定したMEMTAG2のマジック番号が計算値と一致しないためでした。数十回発生していますがすべてがこれです。
コアダンプを見るとメモリ割り当て時に設定したMEMTAG2のマジック番号が、計算値より1つだけ大きい値です。
CheckMemTag2()内で下記のテストをしていますが、tag->Magicが
より1つだけ大きいです。
また、関連があるか不明ですが、これが発生しているときのバッファーの割り当てサイズが24（実際の要求サイズが20バイトの場合もあり、割り当てるときは8の倍数にしているので24になります）バイトです。
もう一つ、を通るパターンでは取得しているバッファーはのタイプで、この構造体自体には書込みしていない（構造体のメンバーのセットはしています）ですが、バッファー解放時で上記エラーが発生しています。
この状況から何が考えられるでしょうか。
コアダンプを見るとメモリ割り当て時に設定したMEMTAG2のマジック番号が、計算値より1つだけ大きい値です。
CheckMemTag2()内で下記のテストをしていますが、tag->Magicが
Code: Select all
(canary_memtag_magic2 ^ ((UINT64)tag * GOLDEN_RATION_PRIME_U64))また、関連があるか不明ですが、これが発生しているときのバッファーの割り当てサイズが24（実際の要求サイズが20バイトの場合もあり、割り当てるときは8の倍数にしているので24になります）バイトです。
もう一つ、
Code: Select all
void OvsSendControlPacketWithAutoSplit(OPENVPN_CHANNEL *c, UCHAR opcode, UCHAR *data, UINT data_size)Code: Select all
struct BUFこの状況から何が考えられるでしょうか。
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
これもメモリの故障である可能性を補強しているように思われます。
一度メモリテストを行われてみるか、他のPCでテストを行うことをお勧めします。
一度メモリテストを行われてみるか、他のPCでテストを行うことをお勧めします。
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
gccのAddressSanitizerを使ってこの現象の確認をしました。その結果、解放後の参照が発生しており、
これによってMEMTAG2のチェックでマジック番号の不一致が検出されていることが分かりました。
概要は下記の通りです。
スレッド1 #1でポインタ 0x7F8D103AAF90 のバッファーを解放します。バッファーの先頭に16バイトのMEMTAG1があるため実際のバッファーポインタは 0x7F8D103AAF80 になります。
スレッド2 #7で 0x7F8D103AAFA0 のバッファーを割り当て、#4でポインタ 0x7F8D103AAFB8 のMEMTAG2のチェックをします。
スレッド3 #0でSOCK_EVENT.current_pipe_dataをインクリメントしますが、SOCK_EVENTのポインタは 0x7F8D103AAFA0 で、スレッド1で解放したバッファーであり、ここで解放後の参照（heap-use-after-free）が発生しています。インクリメント対象のSOCK_EVENT.current_pipe_dataのポインタは0x7F8D103AAFB8 になっており、ちょうどスレッド2のMEMTAG2の先頭と同じになります。
確認で使用しましたopenvpnのクライアントを動かすDockerコンテナのビルドスクリプト等を添付しました。ZIPのまま添付できませんでしたので.txtの拡張子を付けています。添付ファイルの簡単な説明です。
create-vhub-cmd.sh：SoftEtherサーバーに使用する仮想HUB、ユーザーを作成します。サーバーIPは環境に合わせて変更します。
vpn-server.ovpn：OpenVPN定義ファイルです。こちらも環境に合わせて内容を変更します。
build.sh：Dockerコンテナをビルドします。
ビルド後下記コマンドをコンテナを起動します。私の環境では100本のコンテナで1～3時間ぐらいでダウンが発生しています。今回はSoftEtherは4.44-9807を使用しました。
添付ファイル vpnserver-with-asan-out-1.txt はAddressSanitizerの出力です。実行は上記とは別なのでアドレス等は異なります。
これによってMEMTAG2のチェックでマジック番号の不一致が検出されていることが分かりました。
概要は下記の通りです。
- スレッド1でバッファーを解放。
- スレッド2で新規メモリ取得するが、1で解放したポインタと同じポインタが得ら、MEMTAG1、MEMTAG2のマジック番号がセットされる。
- スレッド3で1で解放したバッファー（2で再度割り当てられた）領域の中の値をインクリメントする。このインクリメントする値のポインタはちょうど2で再度割り当てしたバッファーのMEMTAG2のマジック番号を指している。
- 3でインクリメントされたために、2で取得したバッファーを使い終わって解放するときのMEMTAG2のチェックでマジック番号の不一致が検出される。
スレッド1 #1でポインタ 0x7F8D103AAF90 のバッファーを解放します。バッファーの先頭に16バイトのMEMTAG1があるため実際のバッファーポインタは 0x7F8D103AAF80 になります。
Code: Select all
#0 0x7f8a1c8b46b7 in free (/lib64/libasan.so.6+0xb46b7)
#1 0x4a321c in UnixMemoryFree at src/Mayaqua/Unix.c:2267
#2 0x465317 in OSMemoryFree at src/Mayaqua/OS.c:464
#3 0x40f192 in InternalFree at src/Mayaqua/Memory.c:4954
#4 0x410c8a in Free at src/Mayaqua/Memory.c:4849
#5 0x449180 in UnixCleanupSockEvent at src/Mayaqua/Network.c:9696
#6 0x4491df in CleanupSockEvent at src/Mayaqua/Network.c:11683
#7 0x4491df in ReleaseSockEvent at src/Mayaqua/Network.c:11710
#8 0x449475 in SetTubeSockEvent at src/Mayaqua/Network.c:20237
#9 0x44977d in JoinSockToSockEvent at src/Mayaqua/Network.c:11726
#10 0x4f32c9 in IPCSetSockEventWhenRecvL2Packet at src/Cedar/IPsec_IPC.c:653
#11 0x4eecc6 in OvsRecvPacket at src/Cedar/Interop_OpenVPN.c:2249
#12 0x4f21ae in OvsPerformTcpServer at src/Cedar/Interop_OpenVPN.c:2999
#13 0x4bd057 in ConnectionAccept at src/Cedar/Connection.c:3121
#14 0x514be6 in TCPAcceptedThread at src/Cedar/Listener.c:267
#15 0x621c36 in ThreadPoolProc at src/Mayaqua/Kernel.c:1062
#16 0x4a3362 in UnixDefaultThreadProc at src/Mayaqua/Unix.c:1723
Code: Select all
#0 0x7f8d16aa154c in __pthread_kill_implementation from /lib64/libc.so.6
#1 0x7f8d16a54d06 in raise from /lib64/libc.so.6
#2 0x7f8d16a287f3 in abort from /lib64/libc.so.6
#3 0x4c2b07 in AbortExitEx at src/Mayaqua/Kernel.c:2449
#4 0x40ad7e in CheckMemTag2 at src/Mayaqua/Memory.c:4934
#5 0x40bf09 in Free at src/Mayaqua/Memory.c:4835
#6 0x40c708 in FreeBuf at src/Mayaqua/Memory.c:4133
#7 0x45568e in OvsSendControlPacketWithAutoSplit at src/Cedar/Interop_OpenVPN.c:1311
#8 0x457680 in OvsRecvPacket at src/Cedar/Interop_OpenVPN.c:2318
#9 0x458189 in OvsPerformTcpServer at src/Cedar/Interop_OpenVPN.c:2999
#10 0x448b08 in ConnectionAccept at src/Cedar/Connection.c:3121
#11 0x4630e3 in TCPAcceptedThread at src/Cedar/Listener.c:267
#12 0x4c0782 in ThreadPoolProc at src/Mayaqua/Kernel.c:1062
#13 0x4403ac in UnixDefaultThreadProc at src/Mayaqua/Unix.c:1726
Code: Select all
#0 0x421c14 in UnixSetSockEvent at src/Mayaqua/Network.c:9558
#1 0x4392e7 in SetSockEvent at src/Mayaqua/Network.c:11673
#2 0x4392e7 in TubeSendEx2 at src/Mayaqua/Network.c:20347
#3 0x439354 in TubeSendEx at src/Mayaqua/Network.c:20316
#4 0x439365 in TubeSend at src/Mayaqua/Network.c:20312
#5 0x45655f in SendInProc at src/Mayaqua/Network.c:22393
#6 0x4566e8 in Send at src/Mayaqua/Network.c:14790
#7 0x456a87 in SendAll at src/Mayaqua/Network.c:13211
#8 0x45d3a0 in PostHttp at src/Mayaqua/Network.c:23384
#9 0x45da7b in HttpServerSend at src/Mayaqua/Network.c:22967
#10 0x553c26 in ServerAccept at src/Cedar/Protocol.c:4149
#11 0x4bce1e in ConnectionAccept at src/Cedar/Connection.c:3173
#12 0x514be6 in TCPAcceptedThread at src/Cedar/Listener.c:267
#13 0x621c36 in ThreadPoolProc at src/Mayaqua/Kernel.c:1062
#14 0x4a3362 in UnixDefaultThreadProc at src/Mayaqua/Unix.c:1723
create-vhub-cmd.sh：SoftEtherサーバーに使用する仮想HUB、ユーザーを作成します。サーバーIPは環境に合わせて変更します。
vpn-server.ovpn：OpenVPN定義ファイルです。こちらも環境に合わせて内容を変更します。
build.sh：Dockerコンテナをビルドします。
ビルド後下記コマンドをコンテナを起動します。私の環境では100本のコンテナで1～3時間ぐらいでダウンが発生しています。今回はSoftEtherは4.44-9807を使用しました。
Code: Select all
docker compose up -d
You do not have the required permissions to view the files attached to this post.
-
dorjpalam-batbaatar
- Posts: 7
- Joined: Tue Jan 28, 2025 2:12 am
Re: SoftEther VPNのクラッシュについて
SoftEtherサーバーの動作確認する際、1つのサーバーから複数のコンテナから同時に接続するのでVPNクライアントのIPアドレスがみんな同じになってしまうためSoftEtherのListener0のDoSプロテクションを下記のように一旦無効にしています。
/usr/vpnserver/vpn_server.config：
/usr/vpnserver/vpn_server.config：
Code: Select all
declare ListenerList
{
declare Listener0
{
bool DisableDos true
bool Enabled true
uint Port 443
}
declare Listener1
{
bool DisableDos false
bool Enabled true
uint Port 992
}
declare Listener2
{
bool DisableDos false
bool Enabled true
uint Port 1194
}
declare Listener3
{
bool DisableDos false
bool Enabled true
uint Port 5555
}
}
-
cedar
- Site Admin
- Posts: 2287
- Joined: Sat Mar 09, 2013 5:37 am
Re: SoftEther VPNのクラッシュについて
大変ありがとうございます。
大変詳細な情報を提供いただけましたので、このクラッシュの原因と思われる箇所を特定することができました。
この問題を修正したテスト版をアップロードしましたので、よろしければお試しいただければ幸いです。
https://filecenter.softether-upload.com ... 001_57635/
大変詳細な情報を提供いただけましたので、このクラッシュの原因と思われる箇所を特定することができました。
この問題を修正したテスト版をアップロードしましたので、よろしければお試しいただければ幸いです。
https://filecenter.softether-upload.com ... 001_57635/