^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 1) #!/usr/bin/perl -w
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 2) # SPDX-License-Identifier: GPL-2.0-only
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 3) # (c) 2009, Tom Zanussi <tzanussi@gmail.com>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 4)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 5) # Display avg/min/max wakeup latency
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 6)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 7) # The common_* event handler fields are the most useful fields common to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 8) # all events. They don't necessarily correspond to the 'common_*' fields
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 9) # in the status files. Those fields not available as handler params can
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 10) # be retrieved via script functions of the form get_common_*().
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 11)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 12) use 5.010000;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 13) use strict;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 14) use warnings;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 15)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 16) use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 17) use lib "./Perf-Trace-Util/lib";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 18) use Perf::Trace::Core;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 19) use Perf::Trace::Util;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 20)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 21) my %last_wakeup;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 22)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 23) my $max_wakeup_latency;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 24) my $min_wakeup_latency;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 25) my $total_wakeup_latency = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 26) my $total_wakeups = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 27)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 28) sub sched::sched_switch
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 29) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 30) my ($event_name, $context, $common_cpu, $common_secs, $common_nsecs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 31) $common_pid, $common_comm, $common_callchain,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 32) $prev_comm, $prev_pid, $prev_prio, $prev_state, $next_comm, $next_pid,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 33) $next_prio) = @_;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 34)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 35) my $wakeup_ts = $last_wakeup{$common_cpu}{ts};
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 36) if ($wakeup_ts) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 37) my $switch_ts = nsecs($common_secs, $common_nsecs);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 38) my $wakeup_latency = $switch_ts - $wakeup_ts;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 39) if ($wakeup_latency > $max_wakeup_latency) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 40) $max_wakeup_latency = $wakeup_latency;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 41) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 42) if ($wakeup_latency < $min_wakeup_latency) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 43) $min_wakeup_latency = $wakeup_latency;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 44) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 45) $total_wakeup_latency += $wakeup_latency;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 46) $total_wakeups++;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 47) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 48) $last_wakeup{$common_cpu}{ts} = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 49) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 50)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 51) sub sched::sched_wakeup
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 52) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 53) my ($event_name, $context, $common_cpu, $common_secs, $common_nsecs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 54) $common_pid, $common_comm, $common_callchain,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 55) $comm, $pid, $prio, $success, $target_cpu) = @_;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 56)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 57) $last_wakeup{$target_cpu}{ts} = nsecs($common_secs, $common_nsecs);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 58) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 59)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 60) sub trace_begin
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 61) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 62) $min_wakeup_latency = 1000000000;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 63) $max_wakeup_latency = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 64) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 65)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 66) sub trace_end
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 67) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 68) printf("wakeup_latency stats:\n\n");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 69) print "total_wakeups: $total_wakeups\n";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 70) if ($total_wakeups) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 71) printf("avg_wakeup_latency (ns): %u\n",
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 72) avg($total_wakeup_latency, $total_wakeups));
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 73) } else {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 74) printf("avg_wakeup_latency (ns): N/A\n");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 75) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 76) printf("min_wakeup_latency (ns): %u\n", $min_wakeup_latency);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 77) printf("max_wakeup_latency (ns): %u\n", $max_wakeup_latency);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 78)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 79) print_unhandled();
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 80) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 81)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 82) my %unhandled;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 83)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 84) sub print_unhandled
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 85) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 86) if ((scalar keys %unhandled) == 0) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 87) return;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 88) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 89)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 90) print "\nunhandled events:\n\n";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 91)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 92) printf("%-40s %10s\n", "event", "count");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 93) printf("%-40s %10s\n", "----------------------------------------",
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 94) "-----------");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 95)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 96) foreach my $event_name (keys %unhandled) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 97) printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 98) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 99) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 100)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 101) sub trace_unhandled
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 102) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 103) my ($event_name, $context, $common_cpu, $common_secs, $common_nsecs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 104) $common_pid, $common_comm, $common_callchain) = @_;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 105)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 106) $unhandled{$event_name}++;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 107) }