5

背景/イントロ:

非常に奇妙な問題です。特定の例外がスローされると、例外が処理されるまで他のすべてのスレッドの実行が停止するように見えます。アプリケーションはプロキシ サーバーであり、ソックス接続を介して N 個の他のプロキシ クライアントに接続する tcp ソケットのプールを介して複数の要求 (任意の時間枠で数百) をパイプします。これは、例外を使用するのではなく、デリゲートを渡すことによっても試行されましたが、同じパフォーマンスの結果が得られませんでした。

通常の運用時のログ スニペット:

14:40:17.700 [PrxSvc:9058] --> [200] 1217ms http://redact.example.com   
14:40:17.700 [PrxSvc:9058] C-DEBUG:C                
14:40:17.716 [PrxSvc:9058] --> [200] 1098ms http://redact.example.com           
14:40:17.716 [PrxSvc:9058] C-DEBUG:C             
14:40:17.727 [PrxSvc:9054] --> [200] 905ms http://redact.example.com   
14:40:17.727 [PrxSvc:9054] C-DEBUG:C         
14:40:17.778 [PrxSvc:9050] --> [200] 453ms http://redact.example.com           
14:40:17.778 [PrxSvc:9050] C-DEBUG:C         
14:40:17.781 [Unnamed Thread] C-DEBUG:A          
14:40:17.781 [Unnamed Thread] C-DEBUG:B         
14:40:17.796 [PrxSvc:9058] --> [200] 652ms http://redact.example.com             
14:40:17.796 [PrxSvc:9058] C-DEBUG:C                
14:40:17.807 [PrxSvc:9056] --> [200] 1555ms http://redact.example.com              
14:40:17.807 [PrxSvc:9056] C-DEBUG:C           
14:40:17.816 [PrxSvc:9064] --> [200] 396ms http://redact.example.com

ソケット プールはドメインへの接続を再利用しますが、接続が外部サーバーによって閉じられた場合、明らかにこれに関する通知を受け取りません。TcpSocksHandler.TaskHandler メソッドを介してこの接続を再利用しようとすると、次のようになります。

socks.Send(buffer, 0, rcv, SocketFlags.None);
socks.Receive(new byte[1], 0, 1, SocketFlags.Peek);

この例外は、次のようにキャッチされます。

catch
{
    //The socket is bad, we should get a new socket.
    Log("This socket has expired! - Server has closed the connection.");
    Log(String.Format("This socket was {0} seconds old: {1}", seconds, socks.Guid));
    socks.Dispose();
    Log("C-DEBUG:1");
    throw new SocksSocketFailureException(); //throw exception. to bubble back up.
}

これは、呼び出し元のコードによってキャッチされ、次のようにスタックを複数回アップします。

DoHandleRequest{...
try
{
    _actualEndPoint = TcpSocksHandler.TaskHandler(socket, context.SocksSocket, 30000000, method);
}
catch (SocksSocketFailureException ssfe)
{
    context.SocksSocket = null;
    Logger.Log("C-DEBUG:2");
    throw;
}
}

ProxyBase.HandleRequest{...
    try
    {
        ...
        success = DoHandleRequest(context, out bytes);
    }
    catch (SocksSocketFailureException ssfex)
    {
        Logger.Log("C-DEBUG:3");
        throw;
    }
}

ProxyManager.HandleRequest{
    while (true)
    {
        // Pick the best available proxy to handle the request
        Logger.Log("C-DEBUG:A");
        IProxy proxy = GetNextProxy(context) ?? NullProxy.Instance;
        Logger.Log("C-DEBUG:B");
        try
        {
            // Process the request
            proxy.HandleRequest(context);
            Logger.Log("C-DEBUG:C");
            break;
        }
        catch(SocksSocketFailureException ssfex)
        {
            Logger.Log("C-DEBUG:4");
        }
        catch (Exception)
        {
            break;
        }
    }
}

以下のログ スニペットから、このパフォーマンス (またはその欠如) を確認できます。

14:40:34.090 [PrxSvc:9068] C-DEBUG:A             
14:40:34.090 [PrxSvc:9068] C-DEBUG:B                  
14:40:34.231 [PrxSvc:9068] This socket has expired! - Server has closed the connection.
14:40:34.231 [PrxSvc:9068] This socket was 6.281049 seconds old: 61cc51b9-f121-4529-9649-7defcc1f5586           
14:40:34.231 [PrxSvc:9068] C-DEBUG:1            
14:40:34.528 [PrxSvc:9068] C-DEBUG:2              
14:40:34.715 [PrxSvc:9068] C-DEBUG:3              
14:40:34.918 [PrxSvc:9068] C-DEBUG:4             
14:40:34.918 [PrxSvc:9068] C-DEBUG:A

上記のログ行は編集されていません - ほぼ 1 秒間、他に何も処理されていません! （通常、おそらく100のリクエストを処理できます）。さらに、例外をスタックにバブリングするだけでも、1 秒 (場合によってはそれ以上) かかるようです。- 上記のログ行のタイミングに注意してください。例: DEBUG:3 と DEBUG:4 の間に 2 秒のギャップ!!

何が原因なのかわかりません。どんなアドバイスやアイデアも大歓迎です！

アップデート：

Eamon の質問に基づいて、同じ x64 ビルドを、Windows8 64 ビットを実行している非運用のローカル マシンにプッシュしました。前の例のように、サービス、リリース ビルドとしてインストールされます。他の唯一の違いは、以前の 80 ではなく、4 つのプロキシ ノード (PrxSvc 9050、9052、9054、9056) をターゲットにしていることです。今風のファッション：

16:53:59.787 [PrxSvc:9056] This socket has expired! - Server has closed the connection.
16:53:59.787 [PrxSvc:9056] This socket was 0.1280009 seconds old: 69d12cc9-9456-47db-86b2-a2ebf87b41bf
16:53:59.787 [PrxSvc:9056] C-DEBUG:1
16:53:59.787 [PrxSvc:9056] C-DEBUG:2
16:53:59.787 [PrxSvc:9056] C-DEBUG:3
16:53:59.787 [PrxSvc:9056] C-DEBUG:4
16:53:59.787 [PrxSvc:9056] C-DEBUG:A

このマシンでは、コードは現在、1 秒あたり約 80 リクエストの速度で 800 の同時リクエストを問題なく処理しており、さらに多くのリクエストを簡単に処理できます...一体何がこの違いを引き起こしているのでしょうか?!

完全を期すために、最初のテスト (win2008 サーバー上) を 80 ノードではなく 4 ノードで再実行しましたが、同じゴミの結果が得られました。

17:22:44.891 [PrxSvc:9054] C-DEBUG:B
17:22:45.063 [PrxSvc:9054] This socket has expired! - Server has closed the connection.
17:22:45.063 [PrxSvc:9054] This socket was 25.84375 seconds old: cfdee74d-9941-4c8c-80cd-f32aa14b7877
17:22:45.063 [PrxSvc:9054] C-DEBUG:1
17:22:45.485 [PrxSvc:9054] C-DEBUG:2
17:22:45.751 [PrxSvc:9054] C-DEBUG:3
17:22:46.016 [PrxSvc:9054] C-DEBUG:4
4

2 に答える 2

1

これは、あなたの質問に対する答えではありません。あなたのプログラムのエラーは何ですか? 通常、これについてコメントを書きますが、テキストが長すぎます。

最初の例のログ (「通常の操作」) は、私には少しわかりにくいものです。1つだけありますがC-DEBUG:A、C-DEBUG:B少なくともすべてC-DEBUG:Cの場合、それぞれ1つが必要ですよね?

他の例は見栄えがよく、すべてが期待どおりに発生します（A => B => 例外 => 1 => 2 => 3 => 4 => A）。スレッドは 1 つしかないように見えますが、例からはこれが間違っているという手がかりは得られません。私はC-DEBUG:A別のスレッドからの秒を参照してください。代わりに何を期待しますか？

あなたの更新について:ここで、例外のスローごとに実行時間が必要なため、テストマシンのパフォーマンスについてもっと知りたいと思っています。これが、ループで例外をスローするとパフォーマンスが大幅に低下する理由です。あなたのサーバーの時間は少し遅いようですが、私の観点からは問題ありません。

問題のヒントを提供することはできませんが、少なくとも、例外をスローすること自体が他のスレッドのブロック要因ではないという声明を出すことができます。私が小さなプログラムを書いたことを証明するために (私がどのようにそれを行ったかを知りたい場合は、以下のソース コードを参照してください)。そのプログラムの出力は

19:31:09.2788 [Thread-0] 0
19:31:09.2788 [Thread-1] 1
19:31:09.3908 [Thread-0] 0
19:31:09.3908 [Thread-1] 1
19:31:09.4908 [Thread-1] 1
19:31:09.4908 [Thread-0] 0
19:31:09.5908 [Thread-0] 0
19:31:09.5998 [Thread-1] Caught exception callstack frame 29
19:31:09.6078 [Thread-1] Caught exception callstack frame 28
19:31:09.6148 [Thread-1] Caught exception callstack frame 27
19:31:09.6218 [Thread-1] Caught exception callstack frame 26
19:31:09.6288 [Thread-1] Caught exception callstack frame 25
19:31:09.6358 [Thread-1] Caught exception callstack frame 24
19:31:09.6418 [Thread-1] Caught exception callstack frame 23
19:31:09.6488 [Thread-1] Caught exception callstack frame 22
19:31:09.6548 [Thread-1] Caught exception callstack frame 21
19:31:09.6608 [Thread-1] Caught exception callstack frame 20
19:31:09.6668 [Thread-1] Caught exception callstack frame 19
19:31:09.6728 [Thread-1] Caught exception callstack frame 18
19:31:09.6778 [Thread-1] Caught exception callstack frame 17
19:31:09.6828 [Thread-1] Caught exception callstack frame 16
19:31:09.6888 [Thread-1] Caught exception callstack frame 15
19:31:09.6908 [Thread-0] 0
19:31:09.6938 [Thread-1] Caught exception callstack frame 14
19:31:09.6978 [Thread-1] Caught exception callstack frame 13
19:31:09.7028 [Thread-1] Caught exception callstack frame 12
19:31:09.7078 [Thread-1] Caught exception callstack frame 11
19:31:09.7128 [Thread-1] Caught exception callstack frame 10
19:31:09.7168 [Thread-1] Caught exception callstack frame 9
19:31:09.7218 [Thread-1] Caught exception callstack frame 8
19:31:09.7258 [Thread-1] Caught exception callstack frame 7
19:31:09.7299 [Thread-1] Caught exception callstack frame 6
19:31:09.7339 [Thread-1] Caught exception callstack frame 5
19:31:09.7369 [Thread-1] Caught exception callstack frame 4
19:31:09.7409 [Thread-1] Caught exception callstack frame 3
19:31:09.7439 [Thread-1] Caught exception callstack frame 2
19:31:09.7469 [Thread-1] Caught exception callstack frame 1
19:31:09.7499 [Thread-1] Caught exception callstack frame 0
19:31:09.7509 [Thread-1] 1
19:31:09.7919 [Thread-0] 0
19:31:09.8509 [Thread-1] 1
19:31:09.8919 [Thread-0] 0
19:31:09.9509 [Thread-1] 1
19:31:10.0509 [Thread-1] 1
19:31:10.1509 [Thread-1] 1
19:31:10.2509 [Thread-1] 1
19:31:10.3509 [Thread-1] 1

ご覧のとおり、スレッドThread-0は a を出力しますが、 Thread-10の例外はコールスタックを上っていきます。ここではブロックしません！

ここで私のプログラムを参照してください：

class Program {
    class MyException : Exception {}

    // A class for give the starting thread operation some parameters
    class ThreadStartParameter {
        // For identifying each thread
        public int Id { get; set; }

        // For building up a deeper callstack frame
        public int CallStackDepth { get; set; }

        // Indicates that this thread should throw an exception
        public bool ThrowException { get; set; }
    }

    static void Main(string[] args) {
        // Create two threads and let them run concurrently
        Thread t0 = new Thread(BuildUpCallStack) { Name = "Thread-0" };
        Thread t1 = new Thread(BuildUpCallStack) { Name = "Thread-1" };
        t0.Start(new ThreadStartParameter {
            Id = 0,
            CallStackDepth = 0,
            ThrowException = false
        });
        t1.Start(new ThreadStartParameter {
            Id = 1,
            CallStackDepth = 0,
            ThrowException = true
        });
        Console.Read();
    }

    // Recursive helper method to build a callstack of 30 frames, which
    // is used to rethrow an exception at each level
    static void BuildUpCallStack(object data) {
        ThreadStartParameter parameter = (ThreadStartParameter)data;

        if (parameter.CallStackDepth < 30) {
            try {
                BuildUpCallStack(new ThreadStartParameter {
                    Id = parameter.Id,
                    CallStackDepth = parameter.CallStackDepth + 1,
                    ThrowException = parameter.ThrowException
                });
            } catch (MyException e) {
                Log(string.Format("Caught exception callstack frame {0}",
                    parameter.CallStackDepth));
                // If an exception occured, rethrow it unless this
                // callstack frame was the first
                if (parameter.CallStackDepth != 0) throw;

                // If this frame was the first in callstack, restart the
                // thread but this time without throwing an exception (for
                // demonstrate such a restart character like your Proxies do)
                BuildUpCallStack(new ThreadStartParameter {
                    Id = parameter.Id,
                    CallStackDepth = 0,
                    ThrowException = false
                });
            }
            return;
        }

        DoSomething(parameter);
    }

    static void DoSomething(object data) {
        ThreadStartParameter parameter = (ThreadStartParameter)data;

        for (int counter = 0; counter < 7; counter++) {
            if (counter == 3 && parameter.ThrowException)
                throw new MyException();

            Log(parameter.Id);
            Thread.Sleep(100);
        }
    }

    static void Log(object message) {
        Console.WriteLine(
            "    {0:HH:mm:ss.ffff} [{1}] {2}",
            DateTime.Now,
            Thread.CurrentThread.Name,
            message.ToString());
    }
}

テスト マシンでこのプログラムを試す場合は、より多くの「適切な」スレッド (例外をスローしないスレッド) を開始するか、必要なコールスタックの深さを増やして、私が行ったように効果を確認する必要があると思います。

于 2013-01-03T18:44:20.353 に答える
0

例外は、スローするのは安く、キャッチするのは高くつきます。コードが例外の処理方法を認識していない限り、例外をキャッチしないでください。これは、C-Debug:2 と C-Debug:3 の場合のようです。また、相手側が接続を閉じているという既知の状態があります。これを処理するために例外を使用しないでください。IsConnectedスローされる例外に依存するのではなく、ループ内で同様のメソッドまたはプロパティを公開してチェックする必要があります。

while(true) {
   IProxy proxy = GetNextProxy(context) ?? NullProxy.Instance;
   if (!proxy.IsConnected)
       continue;
   try {
     proxy.HandleRequest(context);
     break;
   } catch {
     // handle actual exceptional cases here
   } 
}

上記のコードにカウンターまたはタイマーを追加し、必要に応じて x 回の再試行または特定の期間が経過した場合に例外をスローすることができますが、いずれにせよ IsConnected プロパティ チェックはコードのパフォーマンスを大幅に向上させます。 .

于 2013-01-03T17:58:23.590 に答える