.NET 1.1から3.5へのマイグレーション後の予期しない動作

Question

私たちは最近、フレームワーク1.1からフレームワーク3.5へ一連のサービスを移行しました。私たちは古い（1.1）プロジェクトをインポートして再コンパイルしました。

これらのサービスは、データベースを7秒ごとにチェックして、実行するタスクの数を各タスクごとに（スレッドスコープ内で）同期させるスレッドを作成します（スレッドスコープ内で） 。呼び出しが完了すると、スレッドは完了します。

新しいスレッドを作成するのは、ThreadPoolが使用可能なスレッド全体の50％以上を取得した場合のみです（これを確認するにはThreadPool.GetAvailableThreadsを使用します）。そうであれば、スレッドが作成されます。そうでない場合、サービスは2秒待ってから（Thread.Sleep（1000）;）、新しいチェックを行います。

これらはすべて1.1で正常に機能し、3.5で正常に動作しているように見えますが、テストマシンでのみ動作します。

すべての問題が本番マシンに一度リリースされました。チェックとスレッドは正しく行われましたが、Webサービスコールは膨大な遅延（20分以上）で開始され、ゆっくりと解決されます。 1秒あたりのコール数（多かれ少なかれ）、3.5バージョンでは20秒ごとにコールが解決されます（また、それぞれ20分の遅延があります）。接続の問題やタイムアウトはありませんでした。

私たちが見ると、数多くのスレッド（約30）が非常に短い時間に割り当てられ、それぞれが即座にWS呼び出しを開始します。つまりコードが。（）同期呼び出しを実行します。問題は、それらの呼び出しが、時間とその数分後に1つだけ解決されるということです。

今、なぜこれはプロダクションマシンでのみ発生しますか？なぜ他のテストマシンでこれは起こりませんか？

提案がありますか？

ありがとうございます。

EDIT

我々は、サービス内のいくつかの変更を行いました。今では、最大でスレッドプール（35）の固定数を割り当てることができます。この数に達すると、サービスは新しいスレッドを作成する前にスレッドが完了するのを待ちます。プロセスの作業罰金、我々はまだ、各Web要求はより大きな時間間隔で実行されていることに気づく：

[11:48:40,365] [ 336] INFO MyClass.Call(): Time elapsed: 00:04:07.0172059 
[11:49:14,771] [ 3052] INFO MyClass.Call(): Time elapsed: 00:04:41.4236761 
[11:49:27,256] [ 3928] INFO MyClass.Call(): Time elapsed: 00:04:53.9081310 
[11:49:51,303] [ 5444] INFO MyClass.Call(): Time elapsed: 00:05:17.9551599 
[11:50:34,787] [ 5332] INFO MyClass.Call(): Time elapsed: 00:06:00.2054303 
[11:50:55,366] [ 4672] INFO MyClass.Call(): Time elapsed: 00:06:19.7211802 
[11:51:15,288] [ 1248] INFO MyClass.Call(): Time elapsed: 00:06:38.6588014 
[11:51:34,975] [ 4168] INFO MyClass.Call(): Time elapsed: 00:06:57.3307959 
[11:53:00,429] [ 5224] INFO MyClass.Call(): Time elapsed: 00:08:18.7531920 
[11:53:18,367] [ 908] INFO MyClass.Call(): Time elapsed: 00:08:35.7064255 
[11:53:44,398] [ 3616] INFO MyClass.Call(): Time elapsed: 00:09:00.7222106 
[11:54:04,523] [ 6108] INFO MyClass.Call(): Time elapsed: 00:09:19.8942083 
[11:54:29,523] [ 5536] INFO MyClass.Call(): Time elapsed: 00:09:43.8943619 
[11:54:47,242] [ 5048] INFO MyClass.Call(): Time elapsed: 00:10:00.5819687 
[11:55:05,992] [ 3756] INFO MyClass.Call(): Time elapsed: 00:10:18.3164572 
[11:55:26,508] [ 4628] INFO MyClass.Call(): Time elapsed: 00:10:37.8322071 
[11:55:52,493] [ 5812] INFO MyClass.Call(): Time elapsed: 00:11:02.8167420 
[11:56:22,305] [ 5752] INFO MyClass.Call(): Time elapsed: 00:11:32.0356790 
[11:56:31,680] [ 4688] INFO MyClass.Call(): Time elapsed: 00:11:41.0513617 
[11:57:00,556] [ 5844] INFO MyClass.Call(): Time elapsed: 00:12:08.8952899 
[11:57:10,759] [ 5760] INFO MyClass.Call(): Time elapsed: 00:12:18.0203483 
[11:57:49,321] [ 5684] INFO MyClass.Call(): Time elapsed: 00:12:35.3017089 
[11:57:59,056] [ 5920] INFO MyClass.Call(): Time elapsed: 00:12:26.9110302 

さらなる検査は約20秒でその効果的なTCPの呼び出しが最後の証明が、わずか数分CHE後に実行されますコードコール。例えば

、以下のコード：59：

slg.Info("Beginning connection."); 

DateTime callStart = DateTime.Now; 

odOutput = ws_Proxy.WSMethod(odInput);; 

log.InfoFormat("Time elapsed: {0}", DateTime.Now - callStart); 

農産物このログ

[11:47:59,396] [ 5468] INFO MyClass.Call(): Beginning connection. 
[12:00:17,026] [ 5468] INFO MyClass.Call(): Time elapsed: 00:12:17.6297208 

が、TCP接続はわずか11で行われ56039と12で完了：00：17404

11:59:56.0399905 TCP Connect SUCCESS Length: 0, mss: 1300, sackopt: 4, tsopt: 0, wsopt: 0, rcvwin: 64240, rcvwinscale: 0, sndwinscale: 0, connid: 2254643208, seqnum: 155953480 0 
11:59:56.8962917 TCP Send... SUCCESS Length: 302, startime: 1012803, endtime: 1012811, connid: 2254643208, seqnum: 0 0 
11:59:56.9794909 TCP Receive SUCCESS Length: 2, connid: 2254643208, seqnum: 0 0 
11:59:57.7751084 TCP Send... SUCCESS Length: 625, startime: 1012806, endtime: 1012820, connid: 2254643208, seqnum: 0 0 
11:59:57.7751656 TCP Receive SUCCESS Length: 2, connid: 2254643208, seqnum: 0 0 
12:00:08.3723058 TCP Receive SUCCESS Length: 1300, connid: 2254643208, seqnum: 0 0 
12:00:16.5336435 TCP Unknown SUCCESS Length: 0, connid: 2254643208, seqnum: 0 0 
12:00:16.5337723 TCP Receive SUCCESS Length: 1265, connid: 2254643208, seqnum: 0 0 
12:00:17.4046865 TCP Disconnect SUCCESS Length: 0, connid: 2158355531, seqnum: 4133859281 0 

11：47：59,396と11：59：56,039の間にはどうなりますか？コールと実際の接続の間隔がそれほど大きくなるのはなぜですか？この動作は、多数のリクエストが非同期で実行される場合にのみ発生します。それは、フレームワークが複数の接続を時間通りに実行できないようなものです...

Answer 1

最後に、プロキシによって引き起こされたような問題が見つかりました（システム管理者は誰に、なぜこのプロキシを設定したのかわかりません）。

このプロキシは、システムとして実行されているプロセス（サービスなど）によってのみアクティブ化されます。ユーザとして実行されるプロセス（テストに使用される小さなアプリケーションのような）はこのプロキシを使用しないため、サービスがいくつかの問題で実行されている間に小さなテストアプリケーションが正常に動作するのはこのためです。

私たちは、単にサービスの設定に以下の行を追加し、問題を解決：それは生産ですので

<system.net> 
    <defaultProxy enabled="false" /> 
</system.net> 

Answer 2

a）ThreadPoolのアルゴリズムと制限が変更されました。 AvailableThreads/2を使用するあなたのアプローチは一度はうまくいくかもしれませんが、私のWin7ノートパソコンでは1023/2と500スレッドになりすぎます。

b）あなたはスレッドとThreadPoolを見ていますが、あなたの説明からはネットワークやファイアウォールの問題でもあります。