awk: fatal error: internal error

[george anzinger]

address@hidden  awk -f format.awk awk_input 
found loop
                           no_hz_stats: accounting: end_ -> no_hz_stats:
accounting: end  646             .06           .48           .08        
54.63<> no_hz_stats<> no_hz_stats: accounting: end  646            
.06           .48           .08         54.63<>1
1> no_hz_stats: accounting<
tail 1035.19 18 2
                       no_hz_stats_outlaw: next_timer_ ->
no_hz_stats_outlaw: next_timer  3946            .01         
1.86           .25       1002.32<> no_hz_stats<> no_hz_stats_outlaw:
next_timer  3946            .01          1.86           .25      
1002.32<>0
tail 5159.45 17 1
awk: /usr/src/incoming/tpt/format.awk:158:
(FILENAME=/usr/src/incoming/tpt/errout FNR=18) fatal error: internal
error
Aborted (core dumped)
address@hidden 2.4.4-ntx-kb]$awk --version
GNU Awk 3.0.4
Copyright (C) 1989, 1991-1999 Free Software Foundation.
....

Appears to fail on attempting to return from the awk function "dive". 
All lines produced are debug lines used to try and track down the
problem.  The problem appears to be memory related, in that removing one
line from the input file causes correct operation.  (To see the desired
output, remove any line save the first one.  Productions will include
the above lines followed by the desired output, less, of course, the
info from the deleted line.)

Is there a quick fix?

George

# Awk script to sumrize and total time peg info.
#
# The data comes from tpt as, for example: 

#Timer overhead: update_wall_time_:0 -> Timer overhead: update_wall_time:0  
78104           .11          1.73           .12       9522.06
 
# where the numbers are "count" "min" "max" "average" "total" for each
# measured path.  We assume the path names are to be broken down by
# the ":" separators, into sub paths.  We want to total each class and
# print something like:

# Timer overhead
#                update_wall_time  78104    .11    1.73     .12       9522.06
#                .... etc ...         20    ..
# Timer overhead  % elapsed  TOTALS    nnn      nn                       nnn

# Note that the :0 is a line number and is to be ignored.
# If more than one ":" appears in a name, it will cause further summarizing.
#
# Percent of elapsed time is derived from the line:
#  START TIME PEGS:0 -> ELAPSED TIME PEG TIME:0  1      781848820.55  
781848820.55  781848820.55  781848820.55
#
# Which must appear somewhere in the input.

BEGIN {
    FS = "->";
    no = 0;
}

{
    s0 = " "  $0;
    gsub(":0 "," ",s0);
    gsub(":0 "," ",$1);
    gsub(":0 "," ",$2); 
    no_in_1 = split($1,first,":");
    no_in_2 = split($2,second,":");
    if(no_in_1 != no_in_2)  {
        print s0;
        next;
    }
    if(no_in_2 == 1) {


        if ( index($2,"ELAPSED TIME PEG TIME")) {
            tmp = $2
            gsub("ELAPSED TIME PEG TIME","",tmp);
            split(tmp,ELAPSED," ");
        }
    }
        Master[no++] = s0;
        next;


}
END {
    mm = 0;
    saveline("^");
    for (n in Master) {

        line = Master[n];
        if ( line == "" ) continue;
        gsub(/ +/, " ",line);
        split(line,rec,FS);
        no_in_1 = split(rec[1],first,":");
        no_in_2 = split(rec[2],second,":");
#       print ">" first[1]"<>"first[2]"<>"second[1]"<>"second[2];
        if (first[1] != second[1]){
            line = Master[n];
            gsub(/^ +/," ",line);
            saveline(line);
#           outline[mm++] = line;
            delete Master[n];
            continue;
        }
    }

    saveline("^");
    for (n in Master) {
        if ( Master[n] == "" ) continue;
        record_length = length(Master[n]);
        split(Master[n],rec,FS);
        no_in_1 = split(rec[1],first,":");
        no_in_2 = split(rec[2],second,":");
        dive(n,1,second[1]);
    }
# All the lines are in outline[m].  Head lines have "^" in front.
# Scan to find the longest line then put the lines out with 
# spacing to do an align right, except align left head lines.

    maxline = 0;
    for (l in outline){
        rlen = length(outline[l]);
        if (maxline < rlen) {
            maxline = rlen;
        }
    }
    for (l = 0; l < mm; l++){
#       print l;
        line = outline[l];
        if ( sub(/^\^/,"",line)){
            print line;
        } else {
            datum_length = length(line);
            fill = "";
            for ( i = datum_length; i < maxline; i++){
                fill = fill " ";
            }
            print fill line;
        }
    }
}
 
function dive(lc, level, key,  counter) {
    do_head(lc,key);
    
    found = 0;
    for (nn in Master){
        line = Master[nn];
        gsub(/ +/," ",line);
        split(line,recc,FS);
#       print ">>" key "<>" recc[2] "<";
#       print index(recc[2],key);
        if (index(recc[2],key ":") != 1) continue;
        no_in_1c = split(recc[1],firstc,":");
        no_in_2c = split(recc[2],secondc,":");
#       print no_in_1c, no_in_2c, level, lc
        minc = min(no_in_1c,no_in_2c) -1;
        if (minc == level){
            foo = Master[nn];
            gsub(key ":","",foo);
            saveline(foo);
#           outline[mm++] = foo;
            counter += time(nn);
            delete Master[nn];
        }
        if (minc > level ) {
            found = 1;
        }
    }

    if ( found ) {
        print "found loop"
        for (nn in Master){
            split(Master[nn],recc,FS);
            print Master[nn]"<>"key"<>"recc[2]"<>"index(recc[2],key":")
            if (index(recc[2],key":") == 1){
                    no_in_1c = split(recc[1],firstc,":");
                    no_in_2c = split(recc[2],secondc,":");
                    minc = min(no_in_1c,no_in_2c);
                    print level">"key ":" secondc[level+1]"<"
                    counter += dive(lc+1, level+1, key  ":" secondc[level+1]);
            }
        }
    }
    do_tail(lc,key,counter);
    print "tail",counter,lc,level
    return counter;
    print "what"

}

function min(a,b) {
    return (a < b ? a:b);
}
function do_tail(count, key, counter) {
#    print "tail called " key " " counter;
    saveline( key "  " counter / (ELAPSED[2] / 100) "% of cpu @ " counter);
#    datum_length = length(datum);
#    fill = "";
#    for ( i = datum_length; i < record_length; i++){
#       fill = fill " ";
#    }
#    print fill datum;
#    print " ";
}
function do_head(count,key) {
#    print "head called" Master[count]; 
    saveline( "^" key);
}
function time(rec) {
    time_a = split(Master[rec],time_b," ");
#    print "time" Master[rec] " " time_b[time_a];
    return time_b[time_a];
}
function saveline(inline){
#    print line;
#    print inline;
    gsub(/^ +/," ",inline);
    outline[mm++] = inline;
}

                                               START TIME PEGS:0 -> ELAPSED 
TIME PEG TIME:0  1      194419184.36  194419184.36  194419184.36  194419184.36
                                  no_hz_stats: jiffies_:0 -> no_hz_stats: 
do_timer_notify:0  196            3.25          4.31          3.45        677.47
                                          no_hz_stats: jiffies_:0 -> 
no_hz_stats: jiffies:0  34542           .04           .84           .06       
2424.37
                    no_hz_stats: accounting: end_:0 -> no_hz_stats: accounting: 
end_slice:0  462             .05           .14           .07         35.54
                          no_hz_stats: accounting: end_:0 -> no_hz_stats: 
accounting: end:0  646             .06           .48           .08         54.63
                no_hz_stats: accounting: timer_fn_:0 -> no_hz_stats: 
accounting: timer_fn:0  646             .05           .40           .06         
41.49
      no_hz_stats: accounting: process_times_:0 -> no_hz_stats: accounting: 
process_times:0  646             .00           .37           .01         12.53
no_hz_stats: accounting: do_process_times_:0 -> no_hz_stats: accounting: 
do_process_times:0  646             .02           .68           .06         
43.31
            no_hz_stats: accounting: do_it_virt_:0 -> no_hz_stats: accounting: 
do_it_virt:0  646             .00           .41           .01         13.66
            no_hz_stats: accounting: do_it_prof_:0 -> no_hz_stats: accounting: 
do_it_prof:0  646             .00           .33           .02         14.54
    no_hz_stats: accounting: counter&kstat2_:0 -> no_hz_stats: accounting: 
counter&kstat2:0  646             .01           .65           .04         31.73
                      no_hz_stats: accounting: setup_:0 -> no_hz_stats: 
accounting: setup:0  1108            .07          4.69           .71        
787.76
                          no_hz_stats: do_timer_notify_:0 -> no_hz_stats: 
do_timer_notify:0  1028            .00           .52           .02         26.70
                          no_hz_stats: do_gettimeofday:0 -> no_hz_stats: 
do_gettimeofday_:0  157             .12         10.00           .83        
130.67
                        no_hz_stats: update_wall_time_:0 -> no_hz_stats: 
update_wall_time:0  340             .02          1.41           .19         
67.40
                          no_hz_stats: timer interrupt_:0 -> no_hz_stats: timer 
interrupt:0  3946            .08          1.48           .09        359.62
                      no_hz_stats_outlaw: next_timer_:0 -> no_hz_stats_outlaw: 
next_timer:0  3946            .01          1.86           .25       1002.32
                                no_hz_stats: one_sec_tick_:0 -> no_hz_stats: 
one_sec_tick:0  194             .51         10.18          2.25        438.03