Exemple #1
0
    def authenticate(
        request: HttpRequest,
        username: str = None,
        password: str = None,
        code: str = None,
        token_provider: TokenProviderBase = TokenProvider(),
    ) -> Union[UserModel, None]:
        logger = LoggerAdapter(
            getLogger(__package__),
            get_extra(
                "backends.OAuthClientBackend",
                request.session["OAC_CLIENT_IP"],
                request.session["OAC_STATE_STR"],
            ),
        )
        try:
            token = token_provider.create(code)
        except NoUserError as e_info:
            logger.info(f"raised django_oac.exceptions.NoUserError: {e_info}")
            return None
        else:
            user = token.user

            logger.info(f"user '{user}' authenticated")
            return user
Exemple #2
0
 def logReport(self, log: LoggerAdapter):
     """
     Create an INFO log message to log the Connection report using the keys in self.stats.
     :param log: Logger to use to log the report
     """
     keys = ", ".join([f"{key}: %({key})s" for key in self.stats.keys()])
     log.info(f"Connection report: {keys}", self.stats)
Exemple #3
0
async def get_porter_outputs(msg_body: dict,
                             message_logger_adapter: logging.LoggerAdapter,
                             config: dict):
    """
    Get outputs JSON from a Porter command
    """
    porter_command = await build_porter_command_for_outputs(msg_body)
    returncode, stdout, err = await run_porter(porter_command,
                                               message_logger_adapter, config)

    if returncode != 0:
        error_message = "Error context message = " + " ".join(err.split('\n'))
        message_logger_adapter.info(
            f"{get_installation_id(msg_body)}: Failed to get outputs with error = {error_message}"
        )
        return False, ""
    else:
        outputs_json = {}
        try:
            outputs_json = json.loads(stdout)
            message_logger_adapter.info(f"Got outputs as json: {outputs_json}")
        except ValueError:
            message_logger_adapter.error(f"Got outputs invalid json: {stdout}")

        return True, outputs_json
Exemple #4
0
def authenticate_view(request: HttpRequest) -> HttpResponse:
    state_str = uuid4().hex
    client_ip, _ = get_client_ip(request)

    if request.session.get("OAC_STATE_STR") != "test":
        request.session["OAC_STATE_STR"] = state_str
        request.session["OAC_STATE_TIMESTAMP"] = timezone.now().timestamp()
        request.session["OAC_CLIENT_IP"] = client_ip or "unknown"

    logger = LoggerAdapter(
        getLogger(__package__),
        get_extra(
            "views.authenticate_view",
            request.session["OAC_CLIENT_IP"],
            request.session["OAC_STATE_STR"],
        ),
    )
    logger.info("authentication request")

    try:
        ret = redirect(f"{oac_settings.AUTHORIZE_URI}"
                       f"?scope=openid"
                       f"&client_id={oac_settings.CLIENT_ID}"
                       f"&redirect_uri={oac_settings.REDIRECT_URI}"
                       f"&state={state_str}"
                       "&response_type=code")
    except ConfigurationError as err:
        logger.error(str(err))
        ret = render(
            request,
            TEMPLATES_DIR / "500.html",
            {"message": "App config is incomplete, cannot continue."},
            status=500,
        )
    return ret
Exemple #5
0
def parse_robots_txt(
        records: Iterable[Iterable[Tuple[int, str, str]]],
        logger: LoggerAdapter) -> Mapping[str, Iterable[Tuple[bool, str]]]:
    """Parses C{robots.txt} records.

    @param records:
        Tokenized records as produced by L{scan_robots_txt}.
    @param logger:
        Problems found while parsing are logged here.
    @return:
        rules_map: C{{ user_agent: (allowed, url_prefix)* }}
        A mapping from user agent name (case-folded) to a sequence of
        allow/disallow rules, where C{allowed} is C{True} iff the user agent
        is allowed to visit URLs starting with C{url_prefix}.
    """
    result: Dict[str, Iterable[Tuple[bool, str]]] = {}
    unknowns: Set[str] = set()
    for record in records:
        seen_user_agent = False
        rules: List[Tuple[bool, str]] = []
        for lineno, field, value in record:
            if field == 'user-agent':
                if rules:
                    logger.error(
                        'Line %d specifies user agent after rules; '
                        'assuming new record', lineno)
                    rules = []
                seen_user_agent = True
                name = value.casefold()
                if name in result:
                    logger.error(
                        'Line %d specifies user agent "%s", which was '
                        'already addressed in an earlier record; '
                        'ignoring new record', lineno, value)
                else:
                    result[name] = rules
            elif field in ('allow', 'disallow'):
                if seen_user_agent:
                    try:
                        path = unescape_path(value)
                    except ValueError as ex:
                        logger.error('Bad escape in %s URL on line %d: %s',
                                     field, lineno, ex)
                    else:
                        # Ignore allow/disallow directives without a path.
                        if path:
                            rules.append((field == 'allow', path))
                else:
                    logger.error(
                        'Line %d specifies %s rule without a preceding '
                        'user agent line; ignoring line', lineno, field)
            else:
                # Unknown fields are allowed for extensions.
                if field not in unknowns:
                    unknowns.add(field)
                    logger.info('Unknown field "%s" (line %d)', field, lineno)
    return result
Exemple #6
0
    def __init__(self, colors=None, attributes=None, description=None,\
        delimiter=' | ', delimiter_colors=None):
        """
        Input:
            colors: list of kaleidoscope color names to use in styling the object's attributes
            attributes: list of names of attributes to render
                you can optionally use a list of 2 or 3-tuples where:
                    the first value is the attribute name
                    the second value is the length of the attribute rendering
                    the third value is the NSID of a formatter in the formatter namespace
                The AttributeSpec type exists as well to be passed in here
            description: the description of this object model spec
            delimiter: string to place between attributes on a single line
            delimiter_color: color of delimiter string

        Notes:
            All parameters are optional, but you probably want to fill in the attributes before using this
        """
        log = LoggerAdapter(logger, {'name_ext': 'ObjectModelSpec.__init__'})
        msg = "Entered: colors: {} | attributes: {}".format(colors, attributes)
        msg += " | description: {} | delimiter: {}".format(
            description, delimiter)
        msg += " | delimiter_colors: {}".format(delimiter_colors)
        log.debug(msg)
        self.delimiter = str(delimiter)
        self.description = description

        if colors:
            _colors = list()
            for _color in colors:
                _colors.append(Color(_color))
            self.colors = cycle(_colors)
        else:
            self.colors = repeat(None)

        if delimiter_colors:
            _delimiter_colors = list()
            for _dcolor in delimiter_colors:
                _delimiter_colors.append(Color(_dcolor))
            self.delimiter_colors = cycle(_delimiter_colors)
        else:
            self.delimiter_colors = copy.copy(self.colors)

        #- locally store parsed attributes as AttributeSpec objects
        if attributes:
            if not isinstance(attributes, Iterable):
                attributes = [attributes]
            log.debug("parsing attributes: {}".format(attributes))
            self.attributes = self.parse_attributes(attributes)
        else:
            log.info("spec has no attributes specified.")
            self.attributes = None

        log.debug("initialized: {}".format(self))
Exemple #7
0
    def _send_queue_to_socket(self, port: int, log: logging.LoggerAdapter) -> None:
        while True:
            try:
                self._sock.connect(("localhost", port))
                log.info(f"connected to localhost:{port}")
                break
            except ConnectionRefusedError:
                log.info(f"connecting to localhost:{port} failed, retrying soon")
                time.sleep(0.5)

        while True:
            bytez = self._send_queue.get()
            if bytez is None:
                break
            self._sock.sendall(bytez)
Exemple #8
0
    def generate(remotePath: str, outDir: Path, filesystemDir: Path, log: LoggerAdapter):
        remotePath = Path(remotePath.replace("\\", "/"))
        filesystemPath = filesystemDir / remotePath.relative_to("/")

        tmpOutDir = outDir / "tmp"
        tmpOutDir.mkdir(exist_ok=True)

        handle, tmpPath = tempfile.mkstemp("", "", tmpOutDir)
        file = open(handle, "wb")

        log.info("Saving file '%(remotePath)s' to '%(localPath)s'", {
            "localPath": tmpPath, "remotePath": remotePath
        })

        return FileMapping(file, Path(tmpPath), filesystemPath, filesystemDir, log)
Exemple #9
0
    def logReport(self, log: LoggerAdapter, more_info: Optional[collections.Mapping] = None):
        """
        Create an INFO log message to log the Connection report using the keys in self.stats.
        :param log: Logger to use to log the report
        :param more_info: A dictionary-like object of more information to merge
                          in the connection report
        """
        # merge in the additional data if required
        if isinstance(more_info, collections.Mapping):
            report_data = {**self.stats, **more_info}
        else:
            report_data = self.stats

        keys = ", ".join([f"{key}: %({key})s" for key in report_data.keys()])
        log.info(f"Connection report: {keys}", report_data)
Exemple #10
0
def use2(l: logging.LoggerAdapter) -> None:
    l.info("hai")
Exemple #11
0
class StatusBase:
    """
    This is a base class that provides a single-slot callback for when the
    specific operation has finished.

    Parameters
    ----------
    timeout : float, optional
        The default timeout to use for a blocking wait, and the amount of time
        to wait to mark the operation as failed
    settle_time : float, optional
        The amount of time to wait between the caller specifying that the
        status has completed to running callbacks
    """
    def __init__(self,
                 *,
                 timeout=None,
                 settle_time=None,
                 done=False,
                 success=False):
        super().__init__()
        self._tname = None
        self._lock = threading.RLock()
        self._callbacks = deque()
        self._done = done
        self.success = success
        self.timeout = None

        self.log = LoggerAdapter(logger=logger, extra={'status': self})

        if settle_time is None:
            settle_time = 0.0

        self.settle_time = float(settle_time)

        if timeout is not None:
            self.timeout = float(timeout)

        if self.done:
            # in the case of a pre-completed status object,
            # don't handle timeout
            return

        if self.timeout is not None and self.timeout > 0.0:
            thread = threading.Thread(target=self._wait_and_cleanup,
                                      daemon=True,
                                      name=self._tname)
            self._timeout_thread = thread
            self._timeout_thread.start()

    @property
    def done(self):
        """
        Boolean indicating whether associated operation has completed.

        This is set to True at __init__ time or by calling `_finished()`. Once
        True, it can never become False.
        """
        return self._done

    @done.setter
    def done(self, value):
        # For now, allow this setter to work only if it has no effect.
        # In a future release, make this property not settable.
        if bool(self._done) != bool(value):
            raise RuntimeError(
                "The done-ness of a status object cannot be changed by "
                "setting its `done` attribute directly. Call `_finished()`.")
        warn(
            "Do not set the `done` attribute of a status object directly. "
            "It should only be set indirectly by calling `_finished()`. "
            "Direct setting was never intended to be supported and it will be "
            "disallowed in a future release of ophyd, causing this code path "
            "to fail.", UserWarning)

    def _wait_and_cleanup(self):
        """Handle timeout"""
        try:
            if self.timeout is not None:
                timeout = self.timeout + self.settle_time
            else:
                timeout = None
            wait(self, timeout=timeout, poll_rate=0.2)
        except TimeoutError:
            with self._lock:
                if self.done:
                    # Avoid race condition with settling.
                    return
                self.log.warning('timeout after %.2f seconds', timeout)
                try:
                    self._handle_failure()
                finally:
                    self._finished(success=False)
        except RuntimeError:
            pass
        finally:
            self._timeout_thread = None

    def _handle_failure(self):
        pass

    def _settled(self):
        """Hook for when status has completed and settled"""
        pass

    def _settle_then_run_callbacks(self, success=True):
        # wait until the settling time is done to mark completion
        if self.settle_time > 0.0:
            time.sleep(self.settle_time)

        with self._lock:
            if self.done:
                # We timed out while waiting for the settle time.
                return
            self.success = success
            self._done = True
            self._settled()

            for cb in self._callbacks:
                cb()
            self._callbacks.clear()

    def _finished(self, success=True, **kwargs):
        """Inform the status object that it is done and if it succeeded

        .. warning::

           kwargs are not used, but are accepted because pyepics gives
           in a bunch of kwargs that we don't care about.  This allows
           the status object to be handed directly to pyepics (but
           this is probably a bad idea for other reason.

           This may be deprecated in the future.

        Parameters
        ----------
        success : bool, optional
           if the action succeeded.
        """
        if self.done:
            self.log.info('finished')
            return

        if success and self.settle_time > 0:
            # delay gratification until the settle time is up
            self._settle_thread = threading.Thread(
                target=self._settle_then_run_callbacks,
                daemon=True,
                kwargs=dict(success=success),
            )
            self._settle_thread.start()
        else:
            self._settle_then_run_callbacks(success=success)

    @property
    def callbacks(self):
        """
        Callbacks to be run when the status is marked as finished

        The callback has no arguments ::

            def cb() -> None:

        """
        return self._callbacks

    @property
    @_locked
    def finished_cb(self):
        if len(self.callbacks) == 1:
            warn(
                "The property `finished_cb` is deprecated, and must raise "
                "an error if a status object has multiple callbacks. Use "
                "the `callbacks` property instead.",
                stacklevel=2)
            cb, = self.callbacks
            assert cb is not None
            return cb
        else:
            raise UseNewProperty("The deprecated `finished_cb` property "
                                 "cannot be used for status objects that have "
                                 "multiple callbacks. Use the `callbacks` "
                                 "property instead.")

    @_locked
    def add_callback(self, cb):
        if self.done:
            cb()
        else:
            self._callbacks.append(cb)

    @finished_cb.setter
    @_locked
    def finished_cb(self, cb):
        if not self.callbacks:
            warn(
                "The setter `finished_cb` is deprecated, and must raise "
                "an error if a status object already has one callback. Use "
                "the `add_callback` method instead.",
                stacklevel=2)
            self.add_callback(cb)
        else:
            raise UseNewProperty("The deprecated `finished_cb` setter cannot "
                                 "be used for status objects that already "
                                 "have one callback. Use the `add_callbacks` "
                                 "method instead.")

    def __and__(self, other):
        """
        Returns a new 'composite' status object, AndStatus,
        with the same base API.

        It will finish when both `self` or `other` finish.
        """
        return AndStatus(self, other)
Exemple #12
0
async def receive_message(service_bus_client,
                          logger_adapter: logging.LoggerAdapter, config: dict):
    """
    This method is run per process. Each process will connect to service bus and try to establish a session.
    If messages are there, the process will continue to receive all the messages associated with that session.
    If no messages are there, the session connection will time out, sleep, and retry.
    """
    q_name = config["resource_request_queue"]

    while True:
        try:
            logger_adapter.info("Looking for new session...")
            # max_wait_time=1 -> don't hold the session open after processing of the message has finished
            async with service_bus_client.get_queue_receiver(
                queue_name=q_name,
                max_wait_time=1,
                session_id=NEXT_AVAILABLE_SESSION) as receiver:
                logger_adapter.info("Got a session containing messages")
                async with AutoLockRenewer() as renewer:
                    # allow a session to be auto lock renewed for up to an hour - if it's processing a message
                    renewer.register(receiver,
                                     receiver.session,
                                     max_lock_renewal_duration=3600)

                    async for msg in receiver:
                        result = True
                        message = ""

                        try:
                            message = json.loads(str(msg))
                            logger_adapter.info(
                                f"Message received for resource_id={message['id']}, operation_id={message['operationId']}, step_id={message['stepId']}"
                            )
                            message_logger_adapter = get_message_id_logger(
                                message['operationId']
                            )  # correlate messages per operation
                            result = await invoke_porter_action(
                                message, service_bus_client,
                                message_logger_adapter, config)
                        except (json.JSONDecodeError) as e:
                            logging.error(
                                f"Received bad service bus resource request message: {e}"
                            )

                        if result:
                            logging.info(
                                f"Resource request for {message} is complete")
                        else:
                            logging.error('Message processing failed!')

                        logger_adapter.info(
                            f"Message for resource_id={message['id']}, operation_id={message['operationId']} processed as {result} and marked complete."
                        )
                        await receiver.complete_message(msg)

                    logger_adapter.info("Closing session")
                    await renewer.close()

        except OperationTimeoutError:
            # Timeout occurred whilst connecting to a session - this is expected and indicates no non-empty sessions are available
            logger_adapter.info(
                "No sessions for this process. Will look again...")

        except ServiceBusConnectionError:
            # Occasionally there will be a transient / network-level error in connecting to SB.
            logger_adapter.info(
                "Unknown Service Bus connection error. Will retry...")

        except Exception:
            # Catch all other exceptions, log them via .exception to get the stack trace, sleep, and reconnect
            logger_adapter.exception("Unknown exception. Will retry...")
Exemple #13
0
class OphydObject:
    '''The base class for all objects in Ophyd

    Handles:

      * Subscription/callback mechanism

    Parameters
    ----------
    name : str, optional
        The name of the object.
    attr_name : str, optional
        The attr name on it's parent (if it has one)
        ex ``getattr(self.parent, self.attr_name) is self``
    parent : parent, optional
        The object's parent, if it exists in a hierarchy
    kind : a member of the :class:`~ophydobj.Kind` :class:`~enum.IntEnum`
        (or equivalent integer), optional
        Default is ``Kind.normal``. See :class:`~ophydobj.Kind` for options.

    Attributes
    ----------
    name
    '''

    # Any callables appended to this mutable class variable will be notified
    # one time when a new instance of OphydObj is instantiated. See
    # OphydObject.add_instantiation_callback().
    __instantiation_callbacks = []
    _default_sub = None
    # This is set to True when the first OphydObj is instantiated. This may be
    # of interest to code that adds something to instantiation_callbacks, which
    # may want to know whether it has already "missed" any instances.
    __any_instantiated = False

    def __init__(self,
                 *,
                 name=None,
                 attr_name='',
                 parent=None,
                 labels=None,
                 kind=None):
        if labels is None:
            labels = set()
        self._ophyd_labels_ = set(labels)
        if kind is None:
            kind = Kind.normal
        self.kind = kind

        super().__init__()

        # base name and ref to parent, these go with properties
        if name is None:
            name = ''
        self._attr_name = attr_name
        if not isinstance(name, str):
            raise ValueError("name must be a string.")
        self._name = name
        self._parent = parent

        self.subscriptions = {
            getattr(self, k)
            for k in dir(type(self))
            if (k.startswith('SUB') or k.startswith('_SUB'))
        }

        # dictionary of wrapped callbacks
        self._callbacks = {k: {} for k in self.subscriptions}
        # this is to maintain api on clear_sub
        self._unwrapped_callbacks = {k: {} for k in self.subscriptions}
        # map cid -> back to which event it is in
        self._cid_to_event_mapping = dict()
        # cache of last inputs to _run_subs, the semi-private way
        # to trigger the callbacks for a given subscription to be run
        self._args_cache = {k: None for k in self.subscriptions}
        # count of subscriptions we have handed out, used to give unique ids
        self._cb_count = count()
        # Create logger name from parent or from module class
        if self.parent:
            base_log = self.parent.log.name
            name = self.name.lstrip(self.parent.name + '_')
        else:
            base_log = self.__class__.__module__
            name = self.name
        self.log = LoggerAdapter(logger, {
            'base_log': base_log,
            'ophyd_object_name': name
        })
        self.control_layer_log = LoggerAdapter(control_layer_logger,
                                               {'ophyd_object_name': name})

        if not self.__any_instantiated:
            self.log.info("first instance of OphydObject: id=%s", id(self))
            OphydObject._mark_as_instantiated()
        self.__register_instance(self)

    @classmethod
    def _mark_as_instantiated(cls):
        cls.__any_instantiated = True

    @classmethod
    def add_instantiation_callback(cls, callback, fail_if_late=False):
        """
        Register a callback which will receive each OphydObject instance.

        Parameters
        ----------
        callback : callable
            Expected signature: ``f(ophydobj_instance)``
        fail_if_late : boolean
            If True, verify that OphydObj has not yet been instantiated and raise
            ``RuntimeError`` if it has, as a way of verify that no instances will
            be "missed" by this registry. False by default.
        """
        if fail_if_late and OphydObject.__any_instantiated:
            raise RuntimeError(
                "OphydObject has already been instantiated at least once, and "
                "this callback will not be notified of those instances that "
                "have already been created. If that is acceptable for this "
                "application, set fail_if_false=False.")
        # This is a class variable.
        cls.__instantiation_callbacks.append(callback)

    @classmethod
    def __register_instance(cls, instance):
        """
        Notify the callbacks in OphydObject.instantiation_callbacks of an instance.
        """
        for callback in cls.__instantiation_callbacks:
            callback(instance)

    def __init_subclass__(cls,
                          version=None,
                          version_of=None,
                          version_type=None,
                          **kwargs):
        'This is called automatically in Python for all subclasses of OphydObject'
        super().__init_subclass__(**kwargs)

        if version is None:
            if version_of is not None:
                raise RuntimeError('Must specify a version if `version_of` '
                                   'is specified')
            if version_type is None:
                return
            # Allow specification of version_type without specifying a version,
            # for use in a base class

            cls._class_info_ = dict(versions={},
                                    version=None,
                                    version_type=version_type,
                                    version_of=version_of)
            return

        if version_of is None:
            versions = {}
            version_of = cls
        else:
            versions = version_of._class_info_['versions']
            if version_type is None:
                version_type = version_of._class_info_['version_type']

            elif version_type != version_of._class_info_['version_type']:
                raise RuntimeError(
                    "version_type with in a family must be consistent, "
                    f"you passed in {version_type}, to {cls.__name__} "
                    f"but {version_of.__name__} has version_type "
                    f"{version_of._class_info_['version_type']}")

            if not issubclass(cls, version_of):
                raise RuntimeError(
                    f'Versions are only valid for classes in the same '
                    f'hierarchy. {cls.__name__} is not a subclass of '
                    f'{version_of.__name__}.')

        if versions is not None and version in versions:
            logger.warning('Redefining %r version %s: old=%r new=%r',
                           version_of, version, versions[version], cls)

        versions[version] = cls

        cls._class_info_ = dict(versions=versions,
                                version=version,
                                version_type=version_type,
                                version_of=version_of)

    def _validate_kind(self, val):
        if isinstance(val, str):
            return Kind[val.lower()]
        return Kind(val)

    @property
    def kind(self):
        return self._kind

    @kind.setter
    def kind(self, val):
        self._kind = self._validate_kind(val)

    @property
    def dotted_name(self) -> str:
        """Return the dotted name

        """
        names = []
        obj = self
        while obj.parent is not None:
            names.append(obj.attr_name)
            obj = obj.parent
        return '.'.join(names[::-1])

    @property
    def name(self):
        '''name of the device'''
        return self._name

    @name.setter
    def name(self, name):
        self._name = name

    @property
    def attr_name(self):
        return self._attr_name

    @property
    def connected(self):
        '''If the device is connected.

        Subclasses should override this'''
        return True

    def destroy(self):
        '''Disconnect the object from the underlying control layer'''
        self.unsubscribe_all()

    @property
    def parent(self):
        '''The parent of the ophyd object.

        If at the top of its hierarchy, `parent` will be None
        '''
        return self._parent

    @property
    def root(self):
        "Walk parents to find ultimate ancestor (parent's parent...)."
        root = self
        while True:
            if root.parent is None:
                return root
            root = root.parent

    @property
    def report(self):
        '''A report on the object.'''
        return {}

    @property
    def event_types(self):
        '''Events that can be subscribed to via `obj.subscribe`
        '''
        return tuple(self.subscriptions)

    def _run_subs(self, *args, sub_type, **kwargs):
        '''Run a set of subscription callbacks

        Only the kwarg ``sub_type`` is required, indicating
        the type of callback to perform. All other positional arguments
        and kwargs are passed directly to the callback function.

        The host object will be injected into kwargs as 'obj' unless that key
        already exists.

        If the `timestamp` is None, then it will be replaced by the current
        time.

        No exceptions are raised if the callback functions fail.
        '''
        if sub_type not in self.subscriptions:
            raise UnknownSubscription(
                "Unknown subscription {!r}, must be one of {!r}".format(
                    sub_type, self.subscriptions))

        kwargs['sub_type'] = sub_type
        # Guarantee that the object will be in the kwargs
        kwargs.setdefault('obj', self)

        # And if a timestamp key exists, but isn't filled -- supply it with
        # a new timestamp
        if 'timestamp' in kwargs and kwargs['timestamp'] is None:
            kwargs['timestamp'] = time.time()

        # Shallow-copy the callback arguments for replaying the
        # callback at a later time (e.g., when a new subscription is made)
        self._args_cache[sub_type] = (tuple(args), dict(kwargs))

        for cb in list(self._callbacks[sub_type].values()):
            cb(*args, **kwargs)

    def subscribe(self, callback, event_type=None, run=True):
        '''Subscribe to events this event_type generates.

        The callback will be called as ``cb(*args, **kwargs)`` with
        the values passed to `_run_subs` with the following additional keys:

           sub_type : the string value of the event_type
           obj : the host object, added if 'obj' not already in kwargs

        if the key 'timestamp' is in kwargs _and_ is None, then it will
        be replaced with the current time before running the callback.

        The ``*args``, ``**kwargs`` passed to _run_subs will be cached as
        shallow copies, be aware of passing in mutable data.

        .. warning::

           If the callback raises any exceptions when run they will be
           silently ignored.

        Parameters
        ----------
        callback : callable
            A callable function (that takes kwargs) to be run when the event is
            generated.  The expected signature is ::

              def cb(*args, obj: OphydObject, sub_type: str, **kwargs) -> None:

            The exact args/kwargs passed are whatever are passed to
            ``_run_subs``
        event_type : str, optional
            The name of the event to subscribe to (if None, defaults to
            the default sub for the instance - obj._default_sub)

            This maps to the ``sub_type`` kwargs in `_run_subs`
        run : bool, optional
            Run the callback now

        See Also
        --------
        clear_sub, _run_subs

        Returns
        -------
        cid : int
            id of callback, can be passed to `unsubscribe` to remove the
            callback

        '''
        if not callable(callback):
            raise ValueError("callback must be callable")
        # do default event type
        if event_type is None:
            # warnings.warn("Please specify which call back you wish to "
            #               "attach to defaulting to {}"
            #               .format(self._default_sub), stacklevel=2)
            event_type = self._default_sub

        if event_type is None:
            raise ValueError('Subscription type not set and object {} of class'
                             ' {} has no default subscription set'
                             ''.format(self.name, self.__class__.__name__))

        # check that this is a valid event type
        if event_type not in self.subscriptions:
            raise UnknownSubscription(
                "Unknown subscription {!r}, must be one of {!r}".format(
                    event_type, self.subscriptions))

        # wrapper for callback to snarf exceptions
        def wrap_cb(cb):
            @functools.wraps(cb)
            def inner(*args, **kwargs):
                try:
                    cb(*args, **kwargs)
                except Exception:
                    sub_type = kwargs['sub_type']
                    self.log.exception(
                        'Subscription %s callback exception (%s)', sub_type,
                        self)

            return inner

        # get next cid
        cid = next(self._cb_count)
        wrapped = wrap_cb(callback)
        self._unwrapped_callbacks[event_type][cid] = callback
        self._callbacks[event_type][cid] = wrapped
        self._cid_to_event_mapping[cid] = event_type

        if run:
            cached = self._args_cache[event_type]
            if cached is not None:
                args, kwargs = cached
                wrapped(*args, **kwargs)

        return cid

    def _reset_sub(self, event_type):
        '''Remove all subscriptions in an event type'''
        self._callbacks[event_type].clear()
        self._unwrapped_callbacks[event_type].clear()

    def clear_sub(self, cb, event_type=None):
        '''Remove a subscription, given the original callback function

        See also :meth:`subscribe`, :meth:`unsubscribe`

        Parameters
        ----------
        cb : callable
            The callback
        event_type : str, optional
            The event to unsubscribe from (if None, removes it from all event
            types)
        '''
        if event_type is None:
            event_types = self.event_types
        else:
            event_types = [event_type]
        cid_list = []
        for et in event_types:
            for cid, target in self._unwrapped_callbacks[et].items():
                if cb == target:
                    cid_list.append(cid)
        for cid in cid_list:
            self.unsubscribe(cid)

    def unsubscribe(self, cid):
        """Remove a subscription

        See also :meth:`subscribe`, :meth:`clear_sub`

        Parameters
        ----------
        cid : int
           token return by :meth:`subscribe`
        """
        ev_type = self._cid_to_event_mapping.pop(cid, None)
        if ev_type is None:
            return
        del self._unwrapped_callbacks[ev_type][cid]
        del self._callbacks[ev_type][cid]

    def unsubscribe_all(self):
        for ev_type in self._callbacks:
            self._reset_sub(ev_type)

    def check_value(self, value, **kwargs):
        '''Check if the value is valid for this object

        This function does no normalization, but may raise if the
        value is invalid.

        Raises
        ------
        ValueError
        '''
        pass

    def __repr__(self):
        info = self._repr_info()
        info = ', '.join('{}={!r}'.format(key, value) for key, value in info)
        return '{}({})'.format(self.__class__.__name__, info)

    def _repr_info(self):
        'Yields pairs of (key, value) to generate the object repr'
        if self.name is not None:
            yield ('name', self.name)

        if self._parent is not None:
            yield ('parent', self.parent.name)

    def __copy__(self):
        '''Copy the ophyd object

        Shallow copying ophyd objects uses the repr information from the
        _repr_info method to create a new object.
        '''
        kwargs = dict(self._repr_info())
        return self.__class__(**kwargs)

    def __getnewargs_ex__(self):
        '''Used by pickle to serialize an ophyd object

        Returns
        -------
        (args, kwargs)
            Arguments to be passed to __init__, necessary to recreate this
            object
        '''
        kwargs = dict(self._repr_info())
        return ((), kwargs)
Exemple #14
0
async def invoke_porter_action(msg_body: dict, sb_client: ServiceBusClient,
                               message_logger_adapter: logging.LoggerAdapter,
                               config: dict) -> bool:
    """
    Handle resource message by invoking specified porter action (i.e. install, uninstall)
    """
    installation_id = get_installation_id(msg_body)
    action = msg_body["action"]
    message_logger_adapter.info(
        f"{installation_id}: {action} action starting...")
    sb_sender = sb_client.get_queue_sender(
        queue_name=config["deployment_status_queue"])

    # If the action is install/upgrade, post message on sb queue to start a deployment job
    if action == "install" or action == "upgrade":
        resource_request_message = service_bus_message_generator(
            msg_body, strings.RESOURCE_STATUS_DEPLOYING,
            "Deployment job starting")
        await sb_sender.send_messages(
            ServiceBusMessage(body=resource_request_message,
                              correlation_id=msg_body["id"]))

    # Build and run porter command (flagging if its a built-in action or custom so we can adapt porter command appropriately)
    is_custom_action = action not in ["install", "upgrade", "uninstall"]
    porter_command = await build_porter_command(config, message_logger_adapter,
                                                msg_body, is_custom_action)
    returncode, _, err = await run_porter(porter_command,
                                          message_logger_adapter, config)

    # Handle command output
    if returncode != 0:
        error_message = "Error context message = " + " ".join(
            err.split('\n')) + " ; Command executed: ".join(porter_command)
        resource_request_message = service_bus_message_generator(
            msg_body, statuses.failed_status_string_for[action], error_message)

        # Post message on sb queue to notify receivers of action failure
        await sb_sender.send_messages(
            ServiceBusMessage(body=resource_request_message,
                              correlation_id=msg_body["id"]))
        message_logger_adapter.info(
            f"{installation_id}: Porter action failed with error = {error_message}"
        )
        return False

    else:
        # Get the outputs
        # TODO: decide if this should "fail" the deployment
        _, outputs = await get_porter_outputs(msg_body, message_logger_adapter,
                                              config)

        success_message = f"{action} action completed successfully."
        resource_request_message = service_bus_message_generator(
            msg_body, statuses.pass_status_string_for[action], success_message,
            outputs)

        await sb_sender.send_messages(
            ServiceBusMessage(body=resource_request_message,
                              correlation_id=msg_body["id"]))
        message_logger_adapter.info(f"{installation_id}: {success_message}")
        return True
Exemple #15
0
def stream_to_log(stream: IO[bytes], log: logging.LoggerAdapter) -> None:
    for line_bytes in stream:
        line = line_bytes.rstrip(b"\r\n").decode("utf-8", errors="replace")
        log.info(f"langserver logged: {line}")
Exemple #16
0
 async def test(self, logger: LoggerAdapter, collection: MotorCollection):
     document = {'key': 'value'}
     result = await collection.insert_one(document)
     logger.info('result %s' % repr(result.inserted_id))
Exemple #17
0
    def provide(self, *args, request_id=None, show_progress=True, **kwargs):
        """
        Description:
            perform the implementation for the requested service

        Input:
            *args: passed into self.get_addendum method
            request_id: None (unused in this provider)
            show_progress: show a message when calling each implementor object
            **kwargs: passed into self.get_addendum method

        Notes:
            If an object is set for the 'implementor' attribute, this will be used as the
            implmentor object, else, we will default to looking up the implmentor in a
            root node and iterating over all the sub-nodes.
        """
        log = LoggerAdapter(logger, {'name_ext': 'AddendumFormatter.provide'})
        log.debug("Entering")
        log.debug("varargs: {}".format(args))
        log.debug("kwargs: {}".format(kwargs))

        imp_iter = self._get_implementor_iterator()
        log.debug("got implementor iterator: {}".format(imp_iter))
        #- loop through all the iterators and apply the addendum
        all_outputs = list()
        formatted_outputs = list()
        all_formatted_outputs = list()
        for nsid, implementor in imp_iter:
            if self.implementor_state_ns:
                try:
                    log.debug(
                        "checking implementor flipswitch via nsid: {}".format(
                            nsid))
                    if not self.implementor_state_ns._lookup(nsid):
                        #- skip til next implementor
                        log.debug(
                            "Skipping inactive implementor: {}".format(nsid))
                        continue
                except NamespaceLookupError:
                    log.warning(
                        "No dynamic state for implementor: {}".format(nsid))

            #- per-implementor addendums use key method
            addendum = self.get_addendum(nsid, implementor, *args, **kwargs)
            if show_progress:
                log.info("Calling: {}{}".format(nsid, addendum))

            #TODO: define globals and locals
            outputs = eval("implementor{}".format(addendum), globals(),
                           locals())
            all_outputs += outputs
            formatted_outputs = self.formatter(outputs)
            all_formatted_outputs += formatted_outputs
            if show_progress:
                try:
                    n = len(list(outputs))
                except TypeError:
                    n = 1 if outputs else 0
                log.info("        {} objects returned".format(n))
        log.info("Total: {}".format(len(all_formatted_outputs)))
        return all_formatted_outputs
Exemple #18
0
    def _add_item(self, namespace_id, value, iter=True, overwrite=False):
        """
        Description:
            create new/set existing item in the namespace to a new value
            this will not overwrite existing values, unless overwrite is True

        Input:
            namespace_id: the name of the new / existing object to set
            value: what to set the new item to
            iter: whether or not to add this to our sequence of iterables for this node
            overwrite: whether or not to overrwrite an existing value

        Output:
            Nothing; pure side effect of setting the value
        """
        log = LoggerAdapter(logger, {'name_ext': 'NamespaceNode._add_item'})

        ns_path = self._name_to_path(namespace_id)
        log.debug(f'ns_path: {ns_path}')
        if len(ns_path) == 1:
            #- set this on self
            try:
                val = getattr(self, ns_path[0])
                attr_exists = True
            except AttributeError:
                attr_exists = False

            if overwrite or not attr_exists:
                if not attr_exists:
                    log.debug('{} adding item: {}: {}'.format(self._nsid,\
                        namespace_id, value))
                else:
                    log.debug('{} overwriting item: {}: {}'.format(self._nsid,\
                        namespace_id, value))

                setattr(self, ns_path[0], value)
                if iter:
                    #- TODO: these should be automatically sync'd, not manually
                    self._ns_items[ns_path[0]] = value
                return

            else:
                msg = '[{}] Not overwriting existing item: {}'.format(
                    self._nsid, ns_path[0])
                log.info(msg)
                log.debug("overwrite: {}".format(overwrite))
                return

        else:
            #- ask the next node to set this
            try:
                next_node = getattr(self, ns_path[0])
            except AttributeError:
                #- TODO: make a flag to add children or not
                next_node = self._add_child(ns_path[0])

            #- TODO: support other classes that don't have add_item with setattr?
            new_nsid = '.'.join(ns_path[1:])
            next_node._add_item(new_nsid,
                                value,
                                iter=iter,
                                overwrite=overwrite)
            return
Exemple #19
0
def decode_and_report(
        data: bytes,
        encoding_options: Iterable[Tuple[Optional[str], str]],
        logger: LoggerAdapter
    ) -> Tuple[str, str]:
    """Attempt to decode text using several encoding options in order.

    @param data:
        Encoded version of the text.
    @param encoding_options: C{(encoding | None, source)*}
        Each option is a pair of encoding name and a description of
        where this encoding suggestion originated.
        If the encoding name is C{None}, the option is skipped.
    @param logger:
        Non-fatal problems are logged here.
        Such problems include an unknown or differing encodings
        among the options.
    @return: C{(text, encoding)}
        The decoded string and the encoding used to decode it.
    @raise ValueError:
        If the text could not be decoded.
    """

    # Filter and remember encoding options.
    options = [
        (encoding, source)
        for encoding, source in encoding_options
        if encoding is not None
        ]

    encodings = [encoding for encoding, source in options]
    # Always try to decode as UTF-8, since that is the most common encoding
    # these days, plus it's a superset of ASCII so it also works for old or
    # simple documents.
    encodings.append('utf-8')
    text, used_encoding = try_decode(data, encodings)

    # Report differences between suggested encodings and the one we
    # settled on.
    for encoding, source in options:
        try:
            codec = lookup_codec(encoding)
        except LookupError:
            logger.warning(
                '%s specifies encoding "%s", which is unknown to Python',
                source, encoding
                )
            continue

        std_name = standard_codec_name(codec.name)
        if std_name != used_encoding:
            logger.warning(
                '%s specifies encoding "%s", '
                'while actual encoding seems to be "%s"',
                source, encoding, used_encoding
                )
        elif std_name != encoding:
            logger.info(
                '%s specifies encoding "%s", '
                'which is not the standard name "%s"',
                source, encoding, used_encoding
                )

    return text, used_encoding