Add log statements and remove unused SSHRPCManager

bootstrapvz/remote/build_servers.py

@@ -29,15 +29,16 @@ def pick_build_server(build_servers, manifest, preferences={}):
 		if not matches(name, settings):
 			continue
 		if settings['type'] == 'local':
-			return LocalBuildServer(settings)
+			return LocalBuildServer(name, settings)
 		else:
-			return RemoteBuildServer(settings)
+			return RemoteBuildServer(name, settings)
 	raise Exception('Unable to find a build server that matches your preferences.')
 
 
 class BuildServer(object):
 
-	def __init__(self, settings):
+	def __init__(self, name, settings):
+		self.name = name
 		self.settings = settings
 		self.build_settings = settings.get('build_settings', {})
 		self.can_bootstrap = settings['can_bootstrap']
@@ -57,8 +58,8 @@ class LocalBuildServer(BuildServer):
 
 class RemoteBuildServer(BuildServer):
 
-	def __init__(self, settings):
-		super(RemoteBuildServer, self).__init__(settings)
+	def __init__(self, name, settings):
+		super(RemoteBuildServer, self).__init__(name, settings)
 		self.address = settings['address']
 		self.port = settings['port']
 		self.username = settings['username']
@@ -74,7 +75,7 @@ class RemoteBuildServer(BuildServer):
 		[self.remote_server_port, self.remote_callback_port] = getNPorts(2)
 
 	def connect(self):
-		log.debug('Opening SSH connection')
+		log.debug('Opening SSH connection to build server `{name}\''.format(name=self.name))
 		import subprocess
 
 		server_cmd = ['sudo', self.server_bin, '--listen', str(self.remote_server_port)]
@@ -103,7 +104,7 @@ class RemoteBuildServer(BuildServer):
 			server_uri = 'PYRO:server@localhost:{server_port}'.format(server_port=self.local_server_port)
 			self.connection = Pyro4.Proxy(server_uri)
 
-			log.debug('Connecting to the RPC daemon')
+			log.debug('Connecting to the RPC daemon on build server `{name}\''.format(name=self.name))
 			remaining_retries = 5
 			while True:
 				try:
@@ -123,14 +124,15 @@ class RemoteBuildServer(BuildServer):
 
 	def disconnect(self):
 		if hasattr(self, 'connection'):
-			log.debug('Stopping the RPC daemon')
+			log.debug('Stopping the RPC daemon on build server `{name}\''.format(name=self.name))
 			self.connection.stop()
 			self.connection._pyroRelease()
 		if hasattr(self, 'ssh_process'):
-			log.debug('Waiting for the SSH connection to terminate')
+			log.debug('Waiting for SSH connection to build server `{name}\' to terminate'.format(name=self.name))
 			self.ssh_process.wait()
 
 	def download(self, src, dst):
+		log.debug('Downloading file `{path}\' from build server `{name}\''.format(path=src, name=self.name))
 		# Make sure we can read the file as {user}
 		self._remote_command(['sudo', 'chown', self.username, src])
 		src_arg = '{user}@{host}:{path}'.format(user=self.username, host=self.address, path=src)
@@ -138,6 +140,7 @@ class RemoteBuildServer(BuildServer):
 		                src_arg, dst])
 
 	def delete(self, path):
+		log.debug('Deleting file `{path}\' on build server `{name}\''.format(path=path, name=self.name))
 		self._remote_command(['sudo', 'rm', path])
 
 	def _remote_command(self, command):

bootstrapvz/remote/ssh_rpc_manager.py

@@ -1,72 +0,0 @@
-import logging
-log = logging.getLogger(__name__)
-
-
-class SSHRPCManager(object):
-
-	def __init__(self, settings):
-		self.settings = settings
-
-		# We can't use :0 because
-		# A: It's quite hard to retrieve the port on the remote after the daemon has started
-		# B: SSH doesn't accept 0:localhost:0 as a port forwarding option
-		[self.local_server_port, self.local_callback_port] = self.getNPorts(2)
-		[self.remote_server_port, self.remote_callback_port] = self.getNPorts(2)
-
-	def getNPorts(self, n, port_range=(1024, 65535)):
-		import random
-		ports = []
-		for i in range(0, n):
-			while True:
-				port = random.randrange(*port_range)
-				if port not in ports:
-					ports.append(port)
-					break
-		return ports
-
-	def start(self):
-		log.debug('Opening SSH connection')
-		import subprocess
-
-		ssh_cmd = ['ssh', '-i', self.settings['keyfile'],
-		                  '-p', str(self.settings['port']),
-		                  '-L' + str(self.local_server_port) + ':localhost:' + str(self.remote_server_port),
-		                  '-R' + str(self.remote_callback_port) + ':localhost:' + str(self.local_callback_port),
-		                  self.settings['username'] + '@' + self.settings['address'],
-		                  '--',
-		                  'sudo', self.settings['server_bin'],
-		                  '--listen', str(self.remote_server_port)]
-		import sys
-		self.ssh_process = subprocess.Popen(args=ssh_cmd, stdout=sys.stderr, stderr=sys.stderr)
-
-		# Check that we can connect to the server
-		try:
-			import Pyro4
-			server_uri = 'PYRO:server@localhost:{server_port}'.format(server_port=self.local_server_port)
-			self.rpc_server = Pyro4.Proxy(server_uri)
-
-			log.debug('Connecting to the RPC daemon')
-			remaining_retries = 5
-			while True:
-				try:
-					self.rpc_server.ping()
-					break
-				except (Pyro4.errors.ConnectionClosedError, Pyro4.errors.CommunicationError) as e:
-					if remaining_retries > 0:
-						remaining_retries -= 1
-						from time import sleep
-						sleep(2)
-					else:
-						raise e
-		except (Exception, KeyboardInterrupt) as e:
-			self.ssh_process.terminate()
-			raise e
-
-	def stop(self):
-		if hasattr(self, 'rpc_server'):
-			log.debug('Stopping the RPC daemon')
-			self.rpc_server.stop()
-			self.rpc_server._pyroRelease()
-		if hasattr(self, 'ssh_process'):
-			log.debug('Waiting for the SSH connection to terminate')
-			self.ssh_process.wait()

tests/integration/images/virtualbox.py

@@ -1,6 +1,8 @@
 from __future__ import absolute_import
 from . import Image
 import virtualbox as vboxapi
+import logging
+log = logging.getLogger(__name__)
 
 
 class VirtualBoxImage(Image):
@@ -11,12 +13,14 @@ class VirtualBoxImage(Image):
 		self.vbox = vboxapi.VirtualBox()
 
 	def open(self):
+		log.debug('Opening vbox medium `{path}\''.format(path=self.image_path))
 		self.medium = self.vbox.open_medium(self.image_path,  # location
 		                                    vboxapi.library.DeviceType.hard_disk,  # decive_type
 		                                    vboxapi.library.AccessMode.read_only,  # access_mode
 		                                    False)  # force_new_uuid
 
 	def close(self):
+		log.debug('Closing vbox medium `{path}\''.format(path=self.image_path))
 		self.medium.close()
 
 	def get_instance(self):

tests/integration/instances/virtualbox.py

@@ -1,6 +1,8 @@
 from __future__ import absolute_import
 from . import Instance
 import virtualbox as vboxapi
+import logging
+log = logging.getLogger(__name__)
 
 
 class VirtualBoxInstance(Instance):
@@ -15,6 +17,7 @@ class VirtualBoxInstance(Instance):
 		self.session = manager.get_session()
 
 	def create(self):
+		log.debug('Creating vbox machine `{name}\''.format(name=self.name))
 		# create machine
 		os_type = {'x86': 'Debian',
 		           'amd64': 'Debian_64'}.get(self.image.manifest.system['architecture'])
@@ -26,6 +29,7 @@ class VirtualBoxInstance(Instance):
 		self.vbox.register_machine(self.machine)
 
 		# attach image
+		log.debug('Attaching SATA storage controller to vbox machine `{name}\''.format(name=self.name))
 		with self.Lock(self.machine, self.session) as machine:
 			strg_ctrl = machine.add_storage_controller('SATA Controller',
 			                                           vboxapi.library.StorageBus.sata)
@@ -36,6 +40,7 @@ class VirtualBoxInstance(Instance):
 			machine.save_settings()
 
 		# redirect serial port
+		log.debug('Enabling serial port on vbox machine `{name}\''.format(name=self.name))
 		with self.Lock(self.machine, self.session) as machine:
 			serial_port = machine.get_serial_port(0)
 			serial_port.enabled = True
@@ -49,24 +54,31 @@ class VirtualBoxInstance(Instance):
 			machine.save_settings()
 
 	def boot(self):
+		log.debug('Booting vbox machine `{name}\''.format(name=self.name))
 		self.machine.launch_vm_process(self.session, 'headless').wait_for_completion(-1)
 		from ..tools import read_from_socket
 		self.console_output = read_from_socket(self.serial_port_path, 'INIT: Entering runlevel: 2', 20)
 
 	def shutdown(self):
+		log.debug('Shutting down vbox machine `{name}\''.format(name=self.name))
 		self.session.console.power_down().wait_for_completion(-1)
 		self.Lock(self.machine, self.session).unlock()
 
 	def destroy(self):
+		log.debug('Destroying vbox machine `{name}\''.format(name=self.name))
 		if hasattr(self, 'machine'):
 			try:
+				log.debug('Detaching SATA storage controller from vbox machine `{name}\''.format(name=self.name))
 				with self.Lock(self.machine, self.session) as machine:
 					machine.detach_device(name='SATA Controller', controller_port=0, device=0)
 					machine.save_settings()
 			except vboxapi.library.VBoxErrorObjectNotFound:
 				pass
+			log.debug('Unregistering and removing vbox machine `{name}\''.format(name=self.name))
 			self.machine.unregister(vboxapi.library.CleanupMode.unregister_only)
 			self.machine.remove(delete=True)
+		else:
+			log.debug('vbox machine `{name}\' was not created, skipping destruction'.format(name=self.name))
 
 	def up(self):
 		try: