| Filename | /home/gmc/projects/marcpm/marc-xml/conv.pl |
| Statements | Executed 20012 statements in 296ms |
| Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
|---|---|---|---|---|---|
| 294389 | 2 | 2 | 1.00s | 1.00s | UNIVERSAL::isa (xsub) |
| 40000 | 8 | 1 | 99.0ms | 99.0ms | UNIVERSAL::can (xsub) |
| 5005 | 2 | 1 | 61.8ms | 61.8ms | main::CORE:print (opcode) |
| 1 | 1 | 1 | 3.02ms | 141ms | main::BEGIN@3 |
| 1 | 1 | 1 | 1.02ms | 1.15ms | main::BEGIN@5 |
| 1 | 1 | 1 | 463µs | 463µs | MARC::Field::BEGIN@66 |
| 146 | 1 | 1 | 435µs | 435µs | mro::method_changed_in (xsub) |
| 146 | 1 | 1 | 304µs | 304µs | Internals::SvREADONLY (xsub) |
| 1 | 1 | 1 | 21µs | 56µs | main::BEGIN@4 |
| 1 | 1 | 1 | 14µs | 14µs | main::CORE:binmode (opcode) |
| 1 | 1 | 1 | 14µs | 14µs | version::(bool (xsub) |
| 1 | 1 | 1 | 11µs | 11µs | version::(cmp (xsub) |
| 0 | 0 | 0 | 0s | 0s | main::RUNTIME |
| Line | State ments |
Time on line |
Calls | Time in subs |
Code |
|---|---|---|---|---|---|
| 0 | 3 | 596µs | Profile data that couldn't be associated with a specific line: # spent 463µs making 1 call to MARC::Field::BEGIN@66
# spent 77µs making 1 call to MARC::File::XML::DESTROY
# spent 56µs making 1 call to XML::LibXML::END | ||
| 1 | 1 | 24µs | #!/usr/bin/perl | ||
| 2 | |||||
| 3 | 3 | 180µs | 2 | 141ms | # spent 141ms (3.02+138) within main::BEGIN@3 which was called:
# once (3.02ms+138ms) by main::RUNTIME at line 3 # spent 141ms making 1 call to main::BEGIN@3
# spent 13µs making 1 call to MARC::File::XML::import |
| 4 | 3 | 41µs | 2 | 91µs | # spent 56µs (21+35) within main::BEGIN@4 which was called:
# once (21µs+35µs) by main::RUNTIME at line 4 # spent 56µs making 1 call to main::BEGIN@4
# spent 35µs making 1 call to Exporter::import |
| 5 | 3 | 601µs | 1 | 1.15ms | # spent 1.15ms (1.02+127µs) within main::BEGIN@5 which was called:
# once (1.02ms+127µs) by main::RUNTIME at line 5 # spent 1.15ms making 1 call to main::BEGIN@5 |
| 6 | |||||
| 7 | 1 | 22µs | 1 | 14µs | binmode STDOUT, ':utf8'; # spent 14µs making 1 call to main::CORE:binmode |
| 8 | |||||
| 9 | 1 | 6µs | 1 | 74µs | my $batch = MARC::Batch->new('XML', $ARGV[0]); # spent 74µs making 1 call to MARC::Batch::new |
| 10 | 20001 | 295ms | 5000 | 94.5s | while (my $record = $batch->next) { # spent 94.5s making 5000 calls to MARC::Batch::next, avg 18.9ms/call |
| 11 | $i++; | ||||
| 12 | 10000 | 8.04s | print $record->as_usmarc(); # spent 7.98s making 5000 calls to MARC::Record::as_usmarc, avg 1.60ms/call
# spent 60.7ms making 5000 calls to main::CORE:print, avg 12µs/call | ||
| 13 | 5 | 1.12ms | if ($i % 1000 == 0) { # spent 1.12ms making 5 calls to main::CORE:print, avg 223µs/call | ||
| 14 | print STDERR "$i ", scalar(localtime), "\n"; | ||||
| 15 | } | ||||
| 16 | last if $i == 5000; | ||||
| 17 | } | ||||
| 18 | |||||
| - - | |||||
# spent 304µs within Internals::SvREADONLY which was called 146 times, avg 2µs/call:
# 146 times (304µs+0s) by constant::import at line 111 of constant.pm, avg 2µs/call | |||||
# spent 99.0ms within UNIVERSAL::can which was called 40000 times, avg 2µs/call:
# 5000 times (15.5ms+0s) by XML::SAX::Base::parse at line 2602 of XML/SAX/Base.pm, avg 3µs/call
# 5000 times (14.4ms+0s) by XML::SAX::Base::end_document at line 1428 of XML/SAX/Base.pm, avg 3µs/call
# 5000 times (12.2ms+0s) by XML::SAX::Base::start_element at line 278 of XML/SAX/Base.pm, avg 2µs/call
# 5000 times (11.8ms+0s) by XML::SAX::Base::set_document_locator at line 1612 of XML/SAX/Base.pm, avg 2µs/call
# 5000 times (11.8ms+0s) by XML::SAX::Base::end_element at line 2187 of XML/SAX/Base.pm, avg 2µs/call
# 5000 times (11.5ms+0s) by XML::SAX::Base::start_document at line 1244 of XML/SAX/Base.pm, avg 2µs/call
# 5000 times (11.4ms+0s) by XML::SAX::Base::characters at line 186 of XML/SAX/Base.pm, avg 2µs/call
# 5000 times (10.5ms+0s) by XML::SAX::Base::xml_decl at line 439 of XML/SAX/Base.pm, avg 2µs/call | |||||
# spent 1.00s within UNIVERSAL::isa which was called 294389 times, avg 3µs/call:
# 294381 times (1.00s+0s) by XML::LibXML::SAX::Parser::process_element at line 170 of XML/LibXML/SAX/Parser.pm, avg 3µs/call
# 8 times (31µs+0s) by base::import at line 80 of base.pm, avg 4µs/call | |||||
# spent 14µs within main::CORE:binmode which was called:
# once (14µs+0s) by main::RUNTIME at line 7 | |||||
sub main::CORE:print; # opcode | |||||
# spent 435µs within mro::method_changed_in which was called 146 times, avg 3µs/call:
# 146 times (435µs+0s) by constant::import at line 113 of constant.pm, avg 3µs/call | |||||
# spent 14µs within version::(bool which was called:
# once (14µs+0s) by DynaLoader::BEGIN@24 at line 47 of Config.pm | |||||
# spent 11µs within version::(cmp which was called:
# once (11µs+0s) by DynaLoader::BEGIN@24 at line 50 of Config.pm |