示例#1
0
 def report_on_it(dead, ara_reports_url,
                  gists, gist_mapping,
                  stdout_path, stderr_path):
     started_at = timeutils.now()
     last_report = timeutils.now()
     last_gist_update = timeutils.now()
     emitted_ara = False
     while not dead.is_set():
         now = timeutils.now()
         secs_since_last_report = now - last_report
         if secs_since_last_report >= self.report_period:
             if not emitted_ara and ara_reports_url:
                 replier("Progress can be"
                         " watched at: %s" % ara_reports_url)
                 emitted_ara = True
             if pbar is not None:
                 pbar.update(
                     'Your playbook has been running for'
                     ' %s...' % utils.format_seconds(now - started_at))
             last_report = now
         secs_since_last_gist_update = now - last_gist_update
         if secs_since_last_gist_update >= self.gist_update_period:
             update_or_create_gist(gists, gist_mapping,
                                   stdout_path, stderr_path)
             last_gist_update = now
         dead.wait(min([self.gist_update_period, self.report_period]))
示例#2
0
 def inner(*args, **kwargs):
     t1 = timeutils.now()
     t2 = None
     try:
         with lock(name,
                   lock_file_prefix,
                   external,
                   lock_path,
                   do_log=False,
                   semaphores=semaphores,
                   delay=delay,
                   fair=fair):
             t2 = timeutils.now()
             LOG.debug(
                 'Lock "%(name)s" acquired by "%(function)s" :: '
                 'waited %(wait_secs)0.3fs', {
                     'name': name,
                     'function': reflection.get_callable_name(f),
                     'wait_secs': (t2 - t1)
                 })
             return f(*args, **kwargs)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug(
             'Lock "%(name)s" released by "%(function)s" :: held '
             '%(held_secs)s', {
                 'name': name,
                 'function': reflection.get_callable_name(f),
                 'held_secs': held_secs
             })
示例#3
0
 def _synchronized(f, *a, **k):
     call_args = inspect.getcallargs(f, *a, **k)
     call_args['f_name'] = f.__name__
     lock = coordinator.get_lock(lock_name.format(**call_args))
     t1 = timeutils.now()
     t2 = None
     try:
         with lock(blocking):
             t2 = timeutils.now()
             LOG.debug('Lock "%(name)s" acquired by "%(function)s" :: '
                       'waited %(wait_secs)0.3fs',
                       {'name': lock.name,
                        'function': f.__name__,
                        'wait_secs': (t2 - t1)})
             return f(*a, **k)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug('Lock "%(name)s" released by "%(function)s" :: held '
                   '%(held_secs)s',
                   {'name': lock.name,
                    'function': f.__name__,
                    'held_secs': held_secs})
示例#4
0
 def _synchronized(f, *a, **k):
     call_args = inspect.getcallargs(f, *a, **k)
     call_args['f_name'] = f.__name__
     lock = Lock(lock_name, call_args, coordinator)
     t1 = timeutils.now()
     t2 = None
     try:
         with lock(blocking):
             t2 = timeutils.now()
             LOG.debug(
                 'Lock "%(name)s" acquired by "%(function)s" :: '
                 'waited %(wait_secs)0.3fs', {
                     'name': lock.name,
                     'function': f.__name__,
                     'wait_secs': (t2 - t1)
                 })
             return f(*a, **k)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug(
             'Lock "%(name)s" released by "%(function)s" :: held '
             '%(held_secs)s', {
                 'name': lock.name,
                 'function': f.__name__,
                 'held_secs': held_secs
             })
示例#5
0
 def _synchronized(f, *a, **k):
     if six.PY2:
         # pylint: disable=deprecated-method
         call_args = inspect.getcallargs(f, *a, **k)
     else:
         sig = inspect.signature(f).bind(*a, **k)
         sig.apply_defaults()
         call_args = sig.arguments
     call_args['f_name'] = f.__name__
     lock_format_name = lock_name.format(**call_args)
     t1 = timeutils.now()
     t2 = None
     try:
         with lockutils.lock(lock_format_name):
             t2 = timeutils.now()
             LOG.debug('Lock "%(name)s" acquired by "%(function)s" :: '
                       'waited %(wait_secs)0.3fs',
                       {'name': lock_format_name,
                        'function': f.__name__,
                        'wait_secs': (t2 - t1)})
             return f(*a, **k)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug('Lock "%(name)s" released by "%(function)s" :: held '
                   '%(held_secs)s',
                   {'name': lock_format_name,
                    'function': f.__name__,
                    'held_secs': held_secs})
示例#6
0
 def inner(*args, **kwargs):
     t1 = timeutils.now()
     t2 = None
     gotten = True
     try:
         with lock(name, lock_file_prefix, external, lock_path,
                   do_log=False, semaphores=semaphores, delay=delay,
                   fair=fair, blocking=blocking):
             t2 = timeutils.now()
             LOG.debug('Lock "%(name)s" acquired by "%(function)s" :: '
                       'waited %(wait_secs)0.3fs',
                       {'name': name,
                        'function': reflection.get_callable_name(f),
                        'wait_secs': (t2 - t1)})
             return f(*args, **kwargs)
     except AcquireLockFailedException:
         gotten = False
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug('Lock "%(name)s" "%(gotten)s" by "%(function)s" ::'
                   ' held %(held_secs)s',
                   {'name': name,
                    'gotten': 'released' if gotten else 'unacquired',
                    'function': reflection.get_callable_name(f),
                    'held_secs': held_secs})
示例#7
0
 def inner(*args, **kwargs):
     t1 = timeutils.now()
     t2 = None
     try:
         with lock(name, lock_file_prefix, external, lock_path,
                   do_log=False, semaphores=semaphores, delay=delay,
                   fair=fair):
             t2 = timeutils.now()
             LOG.debug('Lock "%(name)s" acquired by "%(function)s" :: '
                       'waited %(wait_secs)0.3fs',
                       {'name': name,
                        'function': reflection.get_callable_name(f),
                        'wait_secs': (t2 - t1)})
             return f(*args, **kwargs)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug('Lock "%(name)s" released by "%(function)s" :: held '
                   '%(held_secs)s',
                   {'name': name,
                    'function': reflection.get_callable_name(f),
                    'held_secs': held_secs})
 def exc_retrier_sequence(self, exc_id=None,
                          exc_count=None, before_timestamp_calls=(),
                          after_timestamp_calls=()):
     self.exception_to_raise().AndReturn(
         Exception('unexpected %d' % exc_id))
     # Timestamp calls that happen before the logging is possibly triggered.
     for timestamp in before_timestamp_calls:
         timeutils.now().AndReturn(timestamp)
     if exc_count != 0:
         logging.exception(mox.In(
             'Unexpected exception occurred %d time(s)' % exc_count))
     # Timestamp calls that happen after the logging is possibly triggered.
     for timestamp in after_timestamp_calls:
         timeutils.now().AndReturn(timestamp)
示例#9
0
 def exc_retrier_sequence(self, exc_id=None,
                          exc_count=None, before_timestamp_calls=(),
                          after_timestamp_calls=()):
     self.exception_to_raise().AndReturn(
         Exception('unexpected %d' % exc_id))
     # Timestamp calls that happen before the logging is possibly triggered.
     for timestamp in before_timestamp_calls:
         timeutils.now().AndReturn(timestamp)
     if exc_count != 0:
         logging.exception(mox.In(
             'Unexpected exception occurred %d time(s)' % exc_count))
     # Timestamp calls that happen after the logging is possibly triggered.
     for timestamp in after_timestamp_calls:
         timeutils.now().AndReturn(timestamp)
示例#10
0
 def _get_dp_by_dpid(self, dpid_int):
     """Get os-ken datapath object for the switch."""
     timeout_sec = cfg.CONF.OVS.of_connect_timeout
     start_time = timeutils.now()
     while True:
         dp = ofctl_api.get_datapath(self._app, dpid_int)
         if dp is not None:
             break
         # The switch has not established a connection to us; retry again
         # until timeout.
         if timeutils.now() > start_time + timeout_sec:
             m = _("Switch connection timeout")
             LOG.error(m)
             # NOTE(yamamoto): use RuntimeError for compat with ovs_lib
             raise RuntimeError(m)
     return dp
示例#11
0
 def _go_no_go(self):
     now = timeutils.now()
     if self.last_sent is None:
         return now, True
     if (now - self.last_sent) >= self.EMIT_PERIOD:
         return now, True
     return now, False
示例#12
0
 def _publish_request(self, request, worker):
     """Publish request to a given topic."""
     LOG.debug(
         "Submitting execution of '%s' to worker '%s' (expecting"
         " response identified by reply_to=%s and"
         " correlation_id=%s) - waited %0.3f seconds to"
         " get published", request, worker, self._uuid, request.uuid,
         timeutils.now() - request.created_on)
     try:
         self._proxy.publish(request,
                             worker.topic,
                             reply_to=self._uuid,
                             correlation_id=request.uuid)
     except Exception:
         with misc.capture_failure() as failure:
             LOG.critical(
                 "Failed to submit '%s' (transitioning it to"
                 " %s)",
                 request,
                 pr.FAILURE,
                 exc_info=True)
             if request.transition_and_log_error(pr.FAILURE, logger=LOG):
                 with self._ongoing_requests_lock:
                     del self._ongoing_requests[request.uuid]
                 request.set_result(failure)
示例#13
0
    def _execute(self, action, file_path):
        self.last_status = timeutils.now()

        if action.image_status == "deleted":
            raise exception.ImportTaskError("Image has been deleted, aborting"
                                            " import.")
        try:
            action.set_image_data(file_path or self.uri,
                                  self.task_id,
                                  backend=self.backend,
                                  set_active=self.set_active,
                                  callback=self._status_callback)
        # NOTE(yebinama): set_image_data catches Exception and raises from
        # them. Can't be more specific on exceptions catched.
        except Exception:
            if self.all_stores_must_succeed:
                raise
            msg = (_("%(task_id)s of %(task_type)s failed but since "
                     "all_stores_must_succeed is set to false, continue.") % {
                         'task_id': self.task_id,
                         'task_type': self.task_type
                     })
            LOG.warning(msg)
            if self.backend is not None:
                action.add_failed_stores([self.backend])

        if self.backend is not None:
            action.remove_importing_stores([self.backend])
示例#14
0
    def clean(self):
        """Cleans out any dead/expired/not responding workers.

        Returns how many workers were removed.
        """
        if (not self._workers or
                (self._worker_expiry is None or self._worker_expiry <= 0)):
            return 0
        dead_workers = {}
        with self._cond:
            now = timeutils.now()
            for topic, worker in six.iteritems(self._workers):
                if worker.last_seen is None:
                    continue
                secs_since_last_seen = max(0, now - worker.last_seen)
                if secs_since_last_seen >= self._worker_expiry:
                    dead_workers[topic] = (worker, secs_since_last_seen)
            for topic in six.iterkeys(dead_workers):
                self._workers.pop(topic)
            if dead_workers:
                self._cond.notify_all()
        if dead_workers and LOG.isEnabledFor(logging.INFO):
            for worker, secs_since_last_seen in six.itervalues(dead_workers):
                LOG.info("Removed worker '%s' as it has not responded to"
                         " notification requests in %0.3f seconds",
                         worker, secs_since_last_seen)
        return len(dead_workers)
示例#15
0
    def clean(self):
        """Cleans out any dead/expired/not responding workers.

        Returns how many workers were removed.
        """
        if (not self._workers
                or (self._worker_expiry is None or self._worker_expiry <= 0)):
            return 0
        dead_workers = {}
        with self._cond:
            now = timeutils.now()
            for topic, worker in six.iteritems(self._workers):
                if worker.last_seen is None:
                    continue
                secs_since_last_seen = max(0, now - worker.last_seen)
                if secs_since_last_seen >= self._worker_expiry:
                    dead_workers[topic] = (worker, secs_since_last_seen)
            for topic in six.iterkeys(dead_workers):
                self._workers.pop(topic)
            if dead_workers:
                self._cond.notify_all()
        if dead_workers and LOG.isEnabledFor(logging.INFO):
            for worker, secs_since_last_seen in six.itervalues(dead_workers):
                LOG.info(
                    "Removed worker '%s' as it has not responded to"
                    " notification requests in %0.3f seconds", worker,
                    secs_since_last_seen)
        return len(dead_workers)
示例#16
0
 def _get_dp_by_dpid(self, dpid_int):
     """Get Ryu datapath object for the switch."""
     timeout_sec = cfg.CONF.OVS.of_connect_timeout
     start_time = timeutils.now()
     while True:
         dp = ofctl_api.get_datapath(self._app, dpid_int)
         if dp is not None:
             break
         # The switch has not established a connection to us.
         # Wait for a little.
         if timeutils.now() > start_time + timeout_sec:
             m = _("Switch connection timeout")
             LOG.error(m)
             # NOTE(yamamoto): use RuntimeError for compat with ovs_lib
             raise RuntimeError(m)
         eventlet.sleep(1)
     return dp
示例#17
0
 def _get_dp_by_dpid(self, dpid_int):
     """Get Ryu datapath object for the switch."""
     timeout_sec = constants.OF_CONNECT_TIMEOUT
     start_time = timeutils.now()
     while True:
         dp = ofctl_api.get_datapath(self._app, dpid_int)
         if dp is not None:
             break
         # The switch has not established a connection to us.
         # Wait for a little.
         if timeutils.now() > start_time + timeout_sec:
             m = "Switch connection timeout"
             LOG.error(m)
             # NOTE(yamamoto): use RuntimeError for compat with ovs_lib
             raise RuntimeError(m)
         eventlet.sleep(1)
     return dp
示例#18
0
 def _get_dp_by_dpid(self, dpid_int):
     LOG.info('%s(): caller(): %s', log_utils.get_fname(1),
              log_utils.get_fname(2))
     """Get os-ken datapath object for the switch."""
     timeout_sec = cfg.CONF.OVS.of_connect_timeout
     start_time = timeutils.now()
     while True:
         dp = ofctl_api.get_datapath(self._app, dpid_int)
         if dp is not None:
             break
         # The switch has not established a connection to us.
         # Wait for a little.
         if timeutils.now() > start_time + timeout_sec:
             m = _("Switch connection timeout")
             LOG.error(m)
             # NOTE(yamamoto): use RuntimeError for compat with ovs_lib
             raise RuntimeError(m)
         eventlet.sleep(1)
     return dp
示例#19
0
    def _status_callback(self, action, chunk_bytes, total_bytes):
        # NOTE(danms): Only log status every five minutes
        if timeutils.now() - self.last_status > 300:
            LOG.debug('Image import %(image_id)s copied %(copied)i MiB',
                      {'image_id': action.image_id,
                       'copied': total_bytes // units.Mi})
            self.last_status = timeutils.now()

        task = script_utils.get_task(self.task_repo, self.task_id)
        if task is None:
            LOG.error(
                'Status callback for task %(task)s found no task object!',
                {'task': self.task_id})
            raise exception.TaskNotFound(self.task_id)
        if task.status != 'processing':
            LOG.error('Task %(task)s expected "processing" status, '
                      'but found "%(status)s"; aborting.')
            raise exception.TaskAbortedError()

        task.message = _('Copied %i MiB') % (total_bytes // units.Mi)
        self.task_repo.save(task)
示例#20
0
 def _synchronized(f, *a, **k) -> Callable:
     call_args = inspect.getcallargs(f, *a, **k)
     call_args['f_name'] = f.__name__
     lock = coordinator.get_lock(lock_name.format(**call_args))
     name = utils.convert_str(lock.name)
     f_name = f.__name__
     t1 = timeutils.now()
     t2 = None
     try:
         LOG.debug(f'Acquiring lock "{name}" by "{f_name}"')
         with lock(blocking):
             t2 = timeutils.now()
             LOG.debug(f'Lock "{name}" acquired by "{f_name}" :: '
                       f'waited {t2 - t1:0.3f}s')
             return f(*a, **k)
     finally:
         t3 = timeutils.now()
         if t2 is None:
             held_secs = "N/A"
         else:
             held_secs = "%0.3fs" % (t3 - t2)
         LOG.debug(
             f'Lock "{name}" released by "{f_name}" :: held {held_secs}')
示例#21
0
 def process_response(self, data, message):
     """Process notify message sent from remote side."""
     LOG.debug("Started processing notify response message '%s'",
               ku.DelayedPretty(message))
     response = pr.Notify(**data)
     LOG.debug("Extracted notify response '%s'", response)
     with self._cond:
         worker, new_or_updated = self._add(response.topic, response.tasks)
         if new_or_updated:
             LOG.debug(
                 "Updated worker '%s' (%s total workers are"
                 " currently known)", worker, self.total_workers)
             self._cond.notify_all()
         worker.last_seen = timeutils.now()
         self._messages_processed += 1
示例#22
0
 def process_response(self, data, message):
     """Process notify message sent from remote side."""
     LOG.debug("Started processing notify response message '%s'",
               ku.DelayedPretty(message))
     response = pr.Notify(**data)
     LOG.debug("Extracted notify response '%s'", response)
     with self._cond:
         worker, new_or_updated = self._add(response.topic,
                                            response.tasks)
         if new_or_updated:
             LOG.debug("Updated worker '%s' (%s total workers are"
                       " currently known)", worker, self.total_workers)
             self._cond.notify_all()
         worker.last_seen = timeutils.now()
         self._messages_processed += 1
示例#23
0
 def __init__(self, task, uuid, action,
              arguments, timeout=REQUEST_TIMEOUT, result=NO_RESULT,
              failures=None):
     self._action = action
     self._event = ACTION_TO_EVENT[action]
     self._arguments = arguments
     self._result = result
     self._failures = failures
     self._watch = timeutils.StopWatch(duration=timeout).start()
     self._lock = threading.Lock()
     self.state = WAITING
     self.task = task
     self.uuid = uuid
     self.created_on = timeutils.now()
     self.future = futurist.Future()
     self.future.atom = task
示例#24
0
文件: types.py 项目: pombredanne/zag
    def process_response(self, data, message):
        """Process notify message (response) sent from remote side.

        NOTE(harlowja): the message content should already have had
        basic validation performed on it...
        """
        LOG.debug("Started processing notify response message '%s'",
                  ku.DelayedPretty(message))
        response = pr.Notify(**data)
        LOG.debug("Extracted notify response '%s'", response)
        with self._cond:
            worker, new_or_updated = self._add(response.topic, response.tasks)
            if new_or_updated:
                LOG.debug(
                    "Received notification about worker '%s' (%s"
                    " total workers are currently known)", worker,
                    self.available_workers)
                self._cond.notify_all()
            worker.last_seen = timeutils.now()
示例#25
0
 def _publish_request(self, request, worker):
     """Publish request to a given topic."""
     LOG.debug("Submitting execution of '%s' to worker '%s' (expecting"
               " response identified by reply_to=%s and"
               " correlation_id=%s) - waited %0.3f seconds to"
               " get published", request, worker, self._uuid,
               request.uuid, timeutils.now() - request.created_on)
     try:
         self._proxy.publish(request, worker.topic,
                             reply_to=self._uuid,
                             correlation_id=request.uuid)
     except Exception:
         with misc.capture_failure() as failure:
             LOG.critical("Failed to submit '%s' (transitioning it to"
                          " %s)", request, pr.FAILURE, exc_info=True)
             if request.transition_and_log_error(pr.FAILURE, logger=LOG):
                 with self._ongoing_requests_lock:
                     del self._ongoing_requests[request.uuid]
                 request.set_result(failure)
示例#26
0
def set_project_name_to_objects(request, objects):
    global PROJECTS, TIME
    try:
        # NOTE(vponomaryov): we will use saved values making lots of requests
        # in short period of time. 'memoized' is not suitable here
        now = timeutils.now()
        if TIME is None:
            TIME = now
        if not PROJECTS or now > TIME + 20:
            projects, has_more = keystone.tenant_list(request)
            PROJECTS = {t.id: t for t in projects}
            TIME = now
    except Exception:
        msg = _('Unable to retrieve list of projects.')
        exceptions.handle(request, msg)

    for obj in objects:
        project_id = getattr(obj, "project_id", None)
        project = PROJECTS.get(project_id, None)
        obj.project_name = getattr(project, "name", None)
示例#27
0
def set_project_name_to_objects(request, objects):
    global PROJECTS, TIME
    try:
        # NOTE(vponomaryov): we will use saved values making lots of requests
        # in short period of time. 'memoized' is not suitable here
        now = timeutils.now()
        if TIME is None:
            TIME = now
        if not PROJECTS or now > TIME + 20:
            projects, has_more = keystone.tenant_list(request)
            PROJECTS = {t.id: t for t in projects}
            TIME = now
    except Exception:
        msg = _('Unable to retrieve list of projects.')
        exceptions.handle(request, msg)

    for obj in objects:
        project_id = getattr(obj, "project_id", None)
        project = PROJECTS.get(project_id, None)
        obj.project_name = getattr(project, "name", None)
示例#28
0
 def __init__(self,
              task,
              uuid,
              action,
              arguments,
              timeout=REQUEST_TIMEOUT,
              result=NO_RESULT,
              failures=None):
     self._action = action
     self._event = ACTION_TO_EVENT[action]
     self._arguments = arguments
     self._result = result
     self._failures = failures
     self._watch = timeutils.StopWatch(duration=timeout).start()
     self._lock = threading.Lock()
     self.state = WAITING
     self.task = task
     self.uuid = uuid
     self.created_on = timeutils.now()
     self.future = futurist.Future()
     self.future.atom = task
示例#29
0
    def _handle_expired_request(request):
        """Handle a expired request.

        When a request has expired it is removed from the ongoing requests
        dictionary and a ``RequestTimeout`` exception is set as a
        request result.
        """
        if request.transition_and_log_error(pr.FAILURE, logger=LOG):
            # Raise an exception (and then catch it) so we get a nice
            # traceback that the request will get instead of it getting
            # just an exception with no traceback...
            try:
                request_age = timeutils.now() - request.created_on
                raise exc.RequestTimeout(
                    "Request '%s' has expired after waiting for %0.2f"
                    " seconds for it to transition out of (%s) states"
                    % (request, request_age, ", ".join(pr.WAITING_STATES)))
            except exc.RequestTimeout:
                with misc.capture_failure() as failure:
                    LOG.debug(failure.exception_str)
                    request.set_result(failure)
            return True
        return False
示例#30
0
    def _watch(self, job_name, build, jenkins_client, job=None):
        replier = self.message.reply_text
        replier = functools.partial(replier, threaded=True, prefixed=False)

        if job is None:
            replier("Locating job `%s`, please wait..." % job_name)
            job = jenkins_client.get_job(job_name)
            if job is None:
                replier("Job `%s` was not found!" % job_name)
                return

        if isinstance(build, six.string_types):
            build = int(build)
        if isinstance(build, six.integer_types):
            build_num = build
            replier("Locating build `%s`, please wait..." % build_num)
            build = job.get_build(build)
            if build is None:
                replier("Job `%s` build `%s` was"
                        " not found!" % (job_name, build_num))
                return

        build_num = build.number
        replier("Watching initiated for"
                " job `%s` build `%s`" % (job_name, build_num))

        max_build_wait = None
        try:
            max_build_wait = self.config.jenkins.max_build_wait
        except AttributeError:
            pass

        report_bar = self.message.make_manual_progress_bar()
        with timeutils.StopWatch(duration=max_build_wait) as watch:
            # At this point we can be cancelled safely, so allow that
            # to happen (or at least allow someone to try it).
            self.job = job
            self.build = build
            if build.is_running():
                still_running = True
                build_eta = build.get_eta()
                if build_eta != float("inf"):
                    eta_sec = max(0, build_eta - watch.elapsed())
                    eta_text = "%0.2fs/%0.2fm" % (eta_sec, eta_sec / 60.0)
                    report_bar.update("Estimated time to completion is %s" %
                                      eta_text)
                else:
                    report_bar.update("Estimated time to"
                                      " completion is unknown.")
                last_build_fetch = timeutils.now()
                while still_running:
                    if watch.expired():
                        replier("Timed out (waited %0.2f seconds) while"
                                " checking your build." % watch.elapsed())
                        return
                    self.dead.wait(self.poll_delay)
                    if self.dead.is_set():
                        replier("I have been terminated, please"
                                " check the jenkins job url for the"
                                " final result.")
                        return
                    now = timeutils.now()
                    since_last_build_info = now - last_build_fetch
                    if since_last_build_info > self.build_info_delay:
                        build.poll()
                        if build.is_running():
                            build_eta = build.get_eta()
                            if build_eta != float("inf"):
                                eta_sec = build_eta - watch.elapsed()
                                eta_sec_min = eta_sec / 60.0
                                if eta_sec >= 0:
                                    eta_text = "%0.2fs/%0.2fm" % (eta_sec,
                                                                  eta_sec_min)
                                    report_bar.update("Estimated time to"
                                                      " completion is %s" %
                                                      eta_text)
                                else:
                                    eta_sec = eta_sec * -1
                                    eta_sec_min = eta_sec_min * -1
                                    eta_text = "%0.2fs/%0.2fm" % (eta_sec,
                                                                  eta_sec_min)
                                    report_bar.update(
                                        "Job is %s over estimated time"
                                        " to completion" % eta_text)
                            else:
                                report_bar.update("Estimated time to"
                                                  " completion is unknown.")
                        else:
                            still_running = False
                        since_last_build_info = now

        # Force getting the newest data...
        build.poll()
        result = build.get_result()

        # Try to get some console log (if this fails it doesn't really matter)
        result_dict = None
        console_out_pretty = None
        try:
            console_out = build.get_console()
            console_out_pretty = _format_build_console(
                console_out, line_limit=CONSOLE_LINES)
            result_dict = _console_get_result_dict(console_out)
        except Exception:
            LOG.warn("Failed getting build console for '%s'",
                     build,
                     exc_info=True)

        if not result:
            result = "UNKNOWN"
        replier("Your jenkins job finished with result `%s`" % result)
        if result_dict:
            replier(_format_result_dict(result_dict))

        if result == "FAILURE" and console_out_pretty:
            replier(console_out_pretty)

        return result_dict