github.com/swiftstack/proxyfs@v0.0.0-20201223034610-5434d919416e/jrpcfs/io_stats (about) 1 #! /usr/bin/awk -f 2 # 3 # Command to parse periodic stats logs from proxyfsd.log 4 # and count the average duration. 5 # 6 7 BEGIN { 8 PROCINFO["sorted_in"] = "@ind_num_asc" 9 defaultEventString = 36 10 maxEventString = 36 11 } 12 { 13 # Skip lines that we don't care about 14 if ( $0 ~ /Periodic stats:/ ) 15 { 16 # op is the 8th field. Strip the comma from the end. 17 split($8, tempOp, ",") 18 key = tempOp[1] 19 20 #print "*** op is " key 21 22 #print "Number of stats found: " $9 " " $10 " " $11 " " $12 23 split($12, tempArray, ":") 24 numberOfOps = tempArray[1] 25 #print "Number of stats found: " numberOfOps 26 numOps[key] += numberOfOps 27 28 # Count fields, total duration is the ninth-last one 29 #print "op is " key ", num ops is " numberOfOps ", duration is " $(NF-8) 30 totalOpDurationsMs[key] += $(NF-8) 31 32 # Parse out individual events, if present 33 eventNumber = 1 34 split($0, events, ";") 35 for (ev in events) 36 { 37 #print "raw event " ev " is " events[ev] 38 39 # Look for "+" that each event has, but skip the "total duration" one, since it isn't an event 40 if ((events[ev] ~ /\+/) && (events[ev] !~ /total duration/)) 41 { 42 #print "event " eventNumber " is " events[ev] 43 44 # Event name is everything on left of "+", duration stuff on the right 45 split(events[ev], eventDetail, "+") 46 47 eventName = eventDetail[1] 48 49 # Keep track of event name size, for print formatting later 50 if ( length(eventName) > maxEventString ) { 51 # +3 is for event number plus space 52 maxEventString = length(eventName) + 3 53 } 54 55 # Event duration is the first field on rhs 56 split(eventDetail[2], timingDetail, " ") 57 #print " event duration: " timingDetail[1] 58 59 #print "storing OpEventMs["key"]["eventNumber " " eventName"] += " timingDetail[1] 60 OpEventMs[key][eventNumber " " eventName] += timingDetail[1] 61 62 # Number of events is also on the rhs 63 if (timingDetail[6] ~ /\[numEvents/) 64 { 65 # get the ] off the end of the number of events 66 split(timingDetail[7], numEventsDetail, "]") 67 #print "number of events is ", numEventsDetail[1] 68 OpEventCount[key][eventNumber " " eventName] += numEventsDetail[1] 69 } 70 71 eventNumber = eventNumber + 1 72 } 73 } 74 } 75 } 76 END { 77 allOpsDurationMs = 0 78 allOpsCount = 0 79 addlEventString = 0 80 81 if (maxEventString > defaultEventString) 82 { 83 addlEventString = maxEventString - defaultEventString 84 } 85 86 printf "\n" 87 printf " %" 24 + addlEventString "s\n", 88 " Total Average" 89 printf "Operation Quantity %" 30 + addlEventString "s\n", 90 "Duration (ms) duration (ms)" 91 printf "--------- -------- %" 30 + addlEventString "s\n", 92 "------------- -------------" 93 for (op in numOps) 94 { 95 if ( numOps[op] > 0 ) 96 { 97 if (totalOpDurationsMs[op] > 0) 98 { 99 printf "%-12s %5d %" 9 + addlEventString ".0f %9.2f %8.2f %%\n", 100 op, numOps[op], totalOpDurationsMs[op], totalOpDurationsMs[op]/numOps[op], 101 totalOpDurationsMs[op]/totalOpDurationsMs[op] * 100 102 103 allOpsDurationMs += totalOpDurationsMs[op] 104 allOpsCount += numOps[op] 105 106 if ( length(OpEventMs[op]) != 0 ) 107 { 108 countedDurationMs = 0 109 for (event in OpEventMs[op]) 110 { 111 #print "OpEventMs event is " event " = " OpEventMs[key][event] 112 printf " (%-" maxEventString "s) %9.0f %9.2f %8.2f %% (hits %5d/%5d)\n", 113 event, OpEventMs[op][event], OpEventMs[op][event]/numOps[op], 114 OpEventMs[op][event]/totalOpDurationsMs[op] * 100, 115 OpEventCount[op][event], numOps[op] 116 countedDurationMs += OpEventMs[op][event] 117 } 118 119 # Unaccounted doesn't make sense with these stats since we always have 120 # all the data. Comment this out. 121 #remainingDurationMs = totalOpDurationsMs[op] - countedDurationMs 122 #printf " (%-36s) %9.0f %9.2f %8.2f %%\n", 123 # " unaccounted", remainingDurationMs, remainingDurationMs/numOps[op], 124 # remainingDurationMs/totalOpDurationsMs[op] * 100 125 } 126 } else { 127 printf "%-12s %5d %" 9 + addlEventString ".0f %9.2f %8.2f %%\n", 128 op, numOps[op], totalOpDurationsMs[op], totalOpDurationsMs[op]/numOps[op], 100 129 } 130 131 print " " 132 } 133 } 134 135 printf "%-12s %5d %" 9 + addlEventString ".0f\n", 136 "All ops", allOpsCount, allOpsDurationMs 137 printf "\n" 138 }