Socatを使用したシリアル-WiFi接続用のLCPでPPPネゴシエーションが失敗する

Socatを使用したシリアル-WiFi接続用のLCPでPPPネゴシエーションが失敗する

シリアル-WiFiアダプタを介して接続を確立しようとしています。私はSocatを使ってpppdとPTYの接続を接続するソケットを作成しています。データが双方向に流れているようですが、pppdがクライアントから応答を受け取っていないようです。 Socatのデバッグ出力には入出力データが表示され、クライアントのデバッグ出力にはサーバーのLCPネゴシエーションパケットを受け入れることが示されていますが、サーバーデバッグにはSENTパケットのみが表示され、応答は表示されません。私は一体何が起こっているのかを調べるために2週間壁に頭をぶつけました。

クライアントは、USBケーブルで完全に動作するdospppを実行している古いDOSポータブルコンピュータです。 Socatに関連していると思われますが、受信したデータがpppdに渡されるかどうかをデバッグする方法がわかりません。

私は何を見逃していますか?どのように動作させることができますか?

私が使用するSocatコマンドは次のとおりです。

socat -d -d -v tcp-l:2323,fork,reuseaddr exec:'/usr/sbin/pppd notty',pty,rawer,nonblock=1,iexten=0,b19200

.ppprc

debug
nodetach
default-asyncmap
local
mtu 296
mru 296
noipv6
noauth
notty

ソカート出力:

root# socat -d -d -v tcp-l:2323,fork,reuseaddr exec:'/usr/sbin/pppd notty',pty,rawer,nonblock=1,iexten=0,b19200

2021/05/08 00:27:04 socat[1082] N listening on AF=2 0.0.0.0:2323
2021/05/08 00:27:20 socat[1082] N accepting connection from AF=2 10.0.10.46:26185 on AF=2 10.0.10.17:2323
2021/05/08 00:27:20 socat[1082] N forked off child process 1083
2021/05/08 00:27:20 socat[1082] N listening on AF=2 0.0.0.0:2323
2021/05/08 00:27:20 socat[1083] N forking off child, using pty for reading and writing
2021/05/08 00:27:20 socat[1083] N forked off child process 1084
2021/05/08 00:27:20 socat[1083] N forked off child process 1084
2021/05/08 00:27:20 socat[1083] N starting data transfer loop with FDs [6,6] and [5,5]
2021/05/08 00:27:20 socat[1084] N execvp'ing "/usr/sbin/pppd"
< 2021/05/08 00:27:20.122440  length=52 from=0 to=51
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~< 2021/05/08 00:27:23.117722  length=52 from=52 to=103
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~< 2021/05/08 00:27:26.122209  length=52 from=104 to=155
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:26.128144  length=41 from=0 to=40
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           > 2021/05/08 00:27:26.881958  length=50 from=41 to=90
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  < 2021/05/08 00:27:29.124308  length=52 from=156 to=207
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:29.504403  length=41 from=91 to=131
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           > 2021/05/08 00:27:30.154487  length=50 from=132 to=181
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  < 2021/05/08 00:27:32.127473  length=52 from=208 to=259
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:33.004495  length=50 from=182 to=231
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:33.329502  length=41 from=232 to=272
~.}#.!}!}!} }2}!}}!(}%}&}:}4@} }}"}(}"%.~           < 2021/05/08 00:27:35.130645  length=52 from=260 to=311
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:36.056441  length=50 from=273 to=322
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:36.679459  length=41 from=323 to=363
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           < 2021/05/08 00:27:38.133840  length=52 from=312 to=363
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:39.054527  length=50 from=364 to=413
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:39.655287  length=41 from=414 to=454
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           < 2021/05/08 00:27:41.137063  length=52 from=364 to=415
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:42.079453  length=50 from=455 to=504
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:43.029525  length=41 from=505 to=545
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           < 2021/05/08 00:27:44.140293  length=52 from=416 to=467
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:45.079471  length=50 from=546 to=595
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:46.279660  length=41 from=596 to=636
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~           < 2021/05/08 00:27:47.143465  length=52 from=468 to=519
~.}#.!}!}!} }8}!}$}!(}"}&} } } } }%}&.sr.}'}"}(}">.~> 2021/05/08 00:27:48.054620  length=50 from=637 to=686
~.}#.!}"}!} }8}}$}!(}"}&} } }  }%}&.sr.}'}"}(".} ~  > 2021/05/08 00:27:49.554776  length=41 from=687 to=727
~.}#.!}!}!} }2}}$}!(}%}&}:}4@}}'}"}(}"%.~             2021/05/08 00:27:50 socat[1083] N read(5, 0x11f15c8, 8192): Input/output error (probably PTY closed)
2021/05/08 00:27:50 socat[1083] N socket 2 (fd 5) is at EOF
2021/05/08 00:27:50 socat[1083] E waitpid(): child 1084 exited with status 16
2021/05/08 00:27:50 socat[1083] N exit(1)
2021/05/08 00:27:50 socat[1082] N childdied(): handling signal 17
2021/05/08 00:27:50 socat[1082] N childdied(): handling signal 17
2021/05/08 00:28:42 socat[1082] N socat_signal(): handling signal 2
2021/05/08 00:28:42 socat[1082] N exiting on signal 2
2021/05/08 00:28:42 socat[1082] N socat_signal(): finishing signal 2
2021/05/08 00:28:42 socat[1082] N exit(130)

システムログ

May  8 00:27:20  pppd[1084]: pppd 2.4.7 started by pi, uid 0
May  8 00:27:20  pppd[1084]: using channel 2
May  8 00:27:20  pppd[1084]: Using interface ppp0
May  8 00:27:20  pppd[1084]: Connect: ppp0 <--> /dev/pts/2
May  8 00:27:20  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:23  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:26  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:29  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:32  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:35  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:38  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:41  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:44  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:47  pppd[1084]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0x957372ed> <pcomp> <accomp>]
May  8 00:27:50  pppd[1084]: LCP: timeout sending Config-Requests
May  8 00:27:50  pppd[1084]: Connection terminated.
May  8 00:27:50  pppd[1084]: Modem hangup
May  8 00:27:50  pppd[1084]: Waiting for 1 child processes...
May  8 00:27:50  pppd[1084]:   script pppd (charshunt), pid 1085
May  8 00:27:50  pppd[1084]: Script pppd (charshunt) finished (pid 1085), status = 0x0
May  8 00:27:50  pppd[1084]: Exit.

クライアントデバッグ出力:

sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
rcvd [LCP ConfReq id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_rconfreq(LCP): Rcvd id 1.
lcp_reqci: rcvd MRU (296) (ACK)
lcp_reqci: rcvd MAGICNUMBER (99ed93e8) (ACK)
lcp_reqci: rcvd PCOMPRESSION (ACK)
lcp_reqci: rcvd ACCOMPRESSION (ACK)
lcp_reqci: returning CONFACK.
sent [LCP ConfAck id=0x1 <mru 296> <magic 0x99ed93e8> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 2, id 1.
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
calltimeout, calling 53ce:2a06.
sent [LCP ConfReq id=0x1 <mru 296> <magic 0x1aed278> <pcomp> <accomp>]
fsm_sdata(LCP): Sent code 1, id 1.
Timeout 53ce:2a06 in 3 seconds.
LCP: sending Configure-Request, id 1
calltimeout, calling 53ce:2a06.
LCP: timeout sending Config-Requests

修正する:私は以前Wiresharkを試したことがあり、データを見るためにパケットをドリルダウンすることを除いて、内容は-vオプションを使用したSocatの出力と同じです。また試み

socat PTY,link=/tmp/ptya,rawer,nonblock=1,b19200,waitslave tcp-l:2323,fork,reuseaddr

od -ah `readlink /tmp/ptya`

LCPパケットは正しいです(PPP Design-Implementation-Debugging_James-Carlsonに従って)。 pppdがクライアントパケットを受信しないが、socatがクライアントパケットを受信して​​いるかのように問題は引き続き発生します。私はサーバーでpppを起動せずにこれを行いました。

root# od -h --endian=big `readlink /tmp/ptya`

# Every 7D XX sequence should be replaced with XX xor 20 (hex)

0000000 7eff 7d23 c021 7d21 7d21 7d20 7d32 7d7d
0000020 227d 287d 2256 6c7e 7eff 7d23 c021 7d21
0000040 7d21 7d20 7d32 7d7d 247d 2128 7d25 7d26
0000060 7d22 6791 2b7d 7d22 7d28 7d22 566c 7e7e
0000100 ff7d 23c0 217d 217d 217d 207d 327d 7d24
0000120 7d21 287d 257d 267d 2267 912b 7d7d 227d
0000140 287d 2256 6c7e 7eff 7d23 c021 7d21 7d21
0000160 7d20 7d32 7d7d 247d 2128 7d25 7d26 7d22
0000200 6791 2b7d 7d22 7d28 7d22 566c 7e7e ff7d
0000220 23c0 217d 217d 217d 207d 327d 7d24 7d21
0000240 287d 257d 267d 2267 912b 7d7d 227d 287d
0000260 2256 6c7e 7eff 7d23 c021 7d21 7d21 7d20
0000300 7d32 7d7d 247d 2128 7d25 7d26 7d22 6791
0000320 2b7d 7d22 7d28 7d22 566c 7e7e ff7d 23c0
0000340 217d 217d 217d 207d 327d 7d24 7d21 287d
0000360 257d 267d 2267 912b 7d7d 227d 287d 2256
0000400 6c7e 7eff 7d23 c021 7d21 7d21 7d20 7d32
0000420 7d7d 247d 2128 7d25 7d26 7d22 6791 2b7d
0000440 7d22 7d28 7d22 566c 7e7e ff7d 23c0 217d
0000460 217d 217d 207d 327d 7d24 7d21 287d 257d
0000500 267d 2267 912b 7d7d 227d 287d 2256 6c7e
0000520 7eff 7d23 c021 7d21 7d21 7d20 7d32 7d7d
0000540 247d 2128 7d25 7d26 7d22 6791 2b7d 7d22

kdebugオプションを試してみましたが、syslogにpppから受信したパケットは再び表示されません。

アップデート2: この問題は確かにsocatに関連しています。シリアルケーブルで直接接続して非常に迅速にppp接続を取得できますが、PTYをシリアルポートに接続してからPTYを使用してpppに接続しようとすると失敗します。正確に同じ方法。 PPPサーバーは「送信」メッセージのみを表示し、メッセージは受信されません。 Socatは、PPPサーバーがクライアントから応答を受け取ることを防ぎます。何とか、またはpppは他の場所からの受信を探しています。これはkdebugがpppに対して受信したパケットを表示しない理由を説明するのにも役立ちますが、socatを介して接続されている他のアプリケーションからデータが受信されることを示す理由は説明しません。私が試しましたが失敗したコマンドは次のとおりです。

socat -d -d -v file:/dev/ttyUSB0,nonblock,rawer PTY,rawer,link=/tmp/ptya
pppd `readlink /tmp/ptya`

ベストアンサー1

実際の質問に対する答えではありませんが、役に立ちます。

PTYだけを使用したい場合は、コマンドで直接指定してみてはpppdいかがでしょうか?pppdたとえば、私が遊んだとき、私は次のことに効果的でしたpppd

socat PTY,link=/tmp/ptya PTY,link=/tmp/ptyb
sudo pppd `readlink /tmp/ptya` noauth nocrtscts xonxoff local maxfail 0 10.0.3.1:10.0.3.2 persist
sudo pppd `readlink /tmp/ptyb` noauth nocrtscts xonxoff local maxfail 0 10.0.3.2:10.0.3.1 persist

詳細を見ないと、これがpppd notty正しく機能しないことに関連していると思われる可能性があります。

Socat ソケットを ppp 端末デバイスに接続するには PTY が必要です。

はい。たとえば、同じです。

socat -d -d -v tcp-l:2323,fork,reuseaddr PTY,link=/tmp/ptya
/usr/sbin/pppd `readlink /tmp/ptya` ...

うまく機能していることを確認してください。

このオプションを使用すると、pppdは独自に擬似ttyマスター/スレーブペアを割り当て、スレーブデバイスを最終デバイスとして使用します。

もしそうなら、socat1つのPTYが割り当てられ、もう1つのPTYが割り当てられ、最初のPTYを使用し、pppd2番目のPTYを使用する場合、どのように互いに通信する必要がありますか?彼らは使うべきですsocatpppd同じPTY(まあ、それの他の側面)。


私はSocatを使ってpppdとPTYの接続を接続するソケットを作成しています。

クライアントは、USBケーブルで完全に動作するdospppを実行している古いDOSポータブルコンピュータです。

以前はWiresharkを試したことがあり、データを見るためにパケットをドリルダウンすることを除いて、内容は-vオプションを使用してSocatの出力と同じです。

これで、ポート2323に誰が接続されているのか、この最後に何があるのか​​、そしてこれが既存のDOSポータブルコンピュータとどのように関連しているのかを説明する必要があります。なぜなら、私はその部分を本当に理解していないからです。

説明によると、pppdが動作し、socatが動作し、共有PTYが動作し、何でも(何でも)2323に接続されており、socatがそのデバイスにデータを送信していますが、データを受信して​​いないようです。

そうですか? (リモートデバッグは詳細を知らないと本当に難しいです。)

おすすめ記事