Windows Azure のトラブルシュート デプロイ編(小ネタ)

Windows Azure あるある:

せっかくデプロイしたのに「何かがおかしくて」BusyとAbortedを繰り返す

とまぁこういう状況を何とかデバッグするための小ネタです。
厳密ではないですが、ある程度の切り分けはできるんじゃないかな~的な。

さてWindows AzureでデプロイしたロールがBusy・Abortedを繰り返したりするときはどんな場合でしょうか。

十中八九、StartupTasksでこけてるケースだと思われますキリッ(経験談

どんなプロセスで起動してるかはこちらのWindows Azure Roleアーキテクチャ(蒼の王座)を参照して頂くとして、だいたいInitializeが終わった後Busyで止まるのはStartupTasksですね。
それ以外は決まりきった処理(カスタムな処理がない)のでこけるケースはマレなはず。(OnStartでこけたりするのはあるか)

で、一般的にStartup TasksはCMDファイルだったりでデバッグ面倒ですね。あとローカルではテストしにくいケースが大半だと思います。(たとえばWebPIを使ったインストールや、Azure上でしか使えない環境変数などを利用したりとか)

動作を見たくても、PaaSであるWindows Azure上のインスタンス起動時は見れません。
RDPを設定してもRDPが起動してなければ意味がないですね。(※指定したタスクがBackground等で動作する場合はこけてもRDPが起動して接続できたりする可能性はありますが)

じゃぁどうするのか?

RDPが起動してればOKなわけですから、Upgradeが出来るように同じエンドポイントで構成されたダミーの空っぽなサービスパッケージをデプロイして、RDPにつないでおいてから調べたい対象のサービスパッケージをUpgradeでデプロイしましょう。

基本的にRDPが切断されるのは一瞬だけ(RoleRootの切り替わり時だけ)なので、うまく行けばRDP接続を継続したまま起動時の処理を追うことができると思います。UpgradeなのでちゃんとStartupTasksも処理されますしね。

あとはWindows Azureデプロイ失敗時にSysinternalのDebugViewで調査等を参考にデバッグください。

え、ログファイルを追いたい?Tailすればいいんじゃないですかね。

あとUpgrade時にRDPが切断されて結局つながらないってケースもあるのでその場合は諦めましょう。一度ログオンした状態になってるし厳密には初期起動時と同じじゃないので万能じゃないですけどね(

 

おまけ

エントリポイント内のログとか見る場合、AzureらしくDiagnostics設定してもいいんですが転送されなかったり、そこが失敗してると意味ないですね。。
直接Azure Storageに出力してもいいんですが System.Diagnostics.DefaultTraceListener 使ってOutputDebugString APIで出力するようにしておけば上述の方法でDBMon.exeやDebugViewerで拾えますね。

まぁ適材適所ということで…

ちなみにDebugViewで取れたUpgrade時の情報のサンプルです。(※StartupTasksを仕込み忘れたのであまり深い意味はない)

00000536	249.87687683	[1044] [00000009] [05/28/2011 14:52:56.82] Goal state 2 received. 	
00000537	249.87701416	[1044] [00000009] [05/28/2011 14:52:56.82] Goal state being updated. 	
00000538	249.92436218	[1044] [00000009] [05/28/2011 14:52:56.87] Deleting all user accounts. 	
00000539	249.92620850	[1044] [00000009] [05/28/2011 14:52:56.87] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 is being updated. 	
00000540	249.92637634	[1044] [00000009] [05/28/2011 14:52:56.87] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 has goal state Started. 	
00000541	250.03047180	[1044] [00000003] [05/28/2011 14:52:56.96] Goal state execution started for role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0. 	
00000542	250.03065491	[1044] [00000003] [05/28/2011 14:52:56.96] Driving role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 to goal state Started from current state Started. 	
00000543	250.03482056	[1044] [00000003] [05/28/2011 14:52:56.97] New source package detected for role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0. Role will be restarted. 	
00000544	250.03492737	[1044] [00000003] [05/28/2011 14:52:56.97] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 could not be updated. It will be restarted. 	
00000545	250.03778076	[1044] [00000003] [05/28/2011 14:52:56.97] Using default role stop timeout of 300000 milliseconds. 	
00000546	250.40103149	[2740] Microsoft.WindowsAzure.ServiceRuntime Information: 205 : 	
00000547	250.40112305	[2740] Role entrypoint . CALLING   OnStop() 	
00000548	250.40139771	[2740] Microsoft.WindowsAzure.ServiceRuntime Information: 206 : 	
00000549	250.40147400	[2740] Role entrypoint . COMPLETED OnStop() 	
00000550	252.01646423	[1044] [00000003] [05/28/2011 14:52:58.96] Sending new config file: 9bb8199d1d2f40e59c19fe84767fd9db.9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0.2.xml. 	
00000551	252.05427551	[1044] Invalid parameter passed to C runtime function.	
00000552	252.05436707	[1044] Invalid parameter passed to C runtime function.	
00000553	253.57112122	[1044] Invalid parameter passed to C runtime function.	
00000554	253.57127380	[1044] Invalid parameter passed to C runtime function.	
00000555	254.92184448	[1044] [00000009] [05/28/2011 14:53:01.86] WaAppAgent Heartbeat. 	
00000556	259.29455566	[1044] [00000009] [05/28/2011 14:53:06.22] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 is reporting state NotReady with sub-status Starting and details Initializing role.... 	
00000557	259.37777710	[2096] Invalid parameter passed to C runtime function.	
00000558	259.37780762	[2096] Invalid parameter passed to C runtime function.	
00000559	260.99954224	[2940] Invalid parameter passed to C runtime function.	
00000560	260.99960327	[2940] Invalid parameter passed to C runtime function.	
00000561	261.00262451	[1928] Invalid parameter passed to C runtime function.	
00000562	261.00265503	[1928] Invalid parameter passed to C runtime function.	
00000563	271.35952759	[2180] Invalid parameter passed to C runtime function.	
00000564	271.36846924	[2180] Invalid parameter passed to C runtime function.	
00000565	271.37487793	[1044] [00000003] [05/28/2011 14:53:11.32] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 has current state Busy, desired state Started, and goal state execution status StartInProgress. 	
00000566	271.37899780	[2256] Invalid parameter passed to C runtime function.	
00000567	271.37930298	[2256] Invalid parameter passed to C runtime function.	
00000568	271.38226318	[1044] [00000009] [05/28/2011 14:53:12.08] WaAppAgent Heartbeat. 	
00000569	271.38275146	[1044] [00000009] [05/28/2011 14:53:18.30] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 is reporting state NotReady with sub-status Starting and details Waiting for role to start.... 	
00000570	272.89532471	[1852] Invalid parameter passed to C runtime function.	
00000571	272.89538574	[1852] Invalid parameter passed to C runtime function.	
00000572	273.45935059	[2640] Invalid parameter passed to C runtime function.	
00000573	273.45938110	[2640] Invalid parameter passed to C runtime function.	
00000574	273.63766479	[2344] 	
00000575	273.63766479	[2344] *** HR originated: -2147024774	
00000576	273.63766479	[2344] ***   Source File: d:\iso_whid\amd64fre\base\isolation\com\copyout.cpp, line 1302	
00000577	273.63766479	[2344] 	


~中略~

00001015	274.04110718	[2344] *** HR propagated: -2147024774	
00001016	274.04110718	[2344] ***   Source File: d:\iso_whid\amd64fre\base\isolation\com\enumidentityattribute.cpp, line 144	
00001017	274.04110718	[2344] 	
00001018	275.54354858	[2344] Invalid parameter passed to C runtime function.	
00001019	275.54360962	[2344] Invalid parameter passed to C runtime function.	
00001020	275.84848022	[2344] Microsoft.WindowsAzure.ServiceRuntime Information: 200 : 	
00001021	275.85186768	[2344] Role entrypoint . CALLING   OnStart() 	
00001022	275.85708618	[2344] Microsoft.WindowsAzure.ServiceRuntime Information: 202 : 	
00001023	275.85714722	[2344] Role entrypoint . COMPLETED OnStart() 	
00001024	275.86169434	[2344] Microsoft.WindowsAzure.ServiceRuntime Information: 203 : 	
00001025	275.86172485	[2344] Role entrypoint . CALLING   Run() 	
00001026	276.37518311	[1044] [00000003] [05/28/2011 14:53:23.30] Role 9bb8199d1d2f40e59c19fe84767fd9db.Mvc3ApplicationSample_IN_0 has current state Starting, desired state Started, and goal state execution status StartInProgress. 	
00001027	276.70333862	[1044] [00000009] [05/28/2011 14:53:23.63] WaAppAgent Heartbeat. 	

広告

コメントを残す

以下に詳細を記入するか、アイコンをクリックしてログインしてください。

WordPress.com ロゴ

WordPress.com アカウントを使ってコメントしています。 ログアウト / 変更 )

Twitter 画像

Twitter アカウントを使ってコメントしています。 ログアウト / 変更 )

Facebook の写真

Facebook アカウントを使ってコメントしています。 ログアウト / 変更 )

Google+ フォト

Google+ アカウントを使ってコメントしています。 ログアウト / 変更 )

%s と連携中