Ticket #36655

ログファイルオープンエラー

Open Date: 2016-09-21 22:08 Last Update: 2016-11-30 21:34

Reporter:
(Anonymous)
Owner:
(del#24082)
Type:
Status:
Closed
Component:
Priority:
5 - Medium
Severity:
5 - Medium
Resolution:
Fixed
File:
None
Vote
Score: 0
No votes
0.0% (0/0)
0.0% (0/0)

Details

■事象

次のTeraTermマクロを実行し、しばらくするとログファイルオープンエラーが発生する。

logclose
logopen 'e:\logs\teraterm\hoge.log' 0 1 0 0 0

:START
  logclose

  pause 1

  logopen 'e:\logs\teraterm\piyo.log' 0 1 0 0 0
  if result == 0 then
    logclose
  else
    messagebox 'Could not open piyo.log.' ''
    exit
  endif
  
  pause 1
  
  logopen 'e:\logs\teraterm\hoge.log' 0 1 0 0 0
  if result == 0 then
  else
    messagebox 'Could not open hoge.log.' ''

    logopen 'e:\logs\teraterm\piyopiyo.log' 0 1 0 0 0
    if result == 0 then
      logclose
    else
      messagebox 'Could not open piyopiyo.log.' ''
    endif

    logopen 'e:\logs\teraterm\hoge.log' 0 1 0 0 0
    if result == 0 then
      messagebox 'Now opened.' ''
    else
      messagebox 'Could not open hoge.log.' ''

      logopen 'e:\logs\teraterm\piyopiyopiyo.log' 0 1 0 0 0
      if result == 0 then
        logclose
      else
        messagebox 'Could not open piyopiyopiyo.log.' ''
      endif
    endif
    
    exit
    
  endif

goto START

■原因

filesys.cppのLogStartでDefferefWriteLogスレッドを開始すると、通常は、

DefferefWriteLogスレッドでキュー作成

CloseFileSyncでPostThreadMessage

と処理されるが、まれに

CloseFileSyncでPostThreadMessage

DefferefWriteLogスレッドでキュー作成

と処理順序が逆になる場合がある。

この時、CloseFileSyncはDefferefWriteLogスレッドが終了するまでWaitForSingleObjectで待ち、 DefferefWriteLogスレッドはGetMessageでメッセージを待つため、デッドロックに陥る。

Ticket History (3/19 Histories)

2016-09-21 22:08 Updated by: None
  • New Ticket "ログファイルオープンエラー" created
2016-09-23 20:36 Updated by: (del#24082)
Comment
報告どうもありがとうございます。
また、机上チェックもしてくださり、大変助かります。

本件は、当方が3年ほど前に作り込んだバグのようです。
次回リリースまでに修正します。
2016-09-23 22:43 Updated by: (del#24082)
  • Resolution Update from None to Fixed
Comment
(This comment has been deleted)
2016-09-25 15:41 Updated by: (del#24082)
Comment
本件を修正し、リポジトリにコミットしました。
下記に修正版アーカイブを格納しましたので、よろしければテスト願います。

http://ttssh2.osdn.jp/snapshot/snapshot-20160923.zip (with VS2005)
http://ttssh2.osdn.jp/snapshot/snapshot-20160923_vs2015.zip (with VS2015)

2016-09-26 20:39 Updated by: None
Comment

yutakaponさん、ご苦労様です。

報告した事象は、修正されていることを確認しました。

ただ、報告時のTeraTermマクロを30分ほど実行すると、TeraTermウィンドウの描画が正しく行われなくなります。 この問題を修正すると、別の問題が顕在化してくるようです。

また、LogStartに追加されたCreateEventですが、LogRotateには不要でしょうか?

2016-09-26 22:42 Updated by: (del#24082)
Comment

None への返信

報告した事象は、修正されていることを確認しました。 ただ、報告時のTeraTermマクロを30分ほど実行すると、TeraTermウィンドウの描画が正しく行われなくなります。 この問題を修正すると、別の問題が顕在化してくるようです。

当方環境では再現しなかったのですが、具体的にどのような現象でしょうか?

また、LogStartに追加されたCreateEventですが、LogRotateには不要でしょうか?

ご指摘ありがとうございます。修正しました。
http://ttssh2.osdn.jp/snapshot/snapshot-20160926.zip (with VS2005)
http://ttssh2.osdn.jp/snapshot/snapshot-20160926_vs2015.zip (with VS2015)

2016-09-27 21:42 Updated by: None
Comment

当方環境では再現しなかったのですが、具体的にどのような現象でしょうか?

TeraTermマクロを実行すると、TeraTermログウィンドウの描画とクローズがアニメーションのように表示されますが、30分ほど経つとTeraTermログウィンドウの描画がされなくなり、画面がチカチカする状態になります。 この時にTeraTermウィンドウを動かすと、ウィンドウタイトルバーやウィンドウフレームが描画されなくなります。30分で再現しないようでしたら、3時間ほど待てば再現すると思います。 何度か試したところ、この状態になると、かなりの割合でTeraTermは例外で停止します。

VS2005でr6496のソースコードをビルドして試したところ、CResourceExceptionが発生しているのが確認できましたが、発生要因は特定できませんでした。

報告した問題とは別の問題ですので、別チケットにしたほうがよければ、その旨お知らせください。

■環境

Windows 7 Enterprise with Service Pack 1 で、Windows Updateは最新の状態。

■例外詳細
  問題の署名:
  問題イベント名:	APPCRASH
  アプリケーション名:	ttermpro.exe
  アプリケーションのバージョン:	4.92.0.0
  アプリケーションのタイムスタンプ:	57e535c5
  障害モジュールの名前:	StackHash_0a9e
  障害モジュールのバージョン:	0.0.0.0
  障害モジュールのタイムスタンプ:	00000000
  例外コード:	c000001d
  例外オフセット:	0178ff4d
  OS バージョン:	6.1.7601.2.1.0.256.4
  ロケール ID:	1041
  追加情報 1:	0a9e
  追加情報 2:	0a9e372d3b4ad19135b953a78882e789
  追加情報 3:	0a9e
  追加情報 4:	0a9e372d3b4ad19135b953a78882e789
2016-09-27 21:51 Updated by: (del#24082)
Comment

報告どうもありがとうございます。 メモリリークしている可能性がありそうなので、机上調査してみます。

チケットのほうは現状のままでよいです。

2016-09-28 21:19 Updated by: (del#24082)
Comment
以下の環境と手順で再現試験を実施しましたが、再現しませんでした。
何か条件が足らないのかもしれません。

OS: Windows7(32bit)
Tera Term: 下記アーカイブ
http://ttssh2.osdn.jp/snapshot/snapshot-20160926_debug.zip

手順:
1. Tera Termを起動する(未接続状態)。
2. ■事象に記載されているマクロを実行する。
3. 3時間放置する。
2016-10-02 16:07 Updated by: None
Comment

yutakaponさん、ご苦労様です。

いろいろ調べてみたところ、Aeroが有効だと発生しないようです。デスクトップテーマをベーシックテーマに変更し、試してみてもらえますでしょうか。 ベーシックテーマならどれでも再現するはずですが、Windowsクラシックが分かりやすいと思います。

例外は発生したり、しなかったりで、発生条件はまだ掴めていません。

2016-10-03 21:14 Updated by: None
Comment

WindowsタスクマネージャのプロセスタブでUSERオブジェクト列とGDIオブジェクト列を追加し観察したところ、TeraTermマクロの実行でUDIオブジェクトとGDIオブジェクトが増加し続けていくのが確認できました。 GDIオブジェクトが10000に達すると(実際は9997〜9999で頭打ちになる)、TeraTermウィンドウの描画が正しく行われなくなります。

VS2005でのCResourceExceptionは、ホスト未接続状態でTeraTermマクロを実行しても発生せず(GDIオブジェクトは9997で頭打ち)、ホスト接続状態でTeraTermマクロを実行すると発生しました(GDIオブジェクトは9998又は9999で頭打ち)。

2016-10-03 23:00 Updated by: (del#24082)
Comment
調査ありがとうございます。だいぶ解析のヒントになってきました。

GDIViewというソフトで調べてみると、Fontオブジェクトがリークしていたので、r6501で修正しました。
http://www.nirsoft.net/utils/gdi_handles.html

しかし、それでもGDIViewの「All GDI」が増加していくばかりなので、まだどこかでリソースリークが
ありそうです。
引き続き調査します。
2016-10-04 23:38 Updated by: (del#24082)
Comment

どうやら、MFCのダイアログを使うと、メモリリークが発生するようです。
下記サイトに記載してあったWAを試してみましたが、特に効果なさそうです。

https://blogs.msdn.microsoft.com/jpvsblog/2013/08/29/mfc/
http://stackoverflow.com/questions/944033/is-this-a-memory-leak-in-mfc

2016-10-05 18:18 Updated by: None
Comment

yutakaponさん、ご苦労様です。

TeraTermが例外で停止する件ですが、ホスト未接続状態では発生せず、ホスト接続状態の時だけと判りました。つまり、VS2005でCResourceExceptionがキャッチされた時だけでした。

メモリリークの件は、ftdlg.cppのOnInitDialogでアイコンイメージをロードしており、このハンドルをPostNcDestroyで解放してやればリークが無くなりました。

	::PostMessage(GetSafeHwnd(),WM_SETICON,ICON_SMALL,
	              (LPARAM)LoadImage(AfxGetInstanceHandle(),
	                                MAKEINTRESOURCE(IDI_TTERM),
	                                IMAGE_ICON,16,16,fuLoad));
	::PostMessage(GetSafeHwnd(),WM_SETICON,ICON_BIG,
	              (LPARAM)LoadImage(AfxGetInstanceHandle(),
	                                MAKEINTRESOURCE(IDI_TTERM),
	                                IMAGE_ICON, 0, 0, fuLoad));

メモリリークは多そうですね。さっと見たところ、TTPMACROのstatdlg.cppでもFontオブジェクトを解放してませんでした。

2016-10-05 20:22 Updated by: (del#24082)
Comment

重ね重ね、調査どうもありがとうございます。

ftdlg.cppのメモリリークに関しては、r6504 で修正しました。
なお、Tera Term Pro 2.3(1998年)でも再現したので、オリジナルからある問題だったようです。

水平展開に関しては別途実施します。

2016-10-05 23:41 Updated by: (del#24082)
Comment

yutakapon への返信

水平展開に関しては別途実施します。

CreateFontIndirect()とLoadImage()をキーワードで調査したところ、メモリリークしている箇所は
散見されましたが、運用に影響を与えそうなところで、マクロのステータスボックスがありましたので、
r6506 で修正しました。
マクロで statusbox と closesbox を繰り返すと、リークが加速化できてしまうので。

他にもMessageBoxなども対象なのですが、人手操作がかならず入るので、実際影響を
与える可能性は低いかなと考えています。

2016-10-06 00:04 Updated by: None
Comment

yutakaponさん、ご苦労様です。

r6504のソースコードをビルドし、メモリリークが発生しないことを確認しました。 報告したTeraTermマクロを3時間ほど動かし、他に問題が出ないことも確認済みです。

r6506の修正についても、承知しました。

お忙しい中、ご対応いただき、どうもありがとうございました。

2016-10-06 00:30 Updated by: (del#24082)
Comment

いえいえ、こちらこそ恐縮です。

実際にデバッグしていただいたのは、貴殿で、当方ではありませんので、
本当に感謝しております。
なかなかソースコードまでチェックしてもらえるユーザ様はおりませんので。

今後ともよろしくお願いします。

2016-11-30 21:34 Updated by: (del#24082)
  • Status Update from Open to Closed
  • Ticket Close date is changed to 2016-11-30 21:34

Attachment File List

No attachments

Edit

You are not logged in. I you are not logged in, your comment will be treated as an anonymous post. » Login