トップ回答者
快適な動作APの作成方法(物理メモリ使用量とハードフォールト)

質問
-
快適な動作APの作成方法(物理メモリ使用量とハードフォールト)
現在VB.NET(vb2008express)にて開発を行っております。
PCの物理メモリは2G搭載。OSは、VISTA(32bit)
OS起動時リソースモニタとタスクマネージャの状態は以下のとうり
タスクマネージャ・パフォーマンス情報から
キャッシュ済み 1447 空きメモリ 58
ページファイル 1133M/4330M
リソースモニタ情報から
メモリ ハードフォールト/分 0 (常に0)前提条件
機能的には、3画面あり、A画面からB画面を表示しさらにB画面からC画面を表示
します。
A画面では対象のファイルを読み込みその情報を派生した結果をB画面へ表示します。
このとき派生情報と読み込み情報は全てメモリに格納されている状態とします。
C画面は以前変更した内容が表示されその情報はCSVで格納されておりC画面に一覧
(CSV形式で格納された一覧情報)を選択し更新内容をまた別のCSV形式のデータから
読み込み同じC画面へ詳細情報として表示します。
C画面の詳細情報を選択し反映ボタンをクリックするとその内容がB画面へ反映する仕
様となっています。このような仕様で現在二つのパターンで試験を行いメモリ使用状況を調査しました。
結果以下のようになります。1.パターン1
A画面で対象データ150件程度のデータを取り込む。
B画面で生成されたデータは、380件程度に派生される。
(B画面では、派生前データ150件と派生後データ380件
のデータがメモリに保持されている)
C画面操作を実施すると快適に動作する。
タスクマネージャ・パフォーマンス情報から
キャッシュ済み 1245 空きメモリ 14
ページファイル 1411M/4330M
リソースモニタ情報から
メモリ ハードフォールト/分 0 (常に0)2.パターン2
A画面で対象データ123000件程度のデータを取り込む。
B画面で生成されたデータは、175000件程度に派生される。
(B画面では、派生前データ123000件と派生後データ17
5000件のデータがメモリに保持されている)
C画面操作を実施するとレスポンス時間に約4秒かかる。タスクマネージャ・パフォーマンス情報から
キャッシュ済み 1030 空きメモリ 59
ページファイル 1595M/4330M
リソースモニタ情報から
メモリ ハードフォールト /分 1~3補足:B画面には編集機能が搭載されており、派生したデータについて一度に大量のデ
ータを生成し追加することができるため、派生分だけで数十万件のデータをメモリに常駐
することになることが推測される。
分析内容:パターン1及びパターン2のC画面で対象にしているデータは同一のものなので物理メ
モリ上でC画面機能が動作していると仮定するならば同じようにサクサクと動作すると思
いますが、現実には、レスポンス低下がみられディスクスワップが発生してると思います
ご質問内容:対策としてこの場合、単純にメモリを追加するか、もしくはB画面の機能でメモリに蓄
えられている部分の情報を外部ファイルに置き出来る限り常駐化している情報を分散させ
る方式としなければならないのか(この場合、外部ファイルへの高速アクセスを実現する
めインデックスファイル機構を構築すると仮定する)
或いは、もっと別の考えがありレスポンス低下を抑える方法があるのかが身動きのとれ
ない状態です。同じような状況になったかたがいましたらどうかお力添えをよろしくお願
いします。
なお、予算がないため環境は無料のもので現在構築しております。
また、当システムはメモリ量節約のため外部ファイルにはDBは使用しない方向で検討
しています。
回答
すべての返信
-
プロファイラを用いて4秒間の内訳をみるのが一番です。
Visual StudioにはプロファイラがありVisual Studio プロファイラでアプリケーションのボトルネックを見つけるのように分析することができます。ただし無償のExpress Editionにはこのプロファイラは付属しません。一応無償のプロファイラがありますが…使いづらかったように思います。
-
いろいろな可能性が推測されますが、推測できないものが原因の可能性もあります。
正直なところ、第三者にはわからないでしょうというところです。すでに指摘されていますが、”遅い”という場合はどこがどのように遅いのか分析するべきです。
メモリやディスクスワップは一要因に過ぎませんので、正確な要因を知るためにもプロファイラを活用することも検討してください。C 画面がどのような実装、設計かは知りませんが、仮に 10 万件のデータを ListView などに普通に表示しようとすると、まず、もっさりします。
(メモリだけが原因とは限りません。設計・実装上、想定していない件数・操作・状態になっている可能性があります)
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。 -
一応無料のプロファイラ(EQATECを使用)を使用して調査しましたが特に問題となるものは発見できませんでした。ただ、あくまでも無料なので、全てのdllおよびexe全体を指定して調査することは不可能(無料では制限2個まで)なのでどの程度の信頼性があるかはなんとも言えないです)freeでお勧めのものがあれば教えてください。ちなみにC画面の対象データは、パターン1、および2は同じものを使用しており多くて数百件程度のもので質疑内容にも記述したとおりAおよびB画面の対象データが少ない場合には、問題なくサクサク動作することは確認しています。よってこの場合、C画面にてロジック上無駄な処理などが発生してレスポンス低下を招いていることは考慮する必要はありません。
-
さゆりさんへも、同じことを書きましたが、C画面の対象データは、パターン1、および2は同じものを使用しており多くて数百件程度のもので質疑内容にも記述したとおりAおよびB画面の対象データが少ない場合には、問題なくサクサク動作することは確認しています。よってこの場合、C画面にてロジック上無駄な処理などが発生してレスポンス低下を招いていることは考慮する必要はありません。
>、仮に 10 万件のデータを ListView などに普通に表示しようとすると、まず、もっさりします。
そうですね!。私も最初12万件程度を表示する仕様で作成してたのですが、たしかにもっさり動きますね。これは表示のみだけでなく、マウスクリック、スクロールなどしてももっさり動きますね。そこで機能変更して1,2万件程度に表示する仕様に変更しました。おそらく、ListView、とかDatagridviewなどはこれぐらいが限界でしょ。Ritchtextは、100件程度だと思ってます。マシンスペックにもよると思いますが。ちなみに私はIntel(R)Core(TM)2 cpu 6600 @2.40GHz です。 -
何を言われているのかわかりません。プロファイラでC画面操作の4秒間の内訳を測り、それぞれ妥当な処理時間だったということが判明しているということでしょうか?
処理時間に納得されているのならそれで構わないのでは?
納得できないのであれば、4秒間の内訳の中で時間を要しているものについて高速化をはかり、またそれが難しいのならこのフォーラムで該当箇所だけを切り出してアドバイスを受ければいいと思います。ちなみにVisual Studioには評価版があります。2008 と 2010。プロファイラも動作すると思いますので、試してみるのも1つの手かもしれません。
使ってみてプロファイラを必要に感じたら購入することをお勧めします♪# と宣伝したけどMicrosoftの回し者じゃありません。
-
何を言われているのかわかりません。プロファイラでC画面操作の4秒間の内訳を測り、それぞれ妥当な処理時間だったということが判明しているということでしょうか?
処理時間に納得されているのならそれで構わないのでは?
納得できないのであれば、4秒間の内訳の中で時間を要しているものについて高速化をはかり、またそれが難しいのならこのフォーラムで該当箇所だけを切り出してアドバイスを受ければいいと思います。ちなみにVisual Studioには評価版があります。2008 と 2010。プロファイラも動作すると思いますので、試してみるのも1つの手かもしれません。
使ってみてプロファイラを必要に感じたら購入することをお勧めします♪# と宣伝したけどMicrosoftの回し者じゃありません。
何を言われているのかわかりません。プロファイラでC画面操作の4秒間の内訳を測り、それぞれ妥当な処理時間だったということが判明しているということでしょうか?
>違います。4秒かかるのはパターン2の場合のみです。プロファイラでは妥当な検出時間ということが判明しております。ちなみに、A,B,Cの機能は全て私が設計および製造を行っているのでdll提供されたブラックボックスということではないです。
で、私は疑問に思うのですが、さゆりさんと、azuleanさんお二方とも、C機能について問題があると思われておりますが、質問内容にすでに、B画面の作りが原因でメモリを圧迫し、C機能を起動直後、メモリ ハードフォールトの値から、仮想メモリを使いだしていることは明確と思いますが?、また、A,Bの対象データを小さくした場合、問題なくCは快適に動作していることは明確に記述しています。また、4秒という値は、<快適に動いているという表現>から速度比較すると100倍から1000倍の開きがあることは推測できるかと思います。この数値からも仮想メモリへのスワップということが強調されて書いているつもりなのですが...何故C機能に固執するのでしょうか?
-
なるほど、そうゆうことでしたか。では、仮に仮想メモリの使用によるレスポンス低下の原因として考えられた場合、どのような調査を行うとよいのでしょうか?仮にそのような方法があれば、調査してみようかと思います。
ただ、<それよりはデータ量にふさわしくないロジック、データアクセスパターンが原因だろうと予想してます。が、根拠がないためプロファイラで具体的な所要時間を確認すべきと提案しました。>のところは、パターン1もパターン2もC機能については同じデータを利用していることに注目してください。あくまでもA,B機能においての扱ってるデータ量が異なるだけです。
私の考えはこうです。たとえばこの処理に限らず、ゲームしながらieを立ち上げると、反応が極端に悪くなってそのときの物理メモリ使用量は97-100%を行き来してますこのとき、仮想メモリ利用が原因でレスポンス低下が発生していると考えます。今回のケースでは物理メモリは60%-70%のぐらいですが、ただ、B機能においては一時的に95%を超えます。その後、メモリに格納された情報を外部ファイルとして一時退避し、不要な領域にnothingをいれ、System.GC.Collect() を発行し、61%まで物理メモリ使用量が減少しています。この場合、想像ですがC機能が物理メモリに収まる領域はあるが、B機能が解放した領域がフラグメントし領域確保できない状態にあるのではないかと。それにより思ったより、仮想領域使う羽目になり結果的に、ハードフォールト/秒に表せている数値から想定できないようなレスポンス低下を招いているのではないかと推測しています。ただ、<過去の経験からハードフォールト/秒が少数あっても体感できるほどの性能低下はしないと考えています。>から、仮想メモリの利用がどのように割り当てているのかが気になります。なかなか、クラス単位でメモリの利用状況を調査する(どの部分が仮想メモリを利用しているのか?)方法が見つけられない状況(あくまでも、無料で!)なもので。
ちなみに当システム操作時(プロセス)のメモリ使用量は500Mを超えています。ここのフォーラムの別ジャンルなのですが、500Mを超えると、仮想メモリを使いだしレスポンス低下を招いている例が挙げられていました。このときのレスポンス低下による低下率の記述はありませんでしたので比較の対象にはなりせんが。あくまでも参考程度に頭の隅に置いています。
また、System.GC.Collect() を発行すると、解放されない領域ができることも記述がありました。理想的には、System.GC.Collect() を使用しない(作成したAPで発行せず、システムに任せる)メモリは少しずつ確保し使用していくようにするのが理想かなと思っています。
-
EQATEC のプロファイラは十分な機能があると思いますが、実行時間とメモリ消費の計測であれば、JetBrains の dotTrace が使いやすいと思います。
http://www.jetbrains.com/profiler/
パターン2で4秒かかる処理について、パターン1とパターン2の計測結果を(必要であればメソッド名などはかくして)2~3レベルぐらいまで公開されれば、具体的な話がききやすいのではないかと思います。
一応、私もここまでの話を見る限りで想像できる範囲では、画面Cのロジックの問題であってメモリ消費量の問題ではない…のではないかと思います。
-
EQATEC のプロファイラは十分な機能があると思いますが、実行時間とメモリ消費の計測であれば、JetBrains の dotTrace が使いやすいと思います。
http://www.jetbrains.com/profiler/
パターン2で4秒かかる処理について、パターン1とパターン2の計測結果を(必要であればメソッド名などはかくして)2~3レベルぐらいまで公開されれば、具体的な話がききやすいのではないかと思います。
一応、私もここまでの話を見る限りで想像できる範囲では、画面Cのロジックの問題であってメモリ消費量の問題ではない…のではないかと思います。
k.takaokaさん。お久しぶりです。ほぼ一カ月ぶりですね。情報ありがとうございます。JetBrains試してみようとおもいます。 -
ちょっと疑問なのですが、
>メモリ ハードフォールト /分 1~3
これは、ハードページフォルト数回で、体感的にはっきりわかるほど遅くなると考えているということでしょうか?
IO状況によるのは確かですが、ちょっと考えにくい感じがします(率直な感覚では、あり得ないと感じるレベルです)。
普通に処理時間がかかっていると考える方が自然に思います。で、プロファイラで4秒かかるときのプロファイルをとれば明らかにどこかが遅いはずだと思うのですが、
プロファイル結果は妥当だ、というのはどういうことなんでしょうか?Cの機能で使っているデータは、Cで使っている決まった件数?のデータだけですか?
B画面などで使っているデータを利用しているとか、そういうことは確実にないでしょうか?
あるいは、Cの昨日実行中に、B画面などでバックグラウンドのデータ処理が走っているなどということもないでしょうか?最初に書いたように、ページフォルトが原因というのはどうにも信じられない感じがします。
--追記
数回程度?のページフォルトが原因とは思いにくいですが、ページの書き出しで遅いというのは、まだあり得るかもしれません。
それでもやっぱり疑問ですが。
あるいは件数が多い場合に、C機能実行のタイミング周辺で、AやB画面でIOが発生するような「何か」はないですかね?
CでのCSV読み出しに異様に時間がかかっていたりはしないでしょうか? -
>ご自身に知識もなく、分析能力もないのに、それでも自信を持ってハードフォールトが原因と言われるのならきっとそうなのでしょう。
>問題に対して感覚論ばかりで論理的な説明ができない時点で、あなたの書いたプログラムのロジックにも欠陥があることが予想されますけどね。
批判論は、求めてないので、あくまでも推論を立ててください。提示しているデータはあくまでも参考程度に思ってください。それが常に正しい数値でないことは承知しています。私は、皆さんが何故、Cに問題があると思われるかが非常に疑問です。また、ロジックについて色々と想像されているようでが、最初に書いていることを理解していないように思います。Cのロジックが怪しいと思うのでしたらその根拠があるはずです。記述していない想定のロジックをでっちあげて、それについて討論してもなんの解決にもなりません。あくまでも記述していることのみに焦点を合わせてください。
また、記述している機能について解らない、理解できないのであれば、質問してください。こちらも、提示できる情報は公開するつもりです。 -
ちょっと疑問なのですが、
>メモリ ハードフォールト /分 1~3
これは、ハードページフォルト数回で、体感的にはっきりわかるほど遅くなると考えているということでしょうか?
IO状況によるのは確かですが、ちょっと考えにくい感じがします(率直な感覚では、あり得ないと感じるレベルです)。
普通に処理時間がかかっていると考える方が自然に思います。で、プロファイラで4秒かかるときのプロファイルをとれば明らかにどこかが遅いはずだと思うのですが、
プロファイル結果は妥当だ、というのはどういうことなんでしょうか?Cの機能で使っているデータは、Cで使っている決まった件数?のデータだけですか?
B画面などで使っているデータを利用しているとか、そういうことは確実にないでしょうか?
あるいは、Cの昨日実行中に、B画面などでバックグラウンドのデータ処理が走っているなどということもないでしょうか?最初に書いたように、ページフォルトが原因というのはどうにも信じられない感じがします。
--追記
数回程度?のページフォルトが原因とは思いにくいですが、ページの書き出しで遅いというのは、まだあり得るかもしれません。
それでもやっぱり疑問ですが。
あるいは件数が多い場合に、C機能実行のタイミング周辺で、AやB画面でIOが発生するような「何か」はないですかね?
CでのCSV読み出しに異様に時間がかかっていたりはしないでしょうか?
>、プロファイラで4秒かかるときのプロファイルをとれば明らかにどこかが遅いはずだと思うのですが、
>プロファイル結果は妥当だ、というのはどういうことなんでしょうか?数値を100%信用しているわけではありません。ただ仮想メモリを使用しているという証拠を提示しているだけです。
>Cの機能で使っているデータは、Cで使っている決まった件数?のデータだけですか?
>B画面などで使っているデータを利用しているとか、そういうことは確実にないでしょうか?
>あるいは、Cの昨日実行中に、B画面などでバックグラウンドのデータ処理が走っているなどということもないでしょうか?決まった件数です。Bで利用しているものとはまったく別ものです。また、バックグラウンドなる機能は使ってません。機能は最初の説明で書いているもののみです。
>数回程度?のページフォルトが原因とは思いにくいですが、ページの書き出しで遅いというのは、まだあり得るかもしれません。
>それでもやっぱり疑問ですが。
>あるいは件数が多い場合に、C機能実行のタイミング周辺で、AやB画面でIOが発生するような「何か」はないですかね?
>CでのCSV読み出しに異様に時間がかかっていたりはしないでしょうか?パターン1では、快適に動いているというのはどうゆう理由が考えられますか? パターン1も2もC機能においては同じデータから読み込みます。つまりまったく同じデータ同じロジックですよ?
追記
>で、プロファイラで4秒かかるときのプロファイルをとれば明らかにどこかが遅いはずだと思うのですが、
>プロファイル結果は妥当だ、というのはどういうことなんでしょうか?もっか、k.takaokaさんの情報をもとに調査中です。
-
情報追加情報
j.takaokaさんの提供情報によるJetBrainsによる情報(これでいいのかな?)
注意:以下情報において、当システム推測できるクラス名は、xxxx にて置き換えてます。以下の情報は4秒かかっているときの情報です。まだ提示の情報は全てではありません。使用率の大きいもので抜粋してます。
Namespace and classes objects Memory,byte HledObjects Heldmemory byte
99.98 System string 6,617,471 232,565,079 6,618,582 232,611,640
21,38 Collections 4,003,535 141,408,148 4,003,535 141,408,148
9.61 object 1,678,037 49,725,396 3,446,203 118,876,984
6.67 string 8.8,027 22,351,232 2,079,486 79、535、288
1.16 Windows 165 15,512,844 2,079,486 79,535,288
0.00 xxxxConvertProject 17 2、924 6,489,397 228,107,632
0.00 FormMenu 1 384 21 1、116
0.00 FormA 1 628 27 1、652
0.00 FormB 1 440 23 1,308
0.00 formC 1 392 2、781 134,896
0.00 ViewA 1 108 1,892 92,904
0.00 ViewB 1 208 4,361,209 149,936,560
0.00 ViewC 1 84 2,762 133,768
以下略
0.00 CommonDutiesProject 26 1、524 4,669,158 169,177,870
0.00 ConvertXXXX 1 244 3 684
0.00 XMLDomIOEnvironmentSetting 2 168 3、008 132,942
0.00 AccessEnvFile 2 160 4,275 193,942
0.00 AccessAddrCsvFile 1 76 1、598、508 60,091,190
0.00 MentenanceXXXX 1 64 2,857,303 101,774,068
以下略
説明
xxxxConvertProject は、当システム対象のプロジェクトです。 Formxxは、フォームから各コントロールをクリックし自動生成さるソースのものです。ここは、おもにイベントからのコントロール(処理の振り分け)の
部分しか行っていません。ViewXXXは、フォームへの編集処理のみ行っています。 CommonDutiesProjectから受け取ったデータをもとに整形してフォームに設定など行っています。
たとえば、数字編集9999を9,999編集とか(例です)
CommonDutiesProject ここは、当システムの中核です。実際、ファイルからの読み込み、集計、ソートなど、システムの中核となるものが入っているプロジェクトです。
ま、想像どおりのような気がします。
-
>このスレッドにリプライしている人は誰一人として使用メモリを問題視していません。
で何故? そこも質問しているのですが? 理由とした判断は、「メモリ ハードフォールト/分」だけですか? ほかの条件は無視?私としてはおおよそYESです。他の方も私と同じ判断をしていますが、その理由まではわかりません。私と同じ理由だから書くまでもないと判断されたのかも?
ほとんど今までのコメントのまとめでしかありませんが
- ハードフォールト値は十分に少なく、過去の経験からパフォーマンス低下の要因にはなり得ない
- 質問文、および過去の質問から想像される質問者のスキルレベル、このレベルの人がメモリ使用量が原因でパフォーマンス低下を引き起こす可能性
- それよりは質問文の論理展開の仕方からみても効率の良いロジックが書けるかどうか疑わしい
ぐらいです。
その上で、4秒に対して実行時間の内訳を調べ、例えば、メモリアクセスに3.9秒要しているようならその観点での改善を、逆にCPU演算に3.9秒要しているならメモリに関係なくロジックの改善を、と考えています。ただしメモリアクセスの占める割合が高いからといってもハードフォールトには直結しません。さらに次のステップの調査が必要になります。
以上をすべて省略して最初に「プロファイラを用いて4秒間の内訳をみるのが一番です」と書きました。
-
でわ、パターン1について、なぜ、快適に動作していることが理由付けられますか?
仮に、C画面がロジック効率が悪いロジックならパターン1でも4秒かかるはずと
記述があると推測されますが。ここが私の一番疑問点なのです。第三者に原因分析を求めるのは酷では?
C 画面までのロジックは第三者にはわかりませんので、正確な原因分析は無理でしょう。可能性があるとすれば、C 画面の表示パフォーマンスは、C 画面までに処理する件数に依存しているとか。
パターン 1 では B 画面時点で 380 件、パターン 2 では B 画面時点で 175,000 件であるため、もし、B 画面のデータ量が多いとパフォーマンスが悪化するロジックが C 画面に書かれていれば、遅くなることが想定されます。
表示更新時に元データから抽出しなおす処理を間違えて呼んでいるというような不具合の可能性もありますね。
(この場合はメモリのページフォルトの有無を問わず、単純に CPU 時間を食う処理になっているだけになります)とりあえず、どこに時間がかかっているのかメソッドごとの処理時間が見えるプロファイラを使って、想定以上にかかっているところのロジックを見直すことが必要でしょう。(ちなみに、dotTrace Performance はそれを実現できます。dotTrace Memory じゃないですよ)
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。
-
そう、これが聞きたかったのです。つまり、C画面は、B画面の取り込み件数により処理するのは異なっているのではというふうに理解していたわけですね!。ここが、最初の説明を理解してないということだと思うのです。何故そうおもわれたかは、私からは理解できなかったのです。
で、C機能についてはもう少し詳しく説明します。
C機能で表示対象の読み込むデータは、B画面で処理対象としているデータとは全く別のものです。B機能にて、如何なるデータを取り込んでも、C機能には全くその動作に影響を与えません。つまり、パターン1およびパターン2について言えば、C機能は全く同じデータを使用していることになります。C機能の読み込み対象データは1件から100件程度です。
画面イメージで説明すると、画面上段に3つのlistView、画面下段に1つのlistviewが存在します。
初期画面では、上段の一番左側に1件のみ表示します(今の段階では対象データは1件のみなので)。それをクリックすると、上段真ん中に、クリックしたデータの対象のデータを画面上段の真ん中のlistviewに表示するイメージです。これが、画面上段の左、中央、右、下段の順番で処理していきます。どのデータが対象なのかは、クリックしたデータが次に読むべきファイル情報を内部でもっている仕組みなので、単純に、ファイルを指定して読み込んで、listViewに表示しているだけです。
つまり、それぞれのlistViewに表示するデータは、ファイルが異なり、常に少量のファイルを対象とするようになり巨大なCSVファイルを読み込んでIO時間を抑えることにしています。この方式により1クリックすることによる対象とするファイルは現段階において1ファイルで1件から100程度に抑えられています。最終的には、1ファイル数千件程度を対象とし快適に操作できるように設計されています。
パターン2の4秒かかるという対象は、全てのListViewに対してクリックしたとき約4秒かかります。つまり対象データが1件だろうと100件だろうと4秒かかます。パターン1では、同じ対象データにも関わらず、瞬時に応答が帰ってきます。
ですから、この段階でいえるのはB機能のメモリ圧迫により、C機能が仮想メモリに展開されクリックされるたびに、動作部分が実メモリに展開し起動しているのではないかと想定を立てたわけです。そこで、本来の質問内容にも記述したとおりB機能の作りとのもが妥当がどうかご質問した次第なのです。
>第三者に原因分析を求めるのは酷では?
>C 画面までのロジックは第三者にはわかりませんので、正確な原因分析は無理でしょう。このレベルになれば、自己解決が困難と判断した場合、別スレッドを立てて別途質問することにします。
>(ちなみに、dotTrace Performance はそれを実現できます。dotTrace Memory じゃないですよ)
これについて一応dottraceの情報は掲載したとおりです。Perfomanceについてインストールは完了しているのですがide上に起動のためのボタンが出現しません。(IDEを開いたとき、performance起動ボタンが表示されるが、正しいのですよね?)もし、だめなら別な方法を考えなければいけないと思っています。 今、言えるのは、機能単位にスキップ実行したとき、パターン2の場合、全体的に遅い感じがするぐらいです。
-
そう、これが聞きたかったのです。つまり、C画面は、B画面の取り込み件数により処理するのは異なっているのではというふうに理解していたわけですね!。ここが、最初の説明を理解してないということだと思うのです。何故そうおもわれたかは、私からは理解できなかったのです。
あくまで私が出した推論の一つであり、全員の共通認識ではない点をお忘れなく。
そして、「説明を理解していないと言うことだと思う」と言われていますが、最初の説明ではこの推論の可能性を否定できていません。また、「私からは理解できない」と言われていますが、あなたはすべて知っているから可能性を考慮しなかったのでしょう。
そういう風になったのであれば、このスレッドの参加者に、その可能性の否定の根拠を十分に説明し、軌道修正を図ればよいでしょう。パターン2の4秒かかるという対象は、全てのListViewに対してクリックしたとき約4秒かかります。つまり対象データが1件だろうと100件だろうと4秒かかます。パターン1では、同じ対象データにも関わらず、瞬時に応答が帰ってきます。
ですから、この段階でいえるのはB機能のメモリ圧迫により、C機能が仮想メモリに展開されクリックされるたびに、動作部分が実メモリに展開し起動しているのではないかと想定を立てたわけです。そこで、本来の質問内容にも記述したとおりB機能の作りとのもが妥当がどうかご質問した次第なのです。
一つの可能性として疑うことはできますが、それが絶対であることを示す論拠はどこにもありません。
なので、異なる可能性も忘れないようにする、きちんと遅くなる原因を明確にするということで、プロファイラの利用を提言されていますよね。
(影響しないと思い込んでいても、不具合で実は依存しているということが実際問題あります。思い込んでロスするのは私もよくやりますので)あと、B 画面の設計・実装を具体的に説明せず、メモリ使用の方針として妥当かどうかだけ聞かれても正直、回答できる人は居ません。
単に 300MB 確保するぐらいなら、どうってことないと思いますけどね。(使い方による)>第三者に原因分析を求めるのは酷では?
>C 画面までのロジックは第三者にはわかりませんので、正確な原因分析は無理でしょう。このレベルになれば、自己解決が困難と判断した場合、別スレッドを立てて別途質問することにします。
そうしてください。
現状を正確に把握してください。何か一つの可能性ばかり追っていると、実はそれが原因ではなかったときに時間の浪費で終わります。
自分の時間を無駄にしないためにも、プロファイラを活用してください。これについて一応dottraceの情報は掲載したとおりです。Perfomanceについてインストールは完了しているのですがide上に起動のためのボタンが出現しません。(IDEを開いたとき、performance起動ボタンが表示されるが、正しいのですよね?)もし、だめなら別な方法を考えなければいけないと思っています。 今、言えるのは、機能単位にスキップ実行したとき、パターン2の場合、全体的に遅い感じがするぐらいです。
掲載しているのは dotTrace Memory ですよね。
このスレッドでプロファイラを使えと散々言われている機能は、dotTrace Performance のことですよ。
なので、「誰もメモリを気にしていない」と返されたわけです。(メモリが原因かどうか定かではない段階で、メモリだけ突っついても仕方ないので)IDE にメニューが出ないのであれば、統合されていないのかもしれませんね。
スタートメニューからも起動できるので、そっちから起動して対象のアプリケーションに自分で作ったアプリケーションを指定すれば良いでしょう。
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。 -
あくまで私が出した推論の一つであり、全員の共通認識ではない点をお忘れなく。
もちろん、そう認識してましす。他に別の意見があれば、コメントしてくれるでしょ ..きっと
そして、「説明を理解していないと言うことだと思う」と言われていますが、最初の説明ではこの推論の可能性を否定できていません。
また、「私からは理解できない」と言われていますが、あなたはすべて知っているから可能性を考慮しなかったのでしょう。
そういう風になったのであれば、このスレッドの参加者に、その可能性の否定の根拠を十分に説明し、軌道修正を図ればよいでしょう。少なくとも、根拠は書いているつもりです。(あくまでも思いこみですよ)ただ、どの部分が不十分なのかは逆に質問してほしいです。それについてこちらも答えるつもりです。例をたとえるなら、なちゃさんのように
一つの可能性として疑うことはできますが、それが絶対であることを示す論拠はどこにもありません。
気になります。一つの可能性とはなんでしょうか?的外れでもいいので教えて頂けませんか?
なので、異なる可能性も忘れないようにする、きちんと遅くなる原因を明確にするということで、プロファイラの利用を提言されていますよね。
(影響しないと思い込んでいても、不具合で実は依存しているということが実際問題あります。思い込んでロスするのは私もよくやりますので)同感ですね。まさに今それかも..
あと、B 画面の設計・実装を具体的に説明せず、メモリ使用の方針として妥当かどうかだけ聞かれても正直、回答できる人は居ません。
単に 300MB 確保するぐらいなら、どうってことないと思いますけどね。(使い方による)このレベルの回答で十分です。説明で、実際ソースを提示しているわけでもないし。それほど細かく説明している訳でもない(プログラム設計書レベルで)同じレベルで解して頂ければ大変ありがたいです。少し不安が解消されました!
現状を正確に把握してください。何か一つの可能性ばかり追っていると、実はそれが原因ではなかったときに時間の浪費で終わります。
少し上の内容と異なるのですが、実際、このようなツールがない場合、どのような分析をしますか?私は、今起きている現象を元に推論をたて、その可能性を一つずつつぶして、問題を解決に取り組んできました。もし、推論を立てて、問題解決が出来なかった場合、ソースを頭から見直して解析するしかない!(もう、ほとんど突貫工事!)質問内容に、結構しつこく推論はと逆に聞いていたのですが? 多分みなさんとこの辺の考え方が異なるのではないかと今更思った訳ですが!(私の考えが古い?)今はツールありきで、その分析結果をもとに推理するのが主流?
自分の時間を無駄にしないためにも、プロファイラを活用してください。掲載しているのは dotTrace Memory ですよね。
このスレッドでプロファイラを使えと散々言われている機能は、dotTrace Performance のことですよ。
なので、「誰もメモリを気にしていない」と返されたわけです。(メモリが原因かどうか定かではない段階で、メモリだけ突っついても仕方ないので)IDE にメニューが出ないのであれば、統合されていないのかもしれませんね。
スタートメニューからも起動できるので、そっちから起動して対象のアプリケーションに自分で作ったアプリケーションを指定すれば良いでしょう。インストール直後では、スタートメニューにすら、存在してなかったのですが、電源on/off後いつの間にか、スタートメニューに洗われました。ありがとうございます。
結果を以下に提示します。ただ、さゆりさんの(例だとは思うのですが)レスポンスに約4秒かかるのなら、その内訳の合計が約4秒かかるように表示されるといくことですね?実際採取された値はそれよりもかなり少ない値です。また、サンプリングもイベントレベルで採取されないときがあります。どのイベントが採取されないかは一定して同じではありません(数値が未記入のもの)。とりあえず、同じパターン(同じデータをクリックして)数回確認しました。(横軸)。個人的な印象なのですがこのような状態でこのツール信頼性あるのかな?というところです。(traceのバージョンは、4.5 です)
-------------------------4秒かかる場合のパターン-------------
FormxxxList.xxx._SelectIndexChanged 79ms 39ms 45ms
ViewxxxList.Selectxxx 79ms 39ms 45ms
ViewViewxxxList.initxxxxList 47ms 39ms 45ms
system..ColumnHeaderCollection.add 47ms 39ms 45ms
ViewxxxList.InitxxCdList 32ms 39ms 45ms
XXXXXOpen 32ms
XXXXXXOpen 32ms
FileReadCheck 32ms
system.io.exists 32ms
system.io.file.internalExists 32ms
system.io.file.Fillattributeinfo 32ms
Garbage collection 32msFormxxxList.xxx_SelectIndexChanged 48ms 43ms 39ms
ViewXXXXlList.Selectxxxx 48ms 43ms 39ms
ViewXXXXlList.InitxxxList 48ms 43ms 39ms
System.ListView.set_View 48ms 43ms 39ms
system..SendMessage 48ms 43ms 39ms
:
:
FormXXXXList_Clic 31ms 16ms 8ms
ViewXXXList.Select 31ms 16ms 8ms
ViewXXXList.DetailXXXList 31ms 16ms 8ms
ViewXXXList.InitXXXList 16ms 16ms 8ms---------------------------快適に動いているときのパターン-------------
FormxxxList.xxx._SelectIndexChanged 23ms 23ms 31ms
ViewxxxList.Selectxxx 23ms 23ms 31ms
ViewViewxxxList.initxxxxList 23ms 23ms 31ms
system..ColumnHeaderCollection.add 23ms 23ms 31ms
ViewxxxList.InitxxCdList 23ms 23ms 31ms
system...ListViewItemCollection.add 23ms 23ms 31ms
XXXXXOpen ms
XXXXXXOpen ms
FileReadCheck ms
system.io.exists ms
system.io.file.internalExists ms
system.io.file.Fillattributeinfo ms
Garbage collection msFormxxxList.xxx_SelectIndexChanged ms 24ms 31ms
ViewXXXXlList.Selectxxxx ms 24ms 31ms
ViewXXXXlList.InitxxxList ms 24ms 31ms
System.ListView.set_View ms 24ms 31ms
system..SendMessage ms 24ms 31ms
:
:
FormXXXXList_Clic 8ms ms 23ms
ViewXXXList.Select 8ms ms 23ms
ViewXXXList.DetailXXXList 8ms ms 23ms
ViewXXXList.InitXXXList 8ms ms 23ms -
結果を以下に提示します。ただ、さゆりさんの(例だとは思うのですが)レスポンスに約4秒かかるのなら、その内訳の合計が約4秒かかるように表示されるといくことですね?実際採取された値はそれよりもかなり少ない値です。また、サンプリングもイベントレベルで採取されないときがあります。どのイベントが採取されないかは一定して同じではありません(数値が未記入のもの)。とりあえず、同じパターン(同じデータをクリックして)数回確認しました。(横軸)。個人的な印象なのですがこのような状態でこのツール信頼性あるのかな?というところです。(traceのバージョンは、4.5 です)
はい、合計が4秒になるような集計結果を期待していました。挙げられた測定結果は期待しているものと異なり、ここから何かを読み取るのは難しいです。
Visual Studio付属のものだと、呼び出し回数が多いとか、実行時間が長いとか、目立つ関数をピックアップしてくれるのでそこだけ見ても状況がすぐにわかるんですよね。
-
気になります。一つの可能性とはなんでしょうか?的外れでもいいので教えて頂けませんか?
この文脈における「一つの可能性」とは、「原因として考えられるすべての可能性の中の一つである」ということでしょう。
メモリの使用状況が一つの可能性として疑うことがでいますが、それ以外の原因が存在しないこと(それが絶対であること)を示す論拠はどこにもないということです。私も、今までの情報を見る限り、メモリ使用状況だけを疑う、あるいはそれだと断定する根拠としては弱いと思っています。
どこまでやれば絶対かと言われれば、難しいでしょうね。何か証明するコードとか、再現手順とかが確立できればよいとは思いますが。少し上の内容と異なるのですが、実際、このようなツールがない場合、どのような分析をしますか?私は、今起きている現象を元に推論をたて、その可能性を一つずつつぶして、問題を解決に取り組んできました。もし、推論を立てて、問題解決が出来なかった場合、ソースを頭から見直して解析するしかない!(もう、ほとんど突貫工事!)質問内容に、結構しつこく推論はと逆に聞いていたのですが? 多分みなさんとこの辺の考え方が異なるのではないかと今更思った訳ですが!(私の考えが古い?)今はツールありきで、その分析結果をもとに推理するのが主流?
単に疑わしい関数の前後に、Environment.TickCount を Debug.WriteLine するコードを書くだけでも、ツールを使わずに計測できますよ。
ただ、どこが疑わしいかわからない状態であれば、全部に入れるか、ツールを使うかになるとは思います。遅いと思ったら、私ならメモリの使用状況を疑うよりも前に、どこの関数に時間がかかっているかを調べますね。
遅い関数が特定できたときに、その関数の中を見てメモリの使い方という可能性を疑うことはできますが、順序が違うように感じます。結果を以下に提示します。ただ、さゆりさんの(例だとは思うのですが)レスポンスに約4秒かかるのなら、その内訳の合計が約4秒かかるように表示されるといくことですね?実際採取された値はそれよりもかなり少ない値です。また、サンプリングもイベントレベルで採取されないときがあります。どのイベントが採取されないかは一定して同じではありません(数値が未記入のもの)。とりあえず、同じパターン(同じデータをクリックして)数回確認しました。(横軸)。個人的な印象なのですがこのような状態でこのツール信頼性あるのかな?というところです。(traceのバージョンは、4.5 です)
あれ、こんな出力になりました?
http://www.jetbrains.com/profiler/features/index.html の "Convenient data representation" みたいに、どこのメソッドが何パーセントの時間を使い、何回呼び出されているか(calls)を見ることができると期待していました。
違うビューなのかなぁ…。
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。 -
> 今はツールありきで、その分析結果をもとに推理するのが主流?
ツールがどうとかは別にして、少なくとも20年ぐらい前からはパフォーマンスについては、「計測しないで語っても意味がない」と言われていると思います。それ以上の昔はわかりません。(私の経験がそれぐらいなので)
> 結果を以下に提示します。
dotTrace 4.5ベータは使っていないのですが、4.0 以前と出力がかわっていないのならば、こんな結果の表示にはならないはずなんですけどね。上位メソッドに対する時間割合・消費CPU時間・呼び出し回数が記録されるはずです。時間が3つ記録されるようなことはないのですが…。時間割合は(それも重要なのですが)別にして、消費時間と呼び出し回数は共に非常に重要なことなので、この2つが省略されると誰も何もわからないと思います。
> サンプリングもイベントレベルで採取されないときがあります。どのイベントが採取されないかは一定して同じではありません(数値が未記入のもの
親に対する割合が0.01% 未満の表示を省略しているとかではないですか? デバッグビルドではないモジュールを使っている場合は、最適化で削られている可能性も(少ないですが)あります。
-
上位メソッドに対する時間割合・消費CPU時間・呼び出し回数が記録されるはずです。時間が3つ記録されるようなことはないのですが…。時間割合は(それも重要なのですが)別にして、消費時間と呼び出し回数は共に非常に重要なことなので、この2つが省略されると誰も何もわからないと思います。
時間割合については、今回の事象に対して、あまり重要ではないと判断し、省かせていただきました。 一言、その旨を記述しておけばよかったですね!、申し訳なく思います。 ただ、再度確認しましたが、呼び出し回数についてはやはり載ってないです。 呼び出し回数が1回のみの場合、省略されていると行くことはないでしょうか?
親に対する割合が0.01% 未満の表示を省略しているとかではないですか? デバッグビルドではないモジュールを使っている場合は、最適化で削られている可能性も(少ないですが)あります。
そうであれば、出てこない可能性は大だと思います。ご質問した対象の機能まで行き着くまでに大元のメニュー画面から4~5分の時間を必要とします。
ちなみに、これらのツールのCPUTIMEというのは、純粋に対象のメソッドの処理時間なのでしょうか? ELAPSETIME も含めた処理時間なのでしょか?純粋なメソッドの処理時間であれば、空白の時間についてどのような推測を立てることができますか?
ELAPSETIME :ELAPSETIME と表現することが妥当かどうか定かではないのですが、実際の経過時間から実cpu使用時間の差と思ってください、この時間がないと、当サンプルングした時間と実際に掛った時間(約4秒)と等しくならないと思います。
もし、その時間が掲載されていれば、他タスクまたは、スレッドによりCPUの消費していることが明確だと思うのですが、今までのは情報からはそのような手段は無いですよね?(、他タスクまたは、スレッドとは、当対象の機能も含めて(今回の例では、スレッド等の処理は無いので対象外と判断してますが)、ウィルス監視ソフト、ガシェット 、OS等)
-
ほとんど書きあがったあとで投稿前にとんだので、ちょっと殴り書きぎみに^^
> 再度確認しましたが、呼び出し回数についてはやはり載ってないです。
一応、dotTrace Performance 4.5beta をダウンロードしてみましたが、デフォルトできちんと表示されていますし、非表示にするオプションもありません。また、1回どころか、スタック上に現れれば呼び出されていないメソッドであっても 0 回として表示されます。
> CPUTIMEというのは、純粋に対象のメソッドの処理時間なのでしょうか?
一般的に、CPU時間というのは、CPUを占有した量を表現するために使われます。「CPU を100%占有した状態で5分間経過した」場合のCPU時間は「5分」です。同様に「CPU を 50% 占有した状態で10分間経過した」場合も、CPU時間は「5分」です。
一応、dotTrace に表示されている時間は、Round Time(経過時間)になっており、時計が進んだ時間を表示しています。ネットワークやディスクの I/O 待機、ページングによって待ち時間が発生すれば、それは計測値にそのまま残ります。
> ご質問した対象の機能まで行き着くまでに大元のメニュー画面から4~5分の時間を必要とします。
前にもかいていますが、親からの比率なので関係ありません。また、インストール直後ではすべてのメソッドが表示される設定になっています。(メニューの View にある Show Calls Consuming 0% というやつです) また、dotTrace では目的の部分だけの計測も簡単にできるので、とりあえず気になっている画面Cの部分だけを計測して比較されることをおすすめします。
一応、簡単に操作手順を書いておくと、
- dotTrace Performance を起動する
- 目的のプログラムを指定して LANCH を押す
- 目的のプログラムと、dotTrace のコントロールパネルが起動するはずです
- 目的のプログラムを計測手前まで進める(今回の場合は、画面Cが表示されたあたりでしょうか)
- dotTrace コントロールパネルで Drop Snapshot を押して、ここまでの計測結果を破棄する
- 目的の操作だけを行う
- dotTrace コントロールパネルで Get Snapshot を押して、計測結果を取得する
- (邪魔なようなら)目的のプログラムは Get Snaphot が終わったら終了しておきましょう。または、再度プロファイリングを開始して1回目と2回目の差を見たりするのも、とても有用な情報になるでしょう。
といったかんじです。Get Snapshot を押すと自動的に dotTrace のワークスペースが起動するはずなので、まずは左側のツールバーの上から2つめにある矢印が3本重なったアイコンを押して、呼び出しツリーをざっくりながめてみるとよいでしょう。また、2つのパターンで同様に処理をした後、Compere を選べば比較することもできます。
一応、左側ツールバーの一番下にある炎のアイコンを選べば、呼び出し回数や実行時間をもとにパフォーマンスに影響を大きく与えている場所を自動的に検索してくれますが、dotTrace の場合 Windows API や Windows NT のカーネル サービスの呼び出しレベルまで表示してくれちゃうので、最初はみないほうがいいでしょう^^
-
その、「4~5分かかっているのはどこだ?」を探すのが、一番しなければならないことではないですか?たとえあなたがおっしゃるようにスワップによって時間がかかっているのだとしても、何らかの処理によってスワップが発生し、結果として4~5分かかるのですから、4~5分かかっているプロセスがあるはずですよね。
Jitta@わんくま同盟
あ、ここって、具体的にはA機能です。
A機能は、分析対象となるファイルを読み込み、1レコードに対して、およそ30パターンの文字解析を行い、その解析結果に基づいて、レコードを派生してます。つまり、分析のためにおよそ12万件のレコードをバッファに読み込み、それを約30回、バッファ上で情報を検索しています。またその経過状況もプログレスバーおよび処理件数なども表示する仕様になってます。なので、時間的に4-5分かかります。それにより派生されたレコードがB機能にてさらに編集できるようになっています。今、問題となっているのはBから起動したC機能です。-----
お初ですね。投稿ありがとうございます。なんか、人気質問サイトになってきたような..
-
ほとんど書きあがったあとで投稿前にとんだので、ちょっと殴り書きぎみに^^
> 再度確認しましたが、呼び出し回数についてはやはり載ってないです。
一応、dotTrace Performance 4.5beta をダウンロードしてみましたが、デフォルトできちんと表示されていますし、非表示にするオプションもありません。また、1回どころか、スタック上に現れれば呼び出されていないメソッドであっても 0 回として表示されます。
へんですね~ 0というのも出てきてないです。
> CPUTIMEというのは、純粋に対象のメソッドの処理時間なのでしょうか?
一般的に、CPU時間というのは、CPUを占有した量を表現するために使われます。「CPU を100%占有した状態で5分間経過した」場合のCPU時間は「5分」です。同様に「CPU を 50% 占有した状態で10分間経過した」場合も、CPU時間は「5分」です。
一応、dotTrace に表示されている時間は、Round Time(経過時間)になっており、時計が進んだ時間を表示しています。ネットワークやディスクの I/O 待機、ページングによって待ち時間が発生すれば、それは計測値にそのまま残ります。
> ご質問した対象の機能まで行き着くまでに大元のメニュー画面から4~5分の時間を必要とします。
前にもかいていますが、親からの比率なので関係ありません。また、インストール直後ではすべてのメソッドが表示される設定になっています。(メニューの View にある Show Calls Consuming 0% というやつです) また、dotTrace では目的の部分だけの計測も簡単にできるので、とりあえず気になっている画面Cの部分だけを計測して比較されることをおすすめします。
なるほど、であれば合計時間は4秒に限りなく近くなるはずですね!
一応、簡単に操作手順を書いておくと、
- dotTrace Performance を起動する
- 目的のプログラムを指定して LANCH を押す
- 目的のプログラムと、dotTrace のコントロールパネルが起動するはずです
- 目的のプログラムを計測手前まで進める(今回の場合は、画面Cが表示されたあたりでしょうか)
- dotTrace コントロールパネルで Drop Snapshot を押して、ここまでの計測結果を破棄する
- 目的の操作だけを行う
- dotTrace コントロールパネルで Get Snapshot を押して、計測結果を取得する
- (邪魔なようなら)目的のプログラムは Get Snaphot が終わったら終了しておきましょう。または、再度プロファイリングを開始して1回目と2回目の差を見たりするのも、とても有用な情報になるでしょう。
といったかんじです。Get Snapshot を押すと自動的に dotTrace のワークスペースが起動するはずなので、まずは左側のツールバーの上から2つめにある矢印が3本重なったアイコンを押して、呼び出しツリーをざっくりながめてみるとよいでしょう。また、2つのパターンで同様に処理をした後、Compere を選べば比較することもできます。
一応、左側ツールバーの一番下にある炎のアイコンを選べば、呼び出し回数や実行時間をもとにパフォーマンスに影響を大きく与えている場所を自動的に検索してくれますが、dotTrace の場合 Windows API や Windows NT のカーネル サービスの呼び出しレベルまで表示してくれちゃうので、最初はみないほうがいいでしょう^^
上記手順見ましたが、私が行った手順とまったく同じです。 >とりあえず気になっている画面Cの部分だけを計測して比較されることをおすすめします。 ここまで同じというのに驚き!
>一応、左側ツールバーの一番下にある炎のアイコンを選べば、呼び出し回数や実行時間をもとにパフォーマンスに影響を大きく与えている場所を自動的に検索してくれますこちらも、確認しましたが(青薄く表示されているところも含めて)呼び出し回数はでてないです...しかも、%および実行時間は全て0となっています。
-
> しかも、%および実行時間は全て0となっています。
もしかして、プロファイラの設定を変更されていますか? アプリケーションを起動するときに詳細オプションで変更できますが、とても大雑把に書くと
Profiling Type
Tracing : 並
Line-By-Line : 詳細(要:デバッグビルド)
Sampling: 雑Time Measuring:
Performance coutner : パフォーマンスカウンタを使用して時間を計測
CPU instruction : CPU の回転数を利用して時間を計測
Thread : 実時間ではなく CPU 時間を表示するUse Profiler API : 標準のプロファイル機能を使用して計測する(全然違う計測になります)
というかんじです。もしかすると、Sampling mode だと何もでないとかあるかもしれません。(デフォルトは 4.0 は Line-By-Line, CPU instruction ですが、4.5 は Tracing, CPU instruction になっていました)
-
もしかして、プロファイラの設定を変更されていますか? アプリケーションを起動するときに詳細オプションで変更できますが、とても大雑把に書くと
Profiling Type
Tracing : 並
Line-By-Line : 詳細(要:デバッグビルド)
Sampling: 雑Time Measuring:
Performance coutner : パフォーマンスカウンタを使用して時間を計測
CPU instruction : CPU の回転数を利用して時間を計測
Thread : 実時間ではなく CPU 時間を表示するUse Profiler API : 標準のプロファイル機能を使用して計測する(全然違う計測になります)
というかんじです。もしかすると、Sampling mode だと何もでないとかあるかもしれません。(デフォルトは 4.0 は Line-By-Line, CPU instruction ですが、4.5 は Tracing, CPU instruction になっていました)
変更は、特にしてないですよ。
ただ、パラメータの内容が異なるようなので以下にその状況を記述しておきました。
--------------------パラメータの説明--------------------------------------------------------
起動時のオプションについて 規定値は以下のようになってます。変更しても、再起動すると以下の内容と
なるようです。Profile options
profiling type Sampling measure: Wall tim(CPU instruction)
on start Profiling immediately
off High accurcy on Enable inlining on Merge threads with equal names
off Use profiler API※ off High accurcy はチェック不可
on/offのところはチェックボックスで onはチェックがついているProfiling Typeについての選択内容については、K. Takaokaさんのとおりと一致しています。
Measure:については以下の選択が可能です。Wall time(performance counter)
[n/a] Thread time
Wall time(CPU instriction)
ProfilingType をTracingにすると、off High accurcyが選択可能となります。
ProfilingType をLine-by-lineにすると、上記設定可能に加え、「Edit Filters...」と「Edit Symbol Search P
olicy..」のボタンが出現します。Edit FIlters ボタンをクリックすると[Include][Excude]タブボタンと右横に[Add..][Edit...][Remove]ボタン
があるフォームが表示されます。また中央にListViewらしき部品があり「Everything」が選択されています。
これは、[Include]タブが選択された状態です。[Excude]タブ選択したときは、右横には[Add..]ボタンのみ操作
可能であり、ListViewには何も表示されていません。Edit Symol Search Policyボタンをクリックすると、以下のイメージのフォームが表示されます。
Search Path: フォルダ名指定できるテキストボックス フォルダ参照ボタン
on Wuery registry for symbol search paths
off Access symbol server
on Search the path specified in the Debug folder
off Look for the PDB in the application startup folder
-------------------------ここまでが、パラメータの説明------------------------
試しに、Profiling type をTracingにすると、A機能での12万件のデータを読み込む処理で1000件当た
り、約0.8S(感覚ですが1秒よりやや短いぐらいの時間)掛ってます。
通常は(Profileを使わないもしくは、Profile typeをSampling)の場合、12万件で約10秒ぐらいです。分析ロジックに遷移したとき、結構時間かかりそうだったので一度中断しました。
ここで、再度確認なのですが、みなさんは、どのような設定で試験しているのでしょうか?
-
プロファイリング中は収集データの粒度によりますが、まっとうなパフォーマンスなんて出ませんよ。処理内容によりますが、2倍から30倍ぐらいの時間はかかると思ったほうがよいです。
通常は、軽い収集で全体の目安を図っておいて、目的の部分のみを詳細に計測するものだと思います。(dotTrace であれば、目的の処理以外では、Drop Snapshot を押してとめておくか、起動時に同時に計測を開始しない設定にしておけばよいだけです) 今回の場合であれば、最初の4~5分かかるといわれている前処理は計測する必要はないでしょう。(その部分を調査したいのなら別ですが)
> みなさんは、どのような設定で試験しているのでしょうか?
パフォーマンス チューニングを全体的にやることは少ないので、私は (目的の機能だけを評価するので) dotTrace なら Line-By-Line しか使いません。
大雑把な計測で当たりをつけるってのは、慣れてくると感覚でわかるところでもありますし、詳細なデータを何パターンか取得しておいて、あとはそのデータを見ながら検討をするかんじの人は多いんじゃないでしょうか?
- 現状の計測 (データ1)
- データ1を見ながら改善パターンの検討 (プランA, B, C)
- プランA, プランB, プランB 個別の計測 (データ2,3,4)
- データ1 と データ2 を比較して、改善点や改悪点などの検証
- データ1 と データ3、データ1と4、データ2と3、データ2と4などの組み合わせも比較&確認
- 必要なら、A+B の状態での計測データなどを取る → 同様に過去のデータと比較
みたいなかんじかな~。修正内容の検討や、修正案の計測なんかは別の小さなプログラムでやって傾向をみてからプランとして取込むかどうかを考えるかんじで、まあデータとにらめっこしながら現状のコードや流れているデータ量を読んでアルゴリズムの最適化等を考えている時間がほとんどですね。
-
一応、メモリまわりを疑っていないわけではないですよ。しかし、現状で書かれている内容からは
- ページング容量や回数がたいした量ではない(仮想メモリの設定やドライバ関連、ディスクの空き容量などの条件が揃えば、ほんの少しのページングでも問題になることはありますが、除外してもよいかと)
- 選択操作で遅延するという話から、処理されているデータ量が書かれている通りなら、画面Bによって追い出されたメモリのページングが大きな遅延で発生したとしても、UIの応答レスポンスが悪化するとは考えられない。(ページインした処理データがページアウトしないため)
ということから、画面Cのロジックの実装ミスで、画面Bのデータ量に依存した計算処理が発生しているとしか判断できないです。(判断材料がそれ以上にないという話ですが)
画面Bがデータを処理しているときにイベントハンドラを登録していて、画面Cからそのイベントが多量に呼ばれているとか、画面Cのロジックだけみても気が付かない問題もありえます。(プロファイラをみればすぐにわかりますが)
- 回答の候補に設定 Jitta 2011年6月2日 8:03
-
EQATECを使用というのは全然だめ!
結果どうりというのは、期待したデータが採取されてたという意味でなくて、無料版だと2機能までしか採取できず。提示しても意味なし。もし利用したければ、お金よこせ!ってなメッセージ出てきました。
それで今は、DotTraceにてどっぶりと採取中です。ただこれも、8日ぐらいかな使えるのは、そのあとは、ソースに直接、Environment.TickCount を Debug.WriteLine など入れるしかないでしょうね と思ってます。
ただ、私としては、これだけ言われてもまだ、メモリがらみに原因があるの線は消えないのですよ!なまじ、機能およびロジックが頭に入っているせいか
あと、もうひとつ、ぱたーん2について遅くなる原因の想定としていくつかあげられましたが、どれも対象外ではないです。しいて言えば、C機能起動時には、ガベージ走ってます。ただこれが原因とは言えませんが。 -
追伸。もうひとつ仕様的なことで、説明を入れて起きなければならないと思いましたので、以下に記述します。
当初、B機能は、必要なメモリ解放を行わず、すべてメモリに常駐して処理してました。本番データ(つまり入力データ12万件)にたいして当機能を操作中に「out of memry」が発生しました。そこで、B機能を利用すべきA機能で派生生成したデータクラス(仮名クラス A-1)は分析派生したデータを外部ファイルにDOS形式で出力します。B機能でA-1クラスのデータを利用したい場合、A-1のクラスで一時的に出力したDOS形式のファイルを読み込みA-1の、読み込み専用プロパティとして取得できるように改造しました。その改造結果からの質問となります。
-
やっと、採取終わりました。採取結果は以下のURLをクリックしてください。
採取方法は、dotTrace の Line-By-Lineを指定して採取したものです。 なお、空白部分はパターンによって採取できなかったものです。( Line-By-Lineを指定しても、メソッドレベルで採取できないものもあるようです。一応イベントレベルでは採取できました)
以下urlの表の上段は、数回採取し、その平均を記述したものです。経過時間の多くは、collect(System.GC.Collect)に多く取られているようです。なお、C機能へ遷移するまえの、B機能で発行しているcollectは、数ミリ秒で終了しております。
下段のグラフは、B機能において取り込んだ件数と、C機能イベントレスポンス時間をグラフにしたものです。なお、折れ線グラフの最右端で下に折れている部分は気にしないでください。グラフ生成のバグのようです。結果的には、B機能において11万前後当たりから急激にレスポンスが悪くなるようです。話題となった4秒かかるときの状況は、グラフでいうところの290000~310000当たりを指します。
http://www.asahi-net.or.jp/~tn5h-fjsw/index.htm
なお、表中の表示で、名前が長くなり見づらくなるため以下の要領で短くしています。
Microsoft.VisualBasic.CompilerServices.Utils"
->"MSComp"
Microsoft.VisualBasic.CompilerServices.NewLateBinding.LateGet"
->"MsCompNewLateBindingLateGet"
(Object, Type, String, Object[], String[], Type[], Boolean[])"
->"(O,T,S,O[],S[],T[],B[])"
(String, Int32, Int32)"
->"(S,I32,I32)"
(Object, EventArgs)"
->"(O,E)"
System.Windows.Forms.ListView+ColumnHeaderCollection.Add(String, Int32, HorizontalAlignment)"
->"Sys,Coll.Add(S,I32,HA)"
Microsoft.VisualBasic"
->"MsVb"
(String, String, Int32, CompareMethod)"
->"(S,S,I32,Compare)"
(Object, Object[], String[])"
->"(O,O[],S[])"
System.Windows.Forms.ListView"
->"Sys.W.F.LstV"
System.Collections.Specialized.NameValueCollection"
->"Sys.C.S.NameValueColl"
System.Windows.Forms.ListBox"
->"Sys.W.F.ListBox" -
表の一番右側を見て…
1800msかかっているCommonAProject.GCtlAJ.Openが2回呼び出されているように見えますが必要なのでしょうか? 副作用がないのなら戻り値を保持しておいて使いまわすだけで所要時間は4秒から2秒に半減しそうです。
次にCommonAProject.GCtlAJ.Openの内訳ですが、
- CommonAProject.GCtlB.ReadBinf(String)
- CommonAProject.GCtlC.ReadBinf(String)
- CommonAProject.GCtlAJ.get_ReadAInf
にそれぞれ600msずつかかっているので、これについてはそれぞれのソースコードを見ないことには原因がわかりません。
-
重いと言われているのは以下のイベントを起点とする処理のことですか?
ListBoxA_SelectedIndexChanged
ListBoxB_SelectedIndexChanged
ListBoxC_SelectedIndexChanged
ListViewD_Clickこれらは、佐祐理さんも指摘されている CommonAProject.GCtlAJ.Open 以下を呼んでしまっています。
推測ですが、CommonAProject.GCtlAJ.Open 関数以下は B 画面や A 画面のデータ量によって所要時間(コスト)が変動するのでは?
実際、データ量が少ないと思われる表の左側は短時間で終わり、右側にいけばいくほど時間がかかるようになっています。これも佐祐理さんが言われていることですが、毎回、Open するんじゃなくてキャッシュするようにするしかないように思います。
私見:
示されたデータ量 vs メソッド別コストの表を見る限り、2011年5月15日 0:06 付けでの以下の発言の裏付けになりそうなデータに見えます。
「可能性があるとすれば、C 画面の表示パフォーマンスは、C 画面までに処理する件数に依存しているとか。
パターン 1 では B 画面時点で 380 件、パターン 2 では B 画面時点で 175,000 件であるため、もし、B 画面のデータ量が多いとパフォーマンスが悪化するロジックが C 画面に書かれていれば、遅くなることが想定されます。」
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。 -
重いと言われているのは以下のイベントを起点とする処理のことですか?
ListBoxA_SelectedIndexChanged
ListBoxB_SelectedIndexChanged
ListBoxC_SelectedIndexChanged
ListViewD_Clickこれらは、佐祐理さんも指摘されている CommonAProject.GCtlAJ.Open 以下を呼んでしまっています。
推測ですが、CommonAProject.GCtlAJ.Open 関数以下は B 画面や A 画面のデータ量によって所要時間(コスト)が変動するのでは?
実際、データ量が少ないと思われる表の左側は短時間で終わり、右側にいけばいくほど時間がかかるようになっています。これも佐祐理さんが言われていることですが、毎回、Open するんじゃなくてキャッシュするようにするしかないように思います。
佐祐理さんの回答も合わせて、ここで説明します。 ここは、2回読んでいるのではなく、継承されたクラスです。つまり公開されたopenに始まり、openのベースがopenb,openbを子として、さらにopencが継承基となっています。
openで、1874ms掛って、そのうち、OpenB で1237 掛っていると解釈してください。右のネストがそれを表しています。 結果的に経過時間を食っているのは最下層のメソッドになります。
最初のほうで少し機能説明していますが、上段の左、中、中央の関係で、一番左をクリックしたとき、左のクリックした内容 が属する情報を中央のビューに表示します。このとき、中央に存在しなく、右に表示すべき情報が存在するケースがあります。 これをチェックするため、最初のオープンで中央に表示すべき情報を検索、右に表示すべき情報の検索(openB)という具合にopenしていきます。さらに、openC、openDと続きます。なので無駄に同じファイルを読んでいることではないのです。
少し、説明が難しいのですが、たとえば、住所を例にとって説明します。 住所は、大まかに都道府県、市群、区町村、番地からなっています。 ある都道府県を選択した場合、都道府県直下には、市がありますが、市が存在しないで村もあります。また、ある特定の群を指定した場合、町村も存在するが、町村がなくいきなり番地のみがあるものもあります。このときの、都道府県が最初のopen、市群に対応するのが、openBというふうに関連ずけされています。
私見:
示されたデータ量 vs メソッド別コストの表を見る限り、2011年5月15日 0:06 付けでの以下の発言の裏付けになりそうなデータに見えます。
「可能性があるとすれば、C 画面の表示パフォーマンスは、C 画面までに処理する件数に依存しているとか。
パターン 1 では B 画面時点で 380 件、パターン 2 では B 画面時点で 175,000 件であるため、もし、B 画面のデータ量が多いとパフォーマンスが悪化するロジックが C 画面に書かれていれば、遅くなることが想定されます。」仮にそうだとするならば、グラフでは、もっと比例的になだらかに線が右肩上がりに表示されると思います。
何故、110000万件当たりから、急激なカーブとなることが疑問となります。 さらに、細かく数値を見ますと、入力データ取得後についてのメソッドについてさほど、経過時間が多く消費されていません。 また、表示中の例として get_SplitStr とか、LateGet についてのcall数のところは、件数に応じて、件数の変動がありません。これは読み込んだデータに対して処理しているメソッドですが同じデータ量を処理していることが証明されます。
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。
-
ここは、2回読んでいるのではなく、継承されたクラスです。つまり公開されたopenに始まり、openのベースがopenb,openbを子として、さらにopencが継承基となっています。
AProject.FormFEList.ListBoxA_SelectedIndexChanged(O,E)がAProject.ViewFEList.SelectA(Int32)を呼びその中で
AProject.ViewFEList.ViewInitBList
→CommonAProject.GCtlAJ.Open
AProject.ViewFEList.ViewInitCList
→CommonAProject.GCtlAJ.Openと2回呼んでいますが。2回実行する必要があるかどうかを検討する必要があります。 継承だろうがなんだろうが実行しているという事実が重要です。
私の挙げた3つのメソッドはいずれも600ms程度かかり、2回ずつ呼ばれているので 600ms * 6 = 3600ms 要しています。この3つがそれぞれ原因となっています。なぜ600ms要するのかは各メソッド内を再度詳細にプロファイルすることです。もしくはこの辺りまでくればソースコードを読むことで原因がわかるかもしれないので貼ってみてください。
- 回答の候補に設定 Jitta 2011年6月2日 8:02
-
ここは、2回読んでいるのではなく、継承されたクラスです。つまり公開されたopenに始まり、openのベースがopenb,openbを子として、さらにopencが継承基となっています。
AProject.FormFEList.ListBoxA_SelectedIndexChanged(O,E)がAProject.ViewFEList.SelectA(Int32)を呼びその中で
AProject.ViewFEList.ViewInitBList
→CommonAProject.GCtlAJ.Open
AProject.ViewFEList.ViewInitCList
→CommonAProject.GCtlAJ.Openと2回呼んでいますが。2回実行する必要があるかどうかを検討する必要があります。 継承だろうがなんだろうが実行しているという事実が重要です。
私の挙げた3つのメソッドはいずれも600ms程度かかり、2回ずつ呼ばれているので 600ms * 6 = 3600ms 要しています。この3つがそれぞれ原因となっています。なぜ600ms要するのかは各メソッド内を再度詳細にプロファイルすることです。もしくはこの辺りまでくればソースコードを読むことで原因がわかるかもしれないので貼ってみてください。
すいません、勘違いしてました。2回よんでますが、いずれも、別のものをもってくる仕様です。
つまり、「AProject.ViewFEList.ViewInitBList →CommonAProject.GCtlAJ.Open」こっちでは、 ViewInitBに表示させるものを取り込んでいます。AProject.ViewFEList.ViewInitCList →CommonAProject.GCtlAJ.Openこちらのほうは、ViewInitCList に表示させるための情報を取得しています。ちなみに、openは、ファイルオープンという意味ではないです。あくまでも、どのファイルを読むべきか特定するだけの処理です。また、現在、ReadBinfの下位のメソッドで、インスタンスを解放しているためViewInitBでは、情報を取得することができない仕様です。ただ、読み込み時間にこんなに時間を必要としていること自体が問題と思います。600msの内、そのほとんどが、collectに時間を費やされていることに注目してください。
プロファイルについは、残念ながらこれ以上詳しくでないようでした。なお、期限切れのため再度確認することは不可能です。
-
仮にそうだとするならば、グラフでは、もっと比例的になだらかに線が右肩上がりに表示されると思います。
何故、110000万件当たりから、急激なカーブとなることが疑問となります。 さらに、細かく数値を見ますと、入力データ取得後についてのメソッドについてさほど、経過時間が多く消費されていません。 また、表示中の例として get_SplitStr とか、LateGet についてのcall数のところは、件数に応じて、件数の変動がありません。これは読み込んだデータに対して処理しているメソッドですが同じデータ量を処理していることが証明されます。
あまり詳しく見てませんけど、11万件で急激なカーブになってるのは横軸がそういう取り方になってるだけな気がしますが…
また、遅い部分の処理に関して件数に依存してるのではという話で、遅くなっていない部分を取り出してここは遅くなっていないから件数に依存していないと言ってみたところで意味はないように思います。それはさておき、GCで異常に時間がかかっていますね。このGCは、プログラムから明示的に実行しているものですか?どうもそのように見えますが。
明示的に実行している場合、このGCは必要なものですか?何のために実行しているものでしょうか?
オブジェクト数が増えれば、GCにかかる時間が長くなるのは当たり前です。ただ、ちょっとかかりすぎな感じはしたりもしますが、これはオブジェクト間の参照状況によって大きく変わる場合があるので何とも言えません。- 回答の候補に設定 Jitta 2011年6月2日 8:02
-
>あまり詳しく見てませんけど、11万件で急激なカーブになってるのは横軸がそういう取り方になってるだけな気がしますが…
横軸の増幅は、均等にしてますよ!>また、遅い部分の処理に関して件数に依存してるのではという話で、遅くなっていない部分を取り出してここは遅くなっていないから件数に依存していないと言ってみたところで意味はないように思います。
基本的に、利用しているデータはB機能とC機能では全く異なるものなので、データそのものとは関係ないと思います。
>それはさておき、GCで異常に時間がかかっていますね。このGCは、プログラムから明示的に実行しているものですか?どうもそのように見 えますが。
その通りです。GCは明示的に指定してます。明示的に実行している場合、このGCは必要なものですか?何のために実行しているものでしょうか?
不要な領域にnothingをいれて、明確にメモリを空けるために使用しています。>オブジェクト数が増えれば、GCにかかる時間が長くなるのは当たり前です。ただ、ちょっとかかりすぎな感じはしたりもしますが、これはオブ>ジェクト間の参照状況によって大きく変わる場合があるので何とも言えません。
どれぐらい増えるのが一般的なのでしょうか? B機能でもGCを明示的に記述していますが、およそ1ms程度で終了しています。
C機能で仮に、 参照しているオブジェクトが仮に50個増えたとして、600倍、1000倍になるような代物なのでしょうか?今回初めて多様しているのでそのへんがどうも解らないのですが?
GCというのは、今参照している全てのオブジェクトに依存しているものについて関係があると思うのですが(C機能だけでなく)仮に今、B機能において300個のオブジェクトが参照され、C機能にて50個新たに参照され合計で350個参照されたと仮定します。この場合、同じように600~1000倍にGCの経過時間が変わることがあり得るのでしょうか?
-
>あまり詳しく見てませんけど、11万件で急激なカーブになってるのは横軸がそういう取り方になってるだけな気がしますが…
横軸の増幅は、均等にしてますよ!均等にしてはだめでしょう。
グラフはあくまで視覚的に傾向を捉えるためのツールなので、11 万件と 27 万件の間を削ってくっつけた(項目で均等にした)グラフでは傾向を見ることができません。
折れ線よりも散布図の方がよいのではないでしょうか。例:
http://azulea.files.wordpress.com/2011/05/image.png
9 万、10 万、11 万と比例的に増加(y = 2x)するデータを 12 万~ 26 万の部分を意図的に削除したデータにしました。(画像上左上の数値群)
このデータを折れ線でプロットしたものを上に、同じデータを散布図でプロットしたものを下に掲載しています。折れ線は特に設定していないので、データの欠けたところを気にせずそのまま項目ごとに並べてしまっている(軸上で数値が飛んでいる)ので、急激な増加に見えますが、これは軸を削ったことによって起きたものなので傾向を見るために使えない状態です。
他方、散布図はデータがとれた点をプロットしているので、なんとなく比例の線を思い浮かべることができそうですよね。-----
途中まで単調増加ですが、30 万件近辺からデータ数によらない何かに依存しているようにも見えます。
http://azulea.files.wordpress.com/2011/05/graph20110529.jpgまずは単調増加する部分をなんとかしていくことからでしょうか。
// MSDN フォーラムに画像はおけないので、一時的に上記のサイトに置いていますが、支障がある場合はご指摘ください。
// 数値以外の情報はなるべくとれないようにしているつもりですが…。
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。 -
>あまり詳しく見てませんけど、11万件で急激なカーブになってるのは横軸がそういう取り方になってるだけな気がしますが…
横軸の増幅は、均等にしてますよ!均等にしてはだめでしょう。
グラフはあくまで視覚的に傾向を捉えるためのツールなので、11 万件と 27 万件の間を削ってくっつけた(項目で均等にした)グラフでは傾向を見ることができません。
折れ線よりも散布図の方がよいのではないでしょうか。例:
http://azulea.files.wordpress.com/2011/05/image.png
9 万、10 万、11 万と比例的に増加(y = 2x)するデータを 12 万~ 26 万の部分を意図的に削除したデータにしました。(画像上左上の数値群)
このデータを折れ線でプロットしたものを上に、同じデータを散布図でプロットしたものを下に掲載しています。折れ線は特に設定していないので、データの欠けたところを気にせずそのまま項目ごとに並べてしまっている(軸上で数値が飛んでいる)ので、急激な増加に見えますが、これは軸を削ったことによって起きたものなので傾向を見るために使えない状態です。
他方、散布図はデータがとれた点をプロットしているので、なんとなく比例の線を思い浮かべることができそうですよね。-----
途中まで単調増加ですが、30 万件近辺からデータ数によらない何かに依存しているようにも見えます。
http://azulea.files.wordpress.com/2011/05/graph20110529.jpgまずは単調増加する部分をなんとかしていくことからでしょうか。
// MSDN フォーラムに画像はおけないので、一時的に上記のサイトに置いていますが、支障がある場合はご指摘ください。
// 数値以外の情報はなるべくとれないようにしているつもりですが…。
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。
単純に、表示しているデータを線でつないでも、その増加傾向は見れないですよ。何故なら、その要所要所で1件当たりに掛る所要時間が異なっているので、測定した件数に近いところは、その比率で均等に配分した件数毎に計算して予測しないとだめですよ -
-
http://social.msdn.microsoft.com/Forums/ja-JP/netfxgeneralja/thread/918454ed-9cac-4a3a-9143-a875d88a864a
質問スレッドで解決した場合は、解決の参考になった投稿に対して「回答としてマーク」のボタンを押すことで、同じ問題に遭遇した別のユーザが役立つ投稿を見つけやすくなります。