perlperf 5.26.1 と 5.38.0 の差分

1	1
2		=encoding eu~~c-jp~~
	2	=encoding utf8
3	3
4	4	=head1 NAME
5	5
6	6	=begin original
7	7
8	8	perlperf - Perl Performance and Optimization Techniques
9	9
10	10	=end original
11	11
12	12	perlperf - Perl の性能と最適化のテクニック
13	13
14	14	=head1 DESCRIPTION
15	15
16	16	=begin original
17	17
18	18	This is an introduction to the use of performance and optimization techniques
19	19	which can be used with particular reference to perl programs. While many perl
20	20	developers have come from other languages, and can use their prior knowledge
21	21	where appropriate, there are many other people who might benefit from a few
22	22	perl specific pointers. If you want the condensed version, perhaps the best
23	23	advice comes from the renowned Japanese Samurai, Miyamoto Musashi, who said:
24	24
25	25	=end original
26	26
27	27	これは、perl プログラムへの個々の参考として使える性能と最適化の
28	28	テクニックの使用の紹介です。
29	29	多くの perl 開発者は他の言語から来ていて、適切な場所では以前の知識を
30	30	使えますが、いくつかの perl 特有の点から利益を得られるかもしれない多くの
31	31	人もいます。
32	32	要約版がほしいなら、おそらく最良のアドバイスは、有名な日本の侍である
33	33	宮本武蔵の言葉でしょう:
34	34
35	35	=begin original
36	36
37	37	"Do Not Engage in Useless Activity"
38	38
39	39	=end original
40	40
41	41	「役に立ぬ事をせざる事」
42	42
43	43	=begin original
44	44
45	45	in 1645.
46	46
47	47	=end original
48	48
49	49	と 1645 年に記しています。
50	50
51	51	=head1 OVERVIEW
52	52
53	53	(概観)
54	54
55	55	=begin original
56	56
57	57	Perhaps the most common mistake programmers make is to attempt to optimize
58	58	their code before a program actually does anything useful - this is a bad idea.
59	59	There's no point in having an extremely fast program that doesn't work. The
60	60	first job is to get a program to I<correctly> do something B<useful>, (not to
61	61	mention ensuring the test suite is fully functional), and only then to consider
62	62	optimizing it. Having decided to optimize existing working code, there are
63	63	several simple but essential steps to consider which are intrinsic to any
64	64	optimization process.
65	65
66	66	=end original
67	67
68	68	おそらくプログラマが犯す最もよくある間違いは、プログラムが実際に有用な
69	69	ものになる前にコードを最適化しようとすることです - これは悪い考えです。
70	70	うまく動かないすごく高速なプログラムには意味がありません。
71	71	最初の仕事はプログラムが I<正しく> 何か B<有用なこと> をするようにして
72	72	(テストスイートが完全に機能することを保証するという意味ではありません)、
73	73	それからそれを最適化することだけを考えます。
74	74	既に動作するコードを最適化すると決めたら、あらゆる最適化プロセスに内在すると
75	75	考えられる、いくつかの単純だけれども本質的なステップがあります。
76	76
77	77	=head2 ONE STEP SIDEWAYS
78	78
79	79	(一歩横に)
80	80
81	81	=begin original
82	82
83	83	Firstly, you need to establish a baseline time for the existing code, which
84	84	timing needs to be reliable and repeatable. You'll probably want to use the
85	85	C<Benchmark> or C<Devel::NYTProf> modules, or something similar, for this step,
86	86	or perhaps the Unix system C<time> utility, whichever is appropriate. See the
87	87	base of this document for a longer list of benchmarking and profiling modules,
88	88	and recommended further reading.
89	89
90	90	=end original
91	91
92	92	まず、既にあるコードの基準になる時間を決定する必要があります; ここで
93	93	時間は信頼性があって再現可能であるものです。
94	94	おそらく C<Benchmark> または C<Devel::NYTProf> モジュールやあるいは
95	95	似たようなものか、またはおそらく Unix システムの
96	96	C<time> ユーティリティのような、適切なものを使いたいでしょう。
97	97	ベンチマークとプロファイルのモジュールのより長い一覧および、さらに読むための
98	98	お勧めについてはこの文書の末尾を見てください。
99	99
100	100	=head2 ONE STEP FORWARD
101	101
102	102	(一歩前に)
103	103
104	104	=begin original
105	105
106	106	Next, having examined the program for I<hot spots>, (places where the code
107	107	seems to run slowly), change the code with the intention of making it run
108	108	faster. Using version control software, like C<subversion>, will ensure no
109	109	changes are irreversible. It's too easy to fiddle here and fiddle there -
110	110	don't change too much at any one time or you might not discover which piece of
111	111	code B<really> was the slow bit.
112	112
113	113	=end original
114	114
115	115	次に、プログラムの中の I<ホットスポット> (コード中で実行が遅くなっているらしい
116	116	場所) を調べ、より早く実行できるようにコードを変更します。
117	117	C<subversion> のようなバージョンコントロールソフトを使って、全ての変更を
118	118	差し戻せるようにします。
119	119	あちこちをいじるのはとても簡単です - 一度にたくさん変更しないようにします;
120	120	さもないとどこコードが B<本当に> 遅かったのかが分からなくなるかもしれません。
121	121
122	122	=head2 ANOTHER STEP SIDEWAYS
123	123
124	124	(もう一歩横に)
125	125
126	126	=begin original
127	127
128	128	It's not enough to say: "that will make it run faster", you have to check it.
129	129	Rerun the code under control of the benchmarking or profiling modules, from the
130	130	first step above, and check that the new code executed the B<same task> in
131	131	I<less time>. Save your work and repeat...
132	132
133	133	=end original
134	134
135	135	次のように言うだけでは不十分です: 「これでもっと速く動作する」;
136	136	これをチェックする必要があります。
137	137	上述の最初のステップから、ベンチマークやプロファイリングのモジュールの
138	138	制御下でコードを再実行して、新しいコードが I<より短い時間> で、
139	139	B<同じ処理> を実行したことをチェックします。
140	140	作業を保存して、繰り返します…。
141	141
142	142	=head1 GENERAL GUIDELINES
143	143
144	144	(一般的なガイドライン)
145	145
146	146	=begin original
147	147
148	148	The critical thing when considering performance is to remember there is no such
149	149	thing as a C<Golden Bullet>, which is why there are no rules, only guidelines.
150	150
151	151	=end original
152	152
153	153	性能について考えるときに重要なことは、C<金の弾丸> のようなものは
154	154	ないということを忘れないことです; それがなぜここにルールがなく、
155	155	ガイドラインだけがある理由です。
156	156
157	157	=begin original
158	158
159	159	It is clear that inline code is going to be faster than subroutine or method
160	160	calls, because there is less overhead, but this approach has the disadvantage
161	161	of being less maintainable and comes at the cost of greater memory usage -
162	162	there is no such thing as a free lunch. If you are searching for an element in
163	163	a list, it can be more efficient to store the data in a hash structure, and
164	164	then simply look to see whether the key is defined, rather than to loop through
165	165	the entire array using grep() for instance. substr() may be (a lot) faster
166	166	than grep() but not as flexible, so you have another trade-off to access. Your
167	167	code may contain a line which takes 0.01 of a second to execute which if you
168	168	call it 1,000 times, quite likely in a program parsing even medium sized files
169	169	for instance, you already have a 10 second delay, in just one single code
170	170	location, and if you call that line 100,000 times, your entire program will
171	171	slow down to an unbearable crawl.
172	172
173	173	=end original
174	174
175	175	オーバーヘッドが少ないので、インラインコードはサブルーチンやメソッドの
176	176	呼び出しより早いのは明らかですが、この手法は保守性が悪くなってメモリ消費が
177	177	大きくなると言う欠点があります - フリーランチのようなものはありません。
178	178	一覧の要素を探すとき、例えば配列全体を grep() を使ってループを
179	179	するのではなく、データをハッシュ構造に保管して、キーがあるかどうかを調べる
180	180	方がより効率的です。
181	181	substr() は grep() より(とても)早くなりますが、それほど柔軟ではないので、
182	182	アクセスするのにもう一つのトレードオフがあります。
183	183	例えば中くらいのサイズのファイルをパースするような、1,000 回呼び出される
184	184	0.01 秒かかる行が単一の行ですでに 10 秒の遅延があるかもしれませんし、
185	185	その行が 100,000 回呼び出されるなら、プログラム全体が耐えられないぐらい
186	186	遅くなります。
187	187
188	188	=begin original
189	189
190	190	Using a subroutine as part of your sort is a powerful way to get exactly what
191	191	you want, but will usually be slower than the built-in I<alphabetic> C<cmp> and
192	192	I<numeric> C<E<lt>=E<gt>> sort operators. It is possible to make multiple
193	193	passes over your data, building indices to make the upcoming sort more
194	194	efficient, and to use what is known as the C<OM> (Orcish Maneuver) to cache the
195	195	sort keys in advance. The cache lookup, while a good idea, can itself be a
196	196	source of slowdown by enforcing a double pass over the data - once to setup the
197	197	cache, and once to sort the data. Using C<pack()> to extract the required sort
198	198	key into a consistent string can be an efficient way to build a single string
199	199	to compare, instead of using multiple sort keys, which makes it possible to use
200	200	the standard, written in C<c> and fast, perl C<sort()> function on the output,
201	201	and is the basis of the C<GRT> (Guttman Rossler Transform). Some string
202	202	combinations can slow the C<GRT> down, by just being too plain complex for its
203	203	own good.
204	204
205	205	=end original
206	206
207	207	ソートの一部としてサブルーチンを使うことは、したいことを正確にするための
208	208	強力な方法ですが、普通は組み込みの I<文字比較> の C<cmp> および
209	209	I<数値比較> の C<E<lt>=E<gt>> ソート演算子よりも遅いです。
210	210	データに対して複数パスを行って、ソートをより効率的にするためのインデックスを
211	211	構築し、予めソートキーをキャッシュするために C<OM> (Orcish Maneuver) として
212	212	知られてるものを使うことができます。
213	213	キャッシュの検索は、いい考えですが、それ自身データに対する 2 重パスを
214	214	強制することでスローダウンの元となり得ます - キャッシュの設定で一度、
215	215	データのソートでもう一度です。
216	216	必要なソートキーを永続的な文字列に展開するために C<pack()> を使うのは、
217	217	複数のソートキーを使わずに比較するための単一の文字列を構築する効率的な
218	218	方法になり得ます; これにより出力に標準で C<c> で書かれていて高速な
219	219	Perl の C<sort()> 関数を使えるようになり、C<GRT> (Guttman Rossler Transform)
220	220	の基礎となります。
221	221	一部の文字列比較は、単に複雑すぎるので C<GRT> を低下させます。
222	222
223	223	=begin original
224	224
225	225	For applications using database backends, the standard C<DBIx> namespace has
226	226	tries to help with keeping things nippy, not least because it tries to I<not>
227	227	query the database until the latest possible moment, but always read the docs
228	228	which come with your choice of libraries. Among the many issues facing
229	229	developers dealing with databases should remain aware of is to always use
230	230	C<SQL> placeholders and to consider pre-fetching data sets when this might
231	231	prove advantageous. Splitting up a large file by assigning multiple processes
232	232	to parsing a single file, using say C<POE>, C<threads> or C<fork> can also be a
233	233	useful way of optimizing your usage of the available C<CPU> resources, though
234	234	this technique is fraught with concurrency issues and demands high attention to
235	235	detail.
236	236
237	237	=end original
238	238
239	239	データベースバックエンドを使うアプリケーションで、標準の
240	240	C<DBIx> 名前空間は物事をぴりっとしたものにし続けるように助けようとします;
241	241	特に可能な限り遅くまでデータベースに問い合わせ I<しない> ようにしますが、
242	242	常に選択したライブラリに付属している文書を読んでください。
243	243	データベースを扱う開発者が直面する多くの問題で気にするべきことは、
244	244	常に C<SQL> プレースホルダを使うことと、利点がある分かるときにはデータ集合の
245	245	プリフェッチを考慮することです。
246	246	大きなファイルを、C<POE>, C<threads>, C<fork> と言ったものを使って
247	247	単一のファイルをパースする複数のプロセスに割り当てることで分割することも、
248	248	利用可能な C<CPU> リソースの仕様を最適化する有用な方法になり得ますが、
249	249	このテクニックは並列性の問題に直面し、詳細に関して高い注目を必要とします。
250	250
251	251	=begin original
252	252
253	253	Every case has a specific application and one or more exceptions, and there is
254	254	no replacement for running a few tests and finding out which method works best
255	255	for your particular environment, this is why writing optimal code is not an
256	256	exact science, and why we love using Perl so much - TMTOWTDI.
257	257
258	258	=end original
259	259
260	260	それぞれのケースには特定のアプリケーションと一つまたは複数の例外があり、
261	261	いくつかテストを実行して、特定の環境にとってどの手法が最良かを見つけることに
262	262	代わるものはありません; これは、最適なコードを書くことが正確な科学ではない
263	263	理由であり、我々が Perl を使うのをとても愛している理由です - TMTOWTDI。
264	264
265	265	=head1 BENCHMARKS
266	266
267	267	(ベンチマーク)
268	268
269	269	=begin original
270	270
271	271	Here are a few examples to demonstrate usage of Perl's benchmarking tools.
272	272
273	273	=end original
274	274
275	275	以下は、Perl のベンチマークツールの使い方を説明するいくつかの例です。
276	276
277	277	=head2 Assigning and Dereferencing Variables.
278	278
279	279	(変数への代入とデリファレンス)
280	280
281	281	=begin original
282	282
283	283	I'm sure most of us have seen code which looks like, (or worse than), this:
284	284
285	285	=end original
286	286
287	287	私たちのほとんどは、以下のような(あるいはもっとひどい)コードを見たことが
288	288	あるはずです:
289	289
290	290	if ( $obj->{_ref}->{_myscore} >= $obj->{_ref}->{_yourscore} ) {
291	291	...
292	292
293	293	=begin original
294	294
295	295	This sort of code can be a real eyesore to read, as well as being very
296	296	sensitive to typos, and it's much clearer to dereference the variable
297	297	explicitly. We're side-stepping the issue of working with object-oriented
298	298	programming techniques to encapsulate variable access via methods, only
299	299	accessible through an object. Here we're just discussing the technical
300	300	implementation of choice, and whether this has an effect on performance. We
301	301	can see whether this dereferencing operation, has any overhead by putting
302	302	comparative code in a file and running a C<Benchmark> test.
303	303
304	304	=end original
305	305
306	306	この種類のコードは読むと目が疲れ、タイプミスに弱く、変数を明示的に
307	307	デリファレンスすることで遥かに明確になります。
308	308	変数アクセスをメソッド経由でカプセル化して、オブジェクトを通してのみ
309	309	アクセス可能にすると言うオブジェクト指向プログラミングのテクニックを
310	310	使う問題を横に避けておきます。
311	311	ここでは単に選択する技術実装に関して、そしてこれが性能が向上するかどうかを
312	312	議論しています。
313	313	このデリファレンス操作がかなりのコードをファイルに置くことによる
314	314	オーバーヘッドがあるのかを C<Benchmark> テストで見てみます。
315	315
316	316	=begin original
317	317
318	318	# dereference
319	319
320	320	=end original
321	321
322	322	# デリファレンス
323	323
324	324	#!/usr/bin/perl
325	325
326		use ~~strict~~;
	326	use v5.36;
327		use warnings;
328	327
329	328	use Benchmark;
330	329
331	330	my $ref = {
332	331	'ref' => {
333	332	_myscore => '100 + 1',
334	333	_yourscore => '102 - 1',
335	334	},
336	335	};
337	336
338	337	timethese(1000000, {
339	338	'direct' => sub {
340	339	my $x = $ref->{ref}->{_myscore} . $ref->{ref}->{_yourscore} ;
341	340	},
342	341	'dereference' => sub {
343	342	my $ref = $ref->{ref};
344	343	my $myscore = $ref->{_myscore};
345	344	my $yourscore = $ref->{_yourscore};
346	345	my $x = $myscore . $yourscore;
347	346	},
348	347	});
349	348
350	349	=begin original
351	350
352	351	It's essential to run any timing measurements a sufficient number of times so
353	352	the numbers settle on a numerical average, otherwise each run will naturally
354	353	fluctuate due to variations in the environment, to reduce the effect of
355	354	contention for C<CPU> resources and network bandwidth for instance. Running
356	355	the above code for one million iterations, we can take a look at the report
357	356	output by the C<Benchmark> module, to see which approach is the most effective.
358	357
359	358	=end original
360	359
361	360	時間計測は、平均を安定させるために十分な回数行うことが重要です;
362	361	さもなければそれぞれの実行は、例えば C<CPU> リソースの競合の効果や
363	362	ネットワーク帯域のような環境の変化によって自然に変動します。
364	363	どの手法が最も効果的を見るために、上述のコードを 100 万回繰り返して、
365	364	C<Benchmark> モジュールによって出力された報告を見てみます。
366	365
367	366	$> perl dereference
368	367
369	368	Benchmark: timing 1000000 iterations of dereference, direct...
370	369	dereference: 2 wallclock secs ( 1.59 usr + 0.00 sys = 1.59 CPU) @ 628930.82/s (n=1000000)
371	370	direct: 1 wallclock secs ( 1.20 usr + 0.00 sys = 1.20 CPU) @ 833333.33/s (n=1000000)
372	371
373	372	=begin original
374	373
375	374	The difference is clear to see and the dereferencing approach is slower. While
376	375	it managed to execute an average of 628,930 times a second during our test, the
377	376	direct approach managed to run an additional 204,403 times, unfortunately.
378	377	Unfortunately, because there are many examples of code written using the
379	378	multiple layer direct variable access, and it's usually horrible. It is,
380	379	however, minusculy faster. The question remains whether the minute gain is
381	380	actually worth the eyestrain, or the loss of maintainability.
382	381
383	382	=end original
384	383
385	384	違いははっきりと見え、デリファレンスの手法はより遅いです。
386	385	これはテスト中 1 秒間に平均して 628,930 回実行しましたが、直接手法は
387	386	残念ながらさらに 204,403 回実行しています。
388	387	残念ながら、複数層の直接変数アクセスを使ったコード例がたくさんあるので、
389	388	これは普通は恐ろしいものです。
390	389	しかし、これはほんの少し速いです。
391	390	問題は、ほんの少しの向上が疲れ目と保守性の喪失の価値があるかです。
392	391
393	392	=head2 Search and replace or tr
394	393
395	394	(検索と置換または tr)
396	395
397	396	=begin original
398	397
399	398	If we have a string which needs to be modified, while a regex will almost
400	399	always be much more flexible, C<tr>, an oft underused tool, can still be a
401	400	useful. One scenario might be replace all vowels with another character. The
402	401	regex solution might look like this:
403	402
404	403	=end original
405	404
406	405	変更する必要がある文字列がある場合、正規表現はほとんど常により柔軟性が
407	406	ありますが、活用されていない C<tr> も依然有用です。
408	407	一つのシナリオとしては、全ての母音を他の文字に置換するというものです。
409	408	正規表現による解放は以下のようなものになるでしょう:
410	409
411	410	$str =~ s/[aeiou]/x/g
412	411
413	412	=begin original
414	413
415	414	The C<tr> alternative might look like this:
416	415
417	416	=end original
418	417
419	418	C<tr> による代替案は以下のようになります:
420	419
421	420	$str =~ tr/aeiou/xxxxx/
422	421
423	422	=begin original
424	423
425	424	We can put that into a test file which we can run to check which approach is
426	425	the fastest, using a global C<$STR> variable to assign to the C<my $str>
427	426	variable so as to avoid perl trying to optimize any of the work away by
428	427	noticing it's assigned only the once.
429	428
430	429	=end original
431	430
432	431	どの手法が一番早いかをチェックするために、実行するテストファイルにこれを
433	432	置きます; perl が一度しか代入されないことを気付くことで処理しないように
434	433	最適化しようとすることを避けるために、C<my $str> 変数へ代入するために
435	434	グローバルな C<$STR> 変数を使います。
436	435
437	436	=begin original
438	437
439	438	# regex-transliterate
440	439
441	440	=end original
442	441
443	442	# 正規表現-文字変換
444	443
445	444	#!/usr/bin/perl
446	445
447		use ~~strict~~;
	446	use v5.36;
448		use warnings;
449	447
450	448	use Benchmark;
451	449
452	450	my $STR = "$$-this and that";
453	451
454	452	timethese( 1000000, {
455	453	'sr' => sub { my $str = $STR; $str =~ s/[aeiou]/x/g; return $str; },
456	454	'tr' => sub { my $str = $STR; $str =~ tr/aeiou/xxxxx/; return $str; },
457	455	});
458	456
459	457	=begin original
460	458
461	459	Running the code gives us our results:
462	460
463	461	=end original
464	462
465	463	コードを実行することで結果が得られます:
466	464
467	465	$> perl regex-transliterate
468	466
469	467	Benchmark: timing 1000000 iterations of sr, tr...
470	468	sr: 2 wallclock secs ( 1.19 usr + 0.00 sys = 1.19 CPU) @ 840336.13/s (n=1000000)
471	469	tr: 0 wallclock secs ( 0.49 usr + 0.00 sys = 0.49 CPU) @ 2040816.33/s (n=1000000)
472	470
473	471	=begin original
474	472
475	473	The C<tr> version is a clear winner. One solution is flexible, the other is
476	474	fast - and it's appropriately the programmer's choice which to use.
477	475
478	476	=end original
479	477
480	478	C<tr> 版が明らかな勝者です。
481	479	ある解決法は柔軟性があり、他の解決法は高速です - そして適切に
482	480	どちらを使うかはプログラマの選択です。
483	481
484	482	=begin original
485	483
486	484	Check the C<Benchmark> docs for further useful techniques.
487	485
488	486	=end original
489	487
490	488	さらなる有用なテクニックについては C<Benchmark> の文書を参照してください。
491	489
492	490	=head1 PROFILING TOOLS
493	491
494	492	(プロファイリングツール)
495	493
496	494	=begin original
497	495
498	496	A slightly larger piece of code will provide something on which a profiler can
499	497	produce more extensive reporting statistics. This example uses the simplistic
500	498	C<wordmatch> program which parses a given input file and spews out a short
501	499	report on the contents.
502	500
503	501	=end original
504	502
505	503	やや大きめのコードではプロファイラが生成するより大規模な状況報告が
506	504	何かを提供するでしょう。
507	505	この例は、与えられた入力ファイルをパースして、内容の短いレポートを出力する
508	506	単純な C<wordmatch> プログラムを使います。
509	507
510	508	=begin original
511	509
512	510	# wordmatch
513	511
514	512	=end original
515	513
516	514	# 単語マッチング
517	515
518	516	#!/usr/bin/perl
519	517
520		use ~~strict~~;
	518	use v5.36;
521		use warnings;
522	519
523	520	=head1 NAME
524	521
525	522	filewords - word analysis of input file
526	523
527	524	=head1 SYNOPSIS
528	525
529	526	filewords -f inputfilename [-d]
530	527
531	528	=head1 DESCRIPTION
532	529
533	530	This program parses the given filename, specified with C<-f>, and
534	531	displays a simple analysis of the words found therein. Use the C<-d>
535	532	switch to enable debugging messages.
536	533
537	534	=cut
538	535
539	536	use FileHandle;
540	537	use Getopt::Long;
541	538
542	539	my $debug = 0;
543	540	my $file = '';
544	541
545	542	my $result = GetOptions (
546	543	'debug' => \$debug,
547	544	'file=s' => \$file,
548	545	);
549	546	die("invalid args") unless $result;
550	547
551	548	unless ( -f $file ) {
552	549	die("Usage: $0 -f filename [-d]");
553	550	}
554	551	my $FH = FileHandle->new("< $file")
555	552	or die("unable to open file($file): $!");
556	553
557	554	my $i_LINES = 0;
558	555	my $i_WORDS = 0;
559	556	my %count = ();
560	557
561	558	my @lines = <$FH>;
562	559	foreach my $line ( @lines ) {
563	560	$i_LINES++;
564	561	$line =~ s/\n//;
565	562	my @words = split(/ +/, $line);
566	563	my $i_words = scalar(@words);
567	564	$i_WORDS = $i_WORDS + $i_words;
568	565	debug("line: $i_LINES supplying $i_words words: @words");
569	566	my $i_word = 0;
570	567	foreach my $word ( @words ) {
571	568	$i_word++;
572	569	$count{$i_LINES}{spec} += matches($i_word, $word,
573	570	'[^a-zA-Z0-9]');
574	571	$count{$i_LINES}{only} += matches($i_word, $word,
575	572	'^[^a-zA-Z0-9]+$');
576	573	$count{$i_LINES}{cons} += matches($i_word, $word,
577	574	'^[(?i:bcdfghjklmnpqrstvwxyz)]+$');
578	575	$count{$i_LINES}{vows} += matches($i_word, $word,
579	576	'^[(?i:aeiou)]+$');
580	577	$count{$i_LINES}{caps} += matches($i_word, $word,
581	578	'^[(A-Z)]+$');
582	579	}
583	580	}
584	581
585	582	print report( %count );
586	583
587	584	sub matches {
588	585	my $i_wd = shift;
589	586	my $word = shift;
590	587	my $regex = shift;
591	588	my $has = 0;
592	589
593	590	if ( $word =~ /($regex)/ ) {
594	591	$has++ if $1;
595	592	}
596	593
597	594	debug( "word: $i_wd "
598	595	. ($has ? 'matches' : 'does not match')
599	596	. " chars: /$regex/");
600	597
601	598	return $has;
602	599	}
603	600
604	601	sub report {
605	602	my %report = @_;
606	603	my %rep;
607	604
608	605	foreach my $line ( keys %report ) {
609		foreach my $key ( keys %{ $report{$line} } ) {
	606	foreach my $key ( keys $report{$line}->%* ) {
610	607	$rep{$key} += $report{$line}{$key};
611	608	}
612	609	}
613	610
614	611	my $report = qq\|
615	612	$0 report for $file:
616	613	lines in file: $i_LINES
617	614	words in file: $i_WORDS
618	615	words with special (non-word) characters: $i_spec
619	616	words with only special (non-word) characters: $i_only
620	617	words with only consonants: $i_cons
621	618	words with only capital letters: $i_caps
622	619	words with only vowels: $i_vows
623	620	\|;
624	621
625	622	return $report;
626	623	}
627	624
628	625	sub debug {
629	626	my $message = shift;
630	627
631	628	if ( $debug ) {
632	629	print STDERR "DBG: $message\n";
633	630	}
634	631	}
635	632
636	633	exit 0;
637	634
638	635	=head2 Devel::DProf
639	636
640	637	=begin original
641	638
642	639	This venerable module has been the de-facto standard for Perl code profiling
643	640	for more than a decade, but has been replaced by a number of other modules
644	641	which have brought us back to the 21st century. Although you're recommended to
645	642	evaluate your tool from the several mentioned here and from the CPAN list at
646	643	the base of this document, (and currently L<Devel::NYTProf> seems to be the
647	644	weapon of choice - see below), we'll take a quick look at the output from
648	645	L<Devel::DProf> first, to set a baseline for Perl profiling tools. Run the
649	646	above program under the control of C<Devel::DProf> by using the C<-d> switch on
650	647	the command-line.
651	648
652	649	=end original
653	650
654	651	この由緒あるモジュールは 10 年以上 Perl コードプロファイリングのデファクト
655	652	スタンダードでしたが、21 世紀になって色々なその他のモジュールに
656	653	置き換えられています。
657	654	いくつかここで言及されたり、この文書の基礎となる CPAN リストからツールを
658	655	評価することを勧められていますが、(そして現在のところ L<Devel::NYTProf> が
659	656	選択する武器のようですが - 後述します)、Perl プロファイリングツールの
660	657	基本となる L<Devel::DProf> からの出力をまず簡単に見てみます。
661	658	コマンドラインで C<-d> オプションを使うことで C<Devel::DProf> の制御下で
662	659	プログラムを実行します。
663	660
664	661	$> perl -d:DProf wordmatch -f perl5db.pl
665	662
666	663	<...multiple lines snipped...>
667	664
668	665	wordmatch report for perl5db.pl:
669	666	lines in file: 9428
670	667	words in file: 50243
671	668	words with special (non-word) characters: 20480
672	669	words with only special (non-word) characters: 7790
673	670	words with only consonants: 4801
674	671	words with only capital letters: 1316
675	672	words with only vowels: 1701
676	673
677	674	=begin original
678	675
679	676	C<Devel::DProf> produces a special file, called F<tmon.out> by default, and
680	677	this file is read by the C<dprofpp> program, which is already installed as part
681	678	of the C<Devel::DProf> distribution. If you call C<dprofpp> with no options,
682	679	it will read the F<tmon.out> file in the current directory and produce a human
683	680	readable statistics report of the run of your program. Note that this may take
684	681	a little time.
685	682
686	683	=end original
687	684
688	685	C<Devel::DProf> は、デフォルトでは F<tmon.out> という名前の特殊なファイルを
689	686	出力し、このファイルは C<Devel::DProf> ディストリビューションの一部として
690	687	既にインストールされている C<dprofpp> プログラムによって読み込まれます。
691	688	オプションなしで C<dprofpp> を呼び出すと、カレントディレクトリの
692	689	F<tmon.out> ファイルを読み込んで、あなたのプログラムの実行に関する
693	690	人間が読める形での統計情報を出力します。
694	691	これには少し時間がかかるかもしれないことに注意してください。
695	692
696	693	$> dprofpp
697	694
698	695	Total Elapsed Time = 2.951677 Seconds
699	696	User+System Time = 2.871677 Seconds
700	697	Exclusive Times
701	698	%Time ExclSec CumulS #Calls sec/call Csec/c Name
702	699	102. 2.945 3.003 251215 0.0000 0.0000 main::matches
703	700	2.40 0.069 0.069 260643 0.0000 0.0000 main::debug
704	701	1.74 0.050 0.050 1 0.0500 0.0500 main::report
705	702	1.04 0.030 0.049 4 0.0075 0.0123 main::BEGIN
706	703	0.35 0.010 0.010 3 0.0033 0.0033 Exporter::as_heavy
707	704	0.35 0.010 0.010 7 0.0014 0.0014 IO::File::BEGIN
708	705	0.00 - -0.000 1 - - Getopt::Long::FindOption
709	706	0.00 - -0.000 1 - - Symbol::BEGIN
710	707	0.00 - -0.000 1 - - Fcntl::BEGIN
711	708	0.00 - -0.000 1 - - Fcntl::bootstrap
712	709	0.00 - -0.000 1 - - warnings::BEGIN
713	710	0.00 - -0.000 1 - - IO::bootstrap
714	711	0.00 - -0.000 1 - - Getopt::Long::ConfigDefaults
715	712	0.00 - -0.000 1 - - Getopt::Long::Configure
716	713	0.00 - -0.000 1 - - Symbol::gensym
717	714
718	715	=begin original
719	716
720	717	C<dprofpp> will produce some quite detailed reporting on the activity of the
721	718	C<wordmatch> program. The wallclock, user and system, times are at the top of
722	719	the analysis, and after this are the main columns defining which define the
723	720	report. Check the C<dprofpp> docs for details of the many options it supports.
724	721
725	722	=end original
726	723
727	724	C<dprofpp> は C<wordmatch> プログラムの活動のかなり詳細な報告を出力します。
728	725	壁時計時間、ユーザーとシステム時間が分析の先頭にあり、その後は報告を
729	726	定義する定義で主な列です。
730	727	対応している多くのオプションの詳細については C<dprofpp> の文書を
731	728	チェックしてください。
732	729
733	730	=begin original
734	731
735	732	See also C<L<Apache::DProf>> which hooks C<Devel::DProf> into C<mod_perl>.
736	733
737	734	=end original
738	735
739	736	C<Devel::DProf> を C<mod_perl> にフックする C<L<Apache::DProf>> も
740	737	参照してください。
741	738
742	739	=head2 Devel::Profiler
743	740
744	741	=begin original
745	742
746	743	Let's take a look at the same program using a different profiler:
747	744	C<Devel::Profiler>, a drop-in Perl-only replacement for C<Devel::DProf>. The
748	745	usage is very slightly different in that instead of using the special C<-d:>
749	746	flag, you pull C<Devel::Profiler> in directly as a module using C<-M>.
750	747
751	748	=end original
752	749
753	750	同じプログラムの他のプロファイラによる結果も見てみましょう:
754	751	C<Devel::Profiler> は C<Devel::DProf> の Perl 専用のドロップインです。
755	752	使用法は特殊な C<-d:> フラグを使うのとはほんの少し違って、
756	753	C<Devel::Profiler> を C<-M> を使ってモジュールとして直接読み込みます。
757	754
758	755	$> perl -MDevel::Profiler wordmatch -f perl5db.pl
759	756
760	757	<...multiple lines snipped...>
761	758
762	759	wordmatch report for perl5db.pl:
763	760	lines in file: 9428
764	761	words in file: 50243
765	762	words with special (non-word) characters: 20480
766	763	words with only special (non-word) characters: 7790
767	764	words with only consonants: 4801
768	765	words with only capital letters: 1316
769	766	words with only vowels: 1701
770	767
771	768	=begin original
772	769
773	770	C<Devel::Profiler> generates a tmon.out file which is compatible with the
774	771	C<dprofpp> program, thus saving the construction of a dedicated statistics
775	772	reader program. C<dprofpp> usage is therefore identical to the above example.
776	773
777	774	=end original
778	775
779	776	C<Devel::Profiler> は C<dprofpp> プログラムと互換性のある tmon.out ファイルを
780	777	生成するので、専用の統計読み込みプログラムの構築を省略できます。
781	778	従って C<dprofpp> の使用法は上述の例と同じです。
782	779
783	780	$> dprofpp
784	781
785	782	Total Elapsed Time = 20.984 Seconds
786	783	User+System Time = 19.981 Seconds
787	784	Exclusive Times
788	785	%Time ExclSec CumulS #Calls sec/call Csec/c Name
789	786	49.0 9.792 14.509 251215 0.0000 0.0001 main::matches
790	787	24.4 4.887 4.887 260643 0.0000 0.0000 main::debug
791	788	0.25 0.049 0.049 1 0.0490 0.0490 main::report
792	789	0.00 0.000 0.000 1 0.0000 0.0000 Getopt::Long::GetOptions
793	790	0.00 0.000 0.000 2 0.0000 0.0000 Getopt::Long::ParseOptionSpec
794	791	0.00 0.000 0.000 1 0.0000 0.0000 Getopt::Long::FindOption
795	792	0.00 0.000 0.000 1 0.0000 0.0000 IO::File::new
796	793	0.00 0.000 0.000 1 0.0000 0.0000 IO::Handle::new
797	794	0.00 0.000 0.000 1 0.0000 0.0000 Symbol::gensym
798	795	0.00 0.000 0.000 1 0.0000 0.0000 IO::File::open
799	796
800	797	=begin original
801	798
802	799	Interestingly we get slightly different results, which is mostly because the
803	800	algorithm which generates the report is different, even though the output file
804	801	format was allegedly identical. The elapsed, user and system times are clearly
805	802	showing the time it took for C<Devel::Profiler> to execute its own run, but
806	803	the column listings feel more accurate somehow than the ones we had earlier
807	804	from C<Devel::DProf>. The 102% figure has disappeared, for example. This is
808	805	where we have to use the tools at our disposal, and recognise their pros and
809	806	cons, before using them. Interestingly, the numbers of calls for each
810	807	subroutine are identical in the two reports, it's the percentages which differ.
811		As the author of C<Devel::Proviler> writes:
	808	As the author of C<Devel::Profiler> writes:
812	809
813	810	=end original
814	811
815	812	興味深いことに少し異なった結果が得られました; その理由のほとんどは、
816	813	出力ファイル形式は同一とされているにも関わらず、報告を生成するアルゴリズムが
817	814	異なることです。
818	815	経過時間とユーザー+システム時間は明らかに C<Devel::Profiler> が自身の実行で
819	816	かかった時間を表示してますが、列一覧は先に C<Devel::DProf> で得られたものより
820	817	いくらかより正確なものに感じられます。
821	818	例えば、102% の図は消えました。
822	819	これが、ツールを使ってみて、それらを使う前にそれらの利点と欠点を認識する
823	820	必要があるところです。
824	821	興味深いことに、それぞれのサブルーチンの呼び出し回数は二つの報告で
825	822	同じですが、百分率は異なっています。
826		C<Devel::Proviler> の作者が書いているように:
	823	C<Devel::Profiler> の作者が書いているように:
827	824
828	825	...running HTML::Template's test suite under Devel::DProf shows
829	826	output() taking NO time but Devel::Profiler shows around 10% of the
830	827	time is in output(). I don't know which to trust but my gut tells me
831	828	something is wrong with Devel::DProf. HTML::Template::output() is a
832	829	big routine that's called for every test. Either way, something needs
833	830	fixing.
834	831
835	832	=begin original
836	833
837	834	YMMV.
838	835
839	836	=end original
840	837
841	838	あなたの意見は違うかもしれません。
842	839
843	840	=begin original
844	841
845	842	See also C<L<Devel::Apache::Profiler>> which hooks C<Devel::Profiler>
846	843	into C<mod_perl>.
847	844
848	845	=end original
849	846
850	847	C<mod_perl> に C<Devel::Profiler> フックを付ける
851	848	C<L<Devel::Apache::Profiler>> も参照してください。
852	849
853	850	=head2 Devel::SmallProf
854	851
855	852	=begin original
856	853
857	854	The C<Devel::SmallProf> profiler examines the runtime of your Perl program and
858	855	produces a line-by-line listing to show how many times each line was called,
859	856	and how long each line took to execute. It is called by supplying the familiar
860	857	C<-d> flag to Perl at runtime.
861	858
862	859	=end original
863	860
864	861	C<Devel::SmallProf> プロファイラは Perl プログラムの実行時間を調べて、
865	862	それぞれの行が何回呼び出されたかをしめす行単位の一覧を出力します。
866	863	これは実行時に Perl に親しんだ C<-d> フラグを指定することで呼び出されます。
867	864
868	865	$> perl -d:SmallProf wordmatch -f perl5db.pl
869	866
870	867	<...multiple lines snipped...>
871	868
872	869	wordmatch report for perl5db.pl:
873	870	lines in file: 9428
874	871	words in file: 50243
875	872	words with special (non-word) characters: 20480
876	873	words with only special (non-word) characters: 7790
877	874	words with only consonants: 4801
878	875	words with only capital letters: 1316
879	876	words with only vowels: 1701
880	877
881	878	=begin original
882	879
883		C<Devel::SmallProf> writes it's output into a file called F<smallprof.out>, by
	880	C<Devel::SmallProf> writes its output into a file called F<smallprof.out>, by
884	881	default. The format of the file looks like this:
885	882
886	883	=end original
887	884
888	885	C<Devel::SmallProf> は出力を、デフォルトでは F<smallprof.out> と呼ばれる
889	886	ファイルに書き込みます。
890	887	ファイルの形式は以下のようなものです:
891	888
892	889	<num> <time> <ctime> <line>:<text>
893	890
894	891	=begin original
895	892
896	893	When the program has terminated, the output may be examined and sorted using
897	894	any standard text filtering utilities. Something like the following may be
898	895	sufficient:
899	896
900	897	=end original
901	898
902	899	プログラムが終了したとき、出力は任意の標準テキストフィルタリング
903	900	ユーティリティを使って検査とソートが行われます。
904	901	以下のようなもので十分でしょう:
905	902
906	903	$> cat smallprof.out \| grep \d*: \| sort -k3 \| tac \| head -n20
907	904
908	905	251215 1.65674 7.68000 75: if ( $word =~ /($regex)/ ) {
909	906	251215 0.03264 4.40000 79: debug("word: $i_wd ".($has ? 'matches' :
910	907	251215 0.02693 4.10000 81: return $has;
911	908	260643 0.02841 4.07000 128: if ( $debug ) {
912	909	260643 0.02601 4.04000 126: my $message = shift;
913	910	251215 0.02641 3.91000 73: my $has = 0;
914	911	251215 0.03311 3.71000 70: my $i_wd = shift;
915	912	251215 0.02699 3.69000 72: my $regex = shift;
916	913	251215 0.02766 3.68000 71: my $word = shift;
917	914	50243 0.59726 1.00000 59: $count{$i_LINES}{cons} =
918	915	50243 0.48175 0.92000 61: $count{$i_LINES}{spec} =
919	916	50243 0.00644 0.89000 56: my $i_cons = matches($i_word, $word,
920	917	50243 0.48837 0.88000 63: $count{$i_LINES}{caps} =
921	918	50243 0.00516 0.88000 58: my $i_caps = matches($i_word, $word, '^[(A-
922	919	50243 0.00631 0.81000 54: my $i_spec = matches($i_word, $word, '[^a-
923	920	50243 0.00496 0.80000 57: my $i_vows = matches($i_word, $word,
924	921	50243 0.00688 0.80000 53: $i_word++;
925	922	50243 0.48469 0.79000 62: $count{$i_LINES}{only} =
926	923	50243 0.48928 0.77000 60: $count{$i_LINES}{vows} =
927	924	50243 0.00683 0.75000 55: my $i_only = matches($i_word, $word, '^[^a-
928	925
929	926	=begin original
930	927
931	928	You can immediately see a slightly different focus to the subroutine profiling
932	929	modules, and we start to see exactly which line of code is taking the most
933	930	time. That regex line is looking a bit suspicious, for example. Remember that
934	931	these tools are supposed to be used together, there is no single best way to
935	932	profile your code, you need to use the best tools for the job.
936	933
937	934	=end original
938	935
939	936	サブルーチンプロファイリングモジュールとは少し異なったフォーカスであることが
940	937	すぐに分かります; そして正確にコードのどの行が一番時間がかかるかを
941	938	見始めます。
942	939	例えば、正規表現行は少し疑わしく見えます。
943	940	これらのツールは互いに使われることを想定されていて、コードを
944	941	プロファイリングする単一の最良の方法というのはなく、仕事によって最良の
945	942	ツールを使う必要があると言うことを忘れないでください。
946	943
947	944	=begin original
948	945
949	946	See also C<L<Apache::SmallProf>> which hooks C<Devel::SmallProf> into
950	947	C<mod_perl>.
951	948
952	949	=end original
953	950
954	951	C<mod_perl> に C<L<Apache::SmallProf>> フックを付ける C<Apache::SmallProf> も
955	952	参照してください。
956	953
957	954	=head2 Devel::FastProf
958	955
959	956	=begin original
960	957
961	958	C<Devel::FastProf> is another Perl line profiler. This was written with a view
962	959	to getting a faster line profiler, than is possible with for example
963	960	C<Devel::SmallProf>, because it's written in C<C>. To use C<Devel::FastProf>,
964	961	supply the C<-d> argument to Perl:
965	962
966	963	=end original
967	964
968	965	C<Devel::FastProf> はもう一つの Perl 行プロファイラです。
969	966	これは、例えば C<Devel::SmallProf> などよりも速い行プロファイラとして
970	967	C<C> で書かれました。
971	968	C<Devel::FastProf> を使うには、Perl に C<-d> オプションを指定します:
972	969
973	970	$> perl -d:FastProf wordmatch -f perl5db.pl
974	971
975	972	<...multiple lines snipped...>
976	973
977	974	wordmatch report for perl5db.pl:
978	975	lines in file: 9428
979	976	words in file: 50243
980	977	words with special (non-word) characters: 20480
981	978	words with only special (non-word) characters: 7790
982	979	words with only consonants: 4801
983	980	words with only capital letters: 1316
984	981	words with only vowels: 1701
985	982
986	983	=begin original
987	984
988	985	C<Devel::FastProf> writes statistics to the file F<fastprof.out> in the current
989	986	directory. The output file, which can be specified, can be interpreted by using
990	987	the C<fprofpp> command-line program.
991	988
992	989	=end original
993	990
994	991	C<Devel::FastProf> は現在のディレクトリのファイル F<fastprof.out> に
995	992	統計情報を書き込みます。
996	993	指定可能な出力ファイルは C<fprofpp> コマンドラインプログラムを使って
997	994	解釈されます。
998	995
999	996	$> fprofpp \| head -n20
1000	997
1001	998	# fprofpp output format is:
1002	999	# filename:line time count: source
1003	1000	wordmatch:75 3.93338 251215: if ( $word =~ /($regex)/ ) {
1004	1001	wordmatch:79 1.77774 251215: debug("word: $i_wd ".($has ? 'matches' : 'does not match')." chars: /$regex/");
1005	1002	wordmatch:81 1.47604 251215: return $has;
1006	1003	wordmatch:126 1.43441 260643: my $message = shift;
1007	1004	wordmatch:128 1.42156 260643: if ( $debug ) {
1008	1005	wordmatch:70 1.36824 251215: my $i_wd = shift;
1009	1006	wordmatch:71 1.36739 251215: my $word = shift;
1010	1007	wordmatch:72 1.35939 251215: my $regex = shift;
1011	1008
1012	1009	=begin original
1013	1010
1014	1011	Straightaway we can see that the number of times each line has been called is
1015	1012	identical to the C<Devel::SmallProf> output, and the sequence is only very
1016	1013	slightly different based on the ordering of the amount of time each line took
1017	1014	to execute, C<if ( $debug ) { > and C<my $message = shift;>, for example. The
1018	1015	differences in the actual times recorded might be in the algorithm used
1019	1016	internally, or it could be due to system resource limitations or contention.
1020	1017
1021	1018	=end original
1022	1019
1023	1020	直ちに、各行が呼び出された回数が C<Devel::SmallProf> の出力と同じで、並びは
1024	1021	各行の実行時間順を基にしてほんの少しだけ異なる(例えば C<if ( $debug ) { > と
1025	1022	C<my $message = shift;>) ことがわかります。
1026	1023	実際に記録されている時間の違いは内部で使われているアルゴリズムかも
1027	1024	しれませんし、システムリソースの制限や衝突によるかもしれません。
1028	1025
1029	1026	=begin original
1030	1027
1031	1028	See also the L<DBIx::Profile> which will profile database queries running
1032	1029	under the C<DBIx::*> namespace.
1033	1030
1034	1031	=end original
1035	1032
1036	1033	C<DBIx::*> 名前空間で実行されるデータベース問い合わせをプロファイルする
1037	1034	L<DBIx::Profile> も参照してください。
1038	1035
1039	1036	=head2 Devel::NYTProf
1040	1037
1041	1038	=begin original
1042	1039
1043	1040	C<Devel::NYTProf> is the B<next generation> of Perl code profiler, fixing many
1044	1041	shortcomings in other tools and implementing many cool features. First of all it
1045	1042	can be used as either a I<line> profiler, a I<block> or a I<subroutine>
1046	1043	profiler, all at once. It can also use sub-microsecond (100ns) resolution on
1047	1044	systems which provide C<clock_gettime()>. It can be started and stopped even
1048	1045	by the program being profiled. It's a one-line entry to profile C<mod_perl>
1049	1046	applications. It's written in C<c> and is probably the fastest profiler
1050	1047	available for Perl. The list of coolness just goes on. Enough of that, let's
1051	1048	see how to it works - just use the familiar C<-d> switch to plug it in and run
1052	1049	the code.
1053	1050
1054	1051	=end original
1055	1052
1056	1053	C<Devel::NYTProf> は B<新世代> Perl コードプロファイラで、他のツールの
1057	1054	多くの欠点を修正し、多くのクールな機能を実装しています。
1058	1055	まず、これは I<行> プロファイラと I<ブロック> または
1059	1056	I<サブルーチン> プロファイラとして一度に使えます。
1060	1057	また、C<clock_gettime()> を提供しているシステムではマイクロ秒未満 (100ns) の
1061	1058	解像度を使えます。
1062	1059	プログラムがプロファイルからでも開始終了できます。
1063	1060	これは C<mod_perl> アプリケーションをプロファイルする一行エントリです。
1064	1061	これは C<c> で書かれていて、おそらく Perl で利用可能な最速の
1065	1062	プロファイラです。
1066	1063	素晴らしさの一覧はまだ続きます。
1067	1064	これで十分でしょうから、どのように動作するかを見てみましょう - 単に親しんだ
1068	1065	C<-d> スイッチを使って、コードを実行します。
1069	1066
1070	1067	$> perl -d:NYTProf wordmatch -f perl5db.pl
1071	1068
1072	1069	wordmatch report for perl5db.pl:
1073	1070	lines in file: 9427
1074	1071	words in file: 50243
1075	1072	words with special (non-word) characters: 20480
1076	1073	words with only special (non-word) characters: 7790
1077	1074	words with only consonants: 4801
1078	1075	words with only capital letters: 1316
1079	1076	words with only vowels: 1701
1080	1077
1081	1078	=begin original
1082	1079
1083	1080	C<NYTProf> will generate a report database into the file F<nytprof.out> by
1084	1081	default. Human readable reports can be generated from here by using the
1085	1082	supplied C<nytprofhtml> (HTML output) and C<nytprofcsv> (CSV output) programs.
1086	1083	We've used the Unix system C<html2text> utility to convert the
1087	1084	F<nytprof/index.html> file for convenience here.
1088	1085
1089	1086	=end original
1090	1087
1091	1088	C<NYTProf> はデフォルトではファイル F<nytprof.out> にレポートデータベースを
1092	1089	生成します。
1093	1090	人間が読める報告は、提供される C<nytprofhtml> (HTML 出力) または
1094	1091	C<nytprofcsv> (CSV 出力) プログラムを使うことでここから生成されます。
1095	1092	F<nytprof/index.html> ファイルをここで便利なように変換するために Unix
1096	1093	システムの C<html2text> ユーティリティを使っています。
1097	1094
1098	1095	$> html2text nytprof/index.html
1099	1096
1100	1097	Performance Profile Index
1101	1098	For wordmatch
1102	1099	Run on Fri Sep 26 13:46:39 2008
1103	1100	Reported on Fri Sep 26 13:47:23 2008
1104	1101
1105	1102	Top 15 Subroutines -- ordered by exclusive time
1106	1103	\|Calls \|P \|F \|Inclusive\|Exclusive\|Subroutine \|
1107	1104	\| \| \| \|Time \|Time \| \|
1108	1105	\|251215\|5 \|1 \|13.09263 \|10.47692 \|main:: \|matches \|
1109	1106	\|260642\|2 \|1 \|2.71199 \|2.71199 \|main:: \|debug \|
1110	1107	\|1 \|1 \|1 \|0.21404 \|0.21404 \|main:: \|report \|
1111	1108	\|2 \|2 \|2 \|0.00511 \|0.00511 \|XSLoader:: \|load (xsub) \|
1112	1109	\|14 \|14\|7 \|0.00304 \|0.00298 \|Exporter:: \|import \|
1113	1110	\|3 \|1 \|1 \|0.00265 \|0.00254 \|Exporter:: \|as_heavy \|
1114	1111	\|10 \|10\|4 \|0.00140 \|0.00140 \|vars:: \|import \|
1115	1112	\|13 \|13\|1 \|0.00129 \|0.00109 \|constant:: \|import \|
1116	1113	\|1 \|1 \|1 \|0.00360 \|0.00096 \|FileHandle:: \|import \|
1117	1114	\|3 \|3 \|3 \|0.00086 \|0.00074 \|warnings::register::\|import \|
1118	1115	\|9 \|3 \|1 \|0.00036 \|0.00036 \|strict:: \|bits \|
1119	1116	\|13 \|13\|13\|0.00032 \|0.00029 \|strict:: \|import \|
1120	1117	\|2 \|2 \|2 \|0.00020 \|0.00020 \|warnings:: \|import \|
1121	1118	\|2 \|1 \|1 \|0.00020 \|0.00020 \|Getopt::Long:: \|ParseOptionSpec\|
1122	1119	\|7 \|7 \|6 \|0.00043 \|0.00020 \|strict:: \|unimport \|
1123	1120
1124	1121	For more information see the full list of 189 subroutines.
1125	1122
1126	1123	=begin original
1127	1124
1128	1125	The first part of the report already shows the critical information regarding
1129	1126	which subroutines are using the most time. The next gives some statistics
1130	1127	about the source files profiled.
1131	1128
1132	1129	=end original
1133	1130
1134	1131	報告の最初の部分は既に、どのサブルーチンが一番時間がかかっているかという
1135	1132	重要な情報を表示しています。
1136	1133	以下はプロファイリングしたソースファイルに関するいくつかの統計情報です。
1137	1134
1138	1135	Source Code Files -- ordered by exclusive time then name
1139	1136	\|Stmts \|Exclusive\|Avg. \|Reports \|Source File \|
1140	1137	\| \|Time \| \| \| \|
1141	1138	\|2699761\|15.66654 \|6e-06 \|line . block . sub\|wordmatch \|
1142	1139	\|35 \|0.02187 \|0.00062\|line . block . sub\|IO/Handle.pm \|
1143	1140	\|274 \|0.01525 \|0.00006\|line . block . sub\|Getopt/Long.pm \|
1144	1141	\|20 \|0.00585 \|0.00029\|line . block . sub\|Fcntl.pm \|
1145	1142	\|128 \|0.00340 \|0.00003\|line . block . sub\|Exporter/Heavy.pm \|
1146	1143	\|42 \|0.00332 \|0.00008\|line . block . sub\|IO/File.pm \|
1147	1144	\|261 \|0.00308 \|0.00001\|line . block . sub\|Exporter.pm \|
1148	1145	\|323 \|0.00248 \|8e-06 \|line . block . sub\|constant.pm \|
1149	1146	\|12 \|0.00246 \|0.00021\|line . block . sub\|File/Spec/Unix.pm \|
1150	1147	\|191 \|0.00240 \|0.00001\|line . block . sub\|vars.pm \|
1151	1148	\|77 \|0.00201 \|0.00003\|line . block . sub\|FileHandle.pm \|
1152	1149	\|12 \|0.00198 \|0.00016\|line . block . sub\|Carp.pm \|
1153	1150	\|14 \|0.00175 \|0.00013\|line . block . sub\|Symbol.pm \|
1154	1151	\|15 \|0.00130 \|0.00009\|line . block . sub\|IO.pm \|
1155	1152	\|22 \|0.00120 \|0.00005\|line . block . sub\|IO/Seekable.pm \|
1156	1153	\|198 \|0.00085 \|4e-06 \|line . block . sub\|warnings/register.pm\|
1157	1154	\|114 \|0.00080 \|7e-06 \|line . block . sub\|strict.pm \|
1158	1155	\|47 \|0.00068 \|0.00001\|line . block . sub\|warnings.pm \|
1159	1156	\|27 \|0.00054 \|0.00002\|line . block . sub\|overload.pm \|
1160	1157	\|9 \|0.00047 \|0.00005\|line . block . sub\|SelectSaver.pm \|
1161	1158	\|13 \|0.00045 \|0.00003\|line . block . sub\|File/Spec.pm \|
1162	1159	\|2701595\|15.73869 \| \|Total \|
1163	1160	\|128647 \|0.74946 \| \|Average \|
1164	1161	\| \|0.00201 \|0.00003\|Median \|
1165	1162	\| \|0.00121 \|0.00003\|Deviation \|
1166	1163
1167	1164	Report produced by the NYTProf 2.03 Perl profiler, developed by Tim Bunce and
1168	1165	Adam Kaplan.
1169	1166
1170	1167	=begin original
1171	1168
1172	1169	At this point, if you're using the I<html> report, you can click through the
1173	1170	various links to bore down into each subroutine and each line of code. Because
1174	1171	we're using the text reporting here, and there's a whole directory full of
1175	1172	reports built for each source file, we'll just display a part of the
1176	1173	corresponding F<wordmatch-line.html> file, sufficient to give an idea of the
1177	1174	sort of output you can expect from this cool tool.
1178	1175
1179	1176	=end original
1180	1177
1181	1178	この点で、I<html> レポートを使っているなら、サブルーチン単位と行単位の
1182	1179	詳細への様々なリンクをクリックできます。
1183	1180	ここではテキストレポートを使っていて、それぞれのソースファイルに対して
1184	1181	ビルドされたレポートファイルがディレクトリにたくさんあるので、対応する
1185	1182	F<wordmatch-line.html> ファイルの一部だけを表示します; この素晴らしいツールで
1186	1183	どのような出力が得られるかの考えを与えるには十分です。
1187	1184
1188	1185	$> html2text nytprof/wordmatch-line.html
1189	1186
1190	1187	Performance Profile -- -block view-.-line view-.-sub view-
1191	1188	For wordmatch
1192	1189	Run on Fri Sep 26 13:46:39 2008
1193	1190	Reported on Fri Sep 26 13:47:22 2008
1194	1191
1195	1192	File wordmatch
1196	1193
1197	1194	Subroutines -- ordered by exclusive time
1198	1195	\|Calls \|P\|F\|Inclusive\|Exclusive\|Subroutine \|
1199	1196	\| \| \| \|Time \|Time \| \|
1200	1197	\|251215\|5\|1\|13.09263 \|10.47692 \|main::\|matches\|
1201	1198	\|260642\|2\|1\|2.71199 \|2.71199 \|main::\|debug \|
1202	1199	\|1 \|1\|1\|0.21404 \|0.21404 \|main::\|report \|
1203	1200	\|0 \|0\|0\|0 \|0 \|main::\|BEGIN \|
1204	1201
1205	1202	\|Line\|Stmts.\|Exclusive\|Avg. \|Code \|
1206	1203	\| \| \|Time \| \| \|
1207	1204	\|1 \| \| \| \|#!/usr/bin/perl \|
1208	1205	\|2 \| \| \| \| \|
1209	1206	\| \| \| \| \|use strict; \|
1210	1207	\|3 \|3 \|0.00086 \|0.00029\|# spent 0.00003s making 1 calls to strict:: \|
1211	1208	\| \| \| \| \|import \|
1212	1209	\| \| \| \| \|use warnings; \|
1213	1210	\|4 \|3 \|0.01563 \|0.00521\|# spent 0.00012s making 1 calls to warnings:: \|
1214	1211	\| \| \| \| \|import \|
1215	1212	\|5 \| \| \| \| \|
1216	1213	\|6 \| \| \| \|=head1 NAME \|
1217	1214	\|7 \| \| \| \| \|
1218	1215	\|8 \| \| \| \|filewords - word analysis of input file \|
1219	1216	<...snip...>
1220	1217	\|62 \|1 \|0.00445 \|0.00445\|print report( %count ); \|
1221	1218	\| \| \| \| \|# spent 0.21404s making 1 calls to main::report\|
1222	1219	\|63 \| \| \| \| \|
1223	1220	\| \| \| \| \|# spent 23.56955s (10.47692+2.61571) within \|
1224	1221	\| \| \| \| \|main::matches which was called 251215 times, \|
1225	1222	\| \| \| \| \|avg 0.00005s/call: # 50243 times \|
1226	1223	\| \| \| \| \|(2.12134+0.51939s) at line 57 of wordmatch, avg\|
1227	1224	\| \| \| \| \|0.00005s/call # 50243 times (2.17735+0.54550s) \|
1228	1225	\|64 \| \| \| \|at line 56 of wordmatch, avg 0.00005s/call # \|
1229	1226	\| \| \| \| \|50243 times (2.10992+0.51797s) at line 58 of \|
1230	1227	\| \| \| \| \|wordmatch, avg 0.00005s/call # 50243 times \|
1231	1228	\| \| \| \| \|(2.12696+0.51598s) at line 55 of wordmatch, avg\|
1232	1229	\| \| \| \| \|0.00005s/call # 50243 times (1.94134+0.51687s) \|
1233	1230	\| \| \| \| \|at line 54 of wordmatch, avg 0.00005s/call \|
1234	1231	\| \| \| \| \|sub matches { \|
1235	1232	<...snip...>
1236	1233	\|102 \| \| \| \| \|
1237	1234	\| \| \| \| \|# spent 2.71199s within main::debug which was \|
1238	1235	\| \| \| \| \|called 260642 times, avg 0.00001s/call: # \|
1239	1236	\| \| \| \| \|251215 times (2.61571+0s) by main::matches at \|
1240	1237	\|103 \| \| \| \|line 74 of wordmatch, avg 0.00001s/call # 9427 \|
1241	1238	\| \| \| \| \|times (0.09628+0s) at line 50 of wordmatch, avg\|
1242	1239	\| \| \| \| \|0.00001s/call \|
1243	1240	\| \| \| \| \|sub debug { \|
1244	1241	\|104 \|260642\|0.58496 \|2e-06 \|my $message = shift; \|
1245	1242	\|105 \| \| \| \| \|
1246	1243	\|106 \|260642\|1.09917 \|4e-06 \|if ( $debug ) { \|
1247	1244	\|107 \| \| \| \|print STDERR "DBG: $message\n"; \|
1248	1245	\|108 \| \| \| \|} \|
1249	1246	\|109 \| \| \| \|} \|
1250	1247	\|110 \| \| \| \| \|
1251	1248	\|111 \|1 \|0.01501 \|0.01501\|exit 0; \|
1252	1249	\|112 \| \| \| \| \|
1253	1250
1254	1251	=begin original
1255	1252
1256	1253	Oodles of very useful information in there - this seems to be the way forward.
1257	1254
1258	1255	=end original
1259	1256
1260	1257	大量のとても有用な情報がここにあります - これは前進する道のように思えます。
1261	1258
1262	1259	=begin original
1263	1260
1264	1261	See also C<L<Devel::NYTProf::Apache>> which hooks C<Devel::NYTProf> into
1265	1262	C<mod_perl>.
1266	1263
1267	1264	=end original
1268	1265
1269	1266	C<mod_perl> に C<Devel::NYTProf> フックを付ける C<L<Devel::NYTProf::Apache>> も
1270	1267	参照してください。
1271	1268
1272	1269	=head1 SORTING
1273	1270
1274	1271	(ソート)
1275	1272
1276	1273	=begin original
1277	1274
1278	1275	Perl modules are not the only tools a performance analyst has at their
1279	1276	disposal, system tools like C<time> should not be overlooked as the next
1280	1277	example shows, where we take a quick look at sorting. Many books, theses and
1281	1278	articles, have been written about efficient sorting algorithms, and this is not
1282	1279	the place to repeat such work, there's several good sorting modules which
1283	1280	deserve taking a look at too: C<Sort::Maker>, C<Sort::Key> spring to mind.
1284	1281	However, it's still possible to make some observations on certain Perl specific
1285	1282	interpretations on issues relating to sorting data sets and give an example or
1286	1283	two with regard to how sorting large data volumes can effect performance.
1287	1284	Firstly, an often overlooked point when sorting large amounts of data, one can
1288	1285	attempt to reduce the data set to be dealt with and in many cases C<grep()> can
1289	1286	be quite useful as a simple filter:
1290	1287
1291	1288	=end original
1292	1289
1293	1290	Perl モジュールは性能分析者が持っている唯一の道具というわけではなく、
1294	1291	ソートについて軽く見てみる次の例のように、C<time> のようなシステムツールも
1295	1292	見落とすべきではありません。
1296	1293	効率的なソートアルゴリズムについて書かれている多くの多くの本、論文、記事が
1297	1294	あり、ここはそのようなことを繰り返す場所ではありません; 調べてみる価値のある
1298	1295	いくつかのよいソートモジュールもあります: C<Sort::Maker>, C<Sort::Key> が
1299	1296	思い浮かびます。
1300	1297	しかし、まだデータ集合のソートに関連する問題の Perl 特有の解釈に関して
1301	1298	いくつか観測できる可能性があるので、大量のデータがどのように性能に
1302	1299	影響するかに関する例をいくつか示します。
1303	1300	最初に、大量のデータをソートするときにしばしば見落とされる点は、扱うデータ
1304	1301	集合を減らそうと出来ることと、多くの場合 C<grep()> が単純なフィルタとして
1305	1302	かなり有用であるということです:
1306	1303
1307	1304	@data = sort grep { /$filter/ } @incoming
1308	1305
1309	1306	=begin original
1310	1307
1311	1308	A command such as this can vastly reduce the volume of material to actually
1312	1309	sort through in the first place, and should not be too lightly disregarded
1313	1310	purely on the basis of its simplicity. The C<KISS> principle is too often
1314	1311	overlooked - the next example uses the simple system C<time> utility to
1315	1312	demonstrate. Let's take a look at an actual example of sorting the contents of
1316	1313	a large file, an apache logfile would do. This one has over a quarter of a
1317	1314	million lines, is 50M in size, and a snippet of it looks like this:
1318	1315
1319	1316	=end original
1320	1317
1321	1318	このようなコマンドは最初に実際にソートする量をとても減らすことが出来、
1322	1319	単純性の原則だけであまり簡単に無視するべきではありません。
1323	1320	C<KISS> 原則はあまりにも見逃されています - 次の例はデモに単純なシステム
1324	1321	C<time> ユーティリティを使います。
1325	1322	大きなファイルの内容をソートするという実際の例を見てみましょう; apache の
1326	1323	ログファイルを使ってみます。
1327	1324	これは 25 万行 50M バイトを超えますが、その一部は以下のようなものです:
1328	1325
1329	1326	=begin original
1330	1327
1331	1328	# logfile
1332	1329
1333	1330	=end original
1334	1331
1335	1332	# ログファイル
1336	1333
1337	1334	188.209-65-87.adsl-dyn.isp.belgacom.be - - [08/Feb/2007:12:57:16 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1338	1335	188.209-65-87.adsl-dyn.isp.belgacom.be - - [08/Feb/2007:12:57:16 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1339	1336	151.56.71.198 - - [08/Feb/2007:12:57:41 +0000] "GET /suse-on-vaio.html HTTP/1.1" 200 2858 "http://www.linux-on-laptops.com/sony.html" "Mozilla/5.0 (Windows; U; Windows NT 5.2; en-US; rv:1.8.1.1) Gecko/20061204 Firefox/2.0.0.1"
1340	1337	151.56.71.198 - - [08/Feb/2007:12:57:42 +0000] "GET /data/css HTTP/1.1" 404 206 "http://www.rfi.net/suse-on-vaio.html" "Mozilla/5.0 (Windows; U; Windows NT 5.2; en-US; rv:1.8.1.1) Gecko/20061204 Firefox/2.0.0.1"
1341	1338	151.56.71.198 - - [08/Feb/2007:12:57:43 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.2; en-US; rv:1.8.1.1) Gecko/20061204 Firefox/2.0.0.1"
1342	1339	217.113.68.60 - - [08/Feb/2007:13:02:15 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1343	1340	217.113.68.60 - - [08/Feb/2007:13:02:16 +0000] "GET /data/css HTTP/1.1" 404 206 "http://www.rfi.net/" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1344	1341	debora.to.isac.cnr.it - - [08/Feb/2007:13:03:58 +0000] "GET /suse-on-vaio.html HTTP/1.1" 200 2858 "http://www.linux-on-laptops.com/sony.html" "Mozilla/5.0 (compatible; Konqueror/3.4; Linux) KHTML/3.4.0 (like Gecko)"
1345	1342	debora.to.isac.cnr.it - - [08/Feb/2007:13:03:58 +0000] "GET /data/css HTTP/1.1" 404 206 "http://www.rfi.net/suse-on-vaio.html" "Mozilla/5.0 (compatible; Konqueror/3.4; Linux) KHTML/3.4.0 (like Gecko)"
1346	1343	debora.to.isac.cnr.it - - [08/Feb/2007:13:03:58 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "Mozilla/5.0 (compatible; Konqueror/3.4; Linux) KHTML/3.4.0 (like Gecko)"
1347	1344	195.24.196.99 - - [08/Feb/2007:13:26:48 +0000] "GET / HTTP/1.0" 200 3309 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.1; fr; rv:1.8.0.9) Gecko/20061206 Firefox/1.5.0.9"
1348	1345	195.24.196.99 - - [08/Feb/2007:13:26:58 +0000] "GET /data/css HTTP/1.0" 404 206 "http://www.rfi.net/" "Mozilla/5.0 (Windows; U; Windows NT 5.1; fr; rv:1.8.0.9) Gecko/20061206 Firefox/1.5.0.9"
1349	1346	195.24.196.99 - - [08/Feb/2007:13:26:59 +0000] "GET /favicon.ico HTTP/1.0" 404 209 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.1; fr; rv:1.8.0.9) Gecko/20061206 Firefox/1.5.0.9"
1350	1347	crawl1.cosmixcorp.com - - [08/Feb/2007:13:27:57 +0000] "GET /robots.txt HTTP/1.0" 200 179 "-" "voyager/1.0"
1351	1348	crawl1.cosmixcorp.com - - [08/Feb/2007:13:28:25 +0000] "GET /links.html HTTP/1.0" 200 3413 "-" "voyager/1.0"
1352	1349	fhm226.internetdsl.tpnet.pl - - [08/Feb/2007:13:37:32 +0000] "GET /suse-on-vaio.html HTTP/1.1" 200 2858 "http://www.linux-on-laptops.com/sony.html" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1353	1350	fhm226.internetdsl.tpnet.pl - - [08/Feb/2007:13:37:34 +0000] "GET /data/css HTTP/1.1" 404 206 "http://www.rfi.net/suse-on-vaio.html" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)"
1354	1351	80.247.140.134 - - [08/Feb/2007:13:57:35 +0000] "GET / HTTP/1.1" 200 3309 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; .NET CLR 1.1.4322)"
1355	1352	80.247.140.134 - - [08/Feb/2007:13:57:37 +0000] "GET /data/css HTTP/1.1" 404 206 "http://www.rfi.net" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; .NET CLR 1.1.4322)"
1356	1353	pop.compuscan.co.za - - [08/Feb/2007:14:10:43 +0000] "GET / HTTP/1.1" 200 3309 "-" "www.clamav.net"
1357	1354	livebot-207-46-98-57.search.live.com - - [08/Feb/2007:14:12:04 +0000] "GET /robots.txt HTTP/1.0" 200 179 "-" "msnbot/1.0 (+http://search.msn.com/msnbot.htm)"
1358	1355	livebot-207-46-98-57.search.live.com - - [08/Feb/2007:14:12:04 +0000] "GET /html/oracle.html HTTP/1.0" 404 214 "-" "msnbot/1.0 (+http://search.msn.com/msnbot.htm)"
1359	1356	dslb-088-064-005-154.pools.arcor-ip.net - - [08/Feb/2007:14:12:15 +0000] "GET / HTTP/1.1" 200 3309 "-" "www.clamav.net"
1360	1357	196.201.92.41 - - [08/Feb/2007:14:15:01 +0000] "GET / HTTP/1.1" 200 3309 "-" "MOT-L7/08.B7.DCR MIB/2.2.1 Profile/MIDP-2.0 Configuration/CLDC-1.1"
1361	1358
1362	1359	=begin original
1363	1360
1364	1361	The specific task here is to sort the 286,525 lines of this file by Response
1365	1362	Code, Query, Browser, Referring Url, and lastly Date. One solution might be to
1366	1363	use the following code, which iterates over the files given on the
1367	1364	command-line.
1368	1365
1369	1366	=end original
1370	1367
1371	1368	ここでのタスクは Response Code, Query, Browser, Referring Url,
1372	1369	lastly Date からなる 286,525 行のファイルをソートすることです。
1373	1370	一つの解決法は、以下のコードのようにコマンドラインで指定されたファイルを
1374	1371	反復する方法かもしれません。
1375	1372
1376	1373	=begin original
1377	1374
1378	1375	# sort-apache-log
1379	1376
1380	1377	=end original
1381	1378
1382	1379	# apache のログのソート
1383	1380
1384	1381	#!/usr/bin/perl -n
1385	1382
1386		use ~~strict~~;
	1383	use v5.36;
1387		use warnings;
1388	1384
1389	1385	my @data;
1390	1386
1391	1387	LINE:
1392	1388	while ( <> ) {
1393	1389	my $line = $_;
1394	1390	if (
1395	1391	$line =~ m/^(
1396	1392	([\w\.\-]+) # client
1397	1393	\s-\s-\s*\[
1398	1394	([^]]+) # date
1399	1395	\]\s"\w+\s
1400	1396	(\S+) # query
1401	1397	[^"]+"\s*
1402	1398	(\d+) # status
1403	1399	\s+\S+\s+"[^"]*"\s+"
1404	1400	([^"]*) # browser
1405	1401	"
1406	1402	.*
1407	1403	)$/x
1408	1404	) {
1409	1405	my @chunks = split(/ +/, $line);
1410	1406	my $ip = $1;
1411	1407	my $date = $2;
1412	1408	my $query = $3;
1413	1409	my $status = $4;
1414	1410	my $browser = $5;
1415	1411
1416	1412	push(@data, [$ip, $date, $query, $status, $browser, $line]);
1417	1413	}
1418	1414	}
1419	1415
1420	1416	my @sorted = sort {
1421	1417	$a->[3] cmp $b->[3]
1422	1418	\|\|
1423	1419	$a->[2] cmp $b->[2]
1424	1420	\|\|
1425	1421	$a->[0] cmp $b->[0]
1426	1422	\|\|
1427	1423	$a->[1] cmp $b->[1]
1428	1424	\|\|
1429	1425	$a->[4] cmp $b->[4]
1430	1426	} @data;
1431	1427
1432	1428	foreach my $data ( @sorted ) {
1433	1429	print $data->[5];
1434	1430	}
1435	1431
1436	1432	exit 0;
1437	1433
1438	1434	=begin original
1439	1435
1440	1436	When running this program, redirect C<STDOUT> so it is possible to check the
1441	1437	output is correct from following test runs and use the system C<time> utility
1442	1438	to check the overall runtime.
1443	1439
1444	1440	=end original
1445	1441
1446	1442	このプログラムを実行するとき、以後のテストで出力が正しいか
1447	1443	チェックできるように C<STDOUT> をリダイレクトして、全体の実行時間を
1448	1444	チェックするためにシステムの C<time> ユーティリティを使います。
1449	1445
1450	1446	$> time ./sort-apache-log logfile > out-sort
1451	1447
1452	1448	real 0m17.371s
1453	1449	user 0m15.757s
1454	1450	sys 0m0.592s
1455	1451
1456	1452	=begin original
1457	1453
1458	1454	The program took just over 17 wallclock seconds to run. Note the different
1459	1455	values C<time> outputs, it's important to always use the same one, and to not
1460	1456	confuse what each one means.
1461	1457
1462	1458	=end original
1463	1459
1464	1460	プログラムは実行にちょうど 17 壁時計秒ほどかかりました。
1465	1461	C<time> 出力の異なった値に注意して、いつも同じものを使い、それぞれの値の
1466	1462	意味を混乱しないことが重要です。
1467	1463
1468	1464	=over 4
1469	1465
1470	1466	=item Elapsed Real Time
1471	1467
1472	1468	(実経過時間)
1473	1469
1474	1470	=begin original
1475	1471
1476	1472	The overall, or wallclock, time between when C<time> was called, and when it
1477	1473	terminates. The elapsed time includes both user and system times, and time
1478	1474	spent waiting for other users and processes on the system. Inevitably, this is
1479	1475	the most approximate of the measurements given.
1480	1476
1481	1477	=end original
1482	1478
1483	1479	C<time> が呼び出されてからそれが終了するまでの間の全体的な、あるいは
1484	1480	壁時計の、時間です。
1485	1481	経過時間にはユーザー時間とシステム時間、およびシステム上の他のユーザーや
1486	1482	プロセスを待つために費やされた時間を含みます。
1487	1483	必然的に、これは与えられたものに最も近い時間です。
1488	1484
1489	1485	=item User CPU Time
1490	1486
1491	1487	(ユーザー CPU 時間)
1492	1488
1493	1489	=begin original
1494	1490
1495	1491	The user time is the amount of time the entire process spent on behalf of the
1496	1492	user on this system executing this program.
1497	1493
1498	1494	=end original
1499	1495
1500	1496	ユーザー時間はこのシステムでこのプログラムを実行することで消費された
1501	1497	全体のプロセス時間です。
1502	1498
1503	1499	=item System CPU Time
1504	1500
1505	1501	(システム CPU 時間)
1506	1502
1507	1503	=begin original
1508	1504
1509	1505	The system time is the amount of time the kernel itself spent executing
1510	1506	routines, or system calls, on behalf of this process user.
1511	1507
1512	1508	=end original
1513	1509
1514	1510	システム時間はこのプロセスユーザーのためにカーネルが実行したルーチンや
1515	1511	システムコールの時間です。
1516	1512
1517	1513	=back
1518	1514
1519	1515	=begin original
1520	1516
1521	1517	Running this same process as a C<Schwarzian Transform> it is possible to
1522	1518	eliminate the input and output arrays for storing all the data, and work on the
1523	1519	input directly as it arrives too. Otherwise, the code looks fairly similar:
1524	1520
1525	1521	=end original
1526	1522
1527	1523	同じ処理を C<シュワルツ変換> (Schwarzian Transform) として実行すると、
1528	1524	全てのデータを補完するための配列の入出力を除去することができ、
1529	1525	入力を直接届いてすぐに処理します。
1530	1526	さもなければ、コードはほぼ似て見えます:
1531	1527
1532	1528	=begin original
1533	1529
1534	1530	# sort-apache-log-schwarzian
1535	1531
1536	1532	=end original
1537	1533
1538	1534	# apache のログをシュワルツ変換ソート
1539	1535
1540	1536	#!/usr/bin/perl -n
1541	1537
1542		use ~~strict~~;
	1538	use v5.36;
1543		use warnings;
1544	1539
1545	1540	print
1546	1541
1547	1542	map $_->[0] =>
1548	1543
1549	1544	sort {
1550	1545	$a->[4] cmp $b->[4]
1551	1546	\|\|
1552	1547	$a->[3] cmp $b->[3]
1553	1548	\|\|
1554	1549	$a->[1] cmp $b->[1]
1555	1550	\|\|
1556	1551	$a->[2] cmp $b->[2]
1557	1552	\|\|
1558	1553	$a->[5] cmp $b->[5]
1559	1554	}
1560	1555	map [ $_, m/^(
1561	1556	([\w\.\-]+) # client
1562	1557	\s-\s-\s*\[
1563	1558	([^]]+) # date
1564	1559	\]\s"\w+\s
1565	1560	(\S+) # query
1566	1561	[^"]+"\s*
1567	1562	(\d+) # status
1568	1563	\s+\S+\s+"[^"]*"\s+"
1569	1564	([^"]*) # browser
1570	1565	"
1571	1566	.*
1572	1567	)$/xo ]
1573	1568
1574	1569	=> <>;
1575	1570
1576	1571	exit 0;
1577	1572
1578	1573	=begin original
1579	1574
1580	1575	Run the new code against the same logfile, as above, to check the new time.
1581	1576
1582	1577	=end original
1583	1578
1584	1579	新しい時間をチェックするために上述のように同じログファイルに対して
1585	1580	新しいコードを実行します。
1586	1581
1587	1582	$> time ./sort-apache-log-schwarzian logfile > out-schwarz
1588	1583
1589	1584	real 0m9.664s
1590	1585	user 0m8.873s
1591	1586	sys 0m0.704s
1592	1587
1593	1588	=begin original
1594	1589
1595	1590	The time has been cut in half, which is a respectable speed improvement by any
1596	1591	standard. Naturally, it is important to check the output is consistent with
1597	1592	the first program run, this is where the Unix system C<cksum> utility comes in.
1598	1593
1599	1594	=end original
1600	1595
1601	1596	時間は半分になりました; これはあらゆる面で立派な速度改善です。
1602	1597	当然ながら、出力が最初のプログラムの実行と一貫性があることをチェックするのは
1603	1598	重要です; ここは Unix システム C<cksum> ユーティリティの出番です。
1604	1599
1605	1600	$> cksum out-sort out-schwarz
1606	1601	3044173777 52029194 out-sort
1607	1602	3044173777 52029194 out-schwarz
1608	1603
1609	1604	=begin original
1610	1605
1611	1606	BTW. Beware too of pressure from managers who see you speed a program up by 50%
1612	1607	of the runtime once, only to get a request one month later to do the same again
1613	1608	(true story) - you'll just have to point out you're only human, even if you are a
1614	1609	Perl programmer, and you'll see what you can do...
1615	1610
1616	1611	=end original
1617	1612
1618	1613	ところで。
1619	1614	あなたが一度実行時間を 50% 高速化したのを見た管理者が喜びすぎて、
1620	1615	一ヶ月後にもう一度同じことを要求してくることに注意してください(実話) -
1621	1616	例えあなたが Perl プログラマでもあなたがただの人間であることを
1622	1617	指摘する必要があり、何ができるかを見てみましょう…
1623	1618
1624	1619	=head1 LOGGING
1625	1620
1626	1621	(ロギング)
1627	1622
1628	1623	=begin original
1629	1624
1630	1625	An essential part of any good development process is appropriate error handling
1631	1626	with appropriately informative messages, however there exists a school of
1632	1627	thought which suggests that log files should be I<chatty>, as if the chain of
1633	1628	unbroken output somehow ensures the survival of the program. If speed is in
1634	1629	any way an issue, this approach is wrong.
1635	1630
1636	1631	=end original
1637	1632
1638	1633	良い開発プロセスの本質的な部分は、適切に情報があるメッセージによる
1639	1634	適切なエラー処理ですが、プログラムの生存を確実にするための壊れない
1640	1635	出力のチェーンのように、ログファイルは I<おしゃべり> であるべきという
1641	1636	考え方があります。
1642	1637	速度が問題なら、この手法は間違っています。
1643	1638
1644	1639	=begin original
1645	1640
1646	1641	A common sight is code which looks something like this:
1647	1642
1648	1643	=end original
1649	1644
1650	1645	よく見かけるのは以下のような感じのコードです:
1651	1646
1652	1647	logger->debug( "A logging message via process-id: $$ INC: "
1653	1648	. Dumper(\%INC) )
1654	1649
1655	1650	=begin original
1656	1651
1657	1652	The problem is that this code will always be parsed and executed, even when the
1658	1653	debug level set in the logging configuration file is zero. Once the debug()
1659	1654	subroutine has been entered, and the internal C<$debug> variable confirmed to
1660	1655	be zero, for example, the message which has been sent in will be discarded and
1661	1656	the program will continue. In the example given though, the C<\%INC> hash will
1662	1657	already have been dumped, and the message string constructed, all of which work
1663	1658	could be bypassed by a debug variable at the statement level, like this:
1664	1659
1665	1660	=end original
1666	1661
1667	1662	問題は、例えログ設定ファイルのデバッグレベルがゼロでも、このコードは常に
1668	1663	パースされて実行されることです。
1669	1664	例えば、一度 debug() サブルーチンに入って、内部の C<$debug> 変数が
1670	1665	ゼロであることを確認すると、送られたメッセージは捨てられてプログラムは
1671	1666	続行します。
1672	1667	しかし、上述の例では、C<\%INC> はすでにダンプされていて、メッセージ文字列は
1673	1668	構築されていて、このような作業の全ては以下のような文レベルの
1674	1669	デバッグ変数によって回避されるかもしれません:
1675	1670
1676	1671	logger->debug( "A logging message via process-id: $$ INC: "
1677	1672	. Dumper(\%INC) ) if $DEBUG;
1678	1673
1679	1674	=begin original
1680	1675
1681	1676	This effect can be demonstrated by setting up a test script with both forms,
1682	1677	including a C<debug()> subroutine to emulate typical C<logger()> functionality.
1683	1678
1684	1679	=end original
1685	1680
1686	1681	この効果は、両方の形式で設定したテストスクリプトで図示します;
1687	1682	これには典型的な C<logger()> 機能をエミュレートするための
1688	1683	C<debug()> サブルーチンです。
1689	1684
1690	1685	=begin original
1691	1686
1692	1687	# ifdebug
1693	1688
1694	1689	=end original
1695	1690
1696	1691	# ifdebug
1697	1692
1698	1693	#!/usr/bin/perl
1699	1694
1700		use ~~strict~~;
	1695	use v5.36;
1701		use warnings;
1702	1696
1703	1697	use Benchmark;
1704	1698	use Data::Dumper;
1705	1699	my $DEBUG = 0;
1706	1700
1707	1701	sub debug {
1708	1702	my $msg = shift;
1709	1703
1710	1704	if ( $DEBUG ) {
1711	1705	print "DEBUG: $msg\n";
1712	1706	}
1713	1707	};
1714	1708
1715	1709	timethese(100000, {
1716	1710	'debug' => sub {
1717	1711	debug( "A $0 logging message via process-id: $$" . Dumper(\%INC) )
1718	1712	},
1719	1713	'ifdebug' => sub {
1720	1714	debug( "A $0 logging message via process-id: $$" . Dumper(\%INC) ) if $DEBUG
1721	1715	},
1722	1716	});
1723	1717
1724	1718	=begin original
1725	1719
1726	1720	Let's see what C<Benchmark> makes of this:
1727	1721
1728	1722	=end original
1729	1723
1730	1724	これによって C<Benchmark> がすることを見てみましょう:
1731	1725
1732	1726	$> perl ifdebug
1733	1727	Benchmark: timing 100000 iterations of constant, sub...
1734	1728	ifdebug: 0 wallclock secs ( 0.01 usr + 0.00 sys = 0.01 CPU) @ 10000000.00/s (n=100000)
1735	1729	(warning: too few iterations for a reliable count)
1736	1730	debug: 14 wallclock secs (13.18 usr + 0.04 sys = 13.22 CPU) @ 7564.30/s (n=100000)
1737	1731
1738	1732	=begin original
1739	1733
1740	1734	In the one case the code, which does exactly the same thing as far as
1741	1735	outputting any debugging information is concerned, in other words nothing,
1742	1736	takes 14 seconds, and in the other case the code takes one hundredth of a
1743	1737	second. Looks fairly definitive. Use a C<$DEBUG> variable BEFORE you call the
1744	1738	subroutine, rather than relying on the smart functionality inside it.
1745	1739
1746	1740	=end original
1747	1741
1748	1742	ある場合では、デバッグ情報を出力するのと全く同じ、言い換えると何もしない
1749	1743	コードが 14 秒掛かっています; 他の場合ではコードは 0.01 秒掛かっています。
1750	1744	かなり明確に見えます。
1751	1745	内部のスマートな機能に依存するのではなく、サブルーチンを呼び出す前に
1752	1746	C<$DEBUG> 変数を使ってください。
1753	1747
1754	1748	=head2 Logging if DEBUG (constant)
1755	1749
1756	1750	(DEBUG (定数) によるロギング)
1757	1751
1758	1752	=begin original
1759	1753
1760	1754	It's possible to take the previous idea a little further, by using a compile
1761	1755	time C<DEBUG> constant.
1762	1756
1763	1757	=end original
1764	1758
1765	1759	コンパイル時 C<DEBUG> 定数を使うことで、前述のアイデアをさらに少し
1766	1760	進めることも可能です。
1767	1761
1768	1762	=begin original
1769	1763
1770	1764	# ifdebug-constant
1771	1765
1772	1766	=end original
1773	1767
1774	1768	# ifdebug-定数
1775	1769
1776	1770	#!/usr/bin/perl
1777	1771
1778		use ~~strict~~;
	1772	use v5.36;
1779		use warnings;
1780	1773
1781	1774	use Benchmark;
1782	1775	use Data::Dumper;
1783	1776	use constant
1784	1777	DEBUG => 0
1785	1778	;
1786	1779
1787	1780	sub debug {
1788	1781	if ( DEBUG ) {
1789	1782	my $msg = shift;
1790	1783	print "DEBUG: $msg\n";
1791	1784	}
1792	1785	};
1793	1786
1794	1787	timethese(100000, {
1795	1788	'debug' => sub {
1796	1789	debug( "A $0 logging message via process-id: $$" . Dumper(\%INC) )
1797	1790	},
1798	1791	'constant' => sub {
1799	1792	debug( "A $0 logging message via process-id: $$" . Dumper(\%INC) ) if DEBUG
1800	1793	},
1801	1794	});
1802	1795
1803	1796	=begin original
1804	1797
1805	1798	Running this program produces the following output:
1806	1799
1807	1800	=end original
1808	1801
1809	1802	このプログラムを実行すると以下の出力が得られます:
1810	1803
1811	1804	$> perl ifdebug-constant
1812	1805	Benchmark: timing 100000 iterations of constant, sub...
1813	1806	constant: 0 wallclock secs (-0.00 usr + 0.00 sys = -0.00 CPU) @ -7205759403792793600000.00/s (n=100000)
1814	1807	(warning: too few iterations for a reliable count)
1815	1808	sub: 14 wallclock secs (13.09 usr + 0.00 sys = 13.09 CPU) @ 7639.42/s (n=100000)
1816	1809
1817	1810	=begin original
1818	1811
1819	1812	The C<DEBUG> constant wipes the floor with even the C<$debug> variable,
1820	1813	clocking in at minus zero seconds, and generates a "warning: too few iterations
1821	1814	for a reliable count" message into the bargain. To see what is really going
1822	1815	on, and why we had too few iterations when we thought we asked for 100000, we
1823	1816	can use the very useful C<B::Deparse> to inspect the new code:
1824	1817
1825	1818	=end original
1826	1819
1827	1820	C<DEBUG> 定数は C<$debug> 変数に対してでも床掃除をして、マイナスゼロ秒として
1828	1821	記録しています; さらに
1829	1822	"warning: too few iterations for a reliable count" メッセージを生成します。
1830	1823	何が本当に起きているか、そしてなぜ 100000 を聞いたときに反復が
1831	1824	少なすぎるのかを見るために、新しいコードを調べるためにとても有用な
1832	1825	C<B::Deparse> を使えます:
1833	1826
1834	1827	$> perl -MO=Deparse ifdebug-constant
1835	1828
1836	1829	use Benchmark;
1837	1830	use Data::Dumper;
1838	1831	use constant ('DEBUG', 0);
1839	1832	sub debug {
1840	1833	use warnings;
1841	1834	use strict 'refs';
1842	1835	0;
1843	1836	}
1844	1837	use warnings;
1845	1838	use strict 'refs';
1846	1839	timethese(100000, {'sub', sub {
1847	1840	debug "A $0 logging message via process-id: $$" . Dumper(\%INC);
1848	1841	}
1849	1842	, 'constant', sub {
1850	1843	0;
1851	1844	}
1852	1845	});
1853	1846	ifdebug-constant syntax OK
1854	1847
1855	1848	=begin original
1856	1849
1857	1850	The output shows the constant() subroutine we're testing being replaced with
1858	1851	the value of the C<DEBUG> constant: zero. The line to be tested has been
1859	1852	completely optimized away, and you can't get much more efficient than that.
1860	1853
1861	1854	=end original
1862	1855
1863	1856	出力は、テストしている constant() サブルーチンが C<DEBUG> 定数の値: ゼロに
1864	1857	置き換えられていることを示しています。
1865	1858	テストしたラインは完全に最適化されていて、これ以上すごく効率的にすることは
1866	1859	できません。
1867	1860
1868	1861	=head1 POSTSCRIPT
1869	1862
1870	1863	(あとがき)
1871	1864
1872	1865	=begin original
1873	1866
1874	1867	This document has provided several way to go about identifying hot-spots, and
1875	1868	checking whether any modifications have improved the runtime of the code.
1876	1869
1877	1870	=end original
1878	1871
1879	1872	この文書は、ホットスポットの識別と、どの修正がコードの実行時間を
1880	1873	改善するかのチェックに関するいくつかの方法を提供しました。
1881	1874
1882	1875	=begin original
1883	1876
1884	1877	As a final thought, remember that it's not (at the time of writing) possible to
1885	1878	produce a useful program which will run in zero or negative time and this basic
1886	1879	principle can be written as: I<useful programs are slow> by their very
1887	1880	definition. It is of course possible to write a nearly instantaneous program,
1888	1881	but it's not going to do very much, here's a very efficient one:
1889	1882
1890	1883	=end original
1891	1884
1892	1885	最後の考慮点として、(これを書いている時点では) ゼロまたは負の時間で
1893	1886	実行できる有用なプログラムを作成することは不可能であることを
1894	1887	忘れないでください; そしてこの基本原則は次のように書けます:
1895	1888	定義により、I<有用なプログラムは遅い>。
1896	1889	もちろんほぼ瞬間的に動作するプログラムを書くことは可能ですが、とても
1897	1890	多くのことをすることは出来ません; 以下はとても効率的なものです:
1898	1891
1899	1892	$> perl -e 0
1900	1893
1901	1894	=begin original
1902	1895
1903	1896	Optimizing that any further is a job for C<p5p>.
1904	1897
1905	1898	=end original
1906	1899
1907	1900	これ以上の最適化は C<p5p> の仕事です。
1908	1901
1909	1902	=head1 SEE ALSO
1910	1903
1911	1904	=begin original
1912	1905
1913	1906	Further reading can be found using the modules and links below.
1914	1907
1915	1908	=end original
1916	1909
1917	1910	さらなる読み物は以下のモジュールとリンクを使って得られます。
1918	1911
1919	1912	=head2 PERLDOCS
1920	1913
1921	1914	(perldoc)
1922	1915
1923	1916	=begin original
1924	1917
1925	1918	For example: C<perldoc -f sort>.
1926	1919
1927	1920	=end original
1928	1921
1929	1922	例えば: C<perldoc -f sort>
1930	1923
1931	1924	L<perlfaq4>.
1932	1925
1933	1926	L<perlfork>, L<perlfunc>, L<perlretut>, L<perlthrtut>.
1934	1927
1935	1928	L<threads>.
1936	1929
1937	1930	=head2 MAN PAGES
1938	1931
1939	1932	(man ページ)
1940	1933
1941	1934	C<time>.
1942	1935
1943	1936	=head2 MODULES
1944	1937
1945	1938	(モジュール)
1946	1939
1947	1940	=begin original
1948	1941
1949	1942	It's not possible to individually showcase all the performance related code for
1950	1943	Perl here, naturally, but here's a short list of modules from the CPAN which
1951	1944	deserve further attention.
1952	1945
1953	1946	=end original
1954	1947
1955	1948	当然ながら、Perl で性能に関するコードを全て陳列することは不可能ですが、
1956	1949	以下は CPAN の中からさらなる注目を受けるに値するモジュールの短いリストです。
1957	1950
1958	1951	Apache::DProf
1959	1952	Apache::SmallProf
1960	1953	Benchmark
1961	1954	DBIx::Profile
1962	1955	Devel::AutoProfiler
1963	1956	Devel::DProf
1964	1957	Devel::DProfLB
1965	1958	Devel::FastProf
1966	1959	Devel::GraphVizProf
1967	1960	Devel::NYTProf
1968	1961	Devel::NYTProf::Apache
1969	1962	Devel::Profiler
1970	1963	Devel::Profile
1971	1964	Devel::Profit
1972	1965	Devel::SmallProf
1973	1966	Devel::WxProf
1974	1967	POE::Devel::Profiler
1975	1968	Sort::Key
1976	1969	Sort::Maker
1977	1970
1978	1971	=head2 URLS
1979	1972
1980	1973	(URL)
1981	1974
1982	1975	=begin original
1983	1976
1984	1977	Very useful online reference material:
1985	1978
1986	1979	=end original
1987	1980
1988	1981	とても有用なオンラインリファレンス:
1989	1982
1990		http://www.ccl4.org/~nick/P/Fast_Enough/
	1983	https://web.archive.org/web/20120515021937/http://www.ccl4.org/~nick/P/Fast_Enough/
1991	1984
1992		http://www-128.ibm.com/developerworks/library/l-optperl.html
	1985	https://web.archive.org/web/20050706081718/http://www-106.ibm.com/developerworks/library/l-optperl.html
1993	1986
1994		http://perlbuzz.com/2007/11/bind-output-variables-in-dbi-for-speed-and-safety~~.html~~
	1987	https://perlbuzz.com/2007/11/14/bind_output_variables_in_dbi_for_speed_and_safety/
1995	1988
1996	1989	http://en.wikipedia.org/wiki/Performance_analysis
1997	1990
1998	1991	http://apache.perl.org/docs/1.0/guide/performance.html
1999	1992
2000	1993	http://perlgolf.sourceforge.net/
2001	1994
2002	1995	http://www.sysarch.com/Perl/sort_paper.html
2003	1996
2004	1997	=head1 AUTHOR
2005	1998
2006	1999	Richard Foley <richard.foley@rfi.net> Copyright (c) 2008
2007	2000
2008	2001	=cut
2009	2002
2010	2003	=begin meta
2011	2004
2012	2005	Translate: SHIRAKATA Kentaro <argrath@ub32.org>
2013	2006	Status: completed
2014	2007
2015	2008	=end meta

Powered by Amon2, 翻訳, サイト. Operated by Japan Perl Association