search

OpenRTM / OpenRTM-aist

OpenRTM-aist: RT-Middleware and OMG RTC implementation in C++ implemented by AIST
https://openrtm.org/
Other
19 stars 12 forks source link

omniORBのコネクションを自動切断する機能について #1042

Open Nobu19800 opened 2 years ago

Nobu19800 commented 2 years ago

Describe the bug omniORBは一定時間通信のないコネクションを自動的に削除する機能がある。

コネクションが削除された場合、データポートやサービスポートのコネクタが削除される場合がある。 サーバー側でコネクションを削除すると、メソッド呼び出し時にCOMM_FAILURE_WaitingForReply例外が発生する。

まず、下のログを見ての通り、サーバー側で自動削除した時にCloseConnectionを送信している。しかし、クライアント側で受信データを処理するのはメソッド呼び出しのためのリクエスト送信後にリプライを処理する時となる。ソケット通信の問題であるが、サーバー側でソケットを閉じた状態(closesocket関数)でクライアントがデータを送信(send関数)すると、クライアント側で受信したはずのCloseConnectionメッセージが消えるため、クライアント側ではリプライの受信(recv関数)に失敗したと判定してCOMM_FAILURE_WaitingForReply例外が発生する。

To Reproduce Steps to reproduce the behavior:

  1. rtc.confで以下のように設定 
    corba.args: -ORBinConScanPeriod 1 -ORBtraceLevel 50 -ORBtraceFile trace.txt
  2. ConsoleIn、ConsoleOutコンポーネントを起動してデータポートを接続、アクティブ化
  3. 数秒待った後に、ConsoleInからデータを送信する
  4. See error

Reproducibility 100％

Expected behavior

Screenshots or Logs

omniORB: (2) 2022-04-01 09:58:05.835000: Scan for idle connections (1648774685,828000000)
omniORB: (2) 2022-04-01 09:58:05.835000: Scavenger reduce idle count for strand 0000021CB842ED00 to 0
omniORB: (2) 2022-04-01 09:58:05.835000: Scavenger close connection from giop:tcp:[::ffff:192.168.135.1]:54648
omniORB: (2) 2022-04-01 09:58:05.835000: sendCloseConnection: to giop:tcp:[::ffff:192.168.135.1]:54648 12 bytes
omniORB: (2) 2022-04-01 09:58:05.835000: 
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (2) 2022-04-01 09:58:05.837000: Scan for idle connections done (1648774685,828000000).
omniORB: (4) 2022-04-01 09:58:06.200000: Error in network receive (start of message): giop:tcp:[::ffff:192.168.135.1]:54648
omniORB: (4) 2022-04-01 09:58:06.200000: throw giopStream::CommFailure from giopStream.cc:849(0,NO,COMM_FAILURE_UnMarshalArguments)
omniORB: (4) 2022-04-01 09:58:06.200000: Server connection giop:tcp:[::ffff:192.168.135.1]:54648 refcount = 1
omniORB: (4) 2022-04-01 09:58:06.201000: Server connection giop:tcp:[::ffff:192.168.135.1]:54648 refcount = 0
omniORB: (4) 2022-04-01 09:58:06.201000: Server close connection from giop:tcp:[::ffff:192.168.135.1]:54648
omniORB: (4) 2022-04-01 09:58:06.201000: AsyncInvoker: thread id 4 finished immediate server task.
omniORB: (2) 2022-04-01 09:58:06.962000: Scan for idle connections (1648774686,948000000)
omniORB: (2) 2022-04-01 09:58:06.962000: Scan for idle connections done (1648774686,948000000).
omniORB: (? 19080) 2022-04-01 09:58:33.893000: Reset rope addresses (current address giop:tcp:192.168.135.1:54637)
omniORB: (? 19080) 2022-04-01 09:58:33.893000: Error in network receive (start of message): giop:tcp:192.168.135.1:54637
omniORB: (? 19080) 2022-04-01 09:58:33.893000: throw giopStream::CommFailure from giopStream.cc:849(0,MAYBE,COMM_FAILURE_WaitingForReply)
omniORB: (? 19080) 2022-04-01 09:58:33.893000: Client connection giop:tcp:192.168.135.1:54637 refcount = 0
omniORB: (? 19080) 2022-04-01 09:58:33.893000: Client close connection to giop:tcp:192.168.135.1:54637
omniORB: (? 19080) 2022-04-01 09:58:33.893000: throw COMM_FAILURE from omniObjRef.cc:711 (MAYBE,COMM_FAILURE_WaitingForReply)

Environment

Additional context

Nobu19800 commented 2 years ago

予想した通り、Bidirectional通信では例外は発生しませんでした。

corba.args: -ORBinConScanPeriod 1 -ORBoutConScanPeriod 0  -ORBclientTransportRule "* bidir, tcp" -ORBacceptBiDirectionalGIOP 1 -ORBofferBiDirectionalGIOP 1
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (2) 2022-04-11 15:15:03.029000: sendCloseConnection: to giop:tcp:[::ffff:192.168.135.1]:52751 12 bytes
omniORB: (2) 2022-04-11 15:15:03.030000: 
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (2) 2022-04-11 15:15:03.030000: Scan for idle connections done (1649657703,19000000).
omniORB: (5) 2022-04-11 15:15:03.030000: inputMessage: from giop:tcp:192.168.135.1:52739 12 bytes
omniORB: (5) 2022-04-11 15:15:03.030000: 
4749 4f50 0102 0105 0000 0000           GIOP........
omniORB: (5) 2022-04-11 15:15:03.030000: Server has closed a bi-directional connection on strand 000001434B5B7C50. Will scavenge it.
omniORB: (5) 2022-04-11 15:15:03.030000: Orderly connection shutdown: giop:tcp:192.168.135.1:52739
omniORB: (5) 2022-04-11 15:15:03.030000: throw giopStream::CommFailure from giopImpl12.cc:1244(0,NO,COMM_FAILURE_UnMarshalArguments)
omniORB: (5) 2022-04-11 15:15:03.030000: Client connection giop:tcp:192.168.135.1:52739 refcount = 1
omniORB: (5) 2022-04-11 15:15:03.030000: AsyncInvoker: thread id 5 finished immediate server task.
omniORB: (6) 2022-04-11 15:15:03.130000: Error in network receive (start of message): giop:tcp:[::ffff:192.168.135.1]:52747
omniORB: (6) 2022-04-11 15:15:03.130000: throw giopStream::CommFailure from giopStream.cc:849(0,NO,COMM_FAILURE_UnMarshalArguments)
omniORB: (6) 2022-04-11 15:15:03.130000: Server connection giop:tcp:[::ffff:192.168.135.1]:52747 refcount = 1
omniORB: (6) 2022-04-11 15:15:03.130000: Server connection giop:tcp:[::ffff:192.168.135.1]:52747 refcount = 0
omniORB: (6) 2022-04-11 15:15:03.130000: Server close connection from giop:tcp:[::ffff:192.168.135.1]:52747
omniORB: (6) 2022-04-11 15:15:03.130000: AsyncInvoker: thread id 6 finished immediate server task.