これを説明するには少し時間がかかるかもしれませんが、ここに行きます:)。
2 つの Visual Studio 2012 プロジェクトを作成しました。
- Visual Studio の [プロジェクトの追加] ダイアログで (Web -> ASP.NET MVC 4 Web アプリケーション) テンプレートを使用するプロジェクト。単体テスト プロジェクトを追加しませんでした。
- Azure クラウド サービス テンプレートを使用するプロジェクト (クラウド -> Windows Azure クラウド サービス)。ASP.NET MVC 4 Web ロールという 1 つのロールを追加しましたが、単体テスト プロジェクトは追加しませんでした。
これらのプロジェクトは両方とも、Visual Studio で作成された方法からまったく手を加えずに残しました。
次に、プロジェクトごとHomeControllerにクラスに移動し、AboutおよびContactアクション メソッド (ビューを返すだけの退屈なアクション) のそれぞれにブレークポイントを設定しました。たとえば、メソッド内の唯一の行にブレークポイントを設定します。
public ActionResult About()
{
return View();
}
次に、最初のプロジェクト (Azure 以外のプロジェクト) のデバッグを開始しました。すべてが期待どおりでした。つまり、ブラウザーを使用して About ページと Contact ページの間を移動すると、それぞれのアクション メソッドのブレークポイントが要求ごとに 1 回ヒットします。私にはうまく見えました。
次に、Azure プロジェクトのデバッグを開始しました。AboutページとContactページの間を移動するのと同じ手順に従いました. 今回、興味深い非決定論的な振る舞いを見つけました。一部のリクエストでは、ページがレンダリングされる前に、アクション メソッドのブレークポイントが複数回 (場合によっては 2 回以上) ヒットします。リクエストがハングアップし、ページがレンダリングされない場合がありました (数分間待った後でも)。
なぜこれが起こっているのか知りたいのですが、これは、私たちが取り組んでいる別の Azure MVC アプリケーションのより複雑なことに影響を与えているためです (たとえば、この問題のために、アプリケーションはモデル オブジェクトの複数のインスタンスを作成しようとする可能性があります)。 1つのリクエストに対する私のデータベース）。
私は次の環境にいます：
- Windows 8 プロ (x64)
- Visual Studio 2012 アルティメット
- Windows Azure SDK for Visual Studio 2012
- IIS 8 エクスプレス
- Firebugを搭載したFirefoxブラウザ（IEでも動作確認済み）
- SQL Server 2012 (あまり関係ないと思います)
私が気付いた唯一の興味深い点は、Azure プロジェクトをデバッグするたびに、Visual Studioの [出力] ウィンドウに次の警告メッセージが表示されることです。
エミュレーション中の競合を避けるために、ロール 'My_Web_Role_Name' のプライベート ポート 80 を 81 に再マッピングします。
おそらく、この再マッピングはそれと関係があります。それからもう一度、netstat -anoAzure Development Fabric プロセスがポート 80 でリッスンしていることがわかったので、再マッピングを行う必要があるのかもしれません。
とにかく、誰かがこの動作の原因について考えていることを願っています。私が試したいくつかの追加のポイントとアプローチを次に示します。
- IIS のリセット、Azure コンピューティング/ストレージ エミュレーターの再起動、マシン全体の再起動
- すべてのスクリプトのビューを削除します (つまり、ページに基本的な HTML 段落があるだけの場合、動作はそのままです)。
- 関連する IIS Express ログ ファイルを見つけようとしましたが、Azure プロジェクトは他のプロジェクトのように IIS Express を介して実行されないようです (正しいですか?)。
- Azure Compute Emulator コンソールを監視しましたが、特に興味深いものはありませんでした。
それで...最後に、いくつかの質問:
- 他の誰かがこの動作を再現できますか?
- Azure Emulator によって生成された追加のログはありますか?
ここで正しい方向へのプッシュを本当に感謝します:)。
乾杯！
編集
ここにいくつかの詳細情報があります（この問題のデバッグを続けているため、この質問を更新しています）：
Aboutデバッグせずにソリューションを実行することに決め、アクション メソッドとContactアクション メソッドの両方にいくつかの簡単なデバッグ メッセージを入れました。次に例を示します。
public ActionResult About()
{
System.IO.File.AppendAllText(@"c:\Logs\azure.log", DateTime.Now + ": Contact, thread " + System.Threading.Thread.CurrentThread.ManagedThreadId + "\r\n");
return View();
}
このファイルにTailを添付し、 Fiddlerを起動して HTTP で何が起こっているかを確認しました。2 つAboutのContactリンクの間を再度移動すると、次の出力が表示されました。
尻尾より:
- ...
- 2012/9/12 12:14:07 PM: スレッド 7 について
- 2012 年 9 月 12 日 12:14:08 PM: 連絡先、スレッド 7
- 2012/9/12 12:14:09 PM: スレッド 7 について
- 2012 年 9 月 12 日 12:14:10 PM: 連絡先、スレッド 7
- 2012/9/12 12:14:11 PM: スレッド 6 について
- 2012 年 9 月 12 日 12:14:12 PM: 連絡先、スレッド 8
- 2012 年 9 月 12 日 12:14:31 PM: 連絡先、スレッド 7
- 2012 年 9 月 12 日 12:14:50 PM: 連絡先、スレッド 7
- 2012/9/12 12:15:03 PM: スレッド 7 について
- 2012 年 9 月 12 日 12:15:05 PM: 連絡先、スレッド 8
- 2012/9/12 12:15:23 PM: スレッド 6 について
- 2012/9/12 12:15:42 PM: スレッド 14 について
- 2012/9/12 12:16:01 PM: スレッド 6 について
- 2012 年 9 月 12 日 12:16:31 PM: 連絡先、スレッド 7
- 2012/9/12 12:16:33 PM: スレッド 14 について
- ...
- 2012 年 9 月 12 日 12:17:08 PM: 連絡先、スレッド 12
- 2012/9/12 12:17:09 PM: スレッド 12 について
- 2012/9/12 12:17:28 PM: スレッド 5 について
- ...
同じリクエストの Fiddler から (ロール エンドポイントの設定も試してみましたが、役に立たなかったことに注意してください):
というわけで...持ち帰り用のメッセージは次のとおりです。
- HTTP トラフィックは正常に見えます (Fiddler は重複したリクエストを表示していません)
- アクションメソッドは、一見非決定論的に、同じリクエストに対して2回または3回呼び出されることがあります（つまり、上記の元の問題）
- 興味深いことに、私の状況では、アクション メソッドで別の「ヒット」が発生する前に正確に19 秒が経過しているように見えます (つまり、アクション メソッドが複数回ヒットされている場合、ヒット間の時間差は決定論的です)。
- 通常、アクション メソッドが複数回ヒットするたびに、ヒットごとにスレッド ID が異なります。
私はもっと深く掘り下げ続けます...多分誰かがこの更新された情報に基づいて提案を提供するのに十分親切になるでしょう:)。
EDIT 2 それぞれの場合に、アクションメソッド内のスレッド ID とともにプロセス ID を出力することにしました。すべての要求のプロセス ID は、IIS Express ワーカー プロセスに対応するものでした。そのため、IIS Express ワーカー プロセスは、要求を処理するために、それぞれ 19 秒間隔で複数のスレッドを生成することがあるようです。
...さらに深く私は行きます... :)
編集3
私は問題に近づいていると思います... IIS Express トレイを見て、アプリケーションを開始した後に (デバッグなしで) 次のように表示されました。
この URL を (上記の Fiddler で示した 127.0.0.2:8888 の代わりに) 直接使用することにしたところ、問題は解決したように見えました。これは今では意味を成し始めています... ポート 8889 経由で IIS アプリケーションを直接呼び出すと、元の Azure 以外のプロジェクトで行ったように、すべて正常に動作します。ポート 8888 経由で Web ロール (Azure 固有の部分) を呼び出すと、IIS アプリケーションが複数回呼び出されるように見えることがあります。
そのため、私は今、Web ロールに焦点を絞り始めています。関連する Web ロール ログを見つけられるかどうかを確認してみます...
編集4
アプリケーションで診断が適切に設定されていることを確認し、デバッグ モードで実行しました。次に、Azure Compute Emulator UI に移動し、Web ロール インスタンスを右クリックして、[ローカル ストアを開く] を選択しました。これによりエクスプローラーに移動し、子フォルダー「temp\temp\RoleTemp\iisexpress」を見つけることができました。このフォルダーには、次のような内容のログ ファイルが含まれていました (エンドポイントをポート 80 に戻したことに注意してください)。であるため、IIS Express アプリケーションはポート 81 に戻ります):
- リクエスト開始: "GET" 127.0.0.1:81/Home/About
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 について
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/About
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 について
- リクエスト開始: "GET" 127.0.0.1:81/Home/About
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 について
- リクエスト開始: "GET" 127.0.0.1:81/Home/About
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 について
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
- リクエスト開始: "GET" 127.0.0.1:81/Home/About
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 について
- リクエスト開始: "GET" 127.0.0.1:81/Home/Contact
- リクエスト終了: 127.0.0.1:81/Home/HTTP ステータス 200.0 の連絡先
ここでも、About ページと Contact ページを切り替えていたので、ログから、単一の Web ロール エンドポイント要求が、IIS アプリケーションを複数回呼び出す Web ロールになることがあることがわかります。次に、高レベルの Web ロール ログを検索して、なぜこれを行っているのかを突き止めます :)!