Menu
▾
▴
R: [Openpec-devel] Profiling: howto
|
From: Fanton F. <fa...@ks...> - 2004-05-20 08:42:43
|
In realta' quello che mi interessava era analizzare il tempo impiegato =
dalla firma/verifica rispetto al resto ma non ho pensato che queste =
ultime vengono chiamate come processo esterno e DProf rimane nel parent =
in waitpid:
da Opec::Sign::_exec()
defined($child =3D open(OUT, '-|'))
or return (-1);
if($child) {
$res =3D join('', <OUT>);
close(OUT) or not $! or return(-1);
} else {
select(STDERR); $| =3D 1;
select(STDOUT); $| =3D 1;
open(STDERR, ">&STDOUT") or die "Impossibile redirigere STDERR =
su STDOUT";
exec(@arg) or die "Impossibile eseguire exec";
}
return($?, $res);
Per non complicarmi troppo la vita direi di aggiungere dei "bookmark" =
nei punti caldi del codice e alla fine calcolare il tempo trascorso fra =
due "bookmark" consecutivi.
flazan
-----Messaggio originale-----
Da: Fanton Flavio=20
Inviato: gioved=EC 20 maggio 2004 10.33
A: ope...@li...
Oggetto: R: [Openpec-devel] Profiling: howto
I risultati
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
* Dall'output di dprofpp ho tolto le varie chiamate BEGIN visto che a =
regime non influiscono.
Le prove sono state effettuate sulla solita opec1 (caratteristiche su =
http://www.openpec.org/doc_test.shtml) e divise per firma e verifica e =
cambiando la dimensione della mail (1398 - 25914 - 4721768 BYTE).
Log al massimo livello (5) su file.
Ecco i tempi:
* Firma + ricevuta di accettazione
- MAIL DA 1398 BYTE
Total Elapsed Time =3D 10.55452 Seconds
User+System Time =3D 2.174525 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
6.58 0.143 0.142 918 0.0002 0.0002 =
Convert::ASN1::parser::yylex
5.47 0.119 -0.000 55 0.0022 - Exporter::export
3.82 0.083 0.225 1 0.0831 0.2254 =
Convert::ASN1::parser::yyparse
3.13 0.068 0.117 171 0.0004 0.0007 Exporter::import
1.79 0.039 0.039 83 0.0005 0.0005 vars::import
1.20 0.026 0.026 248 0.0001 0.0001 =
Convert::ASN1::parser::compile_one
0.92 0.020 0.069 1 0.0199 0.0693 =
Opec::Out::Dispatcher::new
0.92 0.020 0.057 1 0.0199 0.0573 Net::LDAP::search
0.92 0.020 0.020 34 0.0006 0.0006 =
Mail::Header::_tidy_header
0.92 0.020 0.020 62 0.0003 0.0003 =
Mail::Header::_fold_line
0.46 0.010 0.010 1 0.0100 0.0100 Time::HiRes::bootstrap
0.46 0.010 0.010 1 0.0100 0.0100 AutoLoader::AUTOLOAD
0.46 0.010 0.010 1 0.0100 0.0100 Opec::Conf::read_config
0.46 0.010 0.010 2 0.0050 0.0050 Opec::Xml::_openData
0.46 0.010 0.010 2 0.0050 0.0050 =
MIME::Body::Scalar::init
- MAIL DA 25914 BYTE
Total Elapsed Time =3D 5.147072 Seconds
User+System Time =3D 2.187072 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
7.45 0.163 0.224 1 0.1626 0.2245 =
Convert::ASN1::parser::yyparse
5.40 0.118 0.177 171 0.0007 0.0010 Exporter::import
4.98 0.109 -0.000 55 0.0020 - Exporter::export
2.83 0.062 0.062 918 0.0001 0.0001 =
Convert::ASN1::parser::yylex
1.55 0.034 0.037 3 0.0112 0.0123 =
MIME::Decoder::NBit::encode_it
1.37 0.030 0.030 34 0.0009 0.0009 Mail::Header::_tidy_header
1.33 0.029 0.029 83 0.0004 0.0004 vars::import
0.91 0.020 0.020 6 0.0033 0.0033 Net::LDAP::Constant::_find
0.91 0.020 0.069 1 0.0199 0.0693 Opec::Out::Dispatcher::new
0.91 0.020 0.019 59 0.0003 0.0003 Exporter::as_heavy
0.91 0.020 0.020 62 0.0003 0.0003 Mail::Header::_fold_line
0.87 0.019 0.018 2 0.0097 0.0090 Mail::Header::read
0.87 0.019 0.019 181 0.0001 0.0001 Mail::Header::_tag_case
0.78 0.017 0.011 100 0.0002 0.0001 Opec::Log::writeLog
0.73 0.016 0.026 248 0.0001 0.0001 =
Convert::ASN1::parser::compile_one
- MAIL DA 4721768 BYTE
Total Elapsed Time =3D 23.00064 Seconds
User+System Time =3D 6.400647 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
27.4 1.759 1.759 61413 0.0000 0.0000 IO::Wrap::getline
24.4 1.567 4.024 3 0.5223 1.3412 =
MIME::Decoder::NBit::encode_it
14.3 0.920 6.151 1 0.9195 6.1506 =
Opec::In::SMTP::process_request
10.9 0.698 0.698 61486 0.0000 0.0000 IO::Wrap::print
7.23 0.463 0.468 295 0.0016 0.0016 Net::Cmd::datasend
6.56 0.420 4.519 2 0.2098 2.2596 Opec::Sign::_sign
2.39 0.153 0.224 1 0.1526 0.2245 =
Convert::ASN1::parser::yyparse
1.86 0.119 -0.000 55 0.0022 - Exporter::export
1.69 0.108 0.157 171 0.0006 0.0009 Exporter::import
1.12 0.072 0.072 918 0.0001 0.0001 =
Convert::ASN1::parser::yylex
0.67 0.043 0.553 1 0.0426 0.5527 =
Opec::Out::SMTP::_mailViaSmtpSingle
0.59 0.038 0.038 296 0.0001 0.0001 IO::Handle::read
0.45 0.029 0.029 83 0.0004 0.0004 vars::import
0.41 0.026 0.026 248 0.0001 0.0001 =
Convert::ASN1::parser::compile_one
* Firma + ricevuta di presa in carico e avvenuta consegna
- MAIL DA 1398 BYTE
Total Elapsed Time =3D 6.970199 Seconds
User+System Time =3D 2.270199 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
6.30 0.143 0.214 1 0.1426 0.2145 =
Convert::ASN1::parser::yyparse
6.12 0.139 -0.000 55 0.0025 - Exporter::export
3.88 0.088 0.167 172 0.0005 0.0010 Exporter::import
3.17 0.072 0.072 918 0.0001 0.0001 =
Convert::ASN1::parser::yylex
1.67 0.038 0.038 236 0.0002 0.0002 Mail::Header::_tag_case
1.32 0.030 0.029 35 0.0008 0.0008 Net::Cmd::getline
1.15 0.026 0.026 248 0.0001 0.0001 =
Convert::ASN1::parser::compile_one
0.88 0.020 0.069 1 0.0199 0.0693 Opec::Out::Dispatcher::new
0.88 0.020 0.020 8 0.0025 0.0024 Mail::Field::_require_dir
0.88 0.020 0.020 45 0.0004 0.0004 Convert::ASN1::_decode_tl
0.88 0.020 0.019 59 0.0003 0.0003 Exporter::as_heavy
0.84 0.019 0.025 15 0.0013 0.0017 =
MIME::Parser::Reader::read_chunk
0.79 0.018 0.036 85 0.0002 0.0004 Mail::Header::_fmt_line
0.44 0.010 0.010 1 0.0100 0.0100 =
IO::WrapTie::Master::PRELOAD
- MAIL DA 25914 BYTE
Total Elapsed Time =3D 9.650885 Seconds
User+System Time =3D 2.400885 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
5.96 0.143 0.215 1 0.1431 0.2154 =
Convert::ASN1::parser::yyparse
5.37 0.129 -0.000 55 0.0023 - Exporter::export
3.04 0.073 0.072 918 0.0001 0.0001 =
Convert::ASN1::parser::yylex
2.42 0.058 0.137 172 0.0003 0.0008 Exporter::import
1.58 0.038 0.038 297 0.0001 0.0001 Mail::Header::_tag_case
1.54 0.037 0.056 106 0.0004 0.0005 Mail::Header::_fmt_line
1.54 0.037 0.037 370 0.0001 0.0001 IO::Wrap::read
1.08 0.026 0.026 248 0.0001 0.0001 =
Convert::ASN1::parser::compile_one
1.08 0.026 0.029 127 0.0002 0.0002 Opec::Log::writeLog
0.83 0.020 0.030 3 0.0067 0.0100 vars::BEGIN
0.83 0.020 0.020 6 0.0033 0.0033 Net::LDAP::Constant::_find
0.83 0.020 0.020 4 0.0050 0.0050 Errno::BEGIN
0.83 0.020 0.069 1 0.0199 0.0693 Opec::Out::Dispatcher::new
0.83 0.020 0.020 30 0.0007 0.0007 Mail::Header::_tidy_header
- MAIL DA 4721768 BYTE
Total Elapsed Time =3D 82.25980 Seconds
User+System Time =3D 8.769809 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
24.2 2.123 5.815 13 0.1633 0.4473 =
MIME::Decoder::Base64::encode_it
17.9 1.578 1.578 77604 0.0000 0.0000 IO::Wrap::read
17.2 1.516 1.516 77834 0.0000 0.0000 IO::Wrap::print
10.9 0.960 10.139 1 0.9596 10.138 =
Opec::In::SMTP::process_request
10.8 0.947 0.988 587 0.0016 0.0017 Net::Cmd::datasend
8.87 0.778 0.789 40 0.0194 0.0197 =
MIME::Parser::Reader::read_chunk
7.27 0.638 0.638 77622 0.0000 0.0000 MIME::Base64::encode_base64
5.59 0.490 6.401 2 0.2448 3.2003 Opec::Sign::_sign
2.36 0.207 0.375 13 0.0159 0.0288 =
MIME::Decoder::Base64::decode_it
1.86 0.163 0.225 1 0.1631 0.2254 =
Convert::ASN1::parser::yyparse
1.69 0.148 0.187 172 0.0009 0.0011 Exporter::import
1.47 0.129 1.840 13 0.0099 0.1415 Opec::BEGIN
1.41 0.124 0.124 753 0.0002 0.0002 IO::Handle::read
1.13 0.099 -0.000 55 0.0018 - Exporter::export
flazan
|
