C#のマルチスレッド処理で処理時間が落ちる問題

C#で、UIスレッド内で別スレッドを2つ以上起動するとUIスレッド上の処理時間が延びてしまう問題について質問です。

マルチスレッドを使用すると、UI上では別スレッドで処理が行われるため、並列処理を2つ以上呼び出してもUIスレッドのイベントの処理時間は
延びない想定でしたが、下記のコードを実行すると、イベント内の処理時間が20msecとか30msec以上延びることが時々あります。(0msecの時もある。)
この処理では、開始ボタン押下イベント(btnStart_Click)を実行すると、停止ボタン押下イベント(btn_Stop_Click)が実行されるまで
タイマーにセットした処理(ArrivedTimer)を2秒間隔で呼び出します。
ArrivedTimer中で呼ばれている関数(CalcCls.JikankakaruProc)は、処理時間が2.1秒程かかります。
ちなみに、ArrivedTimer関数内のt2のタスクの処理をコメントアウトすると、処理時間は0msecか1msecぐらいしか延びないです。

UIスレッド側の処理

C#
1using System;
2using System.Collections.Generic;
3using System.ComponentModel;
4using System.Data;
5using System.Diagnostics;
6using System.Drawing;
7using System.IO;
8using System.Linq;
9using System.Text;
10using System.Threading.Tasks;
11using System.Windows.Forms;
12using System.Timers;
13
14namespace Jikankakaru
15{
16    public partial class Form1 : Form
17    {
18        /// <summary>
19        /// タイマークラス
20        /// </summary>
21        private System.Timers.Timer timerProc;
22
23        public Form1()
24        {
25            InitializeComponent();
26
27            // 初期処理
28            InitData();
29        }
30
31        /// <summary>
32        /// 初期処理
33        /// </summary>
34        private void InitData()
35        {
36            // 1秒に1回
37            this.timerProc = new System.Timers.Timer();
38            // 間隔は1秒
39            this.timerProc.Interval = 2000;
40            // イベントセット
41            this.timerProc.Elapsed += ArrivedTimer;
42        }
43
44        #region ■デリゲート
45
46        /// <summary>
47        /// デリゲート
48        /// </summary>
49        /// <param name="str"></param>
50        private delegate void SetLabelDel(Label label, string str);
51
52        #endregion
53
54        #region ■デリゲート用関数
55
56        /// <summary>
57        /// デリゲート
58        /// </summary>
59        /// <param name="str"></param>
60        private void SetLabel(Label label, string str)
61        {
62            label.Text = str;
63        }
64        #endregion
65
66        /// <summary>
67        /// 処理開始
68        /// </summary>
69        /// <param name="sender"></param>
70        /// <param name="e"></param>
71        private void btnStart_Click(object sender, EventArgs e)
72        {
73            this.timerProc.Start();
74        }
75
76        /// <summary>
77        /// タイマー停止
78        /// </summary>
79        /// <param name="sender"></param>
80        /// <param name="e"></param>
81        private void btn_Stop_Click(object sender, EventArgs e)
82        {
83            this.timerProc.Stop();
84        }
85
86        /// <summary>
87        /// タイマーが来たときのイベント
88        /// </summary>
89        private void ArrivedTimer(object sender, ElapsedEventArgs e)
90        {
91            Stopwatch sw = new Stopwatch();
92
93            BeginInvoke(new SetLabelDel(SetLabel), this.lblState, "未完了");
94
95            // 冒頭の処理時間
96            sw.Start();
97
98            // 時間かかる処理
99            OutDll ans1 = new OutDll();
100            OutDll ans2 = new OutDll();
101
102            Task t1 = Task.Run(() => CalcCls.JikankakaruProc(ans1));
103            Task t2 = Task.Run(() => CalcCls.JikankakaruProc(ans2));
104
105            int a1 = CalcCls.GetData();
106            int a2 = CalcCls.GetData();
107
108            // 答え出力
109            BeginInvoke(new SetLabelDel(SetLabel), this.lblAns1, a1.ToString());
110            BeginInvoke(new SetLabelDel(SetLabel), this.lblAns2, a2.ToString());
111            BeginInvoke(new SetLabelDel(SetLabel), this.lblState, "完了");
112
113            sw.Stop();
114            long data = sw.ElapsedMilliseconds;
115            sw.Reset();
116
117            // 処理時間出力
118            BeginInvoke(new SetLabelDel(SetLabel), this.lblProctime, data.ToString());
119
120            // 処理時間ファイル出力
121            WriteFile(data.ToString());
122        }
123
124        /// <summary>
125        /// ファイル出力
126        /// </summary>
127        private void WriteFile(string str)
128        {
129            // 改行追加
130            str += Environment.NewLine;
131
132            // 追加形式
133            string filePath = this.txtFolder.Text + this.txtFile.Text + ".csv";
134
135            Encoding enc = System.Text.Encoding.GetEncoding("shift_jis");
136
137            // ファイル書き込み
138            File.AppendAllText(filePath, str, enc);
139        }
140    }
141}
142

タイマーイベント内で呼び出されている関数のクラス

C#
1/// <summary>
2    /// 計算用クラス
3    /// </summary>
4    public static class CalcCls
5    {
6        /// <summary>
7        /// 共通のデータ
8        /// </summary>
9        static private int commonData;
10
11        /// <summary>
12        /// 時間かかる処理
13        /// </summary>
14        public static void JikankakaruProc(OutDll ansData)
15        {
16            for (int i = 0; i < 1000000000; i++)
17            {
18                double data = 0;
19                data /= 100000;
20            }
21
22            // 共通データに乱数設定
23            System.Random r = new System.Random(1000);
24            commonData = r.Next(100);
25            ansData.FAns = commonData;
26        }
27
28        /// <summary>
29        /// データ返す
30        /// </summary>
31        /// <returns></returns>
32        public static int GetData()
33        {
34            return commonData;
35        }
36    }

実際の現場で使用するコードでは、100msec周期でカメラ画像取得イベントが呼び出されるため、20～30msecの遅れでもかなり致命的になります。
呼び出すタスクを2つにすると処理時間が延びてしまう原因が分かる方がおられましたら、宜しくお願い致します。

行動規範の内容に同意します

回答1件

ベストアンサー

こんにちは。

手元でやってみましたが、そのような現象は起きませんでした。
プロジェクトを作って、Form1.csをコピペし、その中にOutDllクラスを定義、CalcClsクラスをコピペ、2つのボタンと4つのラベルを作り、ボタンのclickイベントを設定しました。WriteFile()関連処理はコメントアウトしてます。
Debug.WriteLine()をArrivedTimerの最初と最後にいれて確認しました。

startを押すと2秒毎にArrivedTimerが呼び出され、この関数は最初の１回目を除き、0mSecで終了しています。正常に動作しているようです。

ところで、JikankakaruProc処理終了を待たずにcommonDataを表示しているので、最初の１回目を除き、結果は全て同じ値ですし、一瞬でBeginInvoke(new SetLabelDel(SetLabel), this.lblState, "完了");が実行されるので、常に「完了」と表示されています。

ざっと見たたところ、３つの問題点があります。（結果が出る前に結果を表示、Randomを毎回初期化、commonDataを複数のスレッドから排他制御無しにアクセス）

投稿2019/05/26 04:30

Chironian

総合スコア23272

TOMO6181

2019/05/26 11:57

御回答ありがとうございます。処理時間が延びるタイミングは割とランダムで、数分待ってからでないと出てこない場合もあります。コードの問題については、ご指摘通りです。現場のコードでは、処理が終わるまで結果を表示しないようにしていたり、スレッドによって別データをもつようにしているのですが、今回は処理時間が延びる再現テストのために簡略化し過ぎてました。

YAmaGNZ

2019/05/26 12:40

単なる思い付きですが、GCが影響していたりはないですかね？

Chironian

2019/05/26 14:02

なるほど、数分待たないと出ないようでしたら、GCの可能性ありますね。 GCはコントロールがかなり難しいです。 https://docs.microsoft.com/ja-jp/dotnet/standard/garbage-collection/gc https://docs.microsoft.com/ja-jp/dotnet/standard/garbage-collection/fundamentals https://docs.microsoft.com/ja-jp/dotnet/standard/garbage-collection/performance しかし、そもそもWindows自体リアルタイムOSではないので、稀に発生する応答遅れが致命的になる分野への応用はナンセンスです。何らかのハードウェアを追加するなどして稀に発生する1～2秒程度の遅れを許容できるようなシステムにしないと厳しいだろうと思います。ただし、稀な応答遅れの発生を許容できるなら、少なくともC++を使ったWindows 7で、数字は忘れたのですがほとんどの場合に1mSec未満の応答性能を確認して関心したことがあります。（平均処理時間で1mSecを問題にするような案件でした。ごく稀であれば数秒遅れても問題ないシステムでしたが、数秒も遅れたという報告を受けたことはないです。） C#で同等の性能を出すには、ガベージ・コレクションをうまくコントロールする必要があると思います。

pepperleaf

2019/05/26 15:45

C# で幾つか(把握してない^_;)スレッドを動かしてますが、秒オーダーの問題は発生して無いですね。一応、カメラ画像の取得を可能な限り高速で行ってます。まあ、最高速が出てないとの指摘はありますが、一瞬のもたつき程度。なんか別の問題無いでしょうか?

Chironian

2019/05/26 16:22

この問題は２つあります。 1)WindowsはリアルタイムOSではない（＝応答性能は保証されない）なので、1～2秒の応答遅れが致命的（機械が壊れるのはもちろん、データ・ロストが許容範囲を越えるなど）にはならないように設計するべきと思います。例えばプチフリーズは結構有名な話と思います。なお、保証がないということは理論的には数分とか数時間、数日、数年もありえるでしょうが、それは流石に非現実的でしょう。（その結果、高価な機械が壊れたり人が死んだりするようならアウトですが。） 2)ガベージコレクションによる停止が不意に発生する上記のコメント内の最後のリンク先にはGCによる停止パターンがいくつか記載されてています。数mSec～数100mSecの停止が発生する可能性があるようです。そうそう、スレッド・プールから次々とスレッドを起動すると、ある一定数を越えるとTask起動に大きな遅延が発生します。https://oita.oika.me/2016/02/18/task-and-threadpool/ これは私も経験したことがあります。このような仕様があることに驚いたものです。数10mSecではなく、数100mSec以上の遅延なので今回のケースには当たらないと思いますが。

TOMO6181

2019/05/28 15:26

御回答下さりありがとうございます。御指摘の中にありますように、GCが影響していたようです。現場で実際に使用しているコードでは、何百万個の要素をもった配列を定義していて、メモリエラーをよく起こしていたため、GC.Collect()を入れたりしていたのですが、ここで処理時間がかかったりかからなかったりするところがありました。また、それとは別に、タイマーイベント内でラベルやピクチャーボックス等の操作や参照が多く、GUIスレッド上で待ちが発生していたのも原因でした。これも処理時間がかかったりかからなかったりするので見落としていました。そういった個所をコメントアウトすると、イベントの処理時間が遅れることがなくなりました。メモリの節約等コードはまだ整理しないといけないですが、解決できそうです。 Chironianさん、詳しい説明をありがとうございました。

行動規範の内容に同意します