Squeak: 文字列の連結とストリームとカンマ・メッセージと VWNC 驚嘆爆速

地味〜で初歩的な話です (笑)．あ，あと，クソ長いッす．

ストリームとカンマ・メッセージによる比較

デバッグ出力や自前のロギングとかで大量の文字列コピーを行うときは，ストリームを使う方が佳さ気というお馴染みのお話．文字列の連結には , メッセージよりストリームを使えという格言があったと思うんだが，ほんとだったっけ．というわけで，単純な例で速度を比較してみた． vm は 4.2.2beta1U， vi は 3.10.2 web++，マシンは 2.66GHz Core 2 Duo 4GB 1067MHz の MBP 二代目バーバラたん．あと， VWNC 7.6[VWNC 7.7 はまだですか？] でもやってみたので，ソースはできるだけ似るように書いてみたが，あまりの速さに唖然 (笑)．結果は以下のとおり．そうそう， VWNC には MessageTally がないので，代わりに JunMessageSpy を使ってる．

String concatinating comparing stream with comma.

environment	comma pattern	stream pattern
4.2.2beta1U / sq3.10.2-7179web09.07.1.J.3	246 msec	87 msec
VWNC 7.6	105 msec	爆速！→ 29 msec

Squeak 版， 3 倍の開きがあるとは言え， 10000 回だけ回して差がおよそ 160 msec なら，あんま変わらんじゃん．それよりも VWNC は速すぎるだろ！ (笑)　ちょい古いオーディオ機器に例えると， VWNC はノッティンガム・アナログ・スタジオの Hyper Spacedeck 辺りのガチガチでハイ・スピードなアナログ・プレイヤーで， Squeak はレガやメリディアン， Linn 辺りのコンパクト・サイズのカジュアルな CD プレイヤーって感じスかね． B&O のコンソレットかな． Squeak 版ソース[Squeak 版ソース：

    | iterationNumber commaBlock string streamBlock |    "Stringのクラス・メソッドを使ってないのは VWNC と合わせるため"    iterationNumber := 10000.    commaBlock :=     [ iterationNumber timesRepeat:             [string := ''.            string := string , '1 string to be copied. '                , (String with: Character cr) , '2 string to be copied. '                , (String with: Character cr) , '3 string to be copied. '                , (String with: Character cr) , '4 string to be copied. '                , (String with: Character cr) , '5 string to be copied. '                , (String with: Character cr) , '6 string to be copied. '                , (String with: Character cr) , '7 string to be copied. '                , (String with: Character cr) , '8 string to be copied. '                , (String with: Character cr) , '9 string to be copied. '                , (String with: Character cr) , '10 string to be copied. '                , (String with: Character cr) , (String with: Character cr)]].    Smalltalk garbageCollectMost.    Transcript        cr;        show: (Time millisecondsToRun: [ commaBlock value ]) printString.    MessageTally spyOn: [ commaBlock value ].    streamBlock :=     [ iterationNumber timesRepeat:         [ | s |        s := WriteStream on: (String new: 1000).        s nextPutAll: '1 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '2 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '3 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '4 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '5 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '6 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '7 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '8 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '9 string to be copied. '.        s nextPut: Character cr.        s nextPutAll: '10 string to be copied. '.        s nextPut: Character cr.        s nextPut: Character cr.        string := s contents ] ].    Smalltalk garbageCollectMost.    Transcript        cr;        show: (Time millisecondsToRun: [ streamBlock value ]) printString.    MessageTally spyOn: [ streamBlock value ]

]， VWNC 版ソース[VWNC 版ソース：

    | iterationNumber commaBlock string streamBlock |    iterationNumber := 10000.    commaBlock := [iterationNumber        timesRepeat:            [string := ''.            string := string , '1 string to be copied. '                , (String with: Character cr) , '2 string to be copied. '                , (String with: Character cr) , '3 string to be copied. '                , (String with: Character cr) , '4 string to be copied. '                , (String with: Character cr) , '5 string to be copied. '                , (String with: Character cr) , '6 string to be copied. '                , (String with: Character cr) , '7 string to be copied. '                , (String with: Character cr) , '8 string to be copied. '                , (String with: Character cr) , '9 string to be copied. '                , (String with: Character cr) , '10 string to be copied. '                , (String with: Character cr) , (String with: Character cr)]].    ObjectMemory garbageCollect.    Transcript        cr;        show: (Time millisecondsToRun: [commaBlock value]) printString.    JunMessageSpy        spy: [commaBlock value]        often: 5        omit: 0.001.    streamBlock := [iterationNumber        timesRepeat:            [| s |            s := WriteStream on: (String new: 1000).            s nextPutAll: '1 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '2 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '3 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '4 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '5 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '6 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '7 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '8 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '9 string to be copied. '.            s nextPut: Character cr.            s nextPutAll: '10 string to be copied. '.            s nextPut: Character cr.            s nextPut: Character cr.            string := s contents]].    ObjectMemory garbageCollect.    Transcript        cr;        show: (Time millisecondsToRun: [streamBlock value]) printString.    JunMessageSpy        spy: [streamBlock value]        often: 5        omit: 0.001

]， Squeak 版カンマ・パターンのスパイ結果[Squeak 版カンマ・パターンのスパイ結果：

 - 256 tallies, 256 msec.**Tree**61.7% {158ms} ByteString(SequenceableCollection)>>,  |44.5% {114ms} ByteString(SequenceableCollection)>>copyReplaceFrom:to:with:  |  |16.8% {43ms} primitives  |  |15.6% {40ms} ByteString class(String class)>>new:  |  |12.1% {31ms} ByteString(Object)>>species  |17.2% {44ms} primitives23.0% {59ms} Character class>>cr  |14.1% {36ms} primitives  |9.0% {23ms} Character class>>value:14.8% {38ms} String class>>with:  9.0% {23ms} primitives  5.9% {15ms} ByteString class(String class)>>new:**Leaves**21.5% {55ms} ByteString class(String class)>>new:17.2% {44ms} ByteString(SequenceableCollection)>>,16.8% {43ms} ByteString(SequenceableCollection)>>copyReplaceFrom:to:with:14.1% {36ms} Character class>>cr12.1% {31ms} ByteString(Object)>>species 9.0% {23ms} Character class>>value: 9.0% {23ms} String class>>with:**Memory**    old         +0 bytes    young       +182,312 bytes    used        +182,312 bytes    free        -182,312 bytes**GCs**    full         0 totalling 0ms (0.0% uptime)    incr        81 totalling 14ms (5.0% uptime), avg 0.0ms    tenures      0    root table   0 overflows

]， Squeak 版ストリーム・パターンのスパイ結果[Squeak 版ストリーム・パターンのスパイ結果：

 - 90 tallies, 90 msec.**Tree**31.1% {28ms} WriteStream>>nextPut:  |18.9% {17ms} Character>>isOctetCharacter  |12.2% {11ms} primitives27.8% {25ms} Character class>>cr  |14.4% {13ms} primitives  |13.3% {12ms} Character class>>value:14.4% {13ms} WriteStream>>contents  |7.8% {7ms} ByteString(SequenceableCollection)>>copyFrom:to:  |  |4.4% {4ms} ByteString class(String class)>>new:  |4.4% {4ms} primitives12.2% {11ms} WriteStream>>nextPutAll:6.7% {6ms} WriteStream class(PositionableStream class)>>on:  |5.6% {5ms} WriteStream>>on:  |  5.6% {5ms} WriteStream(PositionableStream)>>on:  |    4.4% {4ms} primitives5.6% {5ms} String class>>new:  3.3% {3ms} primitives**Leaves**18.9% {17ms} Character>>isOctetCharacter14.4% {13ms} Character class>>cr13.3% {12ms} Character class>>value:12.2% {11ms} WriteStream>>nextPutAll:12.2% {11ms} WriteStream>>nextPut:10.0% {9ms} ByteString class(String class)>>new: 4.4% {4ms} WriteStream>>contents 4.4% {4ms} WriteStream(PositionableStream)>>on:**Memory**    old         +0 bytes    young       +1,074,872 bytes    used        +1,074,872 bytes    free        -1,074,872 bytes**GCs**    full         0 totalling 0ms (0.0% uptime)    incr         8 totalling 1ms (1.0% uptime), avg 0.0ms    tenures      0    root table   0 overflows

]．

メソッドの組み立て例

ストリームとカンマ・メッセージによる文字列連結だけを考えたときにはたいした差が出ないとしても，ストリームを使うかどうかはもちろん連結以外の部分にも影響する．とりあえずひねり出した実際のメソッドの例． for Squeak オンリ〜．下手な例とか言わない．

お題： n 行の文字列 (sourceString) から m (lineNumber) 行だけコピーしたい

とする．で，ごく単純に考えて，以下のように二つのパターンを組んだとする．思い付きで， m > n でもちゃんと動く＝ n 行分だけ返すこと，という条件を追加する．

A: カンマ・メッセージ・パターン

foo: sourceString bar: lineNumber    | limit index string |    limit := sourceString lineCount.    index := 1.    string := ''.    [ index <= limit and: [ index <= lineNumber ] ] whileTrue:         [ string := string , (sourceString lineNumber: index) , String cr.        index := index + 1 ].    ^ string

B: ストリーム・パターン

foo: sourceString bar: lineNumber    | stream index |    stream := sourceString readStream.    index := 1.    ^ String streamContents:         [ :s |         [ stream atEnd not and: [ index <= lineNumber ] ] whileTrue:             [ s nextPutAll: (stream upTo: Character cr).            s nextPut: Character cr.            index := index + 1 ] ]

結果は同一になる．で，実行速度を測ってみる．上記 2 パターンをそれぞれ 10000 回走らせてみる．

method using String concatinating comparing stream with comma.

A: カンマ・メッセージ・パターン	4357 msec
B: ストリーム・パターン	329 msec

と 13 倍以上の差になる． spyOn: で調べてみると， A パターンでは，実は lineCount で全体の 90% 近くの処理時間を喰っていることが判る．それじゃぁってんで，

    limit := sourceString occurrencesOf: Character cr.

や，

    limit := sourceString occursInWithEmpty: Character cr caseSensitive: true.

に変えてみても，もっと遅くなる orz．もし Magritte-Model パッケージを入れてると， lines メソッドが使えるので，これを使うと， 2238 msec と倍ぐらいに速くなる ;-)．

    limit := sourceString lines size.

こいつは Array streamContents: を使っているが，それでも B パターンが 6 倍以上速いことに変わりはない．

A: カンマ・メッセージ・パターンでじたばたする． B: ストリーム・パターンはも〜まんたい

もし， m <= n が常に成り立つとするならば， A ∩ B の A はつねに真となり終端の検査が必要ないことになる．いちばん重い lineCount メソッドを使わずに済むが，それでも 1881 msec 掛かるので 5 倍以上遅い．その一方で， B パターンでストリームの終端判定を外しても 323 msec とかで，有意な差は出ない．

この条件が常に成り立つと仮定した場合，もっと単純化して index をなくし，

    1 to: lineNumber do: [:i | string := string , (sourceString lineNumber: i) , String cr].

とか，

    lineNumber timesRepeat:         [s nextPutAll: (stream upTo: Character cr).         s nextPut: Character cr].

なども考えられる．

でも， sourceString を string のまま使ってる限り，スピードは上がらん．ストリームにすると upTo: はストリーム中のポインタ k を移動してくれるので，コピーは k から l までの転送で済むのに対し， string のままだと，毎回ソース文字列の先頭から転送開始位置までスキャンする必要があるため．

ならば，それでもストリームを使わないことに固執するなら，あらかじめ findTokens: Character cr でコレクションにして渡せば？　という話になりかねん．確かにソレだと m >= n の判定も可能．でもですよ，メソッドの事前条件のチェックをセンダにやらせるんすか，マジで (笑)．

念のためトークン分解他力本願兼ノー・チェック版を試してみる．↓これは単に集合の各要素を順番に取り出して繋げてるだけだ．

    | string |    string := ''.    1         to: maxLineNumber        do: [ :index | string := string , (tokens at: index) , String cr ].    ^ string

ここまで責務を削り落とすと 359 msec と劇的に速くなるのだが，それでもストリーム版よりちょいと遅いという結果になった．トークン分解を自前で抱え込むと，一気に 9301 msec となる．どこでやるにしろ，トークン分解を行うと，全体は重くなる．かえってトークン分解を行わない

...do: [ :index | string := string , (sourceString lineNumber: index) , String cr ].

とした方が 1777 msec と，速い． findTokens: はそれだけ重い処理というわけでした． Java だと StringTokenizer という単独のクラスになってるぐらいだもんね．

まとめると以下のとおり．

various using String concatinating comparing stream with comma.

A: カンマ・メッセージ・パターン			B: ストリーム・パターン (全部同じソース)
安全度	メモ	処理時間	安全度	処理時間
◯	自前でトークン分解 & サイズ・チェック	9081 msec	◯	335 msec
◯	lineNumber: & サイズ・チェック (トークン分解不要)	4329 msec	◯	343 msec
×	自前でトークン分解 & サイズ・チェックなし (サイズ・チェックありより遅いのは計測誤差の積算結果？)	9301 msec	◯	328 msec
×	lineNumber: & サイズ・チェックなし (トークン分解不要)	1777 msec	◯	329 msec
×	トークン分解なし & サイズ・チェックなしでトークン× n をもらう	359 msec	◯	331 msec

B: ストリーム・パターンでエエよ

結論：おとなしくストリーム版を採用することにしますハイ．余談：こ〜ゆ〜のはテストケースにしとくと楽．単体で doIt するときは，

    FooBarBazTest new setTestSelector: #testFooBar; testFooBar.

とかで走りますよん．

さらに，キーワードのパラメータについて

あと， A も B も lineNumber には 0 や負数を喰わせてもちゃんと動く． String streamContents: [ :s | ] は空文字を返すので，同じ動きになってくれる． Float， Fraction を喰わせても，よきに計らってくれます．ここまでは佳い．パラメータはそれぞれ String cr を含む長い文字列と自然数を想定しているが，そうじゃないオブジェクト，たとえば nil が渡されたらどうすんの？　という問題が残る．それぞれ， asString や asNumber (asInteger の方がベター) が判らないオブジェクトが渡されてきたかどうかを見て， nil なり空文字を返すなりすれば佳い．

あと出しはやみれ〜

と，まぁ，このメソッドが使われる状況を考えないと，あれもこれもという話になってしまう．実はこのメソッド，あるクラスのインスタンス・メソッドなんだが，これに与えられるパラメータは， 1) sourceString が，そのクラスのインスタンス変数に格納された文字列と， 2) lineNumber は，(その行数 min: ある正の定数)，ということになっている．つまり， lineNumber は sourceString に依存するわけである．そして sourceString に渡されるインスタンス変数は，インスタンス生成時に空文字を含む何らかの文字列で初期化される．どっかの阿呆が nil とかブチ込まん限りは．その阿呆は間違いなく自分な訳だが (笑)．というわけで，このメソッドのテストに関しては，実は暗黙の仮定だった lineNumber は自然数で，かつ sourceString の行数より大きくなることはない，という条件だけをテストすりゃエエはず．あとは，このクラス自体あるいは他のメソッドのテストでチェックすべきということで一件落着させる．ということはサイズ・チェックなしでも佳かったんじゃネェか！　はい，そのとおりでごぜぇます．でも，「私 ああいうの気持ち悪いんですよね」 © ゆの[蒼樹うめ "ひだまりスケッチ", 第 1 巻, 芳文社, 2005, 2008, ISBN4-8322-7549-6, p.32.]．

余談

文字列クラスに関しては， Java でも似たような話があるよね．新人研修必修ネタだけど，文字列をいじくるときは String じゃなくて StringBuilder や StringBuffer，あるいは StringWriter を使えって． StringWriter なんてもろにストリームでしょ．