Francois Gouget : testbot: Add some traces to help diagnose scheduler issues.

[Alexandre Julliard]

Module: tools
Branch: master
Commit: b8967f23d80d84311decba77b3febc76385566b9
URL:    https://source.winehq.org/git/tools.git/?a=commit;h=b8967f23d80d84311decba77b3febc76385566b9

Author: Francois Gouget <fgouget at codeweavers.com>
Date:   Mon Feb 19 04:25:14 2018 +0100

testbot: Add some traces to help diagnose scheduler issues.

Signed-off-by: Francois Gouget <fgouget at codeweavers.com>
Signed-off-by: Alexandre Julliard <julliard at winehq.org>

---

 testbot/lib/WineTestBot/Jobs.pm | 59 +++++++++++++++++++++++++++++++++++++++++
 1 file changed, 59 insertions(+)

diff --git a/testbot/lib/WineTestBot/Jobs.pm b/testbot/lib/WineTestBot/Jobs.pm
index 0362221..9a0f8bc 100644
--- a/testbot/lib/WineTestBot/Jobs.pm
+++ b/testbot/lib/WineTestBot/Jobs.pm
@@ -1012,6 +1012,63 @@ sub _SacrificeVM($$$)
   return 1;
 }
 
+sub _DumpHostCounters($$)
+{
+  my ($Sched, $VM) = @_;
+  my $Host = _GetSchedHost($Sched, $VM);
+  return if ($Host->{dumpedcounters});
+
+  my $Counters = "";
+  if ($Host->{active})
+  {
+    $Counters .= " active=$Host->{active}/$Host->{MaxActiveVMs}";
+  }
+  if ($Host->{idle})
+  {
+    $Counters .= " idle=$Host->{idle}". ($Host->{queued} ? "" : "/$Host->{MaxVMsWhenIdle}");
+  }
+  if ($Host->{reverting})
+  {
+    $Counters .= " reverting=$Host->{reverting}/". _GetMaxReverts($Host);
+  }
+  for my $Counter ("sleeping", "running", "dirty", "queued")
+  {
+    $Counters .= " $Counter=$Host->{$Counter}" if ($Host->{$Counter});
+  }
+  my $HostKey = $VM->GetHost();
+  my $PrettyHost = ($PrettyHostNames ? $PrettyHostNames->{$HostKey} : "") ||
+                   $HostKey;
+  require WineTestBot::Log;
+  WineTestBot::Log::LogMsg("$PrettyHost:$Counters\n") if ($Counters);
+
+  $Host->{dumpedcounters} = 1;
+}
+
+sub _DumpHostVMs($$$$)
+{
+  my ($Sched, $VM, $SortedNeededVMs, $NeededVMs) = @_;
+  my $Host = _GetSchedHost($Sched, $VM);
+  return if ($Host->{dumpedvms});
+
+  _DumpHostCounters($Sched, $VM);
+
+  my @VMInfo;
+  my $HostKey = $VM->GetHost();
+  foreach my $VMKey (@$SortedNeededVMs)
+  {
+    $VM = $Sched->{VMs}->GetItem($VMKey);
+    next if ($VM->GetHost() ne $HostKey);
+
+    push @VMInfo, join(":", "$VMKey(". $VM->Status .")", $NeededVMs->{$VMKey}->[0], $NeededVMs->{$VMKey}->[1], $NeededVMs->{$VMKey}->[2]);
+  }
+  my $PrettyHost = ($PrettyHostNames ? $PrettyHostNames->{$HostKey} : "") ||
+                   $HostKey;
+  require WineTestBot::Log;
+  WineTestBot::Log::LogMsg("$PrettyHost: @VMInfo\n");
+
+  $Host->{dumpedvms} = 1;
+}
+
 sub _RevertVMs($$)
 {
   my ($Sched, $NeededVMs) = @_;
@@ -1027,6 +1084,7 @@ sub _RevertVMs($$)
     # Check if the host has reached its reverting VMs limit
     my $Host = _GetSchedHost($Sched, $VM);
     next if ($Host->{reverting} >= _GetMaxReverts($Host));
+    _DumpHostCounters($Sched, $VM);
 
     # Skip this VM if the previous step's tasks are not about to run yet
     next if (_HasMissingDependencies($Sched, $NeededVMs, $VMKey));
@@ -1071,6 +1129,7 @@ sub _RevertVMs($$)
       $NeedsSacrifice = ($FutureActive > $Host->{MaxActiveVMs});
     }
 
+    _DumpHostVMs($Sched, $VM, \@SortedNeededVMs, $NeededVMs);
     if ($NeedsSacrifice)
     {
       # Find an active VM to sacrifice so we can revert this VM in the next