ANNOUNCEMENT: NSD 1.3.0 alpha 1
Colm MacCarthaigh
colm.maccarthaigh at heanet.ie
Mon Sep 22 18:56:21 UTC 2003
On Mon, Sep 22, 2003 at 07:46:36PM +0100, Colm MacCarthaigh wrote:
> zonec2 seems to take nearly 3 times as long compared to zonec
> (average of 1m48s Vs 42s), I havn't done a profile yet to
> figure out where it's spending most of it's time though.
Profiles attachted, though I can't see anything immediately obvious.
--
Colm MacCárthaigh / HEAnet, Teach Brooklawn, / Innealtóir Ghréasáin
+353 1 6609040 / Bóthar Shelbourne, BÁC, IE / http://www.hea.net/
-------------- next part --------------
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
47.33 15.18 15.18 183430998 0.00 0.00 dnamecmp
24.29 22.97 7.79 12458894 0.00 0.00 rbtree_find_less_equal
4.43 24.39 1.42 9373370 0.00 0.00 zone_addname
2.93 25.33 0.94 3835316 0.00 0.00 zone_addrrset
2.18 26.03 0.70 1280401 0.00 0.00 rbtree_next
2.06 26.69 0.66 41973548 0.00 0.00 zone_addbuf
2.03 27.34 0.65 1280401 0.00 0.00 zone_adddata
1.87 27.94 0.60 1280401 0.00 0.00 rbtree_insert
1.50 28.42 0.48 2 0.24 10.25 zone_dump
1.34 28.85 0.43 958835 0.00 0.00 zparseline
1.28 29.26 0.41 2 0.20 5.70 zone_read
1.12 29.62 0.36 20877861 0.00 0.00 zone_addcompr
0.81 29.88 0.26 1280401 0.00 0.00 rbtree_insert_fixup
0.78 30.13 0.25 1280401 0.00 0.00 dname_make
0.75 30.37 0.24 12458894 0.00 0.00 rbtree_search
0.59 30.56 0.19 958847 0.00 0.00 strdname
0.50 30.72 0.16 1917656 0.00 0.00 zone_addanswer
0.50 30.88 0.16 958835 0.00 0.00 zread
0.44 31.02 0.14 7386809 0.00 0.00 xalloc
0.37 31.14 0.12 5753013 0.00 0.00 zaddtoken
0.34 31.25 0.11 2592597 0.00 0.00 region_add_cleanup
0.34 31.36 0.11 958844 0.00 0.00 strtottl
0.28 31.45 0.09 1280401 0.00 0.00 namedb_put
0.28 31.54 0.09 958852 0.00 0.00 zrdatascan2
0.25 31.62 0.08 1280405 0.00 0.00 cleanup_rrset
0.22 31.69 0.07 2876499 0.00 0.00 intbyname
0.19 31.75 0.06 3841206 0.00 0.00 write_data
0.19 31.81 0.06 3198069 0.00 0.00 dnamedup
0.16 31.86 0.05 958833 0.00 0.00 zrdata
0.12 31.90 0.04 4156892 0.00 0.00 xrealloc
0.12 31.94 0.04 4 0.01 0.03 region_free_all
0.09 31.97 0.03 1917656 0.00 0.00 zone_initmsg
0.06 31.99 0.02 958833 0.00 0.00 zrdatafree
0.06 32.01 0.02 349170 0.00 0.00 rbtree_rotate_right
0.03 32.02 0.01 3841214 0.00 0.00 region_alloc
0.03 32.03 0.01 1917685 0.00 0.00 zaddrdata
0.03 32.04 0.01 1280401 0.00 0.00 xalloc_zero
0.03 32.05 0.01 958852 0.00 0.00 zrdatascan
0.03 32.06 0.01 Letext
0.03 32.07 0.01 Letext
0.00 32.07 0.00 423331 0.00 0.00 rbtree_rotate_left
0.00 32.07 0.00 4 0.00 0.00 rbtree_create
0.00 32.07 0.00 4 0.00 0.00 rbtree_first
0.00 32.07 0.00 3 0.00 0.00 zrdatacmp
0.00 32.07 0.00 2 0.00 0.00 nsd_zopen
0.00 32.07 0.00 2 0.00 0.00 nsd_zopen2
0.00 32.07 0.00 2 0.00 0.00 region_create
0.00 32.07 0.00 2 0.00 0.03 region_destroy
0.00 32.07 0.00 2 0.00 0.00 zclose
0.00 32.07 0.00 1 0.00 0.00 log_init
0.00 32.07 0.00 1 0.00 0.00 namedb_new
0.00 32.07 0.00 1 0.00 0.04 namedb_save
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.
calls the number of times this function was invoked, if
this function is profiled, else blank.
self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.
name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
Call graph (explanation follows)
granularity: each sample hit covers 4 byte(s) for 0.03% of 32.07 seconds
index % time self children called name
<spontaneous>
[1] 99.9 0.00 32.05 main [1]
0.48 20.02 2/2 zone_dump [4]
0.41 11.00 2/2 zone_read [6]
0.02 0.05 2/4 region_free_all [23]
0.00 0.04 1/1 namedb_save [35]
0.00 0.03 1/2 region_destroy [32]
0.00 0.00 1/1 namedb_new [45]
0.00 0.00 1/2 region_create [46]
0.00 0.00 1/1 log_init [53]
-----------------------------------------------
0.07 6.43 3834595/12458894 zone_read [6]
0.07 6.43 3835322/12458894 zone_adddata [7]
0.09 8.03 4788977/12458894 zone_dump [4]
[2] 65.9 0.24 20.90 12458894 rbtree_search [2]
7.79 13.11 12458894/12458894 rbtree_find_less_equal [3]
-----------------------------------------------
7.79 13.11 12458894/12458894 rbtree_search [2]
[3] 65.2 7.79 13.11 12458894 rbtree_find_less_equal [3]
13.11 0.00 158423928/183430998 dnamecmp [5]
-----------------------------------------------
0.48 20.02 2/2 main [1]
[4] 63.9 0.48 20.02 2 zone_dump [4]
0.65 10.55 1280401/1280401 zone_adddata [7]
0.09 8.03 4788977/12458894 rbtree_search [2]
0.70 0.00 1280401/1280401 rbtree_next [12]
0.00 0.00 4/4 rbtree_first [50]
-----------------------------------------------
0.00 0.00 8/183430998 zone_read [6]
2.07 0.00 25007062/183430998 rbtree_insert [9]
13.11 0.00 158423928/183430998 rbtree_find_less_equal [3]
[5] 47.3 15.18 0.00 183430998 dnamecmp [5]
-----------------------------------------------
0.41 11.00 2/2 main [1]
[6] 35.6 0.41 11.00 2 zone_read [6]
0.07 6.43 3834595/12458894 rbtree_search [2]
0.60 2.35 1280401/1280401 rbtree_insert [9]
0.16 1.16 958835/958835 zread [11]
0.11 0.00 2560808/2592597 region_add_cleanup [28]
0.04 0.04 2239235/3198069 dnamedup [25]
0.02 0.00 958830/7386809 xalloc [22]
0.00 0.00 1280407/3841214 region_alloc [40]
0.00 0.00 8/183430998 dnamecmp [5]
0.00 0.00 2/2 nsd_zopen [44]
0.00 0.00 2/958847 strdname [19]
0.00 0.00 1/958833 zrdatafree [38]
0.00 0.00 2/4156892 xrealloc [34]
0.00 0.00 4/4 rbtree_create [48]
0.00 0.00 3/3 zrdatacmp [51]
0.00 0.00 2/2 zclose [52]
-----------------------------------------------
0.65 10.55 1280401/1280401 zone_dump [4]
[7] 34.9 0.65 10.55 1280401 zone_adddata [7]
0.07 6.43 3835322/12458894 rbtree_search [2]
0.94 2.21 3835316/3835316 zone_addrrset [8]
0.09 0.31 1280401/1280401 namedb_put [15]
0.23 0.00 13207226/20877861 zone_addcompr [16]
0.16 0.02 1917656/1917656 zone_addanswer [20]
0.01 0.02 1280401/1280401 xalloc_zero [36]
0.03 0.00 1917656/1917656 zone_initmsg [37]
0.01 0.00 1280401/4156892 xrealloc [34]
-----------------------------------------------
0.94 2.21 3835316/3835316 zone_adddata [7]
[8] 9.8 0.94 2.21 3835316 zone_addrrset [8]
1.42 0.40 9373370/9373370 zone_addname [10]
0.40 0.00 25144464/41973548 zone_addbuf [13]
-----------------------------------------------
0.60 2.35 1280401/1280401 zone_read [6]
[9] 9.2 0.60 2.35 1280401 rbtree_insert [9]
2.07 0.00 25007062/183430998 dnamecmp [5]
0.26 0.02 1280401/1280401 rbtree_insert_fixup [17]
0.00 0.00 1280401/3841214 region_alloc [40]
-----------------------------------------------
1.42 0.40 9373370/9373370 zone_addrrset [8]
[10] 5.7 1.42 0.40 9373370 zone_addname [10]
0.26 0.00 16829084/41973548 zone_addbuf [13]
0.13 0.00 7670635/20877861 zone_addcompr [16]
-----------------------------------------------
0.16 1.16 958835/958835 zone_read [6]
[11] 4.1 0.16 1.16 958835 zread [11]
0.43 0.12 958835/958835 zparseline [14]
0.19 0.00 958832/958847 strdname [19]
0.05 0.12 958833/958833 zrdata [21]
0.11 0.00 958829/958844 strtottl [29]
0.07 0.00 2876499/2876499 intbyname [31]
0.02 0.02 958832/3198069 dnamedup [25]
0.02 0.00 958833/7386809 xalloc [22]
0.01 0.00 958833/4156892 xrealloc [34]
0.00 0.00 958833/1917685 zaddrdata [41]
-----------------------------------------------
0.70 0.00 1280401/1280401 zone_dump [4]
[12] 2.2 0.70 0.00 1280401 rbtree_next [12]
-----------------------------------------------
0.26 0.00 16829084/41973548 zone_addname [10]
0.40 0.00 25144464/41973548 zone_addrrset [8]
[13] 2.1 0.66 0.00 41973548 zone_addbuf [13]
-----------------------------------------------
0.43 0.12 958835/958835 zread [11]
[14] 1.7 0.43 0.12 958835 zparseline [14]
0.12 0.00 5753013/5753013 zaddtoken [26]
-----------------------------------------------
0.09 0.31 1280401/1280401 zone_adddata [7]
[15] 1.3 0.09 0.31 1280401 namedb_put [15]
0.25 0.00 1280401/1280401 dname_make [18]
0.06 0.00 3841203/3841206 write_data [33]
-----------------------------------------------
0.13 0.00 7670635/20877861 zone_addname [10]
0.23 0.00 13207226/20877861 zone_adddata [7]
[16] 1.1 0.36 0.00 20877861 zone_addcompr [16]
-----------------------------------------------
0.26 0.02 1280401/1280401 rbtree_insert [9]
[17] 0.9 0.26 0.02 1280401 rbtree_insert_fixup [17]
0.02 0.00 349170/349170 rbtree_rotate_right [39]
0.00 0.00 423331/423331 rbtree_rotate_left [49]
-----------------------------------------------
0.25 0.00 1280401/1280401 namedb_put [15]
[18] 0.8 0.25 0.00 1280401 dname_make [18]
0.00 0.00 1280401/3841214 region_alloc [40]
-----------------------------------------------
0.00 0.00 2/958847 zone_read [6]
0.00 0.00 2/958847 nsd_zopen [44]
0.00 0.00 11/958847 zrdatascan2 [27]
0.19 0.00 958832/958847 zread [11]
[19] 0.6 0.19 0.00 958847 strdname [19]
-----------------------------------------------
0.16 0.02 1917656/1917656 zone_adddata [7]
[20] 0.6 0.16 0.02 1917656 zone_addanswer [20]
0.02 0.00 1917656/4156892 xrealloc [34]
-----------------------------------------------
0.05 0.12 958833/958833 zread [11]
[21] 0.5 0.05 0.12 958833 zrdata [21]
0.01 0.11 958852/958852 zrdatascan [24]
-----------------------------------------------
0.00 0.00 2/7386809 nsd_zopen2 [47]
0.00 0.00 6/7386809 region_create [46]
0.00 0.00 28/7386809 region_add_cleanup [28]
0.00 0.00 31788/7386809 region_alloc [40]
0.02 0.00 958830/7386809 zone_read [6]
0.02 0.00 958833/7386809 zread [11]
0.02 0.00 958852/7386809 zrdatascan2 [27]
0.02 0.00 1280401/7386809 xalloc_zero [36]
0.06 0.00 3198069/7386809 dnamedup [25]
[22] 0.4 0.14 0.00 7386809 xalloc [22]
-----------------------------------------------
0.02 0.05 2/4 region_destroy [32]
0.02 0.05 2/4 main [1]
[23] 0.4 0.04 0.10 4 region_free_all [23]
0.08 0.02 1280405/1280405 cleanup_rrset [30]
-----------------------------------------------
0.01 0.11 958852/958852 zrdata [21]
[24] 0.4 0.01 0.11 958852 zrdatascan [24]
0.09 0.02 958852/958852 zrdatascan2 [27]
-----------------------------------------------
0.00 0.00 2/3198069 nsd_zopen2 [47]
0.02 0.02 958832/3198069 zread [11]
0.04 0.04 2239235/3198069 zone_read [6]
[25] 0.4 0.06 0.06 3198069 dnamedup [25]
0.06 0.00 3198069/7386809 xalloc [22]
-----------------------------------------------
0.12 0.00 5753013/5753013 zparseline [14]
[26] 0.4 0.12 0.00 5753013 zaddtoken [26]
-----------------------------------------------
0.09 0.02 958852/958852 zrdatascan [24]
[27] 0.4 0.09 0.02 958852 zrdatascan2 [27]
0.02 0.00 958852/7386809 xalloc [22]
0.01 0.00 958852/1917685 zaddrdata [41]
0.00 0.00 11/958847 strdname [19]
0.00 0.00 15/958844 strtottl [29]
-----------------------------------------------
0.00 0.00 1/2592597 namedb_new [45]
0.00 0.00 31788/2592597 region_alloc [40]
0.11 0.00 2560808/2592597 zone_read [6]
[28] 0.3 0.11 0.00 2592597 region_add_cleanup [28]
0.00 0.00 28/7386809 xalloc [22]
-----------------------------------------------
0.00 0.00 15/958844 zrdatascan2 [27]
0.11 0.00 958829/958844 zread [11]
[29] 0.3 0.11 0.00 958844 strtottl [29]
-----------------------------------------------
0.08 0.02 1280405/1280405 region_free_all [23]
[30] 0.3 0.08 0.02 1280405 cleanup_rrset [30]
0.02 0.00 958832/958833 zrdatafree [38]
-----------------------------------------------
0.07 0.00 2876499/2876499 zread [11]
[31] 0.2 0.07 0.00 2876499 intbyname [31]
-----------------------------------------------
0.00 0.03 1/2 namedb_save [35]
0.00 0.03 1/2 main [1]
[32] 0.2 0.00 0.07 2 region_destroy [32]
0.02 0.05 2/4 region_free_all [23]
-----------------------------------------------
0.00 0.00 1/3841206 namedb_new [45]
0.00 0.00 2/3841206 namedb_save [35]
0.06 0.00 3841203/3841206 namedb_put [15]
[33] 0.2 0.06 0.00 3841206 write_data [33]
-----------------------------------------------
0.00 0.00 2/4156892 zone_read [6]
0.01 0.00 958833/4156892 zread [11]
0.01 0.00 1280401/4156892 zone_adddata [7]
0.02 0.00 1917656/4156892 zone_addanswer [20]
[34] 0.1 0.04 0.00 4156892 xrealloc [34]
-----------------------------------------------
0.00 0.04 1/1 main [1]
[35] 0.1 0.00 0.04 1 namedb_save [35]
0.00 0.03 1/2 region_destroy [32]
0.00 0.00 2/3841206 write_data [33]
-----------------------------------------------
0.01 0.02 1280401/1280401 zone_adddata [7]
[36] 0.1 0.01 0.02 1280401 xalloc_zero [36]
0.02 0.00 1280401/7386809 xalloc [22]
-----------------------------------------------
0.03 0.00 1917656/1917656 zone_adddata [7]
[37] 0.1 0.03 0.00 1917656 zone_initmsg [37]
-----------------------------------------------
0.00 0.00 1/958833 zone_read [6]
0.02 0.00 958832/958833 cleanup_rrset [30]
[38] 0.1 0.02 0.00 958833 zrdatafree [38]
-----------------------------------------------
0.02 0.00 349170/349170 rbtree_insert_fixup [17]
[39] 0.1 0.02 0.00 349170 rbtree_rotate_right [39]
-----------------------------------------------
0.00 0.00 1/3841214 namedb_new [45]
0.00 0.00 4/3841214 rbtree_create [48]
0.00 0.00 1280401/3841214 dname_make [18]
0.00 0.00 1280401/3841214 rbtree_insert [9]
0.00 0.00 1280407/3841214 zone_read [6]
[40] 0.0 0.01 0.00 3841214 region_alloc [40]
0.00 0.00 31788/2592597 region_add_cleanup [28]
0.00 0.00 31788/7386809 xalloc [22]
-----------------------------------------------
0.00 0.00 958833/1917685 zread [11]
0.01 0.00 958852/1917685 zrdatascan2 [27]
[41] 0.0 0.01 0.00 1917685 zaddrdata [41]
-----------------------------------------------
<spontaneous>
[42] 0.0 0.01 0.00 Letext [42]
-----------------------------------------------
<spontaneous>
[43] 0.0 0.01 0.00 Letext [43]
-----------------------------------------------
0.00 0.00 2/2 zone_read [6]
[44] 0.0 0.00 0.00 2 nsd_zopen [44]
0.00 0.00 2/958847 strdname [19]
0.00 0.00 2/2 nsd_zopen2 [47]
-----------------------------------------------
0.00 0.00 1/1 main [1]
[45] 0.0 0.00 0.00 1 namedb_new [45]
0.00 0.00 1/2 region_create [46]
0.00 0.00 1/2592597 region_add_cleanup [28]
0.00 0.00 1/3841206 write_data [33]
0.00 0.00 1/3841214 region_alloc [40]
-----------------------------------------------
0.00 0.00 1/2 namedb_new [45]
0.00 0.00 1/2 main [1]
[46] 0.0 0.00 0.00 2 region_create [46]
0.00 0.00 6/7386809 xalloc [22]
-----------------------------------------------
0.00 0.00 2/2 nsd_zopen [44]
[47] 0.0 0.00 0.00 2 nsd_zopen2 [47]
0.00 0.00 2/3198069 dnamedup [25]
0.00 0.00 2/7386809 xalloc [22]
-----------------------------------------------
0.00 0.00 4/4 zone_read [6]
[48] 0.0 0.00 0.00 4 rbtree_create [48]
0.00 0.00 4/3841214 region_alloc [40]
-----------------------------------------------
0.00 0.00 423331/423331 rbtree_insert_fixup [17]
[49] 0.0 0.00 0.00 423331 rbtree_rotate_left [49]
-----------------------------------------------
0.00 0.00 4/4 zone_dump [4]
[50] 0.0 0.00 0.00 4 rbtree_first [50]
-----------------------------------------------
0.00 0.00 3/3 zone_read [6]
[51] 0.0 0.00 0.00 3 zrdatacmp [51]
-----------------------------------------------
0.00 0.00 2/2 zone_read [6]
[52] 0.0 0.00 0.00 2 zclose [52]
-----------------------------------------------
0.00 0.00 1/1 main [1]
[53] 0.0 0.00 0.00 1 log_init [53]
-----------------------------------------------
This table describes the call tree of the program, and was sorted by
the total amount of time spent in each function and its children.
Each entry in this table consists of several lines. The line with the
index number at the left hand margin lists the current function.
The lines above it list the functions that called this function,
and the lines below it list the functions this one called.
This line lists:
index A unique number given to each element of the table.
Index numbers are sorted numerically.
The index number is printed next to every function name so
it is easier to look up where the function in the table.
% time This is the percentage of the `total' time that was spent
in this function and its children. Note that due to
different viewpoints, functions excluded by options, etc,
these numbers will NOT add up to 100%.
self This is the total amount of time spent in this function.
children This is the total amount of time propagated into this
function by its children.
called This is the number of times the function was called.
If the function called itself recursively, the number
only includes non-recursive calls, and is followed by
a `+' and the number of recursive calls.
name The name of the current function. The index number is
printed after it. If the function is a member of a
cycle, the cycle number is printed between the
function's name and the index number.
For the function's parents, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the function into this parent.
children This is the amount of time that was propagated from
the function's children into this parent.
called This is the number of times this parent called the
function `/' the total number of times the function
was called. Recursive calls to the function are not
included in the number after the `/'.
name This is the name of the parent. The parent's index
number is printed after it. If the parent is a
member of a cycle, the cycle number is printed between
the name and the index number.
If the parents of the function cannot be determined, the word
`<spontaneous>' is printed in the `name' field, and all the other
fields are blank.
For the function's children, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the child into the function.
children This is the amount of time that was propagated from the
child's children to the function.
called This is the number of times the function called
this child `/' the total number of times the child
was called. Recursive calls by the child are not
listed in the number after the `/'.
name This is the name of the child. The child's index
number is printed after it. If the child is a
member of a cycle, the cycle number is printed
between the name and the index number.
If there are any cycles (circles) in the call graph, there is an
entry for the cycle-as-a-whole. This entry shows who called the
cycle (as parents) and the members of the cycle (as children.)
The `+' recursive calls entry shows the number of function calls that
were internal to the cycle, and the calls entry for each member shows,
for that member, how many times it was called from other members of
the cycle.
Index by function name
[42] Letext (rbtree.c) [12] rbtree_next [20] zone_addanswer
[43] Letext (util.c) [49] rbtree_rotate_left [13] zone_addbuf
[30] cleanup_rrset [39] rbtree_rotate_right [16] zone_addcompr
[18] dname_make [2] rbtree_search [7] zone_adddata
[5] dnamecmp [28] region_add_cleanup [10] zone_addname
[25] dnamedup [40] region_alloc [8] zone_addrrset
[31] intbyname [46] region_create [4] zone_dump
[53] log_init [32] region_destroy [37] zone_initmsg
[45] namedb_new [23] region_free_all [6] zone_read
[15] namedb_put [19] strdname [14] zparseline
[35] namedb_save [29] strtottl [21] zrdata
[44] nsd_zopen [33] write_data [51] zrdatacmp
[47] nsd_zopen2 [22] xalloc [38] zrdatafree
[48] rbtree_create [36] xalloc_zero [24] zrdatascan
[3] rbtree_find_less_equal [34] xrealloc [27] zrdatascan2
[50] rbtree_first [41] zaddrdata [11] zread
[9] rbtree_insert [26] zaddtoken
[17] rbtree_insert_fixup [52] zclose
-------------- next part --------------
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
47.33 15.18 15.18 183430998 0.00 0.00 dnamestr
24.04 22.89 7.71 4 1.93 5.21 region_add_cleanup
7.42 25.27 2.38 49642716 0.00 0.00 zone_addrrset
2.99 26.23 0.96 3198063 0.00 0.00 process_rr
2.21 26.94 0.71 1280403 0.00 0.00 region_alloc
1.71 27.49 0.55 zone_dump
1.50 27.97 0.48 2 0.24 11.06 main
1.43 28.43 0.46 rbtree_next
1.22 28.82 0.39 2876542 0.00 0.00 yyparse
0.84 29.09 0.27 3835316 0.00 0.00 zone_addanswer
0.81 29.35 0.26 12458894 0.00 0.00 region_destroy
0.81 29.61 0.26 zone_addzonecut
0.78 29.86 0.25 yy_init_buffer
0.56 30.04 0.18 1280401 0.00 0.00 dname_make
0.50 30.20 0.16 1629571 0.00 0.00 rbtree_insert
0.47 30.35 0.15 7386809 0.00 0.00 zone_print
0.37 30.47 0.12 dnamedup
0.37 30.59 0.12 yy_delete_buffer
0.37 30.71 0.12 yylex
0.34 30.82 0.11 3841214 0.00 0.00 log_open
0.31 30.92 0.10 1280401 0.00 0.00 zone_adddata
0.28 31.01 0.09 1917656 0.00 0.00 zone_addcompr
0.28 31.10 0.09 rbtree_search
0.28 31.19 0.09 zone_read
0.25 31.27 0.08 958835 0.00 0.00 yy_switch_to_buffer
0.22 31.34 0.07 cat_dname
0.22 31.41 0.07 dname_parse
0.19 31.47 0.06 1 0.06 0.08 namedb_save
0.19 31.53 0.06 Letext
0.19 31.59 0.06 usage
0.16 31.64 0.05 7998098 0.00 0.00 zone_addbuf
0.16 31.69 0.05 region_create
0.16 31.74 0.05 region_get_current
0.12 31.78 0.04 5753013 0.00 0.00 yyrestart
0.12 31.82 0.04 4 0.01 0.01 xalloc
0.12 31.86 0.04 rbtree_find_less_equal
0.12 31.90 0.04 rbtree_rotate_left
0.09 31.93 0.03 1280401 0.00 0.00 namedb_put
0.06 31.95 0.02 12458894 0.00 0.00 region_set_current
0.06 31.97 0.02 3198069 0.00 0.00 rbtree_create
0.06 31.99 0.02 yy_create_buffer
0.06 32.01 0.02 yy_load_buffer_state
0.06 32.03 0.02 yy_scan_buffer
0.03 32.04 0.01 1280401 0.00 0.00 rbtree_first
0.03 32.05 0.01 cleanup_rrset
0.03 32.06 0.01 log_file
0.03 32.07 0.01 yy_get_next_buffer
0.00 32.07 0.00 2592597 0.00 0.00 region_free_all
0.00 32.07 0.00 958847 0.00 0.00 strdname
0.00 32.07 0.00 423335 0.00 0.00 rbtree_insert_fixup
0.00 32.07 0.00 2 0.00 0.00 region_alloc_zero
0.00 32.07 0.00 1 0.00 0.00 namedb_new
0.00 32.07 0.00 1 0.00 0.00 xalloc_zero
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.
calls the number of times this function was invoked, if
this function is profiled, else blank.
self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.
name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
Call graph (explanation follows)
granularity: each sample hit covers 4 byte(s) for 0.03% of 32.07 seconds
index % time self children called name
[1] 79.5 1.97 23.53 2876528+4478486 <cycle 1 as a whole> [1]
0.48 21.64 2 main <cycle 1> [2]
0.96 1.67 3198063 process_rr <cycle 1> [7]
0.39 0.20 2876542+5752996 yyparse <cycle 1> [11]
0.04 0.00 4 xalloc <cycle 1> [40]
0.00 0.00 2 region_alloc_zero <cycle 1> [55]
-----------------------------------------------
2 yyparse <cycle 1> [11]
[2] 69.0 0.48 21.64 2 main <cycle 1> [2]
7.71 13.11 4/4 region_add_cleanup [3]
0.71 0.00 1280401/1280403 region_alloc [10]
0.10 0.01 4788977/12458894 region_destroy [15]
1280401 zone_adddata <cycle 1> [23]
-----------------------------------------------
7.71 13.11 4/4 main <cycle 1> [2]
[3] 64.9 7.71 13.11 4 region_add_cleanup [3]
13.11 0.00 158423928/183430998 dnamestr [5]
-----------------------------------------------
<spontaneous>
[4] 58.4 0.55 18.18 zone_dump [4]
1.31 15.68 1917656/2876528 process_rr <cycle 1> [7]
0.63 0.00 13207226/49642716 zone_addrrset [9]
0.27 0.09 3835316/3835316 zone_addanswer [13]
0.09 0.00 1917656/1917656 zone_addcompr [31]
0.08 0.01 3835322/12458894 region_destroy [15]
0.01 0.00 1280401/7998098 zone_addbuf [37]
-----------------------------------------------
0.00 0.00 2/183430998 process_rr <cycle 1> [7]
0.00 0.00 2/183430998 zone_adddata <cycle 1> [23]
0.00 0.00 4/183430998 zone_addzonecut [12]
2.07 0.00 25007062/183430998 rbtree_next [8]
13.11 0.00 158423928/183430998 region_add_cleanup [3]
[5] 47.3 15.18 0.00 183430998 dnamestr [5]
-----------------------------------------------
<spontaneous>
[6] 26.5 0.01 8.50 yy_get_next_buffer [6]
0.66 7.84 958852/2876528 yyparse <cycle 1> [11]
0.00 0.00 1/7386809 zone_print [21]
-----------------------------------------------
2 yyparse <cycle 1> [11]
1280405 xalloc <cycle 1> [40]
1.31 15.68 1917656/2876528 zone_dump [4]
[7] 8.2 0.96 1.67 3198063 process_rr <cycle 1> [7]
1.65 0.00 34517834/49642716 zone_addrrset [9]
0.01 0.00 1917656/7998098 zone_addbuf [37]
0.00 0.00 2/183430998 dnamestr [5]
0.00 0.00 2/3841214 log_open [27]
0.00 0.00 2/3198069 rbtree_create [43]
0.00 0.00 2/2592597 region_free_all [50]
0.00 0.00 2/958847 strdname [54]
958834 yyparse <cycle 1> [11]
-----------------------------------------------
<spontaneous>
[8] 7.9 0.46 2.07 rbtree_next [8]
2.07 0.00 25007062/183430998 dnamestr [5]
-----------------------------------------------
22582063 zone_addrrset [9]
0.09 0.00 1917656/49642716 zone_addanswer [13]
0.63 0.00 13207226/49642716 zone_dump [4]
1.65 0.00 34517834/49642716 process_rr <cycle 1> [7]
[9] 7.4 2.38 0.00 49642716+22582063 zone_addrrset [9]
22582063 zone_addrrset [9]
-----------------------------------------------
0.00 0.00 1/1280403 namedb_new [49]
0.00 0.00 1/1280403 yyparse <cycle 1> [11]
0.71 0.00 1280401/1280403 main <cycle 1> [2]
[10] 2.2 0.71 0.00 1280403 region_alloc [10]
0.00 0.00 4/7386809 zone_print [21]
-----------------------------------------------
5752996 yyparse <cycle 1> [11]
958834 process_rr <cycle 1> [7]
958837 zone_adddata <cycle 1> [23]
0.00 0.00 4/2876528 zone_addzonecut [12]
0.00 0.00 15/2876528 yylex [22]
0.66 7.84 958852/2876528 yy_get_next_buffer [6]
[11] 1.8 0.39 0.20 2876542+5752996 yyparse <cycle 1> [11]
0.06 0.02 1/1 namedb_save [32]
0.08 0.00 958835/958835 yy_switch_to_buffer [33]
0.02 0.00 958835/7386809 zone_print [21]
0.01 0.00 958834/3198069 rbtree_create [43]
0.01 0.00 958833/7998098 zone_addbuf [37]
0.00 0.00 1/1 namedb_new [49]
0.00 0.00 1/1280403 region_alloc [10]
0.00 0.00 958834/958847 strdname [54]
0.00 0.00 1/1 xalloc_zero [56]
2 process_rr <cycle 1> [7]
2 main <cycle 1> [2]
2 xalloc <cycle 1> [40]
1 region_alloc_zero <cycle 1> [55]
5752996 yyparse <cycle 1> [11]
-----------------------------------------------
<spontaneous>
[12] 1.3 0.26 0.17 zone_addzonecut [12]
0.08 0.01 3834595/12458894 region_destroy [15]
0.04 0.00 1280405/3841214 log_open [27]
0.02 0.00 958830/7386809 zone_print [21]
0.01 0.00 2239233/3198069 rbtree_create [43]
0.01 0.00 1280401/1280401 rbtree_first [47]
0.00 0.00 4/2876528 yyparse <cycle 1> [11]
0.00 0.00 2560806/2592597 region_free_all [50]
0.00 0.00 4/183430998 dnamestr [5]
0.00 0.00 2/7998098 zone_addbuf [37]
-----------------------------------------------
0.27 0.09 3835316/3835316 zone_dump [4]
[13] 1.1 0.27 0.09 3835316 zone_addanswer [13]
0.09 0.00 1917656/49642716 zone_addrrset [9]
-----------------------------------------------
<spontaneous>
[14] 0.9 0.25 0.03 yy_init_buffer [14]
0.03 0.00 4794180/5753013 yyrestart [39]
-----------------------------------------------
0.08 0.01 3834595/12458894 zone_addzonecut [12]
0.08 0.01 3835322/12458894 zone_dump [4]
0.10 0.01 4788977/12458894 main <cycle 1> [2]
[15] 0.9 0.26 0.02 12458894 region_destroy [15]
0.02 0.00 12458894/12458894 region_set_current [42]
-----------------------------------------------
<spontaneous>
[16] 0.8 0.06 0.21 usage [16]
0.03 0.18 1280401/1280401 namedb_put [18]
-----------------------------------------------
<spontaneous>
[17] 0.7 0.05 0.16 region_create [17]
0.13 0.00 1280401/1629571 rbtree_insert [20]
0.04 0.00 1280401/3841214 log_open [27]
-----------------------------------------------
0.03 0.18 1280401/1280401 usage [16]
[18] 0.7 0.03 0.18 1280401 namedb_put [18]
0.18 0.00 1280401/1280401 dname_make [19]
0.00 0.00 1/7998098 zone_addbuf [37]
-----------------------------------------------
0.18 0.00 1280401/1280401 namedb_put [18]
[19] 0.6 0.18 0.00 1280401 dname_make [19]
0.00 0.00 1/2876528 region_alloc_zero <cycle 1> [55]
-----------------------------------------------
0.01 0.00 106037/1629571 rbtree_find_less_equal [36]
0.02 0.00 243133/1629571 rbtree_search [26]
0.13 0.00 1280401/1629571 region_create [17]
[20] 0.5 0.16 0.00 1629571 rbtree_insert [20]
0.00 0.00 147595/423335 rbtree_insert_fixup [51]
-----------------------------------------------
1280401 zone_print [21]
0.00 0.00 1/7386809 yy_get_next_buffer [6]
0.00 0.00 2/7386809 region_alloc_init [52]
0.00 0.00 4/7386809 region_alloc [10]
0.00 0.00 28/7386809 region_free_all [50]
0.00 0.00 31788/7386809 log_file [46]
0.02 0.00 958830/7386809 zone_addzonecut [12]
0.02 0.00 958835/7386809 yyparse <cycle 1> [11]
0.02 0.00 958851/7386809 yylex [22]
0.03 0.00 1280401/7386809 zone_adddata <cycle 1> [23]
0.06 0.00 3198069/7386809 rbtree_rotate_left [29]
[21] 0.5 0.15 0.00 7386809+1280401 zone_print [21]
1280401 zone_print [21]
-----------------------------------------------
1917704 yylex [22]
[22] 0.4 0.12 0.02 0+1917704 yylex [22]
0.02 0.00 958851/7386809 zone_print [21]
0.00 0.00 15/2876528 yyparse <cycle 1> [11]
0.00 0.00 11/958847 strdname [54]
1917704 yylex [22]
-----------------------------------------------
1280401 main <cycle 1> [2]
[23] 0.4 0.10 0.03 1280401 zone_adddata <cycle 1> [23]
0.03 0.00 1280401/7386809 zone_print [21]
0.00 0.00 2/183430998 dnamestr [5]
958837 yyparse <cycle 1> [11]
-----------------------------------------------
<spontaneous>
[24] 0.4 0.12 0.00 dnamedup [24]
-----------------------------------------------
<spontaneous>
[25] 0.4 0.12 0.00 yy_delete_buffer [25]
-----------------------------------------------
<spontaneous>
[26] 0.4 0.09 0.02 rbtree_search [26]
0.02 0.00 243133/1629571 rbtree_insert [20]
-----------------------------------------------
0.00 0.00 1/3841214 namedb_new [49]
0.00 0.00 2/3841214 process_rr <cycle 1> [7]
0.00 0.00 4/3841214 rbtree_insert_fixup [51]
0.04 0.00 1280401/3841214 dname_parse [28]
0.04 0.00 1280401/3841214 region_create [17]
0.04 0.00 1280405/3841214 zone_addzonecut [12]
[27] 0.3 0.11 0.00 3841214 log_open [27]
-----------------------------------------------
<spontaneous>
[28] 0.3 0.07 0.04 dname_parse [28]
0.04 0.00 1280401/3841214 log_open [27]
-----------------------------------------------
<spontaneous>
[29] 0.3 0.04 0.06 rbtree_rotate_left [29]
0.06 0.00 3198069/7386809 zone_print [21]
-----------------------------------------------
<spontaneous>
[30] 0.3 0.09 0.00 zone_read [30]
0.00 0.00 4/423335 rbtree_insert_fixup [51]
-----------------------------------------------
0.09 0.00 1917656/1917656 zone_dump [4]
[31] 0.3 0.09 0.00 1917656 zone_addcompr [31]
-----------------------------------------------
0.06 0.02 1/1 yyparse <cycle 1> [11]
[32] 0.3 0.06 0.02 1 namedb_save [32]
0.02 0.00 3841203/7998098 zone_addbuf [37]
-----------------------------------------------
0.08 0.00 958835/958835 yyparse <cycle 1> [11]
[33] 0.2 0.08 0.00 958835 yy_switch_to_buffer [33]
-----------------------------------------------
<spontaneous>
[34] 0.2 0.07 0.00 cat_dname [34]
-----------------------------------------------
<spontaneous>
[35] 0.2 0.06 0.00 Letext [35]
-----------------------------------------------
<spontaneous>
[36] 0.2 0.04 0.01 rbtree_find_less_equal [36]
0.01 0.00 106037/1629571 rbtree_insert [20]
0.00 0.00 275736/423335 rbtree_insert_fixup [51]
-----------------------------------------------
0.00 0.00 1/7998098 namedb_put [18]
0.00 0.00 2/7998098 namedb_discard [53]
0.00 0.00 2/7998098 zone_addzonecut [12]
0.01 0.00 958833/7998098 yyparse <cycle 1> [11]
0.01 0.00 1280401/7998098 zone_dump [4]
0.01 0.00 1917656/7998098 process_rr <cycle 1> [7]
0.02 0.00 3841203/7998098 namedb_save [32]
[37] 0.2 0.05 0.00 7998098 zone_addbuf [37]
-----------------------------------------------
<spontaneous>
[38] 0.2 0.05 0.00 region_get_current [38]
-----------------------------------------------
0.01 0.00 958833/5753013 yy_scan_buffer [41]
0.03 0.00 4794180/5753013 yy_init_buffer [14]
[39] 0.1 0.04 0.00 5753013 yyrestart [39]
-----------------------------------------------
2 region_alloc_zero <cycle 1> [55]
2 yyparse <cycle 1> [11]
[40] 0.1 0.04 0.00 4 xalloc <cycle 1> [40]
1280405 process_rr <cycle 1> [7]
-----------------------------------------------
<spontaneous>
[41] 0.1 0.02 0.01 yy_scan_buffer [41]
0.01 0.00 958833/5753013 yyrestart [39]
-----------------------------------------------
0.02 0.00 12458894/12458894 region_destroy [15]
[42] 0.1 0.02 0.00 12458894 region_set_current [42]
-----------------------------------------------
0.00 0.00 2/3198069 process_rr <cycle 1> [7]
0.01 0.00 958834/3198069 yyparse <cycle 1> [11]
0.01 0.00 2239233/3198069 zone_addzonecut [12]
[43] 0.1 0.02 0.00 3198069 rbtree_create [43]
-----------------------------------------------
<spontaneous>
[44] 0.1 0.02 0.00 yy_create_buffer [44]
-----------------------------------------------
<spontaneous>
[45] 0.1 0.02 0.00 yy_load_buffer_state [45]
-----------------------------------------------
<spontaneous>
[46] 0.0 0.01 0.00 log_file [46]
0.00 0.00 31788/7386809 zone_print [21]
0.00 0.00 31788/2592597 region_free_all [50]
-----------------------------------------------
0.01 0.00 1280401/1280401 zone_addzonecut [12]
[47] 0.0 0.01 0.00 1280401 rbtree_first [47]
-----------------------------------------------
<spontaneous>
[48] 0.0 0.01 0.00 cleanup_rrset [48]
-----------------------------------------------
0.00 0.00 1/1 yyparse <cycle 1> [11]
[49] 0.0 0.00 0.00 1 namedb_new [49]
0.00 0.00 1/1280403 region_alloc [10]
0.00 0.00 1/3841214 log_open [27]
0.00 0.00 1/2592597 region_free_all [50]
-----------------------------------------------
0.00 0.00 1/2592597 namedb_new [49]
0.00 0.00 2/2592597 process_rr <cycle 1> [7]
0.00 0.00 31788/2592597 log_file [46]
0.00 0.00 2560806/2592597 zone_addzonecut [12]
[50] 0.0 0.00 0.00 2592597 region_free_all [50]
0.00 0.00 28/7386809 zone_print [21]
-----------------------------------------------
0.00 0.00 4/423335 zone_read [30]
0.00 0.00 147595/423335 rbtree_insert [20]
0.00 0.00 275736/423335 rbtree_find_less_equal [36]
[51] 0.0 0.00 0.00 423335 rbtree_insert_fixup [51]
0.00 0.00 4/3841214 log_open [27]
-----------------------------------------------
<spontaneous>
[52] 0.0 0.00 0.00 region_alloc_init [52]
0.00 0.00 2/7386809 zone_print [21]
-----------------------------------------------
<spontaneous>
[53] 0.0 0.00 0.00 namedb_discard [53]
0.00 0.00 2/7998098 zone_addbuf [37]
-----------------------------------------------
0.00 0.00 2/958847 process_rr <cycle 1> [7]
0.00 0.00 11/958847 yylex [22]
0.00 0.00 958834/958847 yyparse <cycle 1> [11]
[54] 0.0 0.00 0.00 958847 strdname [54]
-----------------------------------------------
1 yyparse <cycle 1> [11]
0.00 0.00 1/2876528 dname_make [19]
[55] 0.0 0.00 0.00 2 region_alloc_zero <cycle 1> [55]
2 xalloc <cycle 1> [40]
-----------------------------------------------
0.00 0.00 1/1 yyparse <cycle 1> [11]
[56] 0.0 0.00 0.00 1 xalloc_zero [56]
-----------------------------------------------
This table describes the call tree of the program, and was sorted by
the total amount of time spent in each function and its children.
Each entry in this table consists of several lines. The line with the
index number at the left hand margin lists the current function.
The lines above it list the functions that called this function,
and the lines below it list the functions this one called.
This line lists:
index A unique number given to each element of the table.
Index numbers are sorted numerically.
The index number is printed next to every function name so
it is easier to look up where the function in the table.
% time This is the percentage of the `total' time that was spent
in this function and its children. Note that due to
different viewpoints, functions excluded by options, etc,
these numbers will NOT add up to 100%.
self This is the total amount of time spent in this function.
children This is the total amount of time propagated into this
function by its children.
called This is the number of times the function was called.
If the function called itself recursively, the number
only includes non-recursive calls, and is followed by
a `+' and the number of recursive calls.
name The name of the current function. The index number is
printed after it. If the function is a member of a
cycle, the cycle number is printed between the
function's name and the index number.
For the function's parents, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the function into this parent.
children This is the amount of time that was propagated from
the function's children into this parent.
called This is the number of times this parent called the
function `/' the total number of times the function
was called. Recursive calls to the function are not
included in the number after the `/'.
name This is the name of the parent. The parent's index
number is printed after it. If the parent is a
member of a cycle, the cycle number is printed between
the name and the index number.
If the parents of the function cannot be determined, the word
`<spontaneous>' is printed in the `name' field, and all the other
fields are blank.
For the function's children, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the child into the function.
children This is the amount of time that was propagated from the
child's children to the function.
called This is the number of times the function called
this child `/' the total number of times the child
was called. Recursive calls by the child are not
listed in the number after the `/'.
name This is the name of the child. The child's index
number is printed after it. If the child is a
member of a cycle, the cycle number is printed
between the name and the index number.
If there are any cycles (circles) in the call graph, there is an
entry for the cycle-as-a-whole. This entry shows who called the
cycle (as parents) and the members of the cycle (as children.)
The `+' recursive calls entry shows the number of function calls that
were internal to the cycle, and the calls entry for each member shows,
for that member, how many times it was called from other members of
the cycle.
Index by function name
[35] Letext (rbtree.c) [51] rbtree_insert_fixup [6] yy_get_next_buffer
[34] cat_dname [8] rbtree_next [14] yy_init_buffer
[48] cleanup_rrset [29] rbtree_rotate_left [45] yy_load_buffer_state
[19] dname_make [26] rbtree_search [41] yy_scan_buffer
[28] dname_parse [3] region_add_cleanup [33] yy_switch_to_buffer
[24] dnamedup [10] region_alloc [22] yylex
[5] dnamestr [55] region_alloc_zero [11] yyparse
[46] log_file [17] region_create [39] yyrestart
[27] log_open [15] region_destroy [13] zone_addanswer
[2] main [50] region_free_all [37] zone_addbuf
[49] namedb_new [38] region_get_current [31] zone_addcompr
[18] namedb_put [42] region_set_current [23] zone_adddata
[32] namedb_save [54] strdname [9] zone_addrrset
[7] process_rr [16] usage [12] zone_addzonecut
[43] rbtree_create [40] xalloc [4] zone_dump
[36] rbtree_find_less_equal [56] xalloc_zero [21] zone_print
[47] rbtree_first [44] yy_create_buffer [30] zone_read
[20] rbtree_insert [25] yy_delete_buffer [1] <cycle 1>
More information about the nsd-users
mailing list