1*4882a593Smuzhiyun#!/bin/bash 2*4882a593Smuzhiyun# SPDX-License-Identifier: GPL-2.0+ 3*4882a593Smuzhiyun# 4*4882a593Smuzhiyun# Analyze a given results directory for rcuscale performance measurements, 5*4882a593Smuzhiyun# looking for ftrace data. Exits with 0 if data was found, analyzed, and 6*4882a593Smuzhiyun# printed. Intended to be invoked from kvm-recheck-rcuscale.sh after 7*4882a593Smuzhiyun# argument checking. 8*4882a593Smuzhiyun# 9*4882a593Smuzhiyun# Usage: kvm-recheck-rcuscale-ftrace.sh resdir 10*4882a593Smuzhiyun# 11*4882a593Smuzhiyun# Copyright (C) IBM Corporation, 2016 12*4882a593Smuzhiyun# 13*4882a593Smuzhiyun# Authors: Paul E. McKenney <paulmck@linux.ibm.com> 14*4882a593Smuzhiyun 15*4882a593Smuzhiyuni="$1" 16*4882a593Smuzhiyun. functions.sh 17*4882a593Smuzhiyun 18*4882a593Smuzhiyunif test "`grep -c 'rcu_exp_grace_period.*start' < $i/console.log`" -lt 100 19*4882a593Smuzhiyunthen 20*4882a593Smuzhiyun exit 10 21*4882a593Smuzhiyunfi 22*4882a593Smuzhiyun 23*4882a593Smuzhiyunsed -e 's/^\[[^]]*]//' < $i/console.log | 24*4882a593Smuzhiyungrep 'us : rcu_exp_grace_period' | 25*4882a593Smuzhiyunsed -e 's/us : / : /' | 26*4882a593Smuzhiyuntr -d '\015' | 27*4882a593Smuzhiyunawk ' 28*4882a593Smuzhiyun$8 == "start" { 29*4882a593Smuzhiyun if (startseq != "") 30*4882a593Smuzhiyun nlost++; 31*4882a593Smuzhiyun starttask = $1; 32*4882a593Smuzhiyun starttime = $3; 33*4882a593Smuzhiyun startseq = $7; 34*4882a593Smuzhiyun seqtask[startseq] = starttask; 35*4882a593Smuzhiyun} 36*4882a593Smuzhiyun 37*4882a593Smuzhiyun$8 == "end" { 38*4882a593Smuzhiyun if (startseq == $7) { 39*4882a593Smuzhiyun curgpdur = $3 - starttime; 40*4882a593Smuzhiyun gptimes[++n] = curgpdur; 41*4882a593Smuzhiyun gptaskcnt[starttask]++; 42*4882a593Smuzhiyun sum += curgpdur; 43*4882a593Smuzhiyun if (curgpdur > 1000) 44*4882a593Smuzhiyun print "Long GP " starttime "us to " $3 "us (" curgpdur "us)"; 45*4882a593Smuzhiyun startseq = ""; 46*4882a593Smuzhiyun } else { 47*4882a593Smuzhiyun # Lost a message or some such, reset. 48*4882a593Smuzhiyun startseq = ""; 49*4882a593Smuzhiyun nlost++; 50*4882a593Smuzhiyun } 51*4882a593Smuzhiyun} 52*4882a593Smuzhiyun 53*4882a593Smuzhiyun$8 == "done" && seqtask[$7] != $1 { 54*4882a593Smuzhiyun piggybackcnt[$1]++; 55*4882a593Smuzhiyun} 56*4882a593Smuzhiyun 57*4882a593SmuzhiyunEND { 58*4882a593Smuzhiyun newNR = asort(gptimes); 59*4882a593Smuzhiyun if (newNR <= 0) { 60*4882a593Smuzhiyun print "No ftrace records found???" 61*4882a593Smuzhiyun exit 10; 62*4882a593Smuzhiyun } 63*4882a593Smuzhiyun pct50 = int(newNR * 50 / 100); 64*4882a593Smuzhiyun if (pct50 < 1) 65*4882a593Smuzhiyun pct50 = 1; 66*4882a593Smuzhiyun pct90 = int(newNR * 90 / 100); 67*4882a593Smuzhiyun if (pct90 < 1) 68*4882a593Smuzhiyun pct90 = 1; 69*4882a593Smuzhiyun pct99 = int(newNR * 99 / 100); 70*4882a593Smuzhiyun if (pct99 < 1) 71*4882a593Smuzhiyun pct99 = 1; 72*4882a593Smuzhiyun div = 10 ** int(log(gptimes[pct90]) / log(10) + .5) / 100; 73*4882a593Smuzhiyun print "Histogram bucket size: " div; 74*4882a593Smuzhiyun last = gptimes[1] - 10; 75*4882a593Smuzhiyun count = 0; 76*4882a593Smuzhiyun for (i = 1; i <= newNR; i++) { 77*4882a593Smuzhiyun current = div * int(gptimes[i] / div); 78*4882a593Smuzhiyun if (last == current) { 79*4882a593Smuzhiyun count++; 80*4882a593Smuzhiyun } else { 81*4882a593Smuzhiyun if (count > 0) 82*4882a593Smuzhiyun print last, count; 83*4882a593Smuzhiyun count = 1; 84*4882a593Smuzhiyun last = current; 85*4882a593Smuzhiyun } 86*4882a593Smuzhiyun } 87*4882a593Smuzhiyun if (count > 0) 88*4882a593Smuzhiyun print last, count; 89*4882a593Smuzhiyun print "Distribution of grace periods across tasks:"; 90*4882a593Smuzhiyun for (i in gptaskcnt) { 91*4882a593Smuzhiyun print "\t" i, gptaskcnt[i]; 92*4882a593Smuzhiyun nbatches += gptaskcnt[i]; 93*4882a593Smuzhiyun } 94*4882a593Smuzhiyun ngps = nbatches; 95*4882a593Smuzhiyun print "Distribution of piggybacking across tasks:"; 96*4882a593Smuzhiyun for (i in piggybackcnt) { 97*4882a593Smuzhiyun print "\t" i, piggybackcnt[i]; 98*4882a593Smuzhiyun ngps += piggybackcnt[i]; 99*4882a593Smuzhiyun } 100*4882a593Smuzhiyun print "Average grace-period duration: " sum / newNR " microseconds"; 101*4882a593Smuzhiyun print "Minimum grace-period duration: " gptimes[1]; 102*4882a593Smuzhiyun print "50th percentile grace-period duration: " gptimes[pct50]; 103*4882a593Smuzhiyun print "90th percentile grace-period duration: " gptimes[pct90]; 104*4882a593Smuzhiyun print "99th percentile grace-period duration: " gptimes[pct99]; 105*4882a593Smuzhiyun print "Maximum grace-period duration: " gptimes[newNR]; 106*4882a593Smuzhiyun print "Grace periods: " ngps + 0 " Batches: " nbatches + 0 " Ratio: " ngps / nbatches " Lost: " nlost + 0; 107*4882a593Smuzhiyun print "Computed from ftrace data."; 108*4882a593Smuzhiyun}' 109*4882a593Smuzhiyunexit 0 110