orchestra.console: Scope loggers to shortname

This will make reading console debug logging easier.

Signed-off-by: Zack Cerza <zack@redhat.com>

diff --git a/teuthology/orchestra/console.py b/teuthology/orchestra/console.py
index d339f3cb7ecaaa7215a8abb5810c6c0f1bf27106..6361cd42863e5ccb3f5d2c53f6aa95d10e6d4330 100644 (file)
--- a/teuthology/orchestra/console.py
+++ b/teuthology/orchestra/console.py
@@ -39,6 +39,7 @@ class PhysicalConsole(RemoteConsole):
                  timeout=40):
         self.name = name
         self.shortname = self.getShortName(name)
+        self.log = log.getChild(self.shortname)
         self.timeout = timeout
         self.ipmiuser = ipmiuser or config.ipmi_user
         self.ipmipass = ipmipass or config.ipmi_password
@@ -71,7 +72,7 @@ class PhysicalConsole(RemoteConsole):
         """
         Run a command using pexpect.spawn(). Return the child object.
         """
-        log.debug('pexpect command: %s', cmd)
+        self.log.debug('pexpect command: %s', cmd)
         p = pexpect.spawn(
             cmd,
             encoding='utf-8',
@@ -86,7 +87,7 @@ class PhysicalConsole(RemoteConsole):
 
         child = start()
         if self.has_conserver and not child.isalive():
-            log.error("conserver failed to get the console; will try ipmitool")
+            self.log.error("conserver failed to get the console; will try ipmitool")
             self.has_conserver = False
             child = start()
         return child
@@ -116,7 +117,7 @@ class PhysicalConsole(RemoteConsole):
 
     def _check_ipmi_credentials(self):
         if not self.has_ipmi_credentials:
-            log.error(
+            self.log.error(
                 "Must set ipmi_user, ipmi_password, and ipmi_domain in "
                 ".teuthology.yaml"
             )
@@ -131,37 +132,36 @@ class PhysicalConsole(RemoteConsole):
                 timeout=t)
             if r != 0:
                 child.kill(15)
-            log.debug('console disconnect output: %s', child.logfile_read.getvalue().strip())
+            self.log.debug('console disconnect output: %s', child.logfile_read.getvalue().strip())
         else:
             child.send('~.')
             r = child.expect(
                 ['terminated ipmitool', pexpect.TIMEOUT, pexpect.EOF],
                 timeout=t)
-            log.debug('ipmitool disconnect output: %s', child.logfile_read.getvalue().strip())
+            self.log.debug('ipmitool disconnect output: %s', child.logfile_read.getvalue().strip())
             if r != 0:
                 self._pexpect_spawn_ipmi('sol deactivate')
-                log.debug('sol deactivate output: %s', child.logfile_read.getvalue().strip())
+                self.log.debug('sol deactivate output: %s', child.logfile_read.getvalue().strip())
 
     def _wait_for_login(self, timeout=None, attempts=2):
         """
         Wait for login.  Retry if timeouts occur on commands.
         """
         t = timeout or self.timeout
-        log.debug('Waiting for login prompt on {s}'.format(s=self.shortname))
+        self.log.debug('Waiting for login prompt')
         # wait for login prompt to indicate boot completed
         for i in range(0, attempts):
             start = time.time()
             while time.time() - start < t:
                 child = self._get_console(readonly=False)
                 child.send('\n')
-                log.debug('expect: {s} login'.format(s=self.shortname))
                 r = child.expect(
                     ['{s} login: '.format(s=self.shortname),
                      pexpect.TIMEOUT,
                      pexpect.EOF],
                     timeout=(t - (time.time() - start)))
-                log.debug('expect before: {b}'.format(b=child.before))
-                log.debug('expect after: {a}'.format(a=child.after))
+                self.log.debug('expect before: {b}'.format(b=child.before))
+                self.log.debug('expect after: {a}'.format(a=child.after))
 
                 self._exit_session(child)
                 if r == 0:
@@ -183,7 +183,7 @@ class PhysicalConsole(RemoteConsole):
                 c = self._pexpect_spawn_ipmi('power status')
                 r = c.expect(['Chassis Power is {s}'.format(
                     s=state), pexpect.EOF, pexpect.TIMEOUT], timeout=1)
-                log.debug('check power output: %s', c.logfile_read.getvalue().strip())
+                self.log.debug('check power output: %s', c.logfile_read.getvalue().strip())
                 if r == 0:
                     return True
         return False
@@ -197,8 +197,7 @@ class PhysicalConsole(RemoteConsole):
             self._wait_for_login(timeout)
             return True
         except Exception as e:
-            log.info('Failed to get ipmi console status for {s}: {e}'.format(
-                s=self.shortname, e=e))
+            self.log.info('Failed to get ipmi console status: {e}'.format(e=e))
             return False
 
     def power_cycle(self, timeout=300):
@@ -207,46 +206,46 @@ class PhysicalConsole(RemoteConsole):
 
         :param timeout: How long to wait for login
         """
-        log.info('Power cycling {s}'.format(s=self.shortname))
+        self.log.info('Power cycling')
         child = self._pexpect_spawn_ipmi('power cycle')
         child.expect('Chassis Power Control: Cycle', timeout=self.timeout)
-        log.debug('power cycle output: %s', child.logfile_read.getvalue().strip())
+        self.log.debug('power cycle output: %s', child.logfile_read.getvalue().strip())
         self._wait_for_login(timeout=timeout)
-        log.info('Power cycle for {s} completed'.format(s=self.shortname))
+        self.log.info('Power cycle completed')
 
     def hard_reset(self, wait_for_login=True):
         """
         Perform physical hard reset.  Retry if EOF returned from read
         and wait for login when complete.
         """
-        log.info('Performing hard reset of {s}'.format(s=self.shortname))
+        self.log.info('Performing hard reset')
         start = time.time()
         while time.time() - start < self.timeout:
             child = self._pexpect_spawn_ipmi('power reset')
             r = child.expect(['Chassis Power Control: Reset', pexpect.EOF],
                              timeout=self.timeout)
-            log.debug('power reset output: %s', child.logfile_read.getvalue().strip())
+            self.log.debug('power reset output: %s', child.logfile_read.getvalue().strip())
             if r == 0:
                 break
         if wait_for_login:
             self._wait_for_login()
-        log.info('Hard reset for {s} completed'.format(s=self.shortname))
+        self.log.info('Hard reset completed')
 
     def power_on(self):
         """
         Physical power on.  Loop checking cmd return.
         """
-        log.info('Power on {s}'.format(s=self.shortname))
+        self.log.info('Power on')
         start = time.time()
         while time.time() - start < self.timeout:
             child = self._pexpect_spawn_ipmi('power on')
             r = child.expect(['Chassis Power Control: Up/On', pexpect.EOF],
                              timeout=self.timeout)
-            log.debug('power on output: %s', child.logfile_read.getvalue().strip())
+            self.log.debug('power on output: %s', child.logfile_read.getvalue().strip())
             if r == 0:
                 break
         if self.check_power('on'):
-            log.info('Power on for {s} completed'.format(s=self.shortname))
+            self.log.info('Power on completed')
         else:
             err_msg = 'Failed to power on {s}'.format(s=self.shortname)
             raise RuntimeError(err_msg)
@@ -255,19 +254,19 @@ class PhysicalConsole(RemoteConsole):
         """
         Physical power off.  Loop checking cmd return.
         """
-        log.info('Power off {s}'.format(s=self.shortname))
+        self.log.info('Power off')
         start = time.time()
         while time.time() - start < self.timeout:
             child = self._pexpect_spawn_ipmi('power off')
             r = child.expect(['Chassis Power Control: Down/Off', pexpect.EOF],
                              timeout=self.timeout)
-            log.debug('power off output: %s', child.logfile_read.getvalue().strip())
+            self.log.debug('power off output: %s', child.logfile_read.getvalue().strip())
             if r == 0:
                 break
         if self.check_power('off', 60):
-            log.info('Power off for {s} completed'.format(s=self.shortname))
+            self.log.info('Power off completed')
         else:
-            log.error('Failed to power off {s}'.format(s=self.shortname))
+            self.log.error('Failed to power off')
 
     def power_off_for_interval(self, interval=30):
         """
@@ -275,12 +274,11 @@ class PhysicalConsole(RemoteConsole):
 
         :param interval: Length of power-off period.
         """
-        log.info('Power off {s} for {i} seconds'.format(
-            s=self.shortname, i=interval))
+        self.log.info('Power off for {i} seconds'.format(i=interval))
         child = self._pexpect_spawn_ipmi('power off')
         child.expect('Chassis Power Control: Down/Off', timeout=self.timeout)
 
-        log.debug('power off output: %s', child.logfile_read.getvalue().strip())
+        self.log.debug('power off output: %s', child.logfile_read.getvalue().strip())
         child.logfile_read.seek(0)
         child.logfile_read.truncate()
 
@@ -288,9 +286,9 @@ class PhysicalConsole(RemoteConsole):
 
         child = self._pexpect_spawn_ipmi('power on')
         child.expect('Chassis Power Control: Up/On', timeout=self.timeout)
-        log.debug('power on output: %s', child.logfile_read.getvalue().strip())
+        self.log.debug('power on output: %s', child.logfile_read.getvalue().strip())
         self._wait_for_login()
-        log.info('Power off for {i} seconds completed'.format(i=interval))
+        self.log.info('Power off for {i} seconds completed'.format(i=interval))
 
     def spawn_sol_log(self, dest_path):
         """
@@ -323,7 +321,7 @@ class PhysicalConsole(RemoteConsole):
 
         proc = start()
         if self.has_conserver and proc.poll() is not None:
-            log.error("conserver failed to get the console; will try ipmitool")
+            self.log.error("conserver failed to get the console; will try ipmitool")
             self.has_conserver = False
             proc = start()
         return proc
@@ -338,6 +336,7 @@ class VirtualConsole(RemoteConsole):
             raise RuntimeError("libvirt not found")
 
         self.shortname = self.getShortName(name)
+        self.log = log.getChild(self.shortname)
         status_info = teuthology.lock.query.get_status(self.shortname)
         try:
             if teuthology.lock.query.is_vm(status=status_info):
@@ -395,9 +394,8 @@ class VirtualConsole(RemoteConsole):
         """
         Simiulate power off for an interval.
         """
-        log.info('Power off {s} for {i} seconds'.format(
-            s=self.shortname, i=interval))
+        self.log.info('Power off for {i} seconds'.format(i=interval))
         self.vm_domain.info().destroy()
         time.sleep(interval)
         self.vm_domain.info().create()
-        log.info('Power off for {i} seconds completed'.format(i=interval))
+        self.log.info('Power off for {i} seconds completed'.format(i=interval))