コグノスケ


link 未来から過去へ表示(*)  link 過去から未来へ表示

link もっと前
2014年8月26日 >>> 2014年8月26日
link もっと後

2014年8月26日

hprofプロファイラ

Javaのhprofというプロファイラは、準備を必要とせず(JDK標準だから)に、CPU、ヒープ、モニタの衝突など、一通り測れる便利なプロファイラです。

特に各メソッドのカウントを「全て取る」モード(-Xrunhprof:cpu=times)は、明らかに呼び過ぎのメソッドが一発で分かるため、大変に便利です。

しかし便利な反面、実行速度が下がりすぎて使い物にならなくなる場合があります。

今日遭遇したケースは、7MBのファイルをDataInputStreamからreadByte() するプログラムです。通常のデバッグ実行であれば、ほんの一瞬で終わりますが、cpu=timesでプロファイリングすると10分経っても終わりません…。

どうも、細かいメソッドが頻繁に呼ばれすぎるせいで、メソッド呼び出しのカウントを行う部分がパンクしているようです。

思い出してみればInputStream系はInputStream -> BufferedInputStream -> DataInputStreamなどのように連鎖させるのでメソッド呼び出しが深く、データをロードするという処理はループ回数が多くなりがちなので、深さ×ループ回数の掛け算に比例してどんどん遅くなってしまいます。

これはよろしくありません。

頑張って軽くするには

待てるくらいの時間に収まるように、何とか軽くしてみましょう。

まず目を付けたのはreadByte() です。readByte() で1バイトつずつ読むから呼び出しカウントが多くなるわけです。ならばreadLong() で8バイトずつ読めばカウントは1/8です。

コードもちょい変えで済むし、お手軽高速化としては、プロファイリング時の実行速度もほぼ8倍になる、という中々の効果です。

しかしreadLong() を持ってしても100MBオーバーとなると厳しいでしょう。もし本当にそこまで必要なら、根底から覆す(InputStreamを使わないとか)別の手立てを考える必要がありそうです。

編集者:すずき(2014/08/26 03:15)

コメント一覧

  • IKeJIさん(2014/08/26 17:13)
    BufferedInputStreamのうしろは何回もは呼ばれないのでは?
  • すずきさん(2014/08/26 21:43)
    >IKeJI さん
    そうか、確かに BufferedInputStream 以降はあまり呼ばれないから、BufferedInputStream のバックエンドは呼び出し回数にほとんど関係無いですね。すみません、間違ってました。

    ただ BufferedInputStream 自体が結構遅くて、readByte() だとつらいという点は変わりません。
    試しに DataInputStream(new BufferedInputStream(new FileInputStream())) に対して、readLong() で 30万回読みだしてみますと、

    count : method
    307547 : java.io.BufferedInputStream.read
    307547 : java.io.DataInputStream.readLong
    307547 : java.io.DataInputStream.readFully
    307567 : java.io.BufferedInputStream.read1
    307568 : java.io.BufferedInputStream.getBufIfOpen
    307894 : java.io.BufferedInputStream.getBufIfOpen
    301 : java.io.FileInputStream.read
    3584 : java.io.BufferedInputStream.read
    301 : java.io.BufferedInputStream.fill

    こんな感じになっていて、getBufIfOpen がプロファイリングを激しく邪魔します。
  • IKeJIさん(2014/08/27 00:42)
    なるほど。
    その辺のprivateなメソッドはインライン展開できそうなもんですが、何かできない理由があるんですかね?
    BufferedInputStream.readをfinalにしたら早くなるんだろうか?
  • すずきさん(2014/08/27 02:09)
    >IKeJI さん
    BufferedInputStream をコピーした OreBufferedInputStream を作って、read を final にして試してみました。

    (final にする前)
    count method
    616787 net.katsuster.semu.arm.OreBufferedInputStream.read
    616787 java.io.DataInputStream.readFully
    616787 java.io.DataInputStream.readLong
    616787 net.katsuster.semu.arm.OreBufferedInputStream.read1
    616787 net.katsuster.semu.arm.OreBufferedInputStream.getBufIfOpen
    617390 net.katsuster.semu.arm.OreBufferedInputStream.getBufIfOpen
    603 java.io.FileInputStream.read
    2 java.io.FileInputStream.<init>
    3584 java.io.BufferedInputStream.read
    896 java.io.DataInputStream.readInt
    3584 java.io.BufferedInputStream.getBufIfOpen

    (final にした後)
    616787 net.katsuster.semu.arm.OreBufferedInputStream.read
    616787 java.io.DataInputStream.readFully
    616787 java.io.DataInputStream.readLong
    616787 net.katsuster.semu.arm.OreBufferedInputStream.read1
    617390 net.katsuster.semu.arm.OreBufferedInputStream.getBufIfOpen
    616787 net.katsuster.semu.arm.OreBufferedInputStream.getBufIfOpen
    603 java.io.FileInputStream.read
    3584 java.io.BufferedInputStream.getBufIfOpen
    2 java.io.FileInputStream.<init>
    896 java.io.DataInputStream.readInt

    速度も変わらないですね。
  • IKeJIさん(2014/08/27 13:32)
    DataInputStreamがOreBufferedInputStreamをInputStreamとして扱っているからでしょうか?
  • すずきさん(2014/08/28 10:11)
    >IKeJI さん
    もしかして JIT でインライン展開されようとされまいと、関数呼び出しカウントは行われるんじゃないですかね?
    BufferedInputStream.read が遅いわけではないので、単にカウントが遅いのでは。
  • IKeJIさん(2014/08/28 14:26)
    そうですが、プロファイルしない時の実行速度はあがるのでは? > 関数呼び出しカウントは行われる
  • すずきさん(2014/08/29 17:02)
    >IKeJI さん
    プロファイルするときと、しないときとで、JIT の動作が変われば、インライン展開されそうなメソッドなのに、プロファイラにカウントされる理由が付きますかね…?
    うーむ、でも自分で書いておいてなんですが、そこまでやらないよな…さすがに…。
open/close この記事にコメントする



link もっと前
2014年8月26日 >>> 2014年8月26日
link もっと後

管理用メニュー

link 記事を新規作成

<2014>
<<<08>>>
-----12
3456789
10111213141516
17181920212223
24252627282930
31------

最近のコメント5件

  • link 21年3月13日
    すずきさん (03/05 15:13)
    「あー、このプログラムがまずいんですね。ご...」
  • link 21年3月13日
    emkさん (03/05 12:44)
    「キャストでvolatileを外してアクセ...」
  • link 24年1月24日
    すずきさん (02/19 18:37)
    「簡単にできる方法はPowerShellの...」
  • link 24年1月24日
    KKKさん (02/19 02:30)
    「追伸です。\nネットで調べたらマイクロソ...」
  • link 24年1月24日
    KKKさん (02/19 02:25)
    「私もエラーで困ってます\n手動での回復パ...」

最近の記事3件

  • link 24年3月25日
    すずき (03/26 03:20)
    「[Might and Magic Book One TASのその後] 目次: Might and Magicファミコン版以前(...」
  • link 21年10月4日
    すずき (03/26 03:14)
    「[Might and Magicファミコン版 - まとめリンク] 目次: Might and Magicファミコン版TASに挑...」
  • link 24年3月19日
    すずき (03/20 02:52)
    「[モジュラージャックの規格] 古くは電話線で、今だとEthernetで良く見かけるモジュラージャックというコネクタとレセプタク...」
link もっとみる

こんてんつ

open/close wiki
open/close Linux JM
open/close Java API

過去の日記

open/close 2002年
open/close 2003年
open/close 2004年
open/close 2005年
open/close 2006年
open/close 2007年
open/close 2008年
open/close 2009年
open/close 2010年
open/close 2011年
open/close 2012年
open/close 2013年
open/close 2014年
open/close 2015年
open/close 2016年
open/close 2017年
open/close 2018年
open/close 2019年
open/close 2020年
open/close 2021年
open/close 2022年
open/close 2023年
open/close 2024年
open/close 過去日記について

その他の情報

open/close アクセス統計
open/close サーバ一覧
open/close サイトの情報

合計:  counter total
本日:  counter today

link About www.katsuster.net
RDFファイル RSS 1.0

最終更新: 03/26 03:20