プログラムの事とか

お約束ですが「掲載内容は私個人の見解です」

トラブルシューティングゲーム

今回は実際に実務行った調査の流れをざっくりと書いてみようとおもいます

実務なので詳細は書けませんが(関係者にこのブログを捕捉される恐れもあるし)、私はこんな感じで原因を探したよというメモ的なやつ(今回の調査で新しい知識も得たので)

このブログが誰かの助けになったらさいわいです

構成

サーバー+クライアントの2台構成で、サーバーには常時起動のサービスが複数とWebアプリ(IIS)

サーバーにはそれ以外に他社製の何かも入っている模様

サーバーOSもハードも不明(OSはたぶんServer 2016、ハードは小さい奴らしい)

クライアントPCは今回関係ないので割愛

第一報

サーバーが応答しない

常駐アプリを作っている人でこんな報告が来た時に「私は悪くない」といえる人が世の中に何人いるでしょうか?

テスト環境でいくらヒートランしてもしょせんテスト環境だからね、実環境では何が起こるかわからないよね

続報

  • サーバーへのPINGも失敗

ということでサーバーがOSごと落ちているっぽいです

  • 数日前にも同様の現象があったらしい

再現性があるのはいいことですね (白目

再現させるよ

実環境ではいろいろなことができないので(納品したものだし)何とかテスト環境で再現させます

といっても私はソフト担当なのでハードの調達とか再現テストとかは全部ほかの人任せ。さっさと再現させてよ~的なスタンスです

可能な限り実環境と同じ条件で動かしたらめでたく再現してくれました。これで調査がはかどるね

まぁ再現しなかったら「気のせいじゃね?」で終わらせるんですが

まずはログを見よう

こんなこともあろうかと私のアプリはちゃんとログを吐いているので収集してもらいます (当たり前)

OSが逝っているのでWindowsのイベントビューアーのログも収集してもらいます

ログを見た

自分で出しているログではネットワーク系のエラーが大量に (redisとかHttpClientとか)。例外の内容はリソース不足

イベントビューアーのシステムログではIISのリサイクルがリソース不足で失敗、がたくさんでて徐々にいろんなのがリソース不足で失敗して最後におなくなりになってました

リソース不足とは

メモリの空きがなくなったかハンドルの空きがなくなったか、どっちかですかね?

最近ハンドル不足って聞かないのでメモリ不足(メモリリーク)の線で調査します

再現する環境ができると数日に1回OSが亡くなるので情報収集もらくちんちんです

パフォーマンスモニタで収集してもらう

とりあえず空きメモリと作ったプロセスの使用メモリと.Net系のメモリのカウンタと、あとは再現させるのだるいのでそれっぽいものいろいろまとめて収集してもらいました

f:id:puni-o:20180511110604j:plain

どんどん減っているのが空きメモリです

右肩上がりなのはGCの回数たち。 空きメモリが少なくなったら必死にGCで空きを作ろうとしているけなげな様子がうかがえます (かわいいやつよ

ということで空きメモリが無くなってOSが止まってしまったことは間違いなさそうです

ところが我々の入れたアプリには空きメモリを食いつぶすほどのメモリを使っているものがいませんでした

スナップショット的な情報が欲しい

パフォーマンスモニタの結果を見ると線形的にメモリが食われているのがわかります

ということである程度動かした状態でシステムの情報を見れば原因が分かるかもしれません

とりあえずリソースモニターのメモリタブの情報をとってもらいました

使途不明メモリ??

全プロセスの使用メモリの合計と使用中メモリの合計が全然合いませんでした。なんだこれ?

ドライバーなんかがリークしてる???という疑惑が出てきたので

technet.microsoft.com

このアプリで情報収集してもらいました (私の環境では落ちて情報取れないんですが、収集したファイルは見ることができるので)

収集したファイルをRamMapで開いてProcessesタブを見てみると・・・

f:id:puni-o:20180511112353j:plain

プロセスがいっぱいあるよぉぉぉぉ~~~~~

上のスクショではcmd.exeがたくさんありますね。数万行cmd.exeが続きます。PIDも普段見ない桁になってますね。楽しいですね

cmd.exeのほかにはPING.exeやRoboCopy.exeなんかもたくさんありました

タスクマネージャーで見てもこんなにたくさんのプロセスはいないので (いたらさすがに気づくよね) いわゆるゾンビプロセスというやつらですね

このへんで担当者から聞いたのですが、batファイルで定期的にコピーやPINGを実行しているらしいです。上のゾンビたちはその残骸ですね。

ゾンビさがし

どうやらゾンビプロセスたちがメモリを食いつぶしていたようですね (一つは20kくらいですが塵も積もれば山となる)

今度はゾンビに関する情報収集です

Zombie Processes are Eating your Memoryrandomascii.wordpress.com

この中ではCreateProcessのハンドル閉じないとリークするよー的なことが書いてあったような無かったような・・

そこで紹介されている

github.com

このプログラムがゾンビを探してくれます。C#で簡潔に書かれているのでわかりやすいです

FindZombieHandles

85013 total zombie processes.
    170014 zombies held by (4)
        49164 zombies of \Device\HarddiskVolume4\Windows\SysWOW64\Robocopy.exe
        49164 zombies of \Device\HarddiskVolume4\Windows\SysWOW64\cmd.exe
        24582 zombies of \Device\HarddiskVolume4\Windows\System32\PING.EXE

わーい、たくさんみつかったよぅ~~

held by (4) はPID 4の人が持っているハンドルで、PID 4はsystemさんですよね・・・

試しに何か立ち上げて終了してみる

メモ帳立ち上げて終了を数十回繰り返すと

48 zombies of \Device\HarddiskVolume5\Windows\System32\notepad.exe

全部残ってる!!!!

あとは任せた

呼吸するだけで太るような状態のシステムで我々はいったい何ができるのだろうか?

ということであとはサポートにぶん投げて終了 (現象が発生するのは特定のハードだけだったので)

自分が原因でないトラブルは他人事っぽい感じで関われるからたのしいね (楽しくない

Windows 10 April 2018 Update (1803) に関するあれこれ

体験談でしかなく裏取りは相変わらずしていないのであしからず

入れたPC

今のところLaptop以外は問題なさそう

Laptopは

からのWindows 10 Sから入れ直し→1803でUEFI突入であきらめてサポートとチャット

サポートさんに

answers.microsoft.com

を教えてもらい1709に戻して使用中

という久々にトラブルシューティングゲームして楽しかった(楽しくなかった

他のPCはインテルSSDが高いからほかのにしてたおかげて助かったのか?

最近のアップデートは優秀でこんな感じの異常はPreview時に全部見つかっていると思い込んでいたのが敗因ですね(すっかりハードの異常だと思って交換する気満々でした)

IEの動作が変わった?

これはVisual Studio 2017側かもしれません

  • ソリューションに複数のWebプロジェクトを入れておく
  • デバッグ時に立ち上がるブラウザはIE
  • デバッグをマルチスタートアップにして両方起動する

って感じにしておいた場合、今まではIEがそれぞれ立ち上がっていたんですが、今はIE一つが立ち上がって一つのタブに両方表示しようとします(結果的に遅い方のページが表示される)

なんか昔こんな感じの動作への切り替えがはやったような気がしますがすでに過去の事なので(新しく立ち上げるのか既存に突っ込むのかっていう、あの・・・何とかって技術)

まぁWebサービス (IIS Expressで立ち上がるやつ)は両方立ち上がっているので問題ないですし、そもそも複数のWebプロジェクトを同時にデバッグとか私以外にいないんじゃないかという感じなので気にしない

まとめ

みんな早くアップデートするといいよ (とくにSurface勢)

WPFで速い描画方法が知りたい!

WPFで描画処理書いていてもっと速く描きたい!(ていうか自分の書いた処理遅い!)ということで実験を兼ねてプロジェクト作ってあわよくばすごい人に速い方法教えてもらおう!

プロジェクトはこちら

github.com

簡単な説明

class CustomDrawControl : FrameworkElement
{
    protected override void OnRender(DrawingContext drawingContext)
    {
        base.OnRender(drawingContext);

        switch (DrawType)
        {
        case DrawType.NotFreeze:
        case DrawType.Freeze:
        case DrawType.Grouping:
        case DrawType.BackingStore:
        }

        _counter++;
        Task.Run(async () =>
        {
            await Task.Delay(1);
            await Dispatcher.BeginInvoke((Action)this.InvalidateVisual);
        });
    }
}

こんな感じでOnRender内でいろんな方法で描画してみてFPSを確認してみます

FPSの算出方法間違ってるとかそもそもOnRender使っちゃダメとかそういう突っ込みあったら教えてください)

描画はフレーム毎に色が変わるペン(パレットは8色)で点(短い線)をたくさん描きます

計測

最大FPS

何も描かないで上の処理のようにOnRenderTask.Delay(1) -> InvalidateVisual()ってやるだけで大体64fpsでした

f:id:puni-o:20180411131559j:plain

もっと速くなると思っていたのでこの再描画方法がそもそも間違っているんじゃないか疑惑が・・・

FreezableをFreezeした場合としなかった場合

遅い → Freeze()シロ っていう流れはググるとよく出てくるので実際に比較してみました

Freezeしない

f:id:puni-o:20180411131908j:plain

最大で 20 fps くらい

Freezableな奴を片っ端からFreezeする

f:id:puni-o:20180411131923j:plain

最大 64 fps

Freezeシロ

点の数は3000個で実験したのですがここまで差が出るとは

ちゃんとFreezeしようね


3パターンで計測

本番

ですがネット調べたけど私には3パターンしか見つけられませんでした

ここからは点の数を10000個で実験です


2018/4/12

デバッグビルドで計測していたり、一つは完全に間違った処理だったりなので以下はスクショ入れ替えてます


1点ずつ描画

private void FreezeRender(DrawingContext drawingContext)
{
    foreach (var p in _particles)
    {
        drawingContext.DrawLine(penList[p.Pallete], new Point(p.X1, p.Y1), new Point(p.X2, p.Y2));
    }
}

こんな感じで描きます(余計なの消しているので全部見たければGitHubからどうぞ)

f:id:puni-o:20180412103100j:plain

結果は50 fpsちょいでした

パレット毎にまとめて描画

パスはGeometryにまとめて描画した方が速いみたいな書き込みをみたので、パレット毎に一気に描画してみます

private void GroupingRender(DrawingContext drawingContext)
{
    foreach (var g in _particles.GroupBy(p => p.Pallete))
    {
        var geometry = new StreamGeometry();
        using (var context = geometry.Open())
        {
            foreach (var p in g)
            {
                context.BeginFigure(new Point(p.X1, p.Y1), false, false);
                context.LineTo(new Point(p.X2, p.Y2), true, false);
            }
        }
        drawingContext.DrawGeometry(null, penList[g.Key], geometry);
    }
}

余計なの消していますが(以下略

f:id:puni-o:20180412103124j:plain

60 fps以上出ているのでまだ余裕がありそうです(UIの操作が普通にできるので)

ダブルバッファリング?

DrawingGroup作ってそっちに描いてOnRender時はそれを描け的なことを見かけたので実験

昔懐かしのダブルバッファリングなのだろうか?

readonly DrawingGroup _backingStore = new DrawingGroup();
private void BackingStoreRender(DrawingContext drawingContext)
{
    var context = _backingStore.Open();
    foreach (var p in _particles)
    {
        context.DrawLine(penList[p.Pallete], new Point(p.X1, p.Y1), new Point(p.X2, p.Y2));
    }
    context.Close();
    drawingContext.DrawDrawing(_backingStore);
}

f:id:puni-o:20180412103226j:plain

10 fpsくらい

backingStore使って~っていうのは多分こういう使い方じゃないんだよね(OnRenderで事前に描画しておいたのを表示とかそういう使い方かな?)

まとめて描画できるならまとめよう

とりあえずまとめて描けるならまとめた方が速そう


2018/4/16 追記

  • FPSCompositionTarget.Renderingで測るみたいなのでそっちに移しました

  • DrawType.WriteableBitmapを追加しました

スクショとかないけど一番速かったです

雑な測定結果はGitHubの方にまとめてあるのでそちらを参照ということで・・・


まとめ

WPFの便利なもろもろを使いつつ速い描画を求めるならWriteableBitmapになるんですかね?

これより速そうなのだとDirectXくらいしか思いつかないんですが、それだと自由度が無くなりすぎだと思うんですよね(透過できないのが痛い)