389 lines
15 KiB
Python
389 lines
15 KiB
Python
import datetime
|
|
import time
|
|
import logging
|
|
import json
|
|
import trollius
|
|
import re
|
|
|
|
from autobahn.wamp.exception import ApplicationError
|
|
|
|
from buildman.server import BuildJobResult
|
|
from buildman.component.basecomponent import BaseComponent
|
|
from buildman.jobutil.buildjob import BuildJobLoadException
|
|
from buildman.jobutil.buildpack import BuildPackage, BuildPackageException
|
|
from buildman.jobutil.buildstatus import StatusHandler
|
|
from buildman.jobutil.workererror import WorkerError
|
|
|
|
from data.database import BUILD_PHASE
|
|
|
|
HEARTBEAT_DELTA = datetime.timedelta(seconds=30)
|
|
HEARTBEAT_TIMEOUT = 10
|
|
INITIAL_TIMEOUT = 25
|
|
|
|
SUPPORTED_WORKER_VERSIONS = ['0.1-beta']
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
class ComponentStatus(object):
|
|
""" ComponentStatus represents the possible states of a component. """
|
|
JOINING = 'joining'
|
|
WAITING = 'waiting'
|
|
RUNNING = 'running'
|
|
BUILDING = 'building'
|
|
TIMED_OUT = 'timeout'
|
|
|
|
class BuildComponent(BaseComponent):
|
|
""" An application session component which conducts one (or more) builds. """
|
|
def __init__(self, config, realm=None, token=None, **kwargs):
|
|
self.expected_token = token
|
|
self.builder_realm = realm
|
|
|
|
self.parent_manager = None
|
|
self.registry_hostname = None
|
|
|
|
self._component_status = ComponentStatus.JOINING
|
|
self._last_heartbeat = None
|
|
self._current_job = None
|
|
self._build_status = None
|
|
self._image_info = None
|
|
|
|
BaseComponent.__init__(self, config, **kwargs)
|
|
|
|
def onConnect(self):
|
|
self.join(self.builder_realm)
|
|
|
|
def onJoin(self, details):
|
|
logger.debug('Registering methods and listeners for component %s', self.builder_realm)
|
|
yield trollius.From(self.register(self._on_ready, u'io.quay.buildworker.ready'))
|
|
yield trollius.From(self.register(self._ping, u'io.quay.buildworker.ping'))
|
|
yield trollius.From(self.subscribe(self._on_heartbeat, 'io.quay.builder.heartbeat'))
|
|
yield trollius.From(self.subscribe(self._on_log_message, 'io.quay.builder.logmessage'))
|
|
|
|
yield trollius.From(self._set_status(ComponentStatus.WAITING))
|
|
|
|
def is_ready(self):
|
|
""" Determines whether a build component is ready to begin a build. """
|
|
return self._component_status == ComponentStatus.RUNNING
|
|
|
|
@trollius.coroutine
|
|
def start_build(self, build_job):
|
|
""" Starts a build. """
|
|
self._current_job = build_job
|
|
self._build_status = StatusHandler(self.build_logs, build_job.repo_build.uuid)
|
|
self._image_info = {}
|
|
|
|
yield trollius.From(self._set_status(ComponentStatus.BUILDING))
|
|
|
|
# Send the notification that the build has started.
|
|
build_job.send_notification('build_start')
|
|
|
|
# Retrieve the job's buildpack.
|
|
buildpack_url = self.user_files.get_file_url(build_job.repo_build.resource_key,
|
|
requires_cors=False)
|
|
|
|
logger.debug('Retrieving build package: %s', buildpack_url)
|
|
buildpack = None
|
|
try:
|
|
buildpack = BuildPackage.from_url(buildpack_url)
|
|
except BuildPackageException as bpe:
|
|
self._build_failure('Could not retrieve build package', bpe)
|
|
raise trollius.Return()
|
|
|
|
# Extract the base image information from the Dockerfile.
|
|
parsed_dockerfile = None
|
|
logger.debug('Parsing dockerfile')
|
|
|
|
try:
|
|
build_config = build_job.build_config
|
|
except BuildJobLoadException as irbe:
|
|
self._build_failure('Could not load build job information', irbe)
|
|
|
|
try:
|
|
parsed_dockerfile = buildpack.parse_dockerfile(build_config.get('build_subdir'))
|
|
except BuildPackageException as bpe:
|
|
self._build_failure('Could not find Dockerfile in build package', bpe)
|
|
raise trollius.Return()
|
|
|
|
image_and_tag_tuple = parsed_dockerfile.get_image_and_tag()
|
|
if image_and_tag_tuple is None or image_and_tag_tuple[0] is None:
|
|
self._build_failure('Missing FROM line in Dockerfile')
|
|
raise trollius.Return()
|
|
|
|
base_image_information = {
|
|
'repository': image_and_tag_tuple[0],
|
|
'tag': image_and_tag_tuple[1]
|
|
}
|
|
|
|
# Extract the number of steps from the Dockerfile.
|
|
with self._build_status as status_dict:
|
|
status_dict['total_commands'] = len(parsed_dockerfile.commands)
|
|
|
|
# Add the pull robot information, if any.
|
|
if build_job.pull_credentials:
|
|
base_image_information['username'] = build_job.pull_credentials.get('username', '')
|
|
base_image_information['password'] = build_job.pull_credentials.get('password', '')
|
|
|
|
# Retrieve the repository's fully qualified name.
|
|
repo = build_job.repo_build.repository
|
|
repository_name = repo.namespace_user.username + '/' + repo.name
|
|
|
|
# Parse the build queue item into build arguments.
|
|
# build_package: URL to the build package to download and untar/unzip.
|
|
# sub_directory: The location within the build package of the Dockerfile and the build context.
|
|
# repository: The repository for which this build is occurring.
|
|
# registry: The registry for which this build is occuring (e.g. 'quay.io', 'staging.quay.io').
|
|
# pull_token: The token to use when pulling the cache for building.
|
|
# push_token: The token to use to push the built image.
|
|
# tag_names: The name(s) of the tag(s) for the newly built image.
|
|
# base_image: The image name and credentials to use to conduct the base image pull.
|
|
# repository: The repository to pull.
|
|
# tag: The tag to pull.
|
|
# username: The username for pulling the base image (if any).
|
|
# password: The password for pulling the base image (if any).
|
|
build_arguments = {
|
|
'build_package': buildpack_url,
|
|
'sub_directory': build_config.get('build_subdir', ''),
|
|
'repository': repository_name,
|
|
'registry': self.registry_hostname,
|
|
'pull_token': build_job.repo_build.access_token.code,
|
|
'push_token': build_job.repo_build.access_token.code,
|
|
'tag_names': build_config.get('docker_tags', ['latest']),
|
|
'base_image': base_image_information,
|
|
'cached_tag': build_job.determine_cached_tag() or ''
|
|
}
|
|
|
|
# Invoke the build.
|
|
logger.debug('Invoking build: %s', self.builder_realm)
|
|
logger.debug('With Arguments: %s', build_arguments)
|
|
|
|
self.call("io.quay.builder.build", **build_arguments).add_done_callback(self._build_complete)
|
|
|
|
@staticmethod
|
|
def _total_completion(statuses, total_images):
|
|
""" Returns the current amount completion relative to the total completion of a build. """
|
|
percentage_with_sizes = float(len(statuses.values())) / total_images
|
|
sent_bytes = sum([status['current'] for status in statuses.values()])
|
|
total_bytes = sum([status['total'] for status in statuses.values()])
|
|
return float(sent_bytes) / total_bytes * percentage_with_sizes
|
|
|
|
@staticmethod
|
|
def _process_pushpull_status(status_dict, current_phase, docker_data, images):
|
|
""" Processes the status of a push or pull by updating the provided status_dict and images. """
|
|
if not docker_data:
|
|
return
|
|
|
|
num_images = 0
|
|
status_completion_key = ''
|
|
|
|
if current_phase == 'pushing':
|
|
status_completion_key = 'push_completion'
|
|
num_images = status_dict['total_commands']
|
|
elif current_phase == 'pulling':
|
|
status_completion_key = 'pull_completion'
|
|
elif current_phase == 'priming-cache':
|
|
status_completion_key = 'cache_completion'
|
|
else:
|
|
return
|
|
|
|
if 'progressDetail' in docker_data and 'id' in docker_data:
|
|
image_id = docker_data['id']
|
|
detail = docker_data['progressDetail']
|
|
|
|
if 'current' in detail and 'total' in detail:
|
|
images[image_id] = detail
|
|
status_dict[status_completion_key] = \
|
|
BuildComponent._total_completion(images, max(len(images), num_images))
|
|
|
|
def _on_log_message(self, phase, json_data):
|
|
""" Tails log messages and updates the build status. """
|
|
# Parse any of the JSON data logged.
|
|
docker_data = {}
|
|
if json_data:
|
|
try:
|
|
docker_data = json.loads(json_data)
|
|
except ValueError:
|
|
pass
|
|
|
|
logger.debug('Got log message: %s: (%s) => (%s)', phase, json_data, docker_data)
|
|
|
|
# Extract the current status message (if any).
|
|
fully_unwrapped = ''
|
|
keys_to_extract = ['error', 'status', 'stream']
|
|
for key in keys_to_extract:
|
|
if key in docker_data:
|
|
fully_unwrapped = docker_data[key]
|
|
break
|
|
|
|
# Determine if this is a step string.
|
|
current_step = None
|
|
current_status_string = str(fully_unwrapped.encode('utf-8'))
|
|
|
|
if current_status_string and phase == BUILD_PHASE.BUILDING:
|
|
step_increment = re.search(r'Step ([0-9]+) :', current_status_string)
|
|
if step_increment:
|
|
current_step = int(step_increment.group(1))
|
|
|
|
# Parse and update the phase and the status_dict. The status dictionary contains
|
|
# the pull/push progress, as well as the current step index.
|
|
with self._build_status as status_dict:
|
|
if self._build_status.set_phase(phase):
|
|
logger.debug('Build %s has entered a new phase: %s', self.builder_realm, phase)
|
|
|
|
BuildComponent._process_pushpull_status(status_dict, phase, docker_data, self._image_info)
|
|
|
|
# If the current message represents the beginning of a new step, then update the
|
|
# current command index.
|
|
if current_step is not None:
|
|
status_dict['current_command'] = current_step
|
|
|
|
# If the json data contains an error, then something went wrong with a push or pull.
|
|
if 'error' in docker_data:
|
|
self._build_status.set_error(docker_data['error'])
|
|
|
|
if current_step is not None:
|
|
self._build_status.set_command(current_status_string)
|
|
elif phase == BUILD_PHASE.BUILDING:
|
|
self._build_status.append_log(current_status_string)
|
|
|
|
|
|
def _build_failure(self, error_message, exception=None):
|
|
""" Handles and logs a failed build. """
|
|
self._build_status.set_error(error_message, {
|
|
'internal_error': str(exception) if exception else None
|
|
})
|
|
|
|
build_id = self._current_job.repo_build.uuid
|
|
logger.warning('Build %s failed with message: %s', build_id, error_message)
|
|
|
|
# Mark that the build has finished (in an error state)
|
|
trollius.async(self._build_finished(BuildJobResult.ERROR))
|
|
|
|
def _build_complete(self, result):
|
|
""" Wraps up a completed build. Handles any errors and calls self._build_finished. """
|
|
try:
|
|
# Retrieve the result. This will raise an ApplicationError on any error that occurred.
|
|
result.result()
|
|
self._build_status.set_phase(BUILD_PHASE.COMPLETE)
|
|
trollius.async(self._build_finished(BuildJobResult.COMPLETE))
|
|
|
|
# Send the notification that the build has completed successfully.
|
|
self._current_job.send_notification('build_success')
|
|
except ApplicationError as aex:
|
|
worker_error = WorkerError(aex.error, aex.kwargs.get('base_error'))
|
|
|
|
# Write the error to the log.
|
|
self._build_status.set_error(worker_error.public_message(), worker_error.extra_data(),
|
|
internal_error=worker_error.is_internal_error())
|
|
|
|
# Send the notification that the build has failed.
|
|
self._current_job.send_notification('build_failure',
|
|
error_message=worker_error.public_message())
|
|
|
|
# Mark the build as completed.
|
|
if worker_error.is_internal_error():
|
|
trollius.async(self._build_finished(BuildJobResult.INCOMPLETE))
|
|
else:
|
|
trollius.async(self._build_finished(BuildJobResult.ERROR))
|
|
|
|
@trollius.coroutine
|
|
def _build_finished(self, job_status):
|
|
""" Alerts the parent that a build has completed and sets the status back to running. """
|
|
yield trollius.From(self.parent_manager.job_completed(self._current_job, job_status, self))
|
|
self._current_job = None
|
|
|
|
# Set the component back to a running state.
|
|
yield trollius.From(self._set_status(ComponentStatus.RUNNING))
|
|
|
|
@staticmethod
|
|
def _ping():
|
|
""" Ping pong. """
|
|
return 'pong'
|
|
|
|
@trollius.coroutine
|
|
def _on_ready(self, token, version):
|
|
if not version in SUPPORTED_WORKER_VERSIONS:
|
|
logger.warning('Build component (token "%s") is running an out-of-date version: %s', token,
|
|
version)
|
|
raise trollius.Return(False)
|
|
|
|
if self._component_status != ComponentStatus.WAITING:
|
|
logger.warning('Build component (token "%s") is already connected', self.expected_token)
|
|
raise trollius.Return(False)
|
|
|
|
if token != self.expected_token:
|
|
logger.warning('Builder token mismatch. Expected: "%s". Found: "%s"', self.expected_token,
|
|
token)
|
|
raise trollius.Return(False)
|
|
|
|
yield trollius.From(self._set_status(ComponentStatus.RUNNING))
|
|
|
|
# Start the heartbeat check and updating loop.
|
|
loop = trollius.get_event_loop()
|
|
loop.create_task(self._heartbeat())
|
|
logger.debug('Build worker %s is connected and ready', self.builder_realm)
|
|
raise trollius.Return(True)
|
|
|
|
@trollius.coroutine
|
|
def _set_status(self, phase):
|
|
if phase == ComponentStatus.RUNNING:
|
|
yield trollius.From(self.parent_manager.build_component_ready(self))
|
|
|
|
self._component_status = phase
|
|
|
|
def _on_heartbeat(self):
|
|
""" Updates the last known heartbeat. """
|
|
self._last_heartbeat = datetime.datetime.utcnow()
|
|
|
|
@trollius.coroutine
|
|
def _heartbeat(self):
|
|
""" Coroutine that runs every HEARTBEAT_TIMEOUT seconds, both checking the worker's heartbeat
|
|
and updating the heartbeat in the build status dictionary (if applicable). This allows
|
|
the build system to catch crashes from either end.
|
|
"""
|
|
yield trollius.From(trollius.sleep(INITIAL_TIMEOUT))
|
|
|
|
while True:
|
|
# If the component is no longer running or actively building, nothing more to do.
|
|
if (self._component_status != ComponentStatus.RUNNING and
|
|
self._component_status != ComponentStatus.BUILDING):
|
|
raise trollius.Return()
|
|
|
|
# If there is an active build, write the heartbeat to its status.
|
|
build_status = self._build_status
|
|
if build_status is not None:
|
|
with build_status as status_dict:
|
|
status_dict['heartbeat'] = int(time.time())
|
|
|
|
# Mark the build item.
|
|
current_job = self._current_job
|
|
if current_job is not None:
|
|
yield trollius.From(self.parent_manager.job_heartbeat(current_job))
|
|
|
|
# Check the heartbeat from the worker.
|
|
logger.debug('Checking heartbeat on realm %s', self.builder_realm)
|
|
if (self._last_heartbeat and
|
|
self._last_heartbeat < datetime.datetime.utcnow() - HEARTBEAT_DELTA):
|
|
yield trollius.From(self._timeout())
|
|
raise trollius.Return()
|
|
|
|
yield trollius.From(trollius.sleep(HEARTBEAT_TIMEOUT))
|
|
|
|
@trollius.coroutine
|
|
def _timeout(self):
|
|
if self._component_status == ComponentStatus.TIMED_OUT:
|
|
raise trollius.Return()
|
|
|
|
yield trollius.From(self._set_status(ComponentStatus.TIMED_OUT))
|
|
logger.warning('Build component with realm %s has timed out', self.builder_realm)
|
|
|
|
# If we still have a running job, then it has not completed and we need to tell the parent
|
|
# manager.
|
|
if self._current_job is not None:
|
|
self._build_status.set_error('Build worker timed out', internal_error=True)
|
|
|
|
self.parent_manager.job_completed(self._current_job, BuildJobResult.INCOMPLETE, self)
|
|
self._build_status = None
|
|
self._current_job = None
|
|
|
|
# Unregister the current component so that it cannot be invoked again.
|
|
self.parent_manager.build_component_disposed(self, True)
|