ファイナライザ内でインスタンス生成

Question

下のコードを実行すると、
１．毎回異なった回数画面に表示される
２．スレッドIDはすべて同じ（ファイナライザが実行されるスレッドですよね？）
この動作の仕組みを教えていただけないでしょうか？
（基礎がわかってない？？マズイ！とおもったので）

宜しくお願いします。

using System;

using System.Threading;



namespace ConsoleApplication2

{

	class Program

	{

		static void Main(string[] args)

		{

			new Test();

		}

	}



	class Test

	{

		private static int count = 0;

		private Test t;

		~Test()

		{

			Console.WriteLine("finalized...(count : {0}, id : {1})", count++, Thread.CurrentThread.ManagedThreadId);

			t = new Test();

		}

	}

}

ステップ実行すると、
１．Main(){
２．new Test();
３．}
４．ファイナライザをグルグル・・・
５．無限ループを期待したが、不定な回数実行されて終了

Answer 1

ファイナライザはC++のデストラクタと違って実行が保証されていません。
ファイナライザの実行スレッドも保証されていません。

Main()の「new Test();」が次のステートメントに進む際にファイナライザが実行されているわけではなく、Main()を抜けプロセスが終了しようとしている際にファイナライザの実行が開始されています。
C++のデストラクタのようにスコープを抜ける際にメソッドを実行したい場合は、IDisposableを実装しusing構文を使いましょう。

.NET Frameworkでは、パフォーマンスの低下を招く場合があるためファイナライザは必要なときだけ使用してください 、だそうです。

Answer 2

「The Root of .NET Framework 」(ISBN-10: 4797350199 )を読んでて、
Finalization Queue や F-reachable Queue の存在を知りました。

それでふと、
ファイナライザ内で自分自身のインスタンスを生成したら、
それのファイナライザが実行されたときに、またインスタンスを生成して、
キューから消えずに無限ループになると予想して実行してみました。
（だめでした・・・けど、勉強になりました！）

>.NET Frameworkでは、パフォーマンスの低下を招く場合があるためファイナライザは必要なときだけ使用してください 、だそうです。

リンク、ありがとうございました。
もっと注意深く読まないといけませんね。

Answer 3

「実行は保証されていません」と勝手なことを書きましたが、実はそのような記述を見つけているわけではなく、体感的に、だったりします。
で、もうちょっと考えてみました。

今回の場合、Main()は既に終了済みで、プロセスそのものを終了させようとしています。
Console関連のオブジェクトやThread.CurrentThreadオブジェクトも順次解放されていきます。
ある時点からはコンソールに出力すること自体ができなくなるでしょう。
その際、例外が発生し、ファイナライザの実行が中断されるのではないでしょうか。

ま、こういったことは観測するのも難しくよくわかりません。

Answer 4

「実行は保証されていません」と勝手なことを書きましたが、実はそのような記述を見つけているわけではなく、体感的に、だったりします。

MSDN マガジンの記事に「ファイナライザの実行に一定のタイムアウトを設定」という記載はありますね。
http://msdn.microsoft.com/ja-jp/magazine/cc163298.aspx#S9

Console関連のオブジェクトやThread.CurrentThreadオブジェクトも順次解放されていきます。
ある時点からはコンソールに出力すること自体ができなくなるでしょう。
その際、例外が発生し、ファイナライザの実行が中断されるのではないでしょうか。

その仮定で行くと、Console.WriteLine とか Thread.CurrentThread にアクセスせず、単純に new Test(); だけをするファイナライザを作れば、無限に終了しないことになります。
しかしながら、そういったファイナライザにしても、ある程度の時間、実行した後に終了しますので、その仮定は誤りか不足していることが予想できます。

---

解決した場合は、参考になった返信に「回答としてマーク」のボタンを利用して、回答に設定しましょう（複数に設定できます）。

Answer 5

頂いたリンク先に「エスカレーションポリシー」というのが書いてあったので、
「escalation policy」 で検索してみました。

http://msdn.microsoft.com/en-us/magazine/cc163567.aspx
上記のURLを見つけ、ページ内で「escalation policy」を検索して
読んでみたのですが（←ちょっとだけ）、
「Figure 6 CLR Configuration Manager Interfaces」あたりの文章で
stack overflows の言葉が出てきているので、
単純に ファイナライザ スレッド上で、スタック オーバーフローが発生しているのでしょうか？
（自分の書いたソースは、Finalizeメソッドで再帰ループしているんでしょうか？）

逆アセンブルしてみると、
ファイナライザ内でのステップ実行がおかしいと感じました。
理由：
mov なのに、いきなり別のステップへジャンプしました。

		~Test()
		{
00000000  push        ebp  
00000001  mov         ebp,esp 
00000003  push        edi  
00000004  push        esi  
00000005  push        ebx  
00000006  sub         esp,58h 
00000009  xor         eax,eax 
0000000b  mov         dword ptr [ebp-10h],eax 
0000000e  xor         eax,eax 
00000010  mov         dword ptr [ebp-1Ch],eax 
00000013  mov         dword ptr [ebp-3Ch],ecx 
00000016  cmp         dword ptr ds:[00289200h],0 
0000001d  je          00000024 
0000001f  call        70619181 
00000024  nop              
			Console.WriteLine("finalized...(count : {0}, id : {1})", count++, Thread.CurrentThread.ManagedThreadId);
00000025  mov         eax,dword ptr ds:[002893D4h] 
0000002a  mov         dword ptr [ebp-40h],eax 
0000002d  mov         eax,dword ptr [ebp-40h] 
00000030  inc         eax  
00000031  mov         dword ptr ds:[002893D4h],eax 
00000036  mov         ecx,70672DA0h 
0000003b  call        FEC309EC 
00000040  mov         dword ptr [ebp-44h],eax 
00000043  mov         eax,dword ptr ds:[02CC2088h] 
00000049  mov         dword ptr [ebp-48h],eax 
0000004c  mov         eax,dword ptr [ebp-44h] 
0000004f  mov         edx,dword ptr [ebp-40h] 
00000052  mov         dword ptr [eax+4],edx 
00000055  mov         eax,dword ptr [ebp-44h] 
00000058  mov         dword ptr [ebp-4Ch],eax 
0000005b  call        6EFE3400 
00000060  mov         dword ptr [ebp-50h],eax 
00000063  mov         ecx,dword ptr [ebp-50h] 
00000066  cmp         dword ptr [ecx],ecx 
00000068  call        6EFD2070 
0000006d  mov         dword ptr [ebp-54h],eax 
00000070  mov         ecx,70672DA0h 
00000075  call        FEC309EC 
0000007a  mov         dword ptr [ebp-58h],eax 
0000007d  mov         eax,dword ptr [ebp-48h] 
00000080  mov         dword ptr [ebp-60h],eax 
00000083  mov         eax,dword ptr [ebp-4Ch] 
00000086  mov         dword ptr [ebp-64h],eax 
00000089  mov         eax,dword ptr [ebp-58h] 
0000008c  mov         edx,dword ptr [ebp-54h] 
0000008f  mov         dword ptr [eax+4],edx 
00000092  mov         eax,dword ptr [ebp-58h] 
00000095  push        eax  
00000096  mov         ecx,dword ptr [ebp-60h] 
00000099  mov         edx,dword ptr [ebp-64h] 
0000009c  call        6F492340 
000000a1  nop              
			t = new Test();
000000a2  mov         ecx,289E74h 
000000a7  call        703CAFC4 
000000ac  mov         dword ptr [ebp-5Ch],eax 
000000af  mov         ecx,dword ptr [ebp-5Ch] 
000000b2  call        FEC4AF70 
000000b7  mov         edx,dword ptr [ebp-3Ch] 
000000ba  mov         eax,dword ptr [ebp-5Ch] 
000000bd  lea         edx,[edx+4] 
000000c0  call        703C1780 
		}

アドレス
１．00000024
２．00000025
３．000000a2
４．000000c5
1->2->3->4->1->2->・・・と繰り返されました。

それだけで、変かな？としか思えませんでした。

もしかして、まったく関係ないでしょうか？

Answer 6

http://msdn.microsoft.com/en-us/magazine/cc163567.aspx
上記のURLを見つけ、ページ内で「escalation policy」を検索して
読んでみたのですが（←ちょっとだけ）、
「Figure 6 CLR Configuration Manager Interfaces」あたりの文章で
stack overflows の言葉が出てきているので、
単純に ファイナライザ スレッド上で、スタック オーバーフローが発生しているのでしょうか？
（自分の書いたソースは、Finalizeメソッドで再帰ループしているんでしょうか？）

今回のケースにおいて、再帰はしていないはずです。また、escalation policy の話が絡むほどの深いところや致命的なところではないでしょう。
単純にタイムアウト（時間切れ）だと思われます。

アドレス
１．00000024
２．00000025
３．000000a2
４．000000c5
1->2->3->4->1->2->・・・と繰り返されました。

それだけで、変かな？としか思えませんでした。
もしかして、まったく関係ないでしょうか？

その動きは、マネージコードでのステップ実行になっていますね、原因までは分かりませんが。
手元で逆アセンブラのウィンドウで　F10 キーでステップオーバーで見てみましたが、もう少し細かい単位で実行できているようです。

---

解決した場合は、参考になった返信に「回答としてマーク」のボタンを利用して、回答に設定しましょう（複数に設定できます）。

Answer 7

この件で、たくさんの新発見がありました！ 佐祐理さん、Azuleanさん ありがとうございました。

Answer 8

プロセス終了時のファイナライザ実行にはタイムアウトがあります。
確か1ファイナライズメソッドあたり2秒だったかくらいと、ファイナライザ全部で40秒とかだったと思います。
確か「プログラミング .NET Framework」辺りに記述があったと思うのですが失念しました。

もっともそれ以外の何らかの理由で終わってしまう可能性も別にあるかもしれませんが。

Answer 9

やっぱりタイムアウトはありますか。そんな予感はしてました。

Answer 10

プロセス終了時のファイナライザ実行にはタイムアウトがあります。
確か1ファイナライズメソッドあたり2秒だったかくらいと、ファイナライザ全部で40秒とかだったと思います。
確か「プログラミング .NET Framework」辺りに記述があったと思うのですが失念しました。

もっともそれ以外の何らかの理由で終わってしまう可能性も別にあるかもしれませんが。

ありがとうございます。
40秒未満だったので、別の問題なんでしょうか。

http://blogs.microsoft.co.il/blogs/sasha/archive/2008/04/26/don-t-blindly-count-on-a-finalizer.aspx
上記のURLに、それについての記述がありました。

---------翻訳結果-------
特定のシナリオでは、時間に制限を課して、これらのファイナライザに割り当てられる。個々のファイナライザを実行するため、2秒、およびすべてのファイナライザが最大40秒になる組み合わせを取得します。だから、何をすべきかに関係なく、あなたのファイナライズ作業を2秒以上の場合、またはすべてのオブジェクトの組み合わせのファイナライズ作業以上、40秒はかかる、いくつかのファイナライザを実行し、保証されないいくつかの他の途中で中断されることがあります。
------------------------

さらに
http://blogs.microsoft.co.il/blogs/sasha/archive/2008/08/27/debugging-shutdown-finalization-timeout.aspx
ここに、「HKLM\SOFTWARE\Microsoft\.NETFramework」内にDWORDの「BreakOnFinalizeTimeout」を追加（値は1）すると「デバッグできるようになる」・・・？

早速実行してみました。
「ConsoleApplication2でユーザ定義ブレークポイントが見つかりました」とメッセージが表示されました。
どうやってデバッグするんでしょう・・・？？？


こういった仕組みが詳しく乗っている書籍は
「プログラミング .NET Framework」以外にもあるんでしょうか？（和書・洋書）


(http://blogs.ugidotnet.org/adrian/archive/2005/07/18/23787.aspx)
(ここで同じようなコードを書いてる人がいました。翻訳して読んでみます)

Answer 11

さらに
http://blogs.microsoft.co.il/blogs/sasha/archive/2008/08/27/debugging-shutdown-finalization-timeout.aspx
ここに、「HKLM\SOFTWARE\Microsoft\.NETFramework」内にDWORDの「BreakOnFinalizeTimeout」を追加（値は1）すると「デバッグできるようになる」・・・？

早速実行してみました。
「ConsoleApplication2でユーザ定義ブレークポイントが見つかりました」とメッセージが表示されました。
どうやってデバッグするんでしょう・・・？？？

今、知りたかったことは「ファイナライザのタイムアウトを迎えているかどうか」ですよね？
その表示でブレークしているということ、レジストリの値によってブレークする・しないが変化することは、タイムアウトが発生していることを証明していると思います。
そこから”デバッグする”のは、何が目的でしょうか？

なお、手元の環境では確かに 40 秒未満で発生していること、コールスタックで下記の 2 行近辺でブレークしていることは確認しています。

> ntdll.dll!_DbgBreakPoint@0()  
  mscorwks.dll!WKS::GCHeap::FinalizerThreadWatchDogHelper()  + 0xa048f バイト 

---

解決した場合は、参考になった返信に「回答としてマーク」のボタンを利用して、回答に設定しましょう（複数に設定できます）。

Answer 12

今、知りたかったことは「ファイナライザのタイムアウトを迎えているかどうか」ですよね？
その表示でブレークしているということ、レジストリの値によってブレークする・しないが変化することは、タイムアウトが発生していることを証明していると思います。
そこから”デバッグする”のは、何が目的でしょうか？

なお、手元の環境では確かに 40 秒未満で発生していること、コールスタックで下記の 2 行近辺でブレークしていることは確認しています。

> ntdll.dll!_DbgBreakPoint@0()  
  mscorwks.dll!WKS::GCHeap::FinalizerThreadWatchDogHelper()  + 0xa048f バイト 

Azuleanさん、ありがとうございます！
そうですね、BreakOnFinalizeTimeout の名前からして「タイムアウト時にブレーク」ですよね。

先ほどSSCLI2.0で確認したらいろんなのが出てきて、ちょっと混乱してます。

------------------------------------------------------------------------------------------------------- 
<mscoree.h>
列挙体 EClrOperation 中に 
OPR_ProcessExit : 5 
FinalizerRun : 6 
MaxClrOperation : 7 
------------------------------------------------------------------------------------------------------- 

<eepolicy.h>
DWORD EEPolicy::GetTimeout(EClrOperation operation)
{
  ...
  return m_Timeout[operation];
}
------------------------------------------------------------------------------------------------------- 
<eepolicy.cpp>
EEPolicy::EEPolicy ()
{
  ...
  for (n = 0; n < MaxClrOperation; n++)
  {
    m_Timeout[n] = INFINITE;  // EEPolicy::SetTimeout[AndAction]()が呼ばれない限り -1と予想
    ...
  }
  m_Timeout[OPR_ProcessExit] = 40000; // 40s
 ...
}
------------------------------------------------------------------------------------------------------- 
<gcee.cpp>
#define FINALIZER_TOTAL_WAIT 2000 // 2s
static BOOL s_fRaiseExitProcessEvent = FALSE;
static ULONGLONG ShutdownEnd;

BOOL GCHeap::FinalizerThreadWatchDog()
{
  ...
  s_fRaiseExitProcessEvent = TRUE;
  fTimeOut = FinalizerThreadWatchDogHelper();
  s_fRaiseExitProcessEvent = FALSE;
  ...
}

BOOL GCHeap::FinalizerThreadWatchDogHelper()
{
  ...
  // GetTimeout ＝＞ OPR_FinalizerRun : 6, return : -1(SetTimeoutで変更されていなければ)

  DWORD totalWaitTimeout = GetEEPolicy()->GetTimeout(OPR_FinalizerRun);  
  if (totalWaitTimeout == (DWORD)-1)
  {
    totalWaitTimeout = FINALIZER_TOTAL_WAIT; // totalWaitTimeou <- 2s
  }

  // GCHeap::FinalizerThreadWatchDog()の中で呼ばれれば、必ずtrue
  if (s_fRaiseExitProcessEvent)
  {
    DWORD tmp = maxTotalWait/20;  // Normally we assume 2 seconds timeout if total timeout is 40 seconds.
    if (tmp > totalWaitTimeout)
    {
        totalWaitTimeout = tmp;
    }
    ...
  }
 ...
} 
------------------------------------------------------------------------------------------------------- 

Normally we assume 2 seconds timeout if total timeout is 40 seconds.
↓　翻訳結果
合計タイムアウトが40秒、通常は2秒のタイムアウトと仮定します。



ではなぜ、40秒未満でタイムアウトになるのか。
しかし、「プロジェクトのプロパティ」->「デバッグ」->「アンマネージ コード デバッグを有効にする」のチェックを外すと、
何分経ってもコンソールに出力され続け、終了されません。

１．40秒未満でタイムアウトになる原因
２．40秒を超えても終了しない原因

業務で困っているわけではなく、単に興味をもっただけなのですが
どうしても気になります！

知っても無意味な気がしますけど・・・ご存知の方、教えていただけないでしょうか？
よろしくお願いします。