def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing provisioner.", event_type='init_provisioner') provider_config = section2dict(scp, "SLACK") # Load configuration. try: self.endpoint_s = config.get("endpoint", None) self.load_provider_config(provider_config) except KeyError as ex: raise OptionMissingError( "A require option was missing: '{0}:{1}'.".format( section, ex.args[0])) # Create the web client. self.make_web_client() # Initialize the provider. self.init_provider() except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise return defer.succeed(None)
def main(reactor, *descriptions): log = Logger() globalLogBeginner.beginLoggingTo([textFileLogObserver(sys.stdout)]) endpointObjects = [ endpoints.clientFromString(reactor, description) for description in descriptions ] hostPorts = [(endpoint._host, endpoint._port) for endpoint in endpointObjects] pool = threadpool.ThreadPool(minthreads=1, maxthreads=1, name="persiter") persister = Persists(reactor, pool) reactor.addSystemEventTrigger("before", "shutdown", persister.stop) persister.start("log.sqlite", hostPorts) analyzer = AnalyzesText(persister) factory = EncodingCollectionFactory(reactor, random.SystemRandom(), analyzer) for (host, port), endpoint in zip(hostPorts, endpointObjects): try: protocol = yield endpoint.connect(factory) except Exception: log.failure("Could not connect to {host}:{port}", host=host, port=port) raise protocol.addr = (host, port) defer.returnValue(defer.Deferred())
class AirbrakeTestCase(unittest.TestCase): def setUp(self): settings = { "AIRBRAKE": { "PROJECT_ID": 123, "API_KEY": "1234567890asdfghjkl;" } } self.ab = AirbrakeLogObserver(settings) self.exception_msg = "There is a nasty gremlin in this system" self.log = Logger(observer=self.ab) @mock.patch.object(Airbrake, "notify") def test_send_exception(self, notify): try: deep_failure(self.exception_msg) except: self.log.failure("Error") exception = notify.call_args[0][0] self.assertTrue(exception.errors[0]['message'] == self.exception_msg) func_names = [ 'test_send_exception', 'deep_failure', 'fail_with_traceback' ] exception_func_names = map((lambda trace: trace["function"]), exception.errors[0]['backtrace']) self.assertTrue(set(func_names) == set(exception_func_names)) @mock.patch.object(Airbrake, "notify") def test_send_global_exception(self, notify): observers = [self.ab] globalLogBeginner.beginLoggingTo(observers) log = Logger() try: deep_failure(self.exception_msg) except: log.failure("Error") exception = notify.call_args[0][0] print("exception: %s" % exception) self.assertTrue(exception.errors[0]['message'] == self.exception_msg) func_names = [ 'test_send_global_exception', 'deep_failure', 'fail_with_traceback' ] exception_func_names = map((lambda trace: trace["function"]), exception.errors[0]['backtrace']) self.assertTrue(set(func_names) == set(exception_func_names))
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing Orgsync RESTful API provisioner.", event_type='init_provisioner') # Load API configuration info-- endpoint info, URL, API key. try: self.diagnostic_mode = bool( config.get("diagnostic_mode", False)) self.endpoint_s = config.get("endpoint", None) self.url_prefix = config["url_prefix"] self.api_key = config["api_key"] self.max_per_day = config.get("max_per_day", 20) self.account_query = jinja2.Template(config['account_query']) self.account_update = jinja2.Template(config['account_update']) self.account_delete = jinja2.Template(config['account_delete']) self.account_add = jinja2.Template(config['account_add']) account_template_path = config['account_template'] attrib_map_path = config["attribute_map"] except KeyError as ex: raise OptionMissingError( "A require option was missing: '{0}:{1}'.".format( section, ex.args[0])) # Start the daiy countdown timer. self.daily_reset = LoopingCall(self.reset_daily_countdown) d = self.daily_reset.start(60 * 60 * 24, now=True) # Create the web client. self.make_web_client() # Create the attribute map. self.make_attribute_map(attrib_map_path) # Create the account template. self.make_account_template(account_template_path) except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise return defer.succeed(None)
def test_logger_namespace_failure(self): """ An unexpected failure, logged as critical, is displayed across multiple lines. """ fout = StringIO() log = Logger(namespace="ns", observer=FileLogObserver(fout, formatForSystemd)) log.failure("Something went wrong", Failure(Exception("1\n2\n3"))) self.assertEqual(( "<2>[ns] Something went wrong\n" "<2> Traceback (most recent call last):\n" "<2> Failure: builtins.Exception: 1\n" "<2> 2\n" "<2> 3\n" ), fout.getvalue())
def test_log_converter(handler, framework): pytest.importorskip("twisted.logger") # this checks that we can convert a plain Twisted Logger calling # failure() into a traceback on our observers. from twisted.logger import Logger from txaio.tx import _LogObserver out = six.StringIO() observer = _LogObserver(out) logger = Logger(observer=observer) try: raise RuntimeError("failed on purpose") except: logger.failure(None) output = out.getvalue() assert "failed on purpose" in output assert "Traceback" in output
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing provisioner.", event_type='init_provisioner') # Load configuration info-- endpoint info, credentials, base DN, etc. try: self.provision_group = config["provision_group"].lower() self.endpoint_s = config["endpoint"] self.use_starttls = bool(config.get("use_starttls", True)) self.starttls_hostname = config.get("starttls_hostname", "localhost") starttls_trust_anchor = config.get('starttls_trust_anchor', None) self.bind_dn = config["bind_dn"] self.bind_passwd = config["bind_passwd"] self.base_dn = config["base_dn"] self.search_filter = config.get('filter', None) self.account_template_path = config["account_template"] self.page_size = int(config.get('page_size', 100)) except KeyError as ex: raise OptionMissingError( "A required option was missing: '{}:{}'.".format( section, ex.args[0])) self.parse_account_template_() self.load_starttls_trust_anchor(starttls_trust_anchor) except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {}".format(ex)) raise return defer.succeed(None)
def test_logger_namespace_failure(self): """ An unexpected failure, logged as critical, is displayed across multiple lines. """ fout = StringIO() log = Logger(namespace="ns", observer=FileLogObserver(fout, formatForSystemd)) log.failure("Something went wrong", Failure(Exception("1\n2\n3"))) self.assertEqual( ("<2>[ns] Something went wrong\n" "<2> Traceback (most recent call last):\n" "<2> Failure: builtins.Exception: 1\n" "<2> 2\n" "<2> 3\n"), fout.getvalue(), )
def test_send_global_exception(self, notify): observers = [self.ab] globalLogBeginner.beginLoggingTo(observers) log = Logger() try: deep_failure(self.exception_msg) except: log.failure("Error") exception = notify.call_args[0][0] print("exception: %s" % exception) self.assertTrue(exception.errors[0]['message'] == self.exception_msg) func_names = [ 'test_send_global_exception', 'deep_failure', 'fail_with_traceback' ] exception_func_names = map((lambda trace: trace["function"]), exception.errors[0]['backtrace']) self.assertTrue(set(func_names) == set(exception_func_names))
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. config_parser = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(config_parser, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.debug("Initialized logging for Kiki provisioner delivery service.", event_type='init_provisioner_logging') # Load and configure the attribute resolver. attrib_resolver_tag = get_config_opt(config, section, "attrib_resolver") self.install_attribute_resolver(attrib_resolver_tag, config_parser) # Load and configure the group attribute resolver. group_attrib_resolver_tag = config.get("group_attrib_resolver", None) self.install_group_attribute_resolver(group_attrib_resolver_tag, config_parser) # Load parse map. parser_map_filename = get_config_opt(config, section, "parser_map") self.load_parser_map(parser_map_filename) # Install group mapper. group_mapper_tag = get_config_opt(config, section, "group_mapper") self.install_group_mapper(group_mapper_tag, config_parser) # Install the router router_tag = get_config_opt(config, section, "router") self.install_router(router_tag, config_parser) # Connect to exchange for publishing. self.configure_target_exchange(config_parser) yield self.connect_to_exchange() except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise
def build_service(reactor): multi = MultiService() StreamServerEndpointService( TCP4ServerEndpoint(reactor, port), server.Site( wsgi.WSGIResource(reactor, reactor.getThreadPool(), app), )).setServiceParent(multi) logger = Logger() TimerService( # Run every 10 minutes 10 * 60, lambda: deferToThread(check_for_revocation, cert_db, crtsh_checker) .addErrback(lambda f: logger.failure( "Error checking for revocation", f))).setServiceParent(multi) TimerService( 60 * 60, lambda: deferToThread(raw_app._update_lint_summaries).addErrback( lambda f: logger.failure("Error updating cablint summaries", f ))).setServiceParent(multi) return multi
class OurStreamProtocol(Protocol): """Protocol implementing ShinySDR's WebSocket service. This protocol's transport should be a txWS WebSocket transport. """ def __init__(self, caps, subscription_context): self.__log = Logger() self.__subscription_context = subscription_context self._caps = caps self._seenValues = {} self.inner = None def dataReceived(self, data): """Twisted Protocol implementation. Additionally, txWS takes no care with exceptions here, so we catch and log.""" # pylint: disable=broad-except try: if self.inner is None: # To work around txWS's lack of a notification when the URL is available, all clients send a dummy first message. self.__dispatch_url() else: self.inner.dataReceived(data) except Exception: self.__log.failure('Error processing incoming WebSocket message') def __dispatch_url(self): loc = self.transport.location self.__log.info('Stream connection to {url}', url=loc) path = [urllib.unquote(x) for x in loc.split('/')] assert path[0] == '' path[0:1] = [] cap_string = path[0].decode('utf-8') # TODO centralize url decoding if cap_string in self._caps: root_object = self._caps[cap_string] path[0:1] = [] else: raise Exception('Unknown cap') # TODO better error reporting if len(path) == 1 and path[0].startswith(b'audio?rate='): rate = int( json.loads(urllib.unquote(path[0][len(b'audio?rate='):]))) self.inner = AudioStreamInner(the_reactor, self.__send, root_object, rate) elif len(path) >= 1 and path[0] == CAP_OBJECT_PATH_ELEMENT: # note _lookup_block may throw. TODO: Better error reporting root_object = _lookup_block(root_object, path[1:]) self.inner = StateStreamInner( self.__send, root_object, loc, self.__subscription_context ) # note reuse of loc as HTTP path; probably will regret this else: raise Exception('Unknown path: %r' % (path, )) def connectionMade(self): """twisted Protocol implementation""" self.transport.setBinaryMode(True) # Unfortunately, txWS calls this too soon for transport.location to be available def connectionLost(self, reason): # pylint: disable=signature-differs """twisted Protocol implementation""" if self.inner is not None: self.inner.connectionLost(reason) def __send(self, message, safe_to_drop=False): if len(self.transport.transport.dataBuffer) > 1000000: # TODO: condition is horrible implementation-diving kludge # Don't accumulate indefinite buffer if we aren't successfully getting it onto the network. # TODO: There are no tests of this mechanism if safe_to_drop: self.__log.warn('Dropping data going to stream {url}', url=self.transport.location) else: self.__log.error( 'Dropping connection due to too much data on stream {url}', url=self.transport.location) self.transport.close(reason='Too much data buffered') else: self.transport.write(message)
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing provisioner.", event_type='init_provisioner') # Load API configuration info-- endpoint info, URL, API key. try: self.diagnostic_mode = bool( int(config.get("diagnostic_mode", 0))) self.unmanaged_logins = set( login.lower() for login in config.get("unmanaged_logins", "").split()) self.provision_group = config.get("provision_group", None) if self.provision_group is not None: self.provision_group = self.provision_group.lower() workroom_map_path = config.get("workroom_map", None) self.endpoint_s = config.get("endpoint", None) self.url_prefix = config["url_prefix"] self.api_key = config["api_key"] self.cache_size = int(config["cache_size"]) self.authenticate = config['authenticate'] self.accounts_query = config['accounts_query'] self.max_page = int(config.get('max_page', 100)) self.local_computed_match_template = jinja2.Template( config['local_computed_match_template']) if self.provision_group: self.account_update = jinja2.Template( config['account_update']) self.account_delete = jinja2.Template( config['account_delete']) self.account_add = config['account_add'] account_template_path = config['account_template'] attrib_map_path = config["attribute_map"] if workroom_map_path: self.workrooms_query = config['workrooms_query'] self.workroom_members = jinja2.Template( config['workroom_members']) self.workroom_subject = jinja2.Template( config['workroom_subject']) self.workroom_cache_size = int( config.get("workroom_cache_size", 100)) self.workroom_retry_delay = int( config.get("workroom_retry_delay", 20)) except KeyError as ex: raise OptionMissingError( "A require option was missing: '{0}:{1}'.".format( section, ex.args[0])) if self.provision_group is None and workroom_map_path is None: raise OptionMissingError( "Must provide at least one of `provision_group` (account " "provisioning) or `workroom_map` (workroom mapping).") # Create the web client. self.make_default_web_client() self.__workroom_cache = None if self.provision_group: # Create the attribute map. self.make_attribute_map(attrib_map_path) # Create the account template. self.make_account_template(account_template_path) if workroom_map_path: # Create the workroom cache. self.__workroom_cache = pylru.lrucache( self.workroom_cache_size) # Create the workroom map. self.make_workroom_map(workroom_map_path) # Create account cache. self.__account_cache = pylru.lrucache(self.cache_size) # Initialize access token. self.__auth_token = None log.info("Diagnostic mode: {diagnostic}", diagnostic=self.diagnostic_mode) except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise return defer.succeed(None)
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing provisioner.", event_type='init_provisioner') # Load API configuration info-- endpoint info, URL, API key. try: self.unmanaged_logins = set( login.lower() for login in config.get("unmanaged_logins", "").split()) log.debug("unmanaged_logins: {unmanaged_logins}", unmanaged_logins=list(self.unmanaged_logins)) self.provision_group = config.get("provision_group", None) if self.provision_group is not None: self.provision_group = self.provision_group.lower() target_group_map_path = config.get("target_group_map", None) self.endpoint_s = config.get("endpoint", None) self.url_prefix = config["url_prefix"] self.client_secret = config["client_secret"] self.account_cache_size = int(config["account_cache_size"]) if target_group_map_path: self.target_group_cache_size = int( config.get("target_group_cache_size", 100)) self.target_group_retry_delay = int( config.get("target_group_retry_delay", 20)) self.account_sync_rate_limit_ms = int( config.get("account_sync_rate_limit_ms", 0)) self.member_sync_rate_limit_ms = int( config.get("member_sync_rate_limit_ms", 0)) self.provision_strategy = config.get("provision_strategy", "query-first").lower() self.group_sync_strategy = config.get( "group_sync_strategy", "add-members-first").lower() if not self.group_sync_strategy in ('query-first', 'add-members-first'): raise Exception("Unknown group_sync_strategy: {}".format( self.group_sync_strategy)) self.account_cache_validity_period = int( config.get("account_cache_validity_period", 0)) except KeyError as ex: raise OptionMissingError( "A require option was missing: '{0}:{1}'.".format( section, ex.args[0])) if self.provision_group is None and target_group_map_path is None: raise OptionMissingError( "Must provide at least one of `provision_group` (account " "provisioning) or `target_group_map` (target_group mapping)." ) if not self.provision_strategy in ('query-first', 'create-first'): raise Exception( "`provision_strategy` must be one of: query-first, create-first" ) # Create the web client. self.make_default_web_client() self.__target_group_cache = None if target_group_map_path: # Create the target_group cache. self.__target_group_cache = pylru.lrucache( self.target_group_cache_size) # Create the target_group map. self.make_target_group_map(target_group_map_path) # Create account cache. self.__account_cache = pylru.lrucache(self.account_cache_size) # Initialize access token. self.auth_token = None except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise self.parse_config(scp) return defer.succeed(None)
# -*- coding: utf-8 -*- # (c) 2016-2021 Andreas Motl <*****@*****.**> from twisted.logger import Logger, LogLevel log = Logger() try: import pandas from pandas.tslib import Timedelta except ImportError: log.failure('Dataframe functions not available, please install "pandas".', level=LogLevel.warn) def dataframe_index_to_column(df, column): """ Copy DataFrame index column to real data column. """ dt = df.index df[column] = dt #df.reset_index(drop=True, inplace=True) return df def dataframe_wide_to_long_indexed(df, column): """ Convert DataFrame from wide to long format using specified column as index column, followed by indexing the DataFrame on the very same column and finally sorting it. See also: - http://pandas.pydata.org/pandas-docs/stable/reshaping.html#reshaping-by-melt - http://stackoverflow.com/questions/17688155/complicated-for-me-reshaping-from-wide-to-long-in-pandas
# import sites.SitePlugin and make sites.SitePlugin.plugin available imp = __import__(pth, globals(), locals(), ['plugin']) try: verifyClass(plugin_type, imp.plugin) # Instantiate the plugin kwargs.update({ 'config': cfg[imp.plugin.settings_name] }) _tmp = imp.plugin(*args, **kwargs) verifyObject(plugin_type, _tmp) except [BrokenImplementation, AttributeError], e: logger.failure("%s:\n%s" % (location, str(e))) except ImportError, e: logger.failure("Is your plugin configured correctly?\n%s" % e) return _tmp def load_site_plugins(cfg): """ load SitePlugin based plugins listed in the config. @type cfg: ConfigObj @param cfg: The sites' section of the config @rtrype: list @returns: list of loaded plugins """ plugins = []
# -*- coding: utf-8 -*- # (c) 2016 Andreas Motl <*****@*****.**> import tempfile from pprint import pprint from twisted.logger import Logger, LogLevel from twisted.web.template import renderElement from kotori.io.export.html import DatatablesPage from kotori.io.protocol.util import get_data_uri from kotori.io.export.util import dataframe_index_and_sort log = Logger() try: import pandas except ImportError: log.failure('Tabular export not available, please install "pandas".', level=LogLevel.warn) class UniversalTabularExporter(object): """ Universal exporter for tabular data. Render pandas DataFrame to Excel (XLSX), HDF5 and NetCDF formats and as DataTables HTML widget. """ def __init__(self, bucket, dataframe): self.bucket = bucket self.request = bucket.request self.dataframe = dataframe def render(self, format, kind=None, buffer=None):
class JWTClientIPAuthResource(resource.Resource): """ Validates JWT token passed in via a HTTP query parameter. Sets a session cookie in order to authenticate subsequent requests. """ isLeaf = True def __init__(self, param: bytes, cookie: bytes, header: bytes, keyfile: str, sessttl: int): self.log = Logger() self.key = jwt.JWK() self.param = param self.cookie = cookie self.header = header # Very naive session store. Extract and improve if necessary. self.sessttl = sessttl self.sessions = set() with open(keyfile, 'rb') as stream: self.key.import_from_pem(stream.read()) def render(self, request: server.Request) -> bytes: # Deny by default. request.setResponseCode(401) # Get session cookie value if any. sessionid = request.getCookie(self.cookie) if sessionid is not None: if sessionid in self.sessions: request.setResponseCode(200) self.log.info("Session: Validation succeeded") return b"" else: self.log.info("Session: Invalid session id") # Token is passed as a query parameter in the original URL. origurl = http.urlparse(request.getHeader(self.header)) query = http.parse_qs(origurl.query) args = query.get(self.param, []) if len(args) != 1: self.log.error("Request: Token {param} missing", param=self.param) return b"" try: token = jwt.JWT(key=self.key, jwt=args[0].decode()) except (jwt.JWTExpired, jwt.JWTNotYetValid, jwt.JWTMissingClaim, jwt.JWTInvalidClaimValue, jwt.JWTInvalidClaimFormat, jwt.JWTMissingKeyID, jwt.JWTMissingKey) as error: self.log.error("JWT token: {error}", error=error) return b"" except Exception: self.log.failure("JWT token: Unknown exception") return b"" try: claims = json.loads(token.claims) except json.JSONDecodeError as error: self.log.failure("JWT token: Claims {error}", error=error) return b"" # Collect session parameters from claims. sessparams = claims.get("session", {}) kwargs = { "expires": sessparams.get("expires", None), "domain": sessparams.get("domain", None), "path": sessparams.get("path", None), "secure": sessparams.get("secure", None), "httpOnly": sessparams.get("httpOnly", None), "sameSite": sessparams.get("sameSite", None), } # Use maxAge for session ttl if it is present, convert it into a str # type as required by the addCookie call. if "maxAge" in sessparams: kwargs["max_age"] = str(sessparams["maxAge"]) sessttl = int(sessparams["maxAge"]) else: sessttl = self.sessttl # Generate a new session id and remember it. Also clean it up after # ttl seconds. sessionid = secrets.token_urlsafe(nbytes=16).encode() self.sessions.add(sessionid) reactor.callLater(sessttl, self._session_remove, sessionid) self.log.info("Session: Created, num sessions: {sessions}", sessions=len(self.sessions)) # Set cookie in the browser. request.addCookie(self.cookie, sessionid, **kwargs) request.setResponseCode(200) self.log.info("JWT token: Validation succeeded") return b"" def _session_remove(self, sessionid: bytes): self.sessions.remove(sessionid) self.log.info("Session: Removed, num sessions: {sessions}", sessions=len(self.sessions))
def load_config(self, config_file, default_log_level, logObserverFactory): """ Load the configuration for this provisioner and initialize it. """ log = Logger(observer=logObserverFactory("ERROR")) try: # Load config. scp = load_config(config_file, defaults=self.get_config_defaults()) section = "PROVISIONER" config = section2dict(scp, section) self.config = config # Start logger. log_level = config.get('log_level', default_log_level) log = Logger(observer=logObserverFactory(log_level)) self.log = log log.info("Initializing SSH provisioner.", event_type='init_provisioner') # Initialize template environment. self.template_env = jinja2.Environment(trim_blocks=True, lstrip_blocks=True) self.template_env.filters['shellquote'] = filter_shellquote self.template_env.filters['newline'] = filter_newline # Load SSH configuration info. try: self.provision_cmd = self.template_env.from_string( config["provision_cmd"].strip()) self.deprovision_cmd = self.template_env.from_string( config["deprovision_cmd"].strip()) template_str = config.get("sync_cmd", None) if template_str is not None: log.debug("Sync command template: {template}", template=template_str) self.sync_cmd = self.template_env.from_string( template_str.strip()) self.provision_cmd_type = self.parse_command_type( config.get("provision_cmd_type", "simple")) self.deprovision_cmd_type = self.parse_command_type( config.get("deprovision_cmd_type", "simple")) self.sync_cmd_type = self.parse_command_type( config.get("sync_cmd_type", "simple")) if self.provision_cmd_type == self.CMD_TYPE_INPUT: self.provision_input = self.template_env.from_string( config["provision_input"].strip()) if self.deprovision_cmd_type == self.CMD_TYPE_INPUT: self.deprovision_input = self.template_env.from_string( config["deprovision_input"].strip()) if self.sync_cmd_type == self.CMD_TYPE_INPUT: template_str = config.get("sync_input", None) log.debug("Sync input template: {template}", template=template_str) self.sync_input = self.template_env.from_string( template_str.strip()) result = config.get("provision_ok_result", None) if result is not None: self.provision_ok_result = int(result.strip()) result = config.get("deprovision_ok_result", None) if result is not None: self.deprovision_ok_result = int(result.strip()) result = config.get("sync_ok_result", None) if result is not None: self.sync_ok_result = int(result.strip()) self.cmd_timeout = int(config['cmd_timeout']) self.host = config["host"] self.port = int(config["port"]) self.ssh_user = config["user"] self.known_hosts = os.path.expanduser(config["known_hosts"]) if "keys" in config: self.keys = config["keys"].split(",") except KeyError as ex: raise OptionMissingError( "A require option was missing: '{0}:{1}'.".format( section, ex.args[0])) self.load_groupmap(config.get("group_map", None)) except Exception as ex: d = self.reactor.callLater(0, self.reactor.stop) log.failure("Provisioner failed to initialize: {0}".format(ex)) raise return defer.succeed(None)
class WebSocketDispatcherProtocol(Protocol): """Protocol implementing ShinySDR's WebSocket service. This protocol's transport should be a txWS WebSocket transport. """ def __init__(self, caps, subscription_context): self.__log = Logger() self.__subscription_context = subscription_context self._caps = caps self._seenValues = {} self.inner = None def dataReceived(self, data): """Twisted Protocol implementation. Additionally, txWS takes no care with exceptions here, so we catch and log.""" # pylint: disable=broad-except try: if self.inner is None: # To work around txWS's lack of a notification when the URL is available, all clients send a dummy first message. self.__dispatch_url() else: self.inner.dataReceived(data) except Exception: self.__log.failure('Error processing incoming WebSocket message') def __dispatch_url(self): self.__log.info('Stream connection to {url}', url=self.transport.location) _scheme, _netloc, path_bytes, _params, query_bytes, _fragment = urlparse( bytes_or_ascii(self.transport.location)) # py2/3: unquote returns str in either version but we want Unicode path = [ six.text_type(urllib.parse.unquote(x)) for x in path_bytes.split(b'/') ] assert path[0] == '' path[0:1] = [] cap_string = path[0] if cap_string in self._caps: root_object = self._caps[cap_string] path[0:1] = [] else: raise Exception('Unknown cap') # TODO better error reporting if path == [AUDIO_STREAM_PATH_ELEMENT]: options = parse_audio_stream_options(parse_qs(query_bytes, 1)) self.inner = AudioStreamInner(the_reactor, self.__send, root_object, options.sample_rate) elif len(path) >= 1 and path[0] == CAP_OBJECT_PATH_ELEMENT: # note _lookup_block may throw. TODO: Better error reporting root_object = _lookup_block(root_object, path[1:]) self.inner = StateStreamInner( self.__send, root_object, path_bytes.decode('utf-8'), self.__subscription_context ) # note reuse of WS path as HTTP path; probably will regret this else: raise Exception('Unknown path: %r' % (path, )) def connectionMade(self): """twisted Protocol implementation""" self.transport.setBinaryMode(True) # Unfortunately, txWS calls this too soon for transport.location to be available def connectionLost(self, reason): # pylint: disable=signature-differs """twisted Protocol implementation""" if self.inner is not None: self.inner.connectionLost(reason) def __send(self, message, safe_to_drop=False): if len(self.transport.transport.dataBuffer) > 1000000: # TODO: condition is horrible implementation-diving kludge # Don't accumulate indefinite buffer if we aren't successfully getting it onto the network. # TODO: There are no tests of this mechanism if safe_to_drop: self.__log.warn('Dropping data going to stream {url}', url=self.transport.location) else: self.__log.error( 'Dropping connection due to too much data on stream {url}', url=self.transport.location) self.transport.close(reason='Too much data buffered') else: self.transport.write(message)
from twisted.web import http, server from twisted.logger import Logger, LogLevel from twisted.application.service import MultiService from kotori.util.configuration import read_list from kotori.daq.services import MultiServiceMixin from kotori.daq.intercom.mqtt import MqttAdapter from kotori.io.protocol.http import HttpDataFrameResponse from kotori.io.protocol.util import handleFailure from kotori.util.errors import last_error_and_traceback log = Logger() try: from kotori.io.export.influx import DataFrameQuery except ImportError: log.failure('InfluxDB export not available, please install "pandas".', level=LogLevel.warn) class ForwarderTargetService(MultiServiceMixin, MultiService): """ Container service for target services. As of June 2016, there are currently two target services for emitting data, MQTT and InfluxDB. """ def __init__(self, address=None, **kwargs): MultiServiceMixin.__init__(self, **kwargs) self.address = address self.scheme = self.address.uri.scheme
class PhotometerService(ClientService): def __init__(self, options, reference): self.options = options self.namespace = 'ref.' if reference else 'test' self.label = self.namespace.upper() setLogLevel(namespace=self.label, levelStr=options['log_messages']) setLogLevel(namespace=self.namespace, levelStr=options['log_level']) self.log = Logger(namespace=self.namespace) self.reference = reference # Flag, is this instance for the reference photometer self.factory = self.buildFactory() self.protocol = None self.serport = None self.info = None # Photometer info self.buffer = CircularBuffer(options['size'], self.log) parts = chop(self.options['endpoint'], sep=':') if parts[0] == 'tcp': endpoint = clientFromString(reactor, self.options['endpoint']) ClientService.__init__(self, endpoint, self.factory, retryPolicy=backoffPolicy(initialDelay=0.5, factor=3.0)) @inlineCallbacks def startService(self): ''' Starts the photometer service listens to a TESS Although it is technically a synchronous operation, it works well with inline callbacks ''' self.log.info("starting {name} service", name=self.name) yield self.connect() self.info = yield self.getInfo() if self.reference: returnValue(None) # Now this is for the test photometer only if self.options['dry_run']: self.log.info('Dry run. Will stop here ...') yield self.stopService() elif self.info is None: yield self.stopService() elif self.options['zero_point'] is not None: try: result = yield self.protocol.writeZeroPoint( self.options['zero_point']) except Exception as e: self.log.error("Timeout when updating Zero Point") self.log.failure("{excp}", excp=e) else: self.log.info("[{label}] Writen ZP : {zp:0.2f}", label=self.label, zp=result['zp']) finally: yield self.stopService() def stopService(self): self.log.info("stopping {name} service", name=self.name) try: reactor.callLater(0, reactor.stop) except Exception as e: log.error("could not stop the reactor") return defer.succeed(None) # -------------- # Photometer API # -------------- def writeZeroPoint(self, zero_point): '''Writes Zero Point to the device. Returns a Deferred''' return self.protocol.writeZeroPoint(zero_point) def getPhotometerInfo(self): if self.protocol is None: self.log.warn("Requested photometer info but no protocol yet!") return defer.fail() if self.info is None: return self.getInfo() else: return defer.succeed(self.info) # -------------- # Helper methods # --------------- @inlineCallbacks def connect(self): parts = chop(self.options['endpoint'], sep=':') if parts[0] == 'serial': endpoint = parts[1:] self.protocol = self.factory.buildProtocol(0) try: self.serport = SerialPort(self.protocol, endpoint[0], reactor, baudrate=endpoint[1]) except Exception as e: self.log.error("{excp}", excp=e) yield self.stopService() else: self.gotProtocol(self.protocol) self.log.info("Using serial port {tty} at {baud} bps", tty=endpoint[0], baud=endpoint[1]) else: ClientService.startService(self) try: protocol = yield self.whenConnected(failAfterFailures=1) except Exception as e: self.log.error("{excp}", excp=e) yield self.stopService() else: self.gotProtocol(protocol) self.log.info("Using TCP endpoint {endpoint}", endpoint=self.options['endpoint']) @inlineCallbacks def getInfo(self): try: info = yield self.protocol.readPhotometerInfo() except Exception as e: self.log.error("Timeout when reading photometer info") info = self.fixIt() returnValue(info) # May be None else: info['model'] = self.options['model'] info['label'] = self.label self.log.info("[{label}] Model : {value}", label=self.label, value=info['model']) self.log.info("[{label}] Name : {value}", label=self.label, value=info['name']) self.log.info("[{label}] MAC : {value}", label=self.label, value=info['mac']) self.log.info("[{label}] Zero Point: {value:.02f} (old)", label=self.label, value=info['zp']) self.log.info("[{label}] Firmware : {value}", label=self.label, value=info['firmware']) returnValue(info) def fixIt(self): parts = chop(self.options['endpoint'], sep=':') if self.reference and (self.options['model'] == TESSW) and parts[0] == 'serial': info = { 'model': TESSW, 'label': self.label, 'name': self.options['name'], 'mac': self.options['mac'], 'zp': 20.50, 'firmware': "", } self.log.error("Fixed photometer info with defaults {info}", info=info) return info else: return None def limitedStart(self): '''Detects the case where only the Test photometer service is started''' if self.reference: return False return (self.options['dry_run'] or self.options['zero_point'] is not None) def buildFactory(self): if self.options['model'] == TESSW: self.log.debug("Choosing a {model} factory", model=TESSW) import zptess.tessw factory = zptess.tessw.TESSProtocolFactory(self.label) elif self.options['model'] == TESSP: self.log.debug("Choosing a {model} factory", model=TESSP) import zptess.tessp factory = zptess.tessp.TESSProtocolFactory(self.label) else: self.log.debug("Choosing a {model} factory", model=TAS) import zptess.tas factory = zptess.tas.TESSProtocolFactory(self.label) return factory def gotProtocol(self, protocol): self.log.debug("got protocol") protocol.setContext(self.options['endpoint']) self.buffer.registerProducer(protocol, True) if self.limitedStart(): protocol.stopProducing( ) # We don need to feed messages to the buffer self.protocol = protocol
class PostgresListenerService(Service, object): """Listens for NOTIFY messages from postgres. A new connection is made to postgres with the isolation level of autocommit. This connection is only used for listening for notifications. Any query that needs to take place because of a notification should use its own connection. This class runs inside of the reactor. Any long running action that occurrs based on a notification should defer its action to a thread to not block the reactor. :ivar connection: A database connection within one of Django's wrapper. :ivar connectionFileno: The fileno of the underlying database connection. :ivar connecting: a :class:`Deferred` while connecting, `None` at all other times. :ivar disconnecting: a :class:`Deferred` while disconnecting, `None` at all other times. """ # Seconds to wait to handle new notifications. When the notifications set # is empty it will wait this amount of time to check again for new # notifications. HANDLE_NOTIFY_DELAY = 0.5 CHANNEL_REGISTRAR_DELAY = 0.5 def __init__(self, alias="default"): self.alias = alias self.listeners = defaultdict(list) self.autoReconnect = False self.connection = None self.connectionFileno = None self.notifications = set() self.notifier = task.LoopingCall(self.handleNotifies) self.notifierDone = None self.connecting = None self.disconnecting = None self.registeredChannels = set() self.channelRegistrar = task.LoopingCall( lambda: ensureDeferred(self.registerChannels())) self.channelRegistrarDone = None self.log = Logger(__name__, self) self.events = EventGroup("connected", "disconnected") def startService(self): """Start the listener.""" super(PostgresListenerService, self).startService() self.autoReconnect = True return self.tryConnection() def stopService(self): """Stop the listener.""" super(PostgresListenerService, self).stopService() self.autoReconnect = False return self.loseConnection() def connected(self): """Return True if connected.""" if self.connection is None: return False if self.connection.connection is None: return False return self.connection.connection.closed == 0 def logPrefix(self): """Return nice name for twisted logging. This is required to satisfy `IReadDescriptor`, which inherits from `ILoggingContext`. """ return self.log.namespace def isSystemChannel(self, channel): """Return True if channel is a system channel.""" return channel.startswith("sys_") def doRead(self): """Poll the connection and process any notifications.""" try: self.connection.connection.poll() except Exception: # If the connection goes down then `OperationalError` is raised. # It contains no pgcode or pgerror to identify the reason so no # special consideration can be made for it. Hence all errors are # treated the same, and we assume that the connection is broken. # # We do NOT return a failure, which would signal to the reactor # that the connection is broken in some way, because the reactor # will end up removing this instance from its list of selectables # but not from its list of readable fds, or something like that. # The point is that the reactor's accounting gets muddled. Things # work correctly if we manage the disconnection ourselves. # self.loseConnection(Failure(error.ConnectionLost())) else: # Add each notify to to the notifications set. This removes # duplicate notifications when one entity in the database is # updated multiple times in a short interval. Accumulating # notifications and allowing the listener to pick them up in # batches is imperfect but good enough, and simple. notifies = self.connection.connection.notifies if len(notifies) != 0: for notify in notifies: if self.isSystemChannel(notify.channel): # System level message; pass it to the registered # handler immediately. if notify.channel in self.listeners: # Be defensive in that if a handler does not exist # for this channel then the channel should be # unregisted and removed from listeners. if len(self.listeners[notify.channel]) > 0: handler = self.listeners[notify.channel][0] handler(notify.channel, notify.payload) else: self.unregisterChannel(notify.channel) del self.listeners[notify.channel] else: # Unregister the channel since no listener is # registered for this channel. self.unregisterChannel(notify.channel) else: # Place non-system messages into the queue to be # processed. self.notifications.add( (notify.channel, notify.payload)) # Delete the contents of the connection's notifies list so # that we don't process them a second time. del notifies[:] def fileno(self): """Return the fileno of the connection.""" return self.connectionFileno def startReading(self): """Add this listener to the reactor.""" self.connectionFileno = self.connection.connection.fileno() reactor.addReader(self) def stopReading(self): """Remove this listener from the reactor.""" try: reactor.removeReader(self) except IOError as error: # ENOENT here means that the fd has already been unregistered # from the underlying poller. It is as yet unclear how we get # into this state, so for now we ignore it. See epoll_ctl(2). if error.errno != ENOENT: raise finally: self.connectionFileno = None def register(self, channel, handler): """Register listening for notifications from a channel. When a notification is received for that `channel` the `handler` will be called with the action and object id. """ handlers = self.listeners[channel] if self.isSystemChannel(channel) and len(handlers) > 0: # A system can only be registered once. This is because the # message is passed directly to the handler and the `doRead` # method does not wait for it to finish if its a defer. This is # different from normal handlers where we will call each and wait # for all to resolve before continuing to the next event. raise PostgresListenerRegistrationError( "System channel '%s' has already been registered." % channel) else: handlers.append(handler) self.runChannelRegistrar() def unregister(self, channel, handler): """Unregister listening for notifications from a channel. `handler` needs to be same handler that was registered. """ if channel not in self.listeners: raise PostgresListenerUnregistrationError( "Channel '%s' is not registered with the listener." % channel) handlers = self.listeners[channel] if handler in handlers: handlers.remove(handler) else: raise PostgresListenerUnregistrationError( "Handler is not registered on that channel '%s'." % channel) if len(handlers) == 0: # Channels have already been registered. Unregister the channel. del self.listeners[channel] self.runChannelRegistrar() @synchronous def createConnection(self): """Create new database connection.""" db = connections.databases[self.alias] backend = load_backend(db["ENGINE"]) return backend.DatabaseWrapper(db, self.alias, allow_thread_sharing=True) @synchronous def startConnection(self): """Start the database connection.""" self.connection = self.createConnection() self.connection.connect() self.connection.set_autocommit(True) @synchronous def stopConnection(self): """Stop database connection.""" # The connection is often in an unexpected state here -- for # unexplained reasons -- so be careful when unpealing layers. connection_wrapper, self.connection = self.connection, None if connection_wrapper is not None: connection = connection_wrapper.connection if connection is not None and not connection.closed: connection_wrapper.commit() connection_wrapper.close() def tryConnection(self): """Keep retrying to make the connection.""" if self.connecting is None: if self.disconnecting is not None: raise RuntimeError( "Cannot attempt to make new connection before " "pending disconnection has finished.") def cb_connect(_): self.log.info("Listening for database notifications.") def eb_connect(failure): self.log.error( "Unable to connect to database: {error}", error=failure.getErrorMessage(), ) if failure.check(CancelledError): return failure elif self.autoReconnect: return deferLater(reactor, 3, connect) else: return failure def connect(interval=self.HANDLE_NOTIFY_DELAY): d = deferToThread(self.startConnection) d.addCallback(callOut, self.runChannelRegistrar) d.addCallback(lambda result: self.channelRegistrarDone) d.addCallback(callOut, self.events.connected.fire) d.addCallback(callOut, self.startReading) d.addCallback(callOut, self.runHandleNotify, interval) # On failure ensure that the database connection is stopped. d.addErrback(callOut, deferToThread, self.stopConnection) d.addCallbacks(cb_connect, eb_connect) return d def done(): self.connecting = None self.connecting = connect().addBoth(callOut, done) return self.connecting def loseConnection(self, reason=Failure(error.ConnectionDone())): """Request that the connection be dropped.""" if self.disconnecting is None: self.registeredChannels.clear() d = self.disconnecting = Deferred() d.addBoth(callOut, self.stopReading) d.addBoth(callOut, self.cancelChannelRegistrar) d.addBoth(callOut, self.cancelHandleNotify) d.addBoth(callOut, deferToThread, self.stopConnection) d.addBoth(callOut, self.connectionLost, reason) def done(): self.disconnecting = None d.addBoth(callOut, done) if self.connecting is None: # Already/never connected: begin shutdown now. self.disconnecting.callback(None) else: # Still connecting: cancel before disconnect. self.connecting.addErrback(suppress, CancelledError) self.connecting.chainDeferred(self.disconnecting) self.connecting.cancel() return self.disconnecting def connectionLost(self, reason): """Reconnect when the connection is lost.""" self.connection = None if reason.check(error.ConnectionDone): self.log.debug("Connection closed.") elif reason.check(error.ConnectionLost): self.log.debug("Connection lost.") else: self.log.failure("Connection lost.", reason) if self.autoReconnect: reactor.callLater(3, self.tryConnection) self.events.disconnected.fire(reason) def registerChannel(self, channel): """Register the channel.""" with closing(self.connection.cursor()) as cursor: if self.isSystemChannel(channel): # This is a system channel so listen only called once. cursor.execute("LISTEN %s;" % channel) else: # Not a system channel so listen called once for each action. for action in sorted(map_enum(ACTIONS).values()): cursor.execute("LISTEN %s_%s;" % (channel, action)) def unregisterChannel(self, channel): """Unregister the channel.""" with closing(self.connection.cursor()) as cursor: if self.isSystemChannel(channel): # This is a system channel so unlisten only called once. cursor.execute("UNLISTEN %s;" % channel) else: # Not a system channel so unlisten called once for each action. for action in sorted(map_enum(ACTIONS).values()): cursor.execute("UNLISTEN %s_%s;" % (channel, action)) async def registerChannels(self): """Listen/unlisten to channels that were registered/unregistered. When a call to register() or unregister() is made, the listeners dict is updated, and the keys of that dict represents all the channels that we should listen to. The service keeps a list of channels that it already listens to in the registeredChannels dict. We issue a call to postgres to listen to all channels that are in listeners but not in registeredChannels, and a call to unlisten for all channels that are in registeredChannels but not in listeners. """ to_register = set(self.listeners.keys()).difference( self.registeredChannels) to_unregister = self.registeredChannels.difference( set(self.listeners.keys())) # If there's nothing to do, we can stop the loop. If there is # any work to be done, we do the work, and then check # whether we should stop at the beginning of the next loop # iteration. The reason is that every time we yield, another # deferred might call register() or unregister(). if not to_register and not to_unregister: self.channelRegistrar.stop() else: for channel in to_register: await deferToThread(self.registerChannel, channel) self.registeredChannels.add(channel) for channel in to_unregister: await deferToThread(self.unregisterChannel, channel) self.registeredChannels.remove(channel) def convertChannel(self, channel): """Convert the postgres channel to a registered channel and action. :raise PostgresListenerNotifyError: When {channel} is not registered or {action} is not in `ACTIONS`. """ channel, action = channel.split("_", 1) if channel not in self.listeners: raise PostgresListenerNotifyError( "%s is not a registered channel." % channel) if action not in map_enum(ACTIONS).values(): raise PostgresListenerNotifyError("%s action is not supported." % action) return channel, action def runChannelRegistrar(self): """Start the loop for listening to channels in postgres. It will only start if the service is connected to postgres. """ if self.connection is not None and not self.channelRegistrar.running: self.channelRegistrarDone = self.channelRegistrar.start( self.CHANNEL_REGISTRAR_DELAY, now=True) def cancelChannelRegistrar(self): """Stop the loop for listening to channels in postgres.""" if self.channelRegistrar.running: self.channelRegistrar.stop() return self.channelRegistrarDone else: return succeed(None) def runHandleNotify(self, delay=0, clock=reactor): """Defer later the `handleNotify`.""" if not self.notifier.running: self.notifierDone = self.notifier.start(delay, now=False) def cancelHandleNotify(self): """Cancel the deferred `handleNotify` call.""" if self.notifier.running: self.notifier.stop() return self.notifierDone else: return succeed(None) def handleNotifies(self, clock=reactor): """Process all notify message in the notifications set.""" def gen_notifications(notifications): while len(notifications) != 0: yield notifications.pop() return task.coiterate( self.handleNotify(notification, clock=clock) for notification in gen_notifications(self.notifications)) def handleNotify(self, notification, clock=reactor): """Process a notify message in the notifications set.""" channel, payload = notification try: channel, action = self.convertChannel(channel) except PostgresListenerNotifyError: # Log the error and continue processing the remaining # notifications. self.log.failure("Failed to convert channel {channel!r}.", channel=channel) else: defers = [] handlers = self.listeners[channel] # XXX: There could be an arbitrary number of listeners. Should we # limit concurrency here? Perhaps even do one at a time. for handler in handlers: d = defer.maybeDeferred(handler, action, payload) d.addErrback(lambda failure: self.log.failure( "Failure while handling notification to {channel!r}: " "{payload!r}", failure, channel=channel, payload=payload, )) defers.append(d) return defer.DeferredList(defers)