def main(ctx, auth_config, endpoint, verbose_logs, very_verbose_logs,
only_error_logs):
"""Gen3 Command Line Interface"""
ctx.ensure_object(dict)
ctx.obj["auth_config"] = auth_config
ctx.obj["endpoint"] = endpoint
ctx.obj["auth_factory"] = AuthFactory(auth_config)
if very_verbose_logs:
logger = cdislogging.get_logger(__name__,
format=gen3.LOG_FORMAT,
log_level="debug")
sdklogging.setLevel("DEBUG")
elif verbose_logs:
logger = cdislogging.get_logger(__name__,
format=gen3.LOG_FORMAT,
log_level="info")
sdklogging.setLevel("INFO")
elif only_error_logs:
logger = cdislogging.get_logger(__name__,
format=gen3.LOG_FORMAT,
log_level="error")
sdklogging.setLevel("ERROR")
else:
logger = cdislogging.get_logger(__name__,
format=gen3.LOG_FORMAT,
log_level="warning")
sdklogging.setLevel("WARNING")
def test_child_change_level_from_notset_logs_own_level():
"""
Check that if a child logger was instantiated with level NOTSET
and then get_logger() is called on it with a log_level arg != 'notset',
the child logger correctly logs at its own new level
on its own new handler
"""
parent = cdislogging.get_logger("parent", log_level="info")
mock_parent_hdlr_emit = MagicMock()
parent.handlers[0].emit = mock_parent_hdlr_emit
child = cdislogging.get_logger("parent.child")
cdislogging.get_logger("parent.child", log_level="warn")
mock_child_hdlr_emit = MagicMock()
child.handlers[0].emit = mock_child_hdlr_emit
child.warn(
"Should emit with child hdlr only; child no longer inherits/propagates"
)
assert mock_parent_hdlr_emit.call_count == 0
assert mock_child_hdlr_emit.call_count == 1
child.info("Should not emit; child level is now warn")
assert mock_parent_hdlr_emit.call_count == 0
assert mock_child_hdlr_emit.call_count == 1
def test_no_unintentional_reset_to_notset():
"""
Check that if logger was instantiated with log_level != NOTSET
and then get_logger() is called on it again without a log_level arg,
the logger's log level does _not_ get reset to NOTSET
"""
parent = cdislogging.get_logger("parent", log_level="debug")
mock_parent_hdlr_emit = MagicMock()
parent.handlers[0].emit = mock_parent_hdlr_emit
child = cdislogging.get_logger("parent.child", log_level="info")
mock_child_hdlr_emit = MagicMock()
child.handlers[0].emit = mock_child_hdlr_emit
child.info("Sanity check that this will emit on child hdlr")
assert mock_parent_hdlr_emit.call_count == 0
assert mock_child_hdlr_emit.call_count == 1
child = cdislogging.get_logger("parent.child")
child.debug(
"Should not emit, but will emit on parent hdlr if child level was reset to NOTSET"
)
assert mock_parent_hdlr_emit.call_count == 0
assert mock_child_hdlr_emit.call_count == 1
def test_multiple_log_handlers():
logger = cdislogging.get_logger('one_handler')
assert len(logger.handlers) == 1
# make sure it only has one handler associated with the logger name
logger = cdislogging.get_logger('one_handler')
assert len(logger.handlers) == 1
def test_reset_to_notset():
"""
Check that if logger was instantiated with log_level != NOTSET
and then get_logger() is called on it again with log_level='notset',
the logger's log level is correctly reset to NOTSET
and the logger logs at the correct level
"""
parent = cdislogging.get_logger("parent", log_level="debug")
mock_parent_hdlr_emit = MagicMock()
parent.handlers[0].emit = mock_parent_hdlr_emit
child = cdislogging.get_logger("parent.child", log_level="info")
mock_child_hdlr_emit = MagicMock()
child.handlers[0].emit = mock_child_hdlr_emit
child = cdislogging.get_logger("parent.child", log_level="notset")
assert child.propagate == True
assert len(child.handlers) == 0
child.info("Should emit with parent hdlr only")
assert mock_parent_hdlr_emit.call_count == 1
assert mock_child_hdlr_emit.call_count == 0
child.debug("Should emit with parent hdlr only")
assert mock_parent_hdlr_emit.call_count == 2
assert mock_child_hdlr_emit.call_count == 0
def app_config(
app,
settings="fence.settings",
root_dir=None,
config_path=None,
file_name=None,
):
"""
Set up the config for the Flask app.
"""
if root_dir is None:
root_dir = os.path.dirname(os.path.dirname(os.path.realpath(__file__)))
logger.info("Loading settings...")
# not using app.config.from_object because we don't want all the extra flask cfg
# vars inside our singleton when we pass these through in the next step
settings_cfg = flask.Config(app.config.root_path)
settings_cfg.from_object(settings)
# dump the settings into the config singleton before loading a configuration file
config.update(dict(settings_cfg))
# load the configuration file, this overwrites anything from settings/local_settings
config.load(
config_path=config_path,
search_folders=CONFIG_SEARCH_FOLDERS,
file_name=file_name,
)
# load all config back into flask app config for now, we should PREFER getting config
# directly from the fence config singleton in the code though.
app.config.update(**config._configs)
_setup_arborist_client(app)
_setup_audit_service_client(app)
_setup_data_endpoint_and_boto(app)
_load_keys(app, root_dir)
_set_authlib_cfgs(app)
app.prometheus_counters = {}
if config["ENABLE_PROMETHEUS_METRICS"]:
logger.info("Enabling Prometheus metrics...")
_setup_prometheus(app)
else:
logger.info("Prometheus metrics are NOT enabled.")
app.storage_manager = StorageManager(config["STORAGE_CREDENTIALS"],
logger=logger)
app.debug = config["DEBUG"]
# Following will update logger level, propagate, and handlers
get_logger(__name__,
log_level="debug" if config["DEBUG"] is True else "info")
_setup_oidc_clients(app)
with app.app_context():
_check_aws_creds_and_region(app)
_check_azure_storage(app)
def app_init() -> FastAPI:
logger.info("Initializing app")
config.validate(logger)
debug = config["DEBUG"]
app = FastAPI(
title="Audit Service",
version=version("audit"),
debug=debug,
root_path=config["DOCS_URL_PREFIX"],
)
app.add_middleware(ClientDisconnectMiddleware)
app.async_client = httpx.AsyncClient()
# Following will update logger level, propagate, and handlers
get_logger("audit-service", log_level="debug" if debug == True else "info")
logger.info("Initializing Arborist client")
if os.environ.get("ARBORIST_URL"):
app.arborist_client = ArboristClient(
arborist_base_url=os.environ["ARBORIST_URL"],
logger=logger,
)
else:
app.arborist_client = ArboristClient(logger=logger)
db.init_app(app)
load_modules(app)
@app.on_event("startup")
async def startup_event():
if (config["PULL_FROM_QUEUE"]
and config["QUEUE_CONFIG"].get("type") == "aws_sqs"):
loop = asyncio.get_running_loop()
loop.create_task(pull_from_queue_loop())
loop.set_exception_handler(handle_exception)
@app.on_event("shutdown")
async def shutdown_event():
logger.info("Closing async client.")
await app.async_client.aclose()
logger.info("[Completed] Closing async client.")
def handle_exception(loop, context):
"""
Whenever an exception occurs in the asyncio loop, the loop still continues to execute without crashing.
Therefore, we implement a custom exception handler that will ensure that the loop is stopped upon an Exception.
"""
msg = context.get("exception", context.get("message"))
logger.error(f"Caught exception: {msg}")
for index, task in enumerate(asyncio.all_tasks()):
task.cancel()
logger.info("Closed all tasks")
return app
def test_log_level_changes():
"""
Check that logger responds to changes in own log level
"""
logger = cdislogging.get_logger("logger", log_level="info")
mock_logger_hdlr_emit = MagicMock()
logger.handlers[0].emit = mock_logger_hdlr_emit
logger.debug("Should not emit")
assert mock_logger_hdlr_emit.call_count == 0
cdislogging.get_logger("logger", log_level="debug")
logger.debug("Should now emit")
assert mock_logger_hdlr_emit.call_count == 1
def test_child_inherits_parent_level():
"""
Check that child logger with level NOTSET will log according to parent level
"""
parent = cdislogging.get_logger("parent", log_level="info")
mock_parent_hdlr_emit = MagicMock()
parent.handlers[0].emit = mock_parent_hdlr_emit
child = cdislogging.get_logger("parent.child") # No handlers
child.info("Should emit via parent")
assert mock_parent_hdlr_emit.call_count == 1
child.debug(
"Should not emit since parent level is info and child level is notset")
assert mock_parent_hdlr_emit.call_count == 1
def require_auth_header(aud, purpose=None, logger=None):
"""
Return a decorator which adds request validation to check the given
audiences and (optionally) purpose.
"""
logger = logger or get_logger(__name__, log_level="info")
def decorator(f):
"""
Decorate the given function to check for a valid JWT header.
"""
@functools.wraps(f)
def wrapper(*args, **kwargs):
"""
Wrap a function to first validate the request header token.
Assign the claims from the token to ``flask.g._current_token`` so
the code inside the function can use the ``LocalProxy`` for the
token (see top of this file).
"""
set_current_token(
validate_request(aud=aud, purpose=purpose, logger=logger))
return f(*args, **kwargs)
return wrapper
return decorator
def get_public_key_for_token(encoded_token, attempt_refresh=True, logger=None):
"""
Attempt to look up the public key which should be used to verify the token.
Really just a thin wrapper around ``get_public_key`` which grabs the
``kid`` from the token headers and the ``iss`` from the token claims.
Args:
encoded_token (str): encoded JWT
attempt_refresh (bool): whether to refresh public keys
Return:
str: public RSA key for token verification
"""
logger = logger or get_logger(__name__, log_level="info")
kid = get_kid(encoded_token)
force_issuer = flask.current_app.config.get("FORCE_ISSUER")
if force_issuer:
iss = flask.current_app.config["USER_API"]
else:
iss = get_iss(encoded_token)
return get_public_key(kid,
iss=iss,
attempt_refresh=attempt_refresh,
logger=logger)
def test_child_change_level_from_notset_updates_properties():
"""
Check that if a child logger was instantiated with level NOTSET
and then get_logger() is called on it with a log_level arg != 'notset',
the child logger correctly updates level and propagate,
and gets its own handler
"""
parent = cdislogging.get_logger("parent", log_level="info")
child = cdislogging.get_logger("parent.child")
assert child.propagate == True
assert len(child.handlers) == 0
# TODO: should really rename this to get_or_update_logger...
cdislogging.get_logger("parent.child", log_level="warn")
assert child.propagate == False
assert len(child.handlers) == 1
def test_child_inherits_parent_level_changes():
"""
Check that child logger with level NOTSET will respond to changes in parent log level
"""
parent = cdislogging.get_logger("parent", log_level="info")
mock_parent_hdlr_emit = MagicMock()
parent.handlers[0].emit = mock_parent_hdlr_emit
child = cdislogging.get_logger("parent.child") # No handlers
child.debug("should not emit since parent level is info")
assert mock_parent_hdlr_emit.call_count == 0
cdislogging.get_logger("parent", log_level="debug")
child.debug("should now emit")
assert mock_parent_hdlr_emit.call_count == 1
def __init__(self, conn, logger=None, **config):
super(SQLAlchemyIndexTestDriver, self).__init__(conn, **config)
self.logger = logger or get_logger('SQLAlchemyIndexTestDriver')
Base.metadata.bind = self.engine
Base.metadata.create_all()
self.Session = sessionmaker(bind=self.engine)
def __init__(self,
logger=None,
arborist_base_url="http://arborist-service/"):
self.logger = logger or get_logger("ArboristClient")
self._base_url = arborist_base_url.strip("/")
self._policy_url = self._base_url + "/policy/"
self._resource_url = self._base_url + "/resource"
self._role_url = self._base_url + "/role/"
def test_instantiate_with_log_level():
"""
Check that if logger instantiated with log_level != NOTSET
then level and propagate are set correctly and handler is created
"""
logger = cdislogging.get_logger("logger", log_level="info")
assert logger.level == logging.INFO
assert logger.propagate == False
assert len(logger.handlers) == 1
def test_instantiate_without_log_level():
"""
Check that if logger instantiated without log_level arg
then level and propagate are set correctly and no handlers created
"""
logger = cdislogging.get_logger("logger")
assert logger.level == logging.NOTSET
assert logger.propagate == True
assert len(logger.handlers) == 0
def refresh_jwt_public_keys(user_api=None, logger=None):
"""
Update the public keys that the Flask app is currently using to validate
JWTs.
Response from ``/jwt/keys`` should look like this:
.. code-block:: javascript
{
"keys": [
[
"key-id-01",
"-----BEGIN PUBLIC KEY---- ... -----END PUBLIC KEY-----\n"
],
[
"key-id-02",
"-----BEGIN PUBLIC KEY---- ... -----END PUBLIC KEY-----\n"
]
]
}
Take out the array of keys, put it in an ordered dictionary, and assign
that to ``flask.current_app.jwt_public_keys``.
Args:
user_api (Optional[str]):
the URL of the user API to get the keys from; default to whatever
the flask app is configured to use
Return:
None
Side Effects:
- Reassign ``flask.current_app.jwt_public_keys`` to the keys obtained
from ``get_jwt_public_keys``, as an OrderedDict.
Raises:
ValueError: if user_api is not provided or set in app config
"""
logger = logger or get_logger(__name__, log_level="info")
# First, make sure the app has a ``jwt_public_keys`` attribute set up.
missing_public_keys = (not hasattr(flask.current_app, "jwt_public_keys")
or not flask.current_app.jwt_public_keys)
if missing_public_keys:
flask.current_app.jwt_public_keys = {}
user_api = user_api or flask.current_app.config.get("USER_API")
if not user_api:
raise ValueError("no URL(s) provided for user API")
path = get_keys_url(user_api)
jwt_public_keys = httpx.get(path).json()["keys"]
logger.info("refreshing public keys; updated to:\n" +
json.dumps(str(jwt_public_keys), indent=4))
flask.current_app.jwt_public_keys.update(
{user_api: OrderedDict(jwt_public_keys)})
def app_config(app,
settings="fence.settings",
root_dir=None,
config_path=None,
file_name=None):
"""
Set up the config for the Flask app.
"""
if root_dir is None:
root_dir = os.path.dirname(os.path.dirname(os.path.realpath(__file__)))
logger.info("Loading settings...")
# not using app.config.from_object because we don't want all the extra flask cfg
# vars inside our singleton when we pass these through in the next step
settings_cfg = flask.Config(app.config.root_path)
settings_cfg.from_object(settings)
# dump the settings into the config singleton before loading a configuration file
config.update(dict(settings_cfg))
# load the configuration file, this overwrites anything from settings/local_settings
config.load(config_path, file_name)
# load all config back into flask app config for now, we should PREFER getting config
# directly from the fence config singleton in the code though.
app.config.update(**config._configs)
_setup_arborist_client(app)
_setup_data_endpoint_and_boto(app)
_load_keys(app, root_dir)
_set_authlib_cfgs(app)
app.storage_manager = StorageManager(config["STORAGE_CREDENTIALS"],
logger=logger)
app.debug = config["DEBUG"]
# Following will update logger level, propagate, and handlers
get_logger(__name__,
log_level="debug" if config["DEBUG"] == True else "info")
_setup_oidc_clients(app)
def app_init() -> FastAPI:
logger.info("Initializing app")
config.validate()
debug = config["DEBUG"]
app = FastAPI(
title="Requestor",
version=version("requestor"),
debug=debug,
root_path=config["DOCS_URL_PREFIX"],
)
app.add_middleware(ClientDisconnectMiddleware)
app.async_client = httpx.AsyncClient()
# Following will update logger level, propagate, and handlers
get_logger("requestor", log_level="debug" if debug == True else "info")
logger.info("Initializing Arborist client")
custom_arborist_url = os.environ.get("ARBORIST_URL",
config["ARBORIST_URL"])
if custom_arborist_url:
app.arborist_client = ArboristClient(
arborist_base_url=custom_arborist_url,
authz_provider="requestor",
logger=get_logger("requestor.gen3authz", log_level="debug"),
)
else:
app.arborist_client = ArboristClient(
authz_provider="requestor",
logger=get_logger("requestor.gen3authz", log_level="debug"),
)
db.init_app(app)
load_modules(app)
@app.on_event("shutdown")
async def shutdown_event():
logger.info("Closing async client.")
await app.async_client.aclose()
return app
def __init__(self,
logger=None,
arborist_base_url="http://arborist-service/"):
self.logger = logger or get_logger(
"ArboristClient",
log_level="debug" if config["DEBUG"] == True else "info")
self._base_url = arborist_base_url.strip("/")
self._auth_url = self._base_url + "/auth/"
self._health_url = self._base_url + "/health"
self._policy_url = self._base_url + "/policy/"
self._resource_url = self._base_url + "/resource"
self._role_url = self._base_url + "/role/"
def __init__(self, db, logger=None, proxies={}):
"""Instantiate a class to crossvalidate entity existence in dbGaP.
"""
self._cached_telemetry_xmls = {
# "phsid": "telemetry xml"
}
self.db = db
self.proxies = proxies
self.logger = logger or get_logger("dbGapXReferencer",
log_level="info")
self.logger.info("Creating new dbGaP Cross Referencer")
def test_log_level():
"""
Check that logger with level != NOTSET correctly logs according to own level
"""
logger = cdislogging.get_logger("logger", log_level="info")
mock_logger_hdlr_emit = MagicMock()
logger.handlers[0].emit = mock_logger_hdlr_emit
logger.info("Should emit")
assert mock_logger_hdlr_emit.call_count == 1
logger.debug("Should not emit")
assert mock_logger_hdlr_emit.call_count == 1
def __init__(self,
logger=None,
arborist_base_url="http://arborist-service/"):
self.logger = logger or get_logger("ArboristClient")
self._base_url = arborist_base_url.strip("/")
self._auth_url = self._base_url + "/auth/"
self._health_url = self._base_url + "/health"
self._policy_url = self._base_url + "/policy/"
self._resource_url = self._base_url + "/resource"
self._role_url = self._base_url + "/role/"
self._user_url = self._base_url + "/user"
self._client_url = self._base_url + "/client"
self._group_url = self._base_url + "/group"
def validate_jwt(
encoded_token,
aud,
purpose="access",
issuers=None,
public_key=None,
attempt_refresh=True,
logger=None,
):
"""
Validate a JWT and return the claims.
Args:
encoded_token (str): the base64 encoding of the token
aud (Optional[Iterable[str]]):
list of audiences that the token must satisfy; defaults to
``{'openid'}`` (minimum expected by OpenID provider)
purpose (Optional[str]):
which purpose the token is supposed to be used for (access,
refresh, or id)
issuers (Iterable[str]): list of allowed token issuers
public_key (Optional[str]): public key to vaidate JWT with
Return:
dict: dictionary of claims from the validated JWT
Raises:
ValueError: if ``aud`` is empty
JWTError:
if auth header is missing, decoding fails, or the JWT fails to
satisfy any expectation
"""
logger = logger or get_logger(__name__, log_level="info")
if not issuers:
issuers = []
for config_var in ["OIDC_ISSUER", "USER_API", "BASE_URL"]:
value = flask.current_app.config.get(config_var)
if value:
issuers.append(value)
if public_key is None:
public_key = get_public_key_for_token(encoded_token,
attempt_refresh=attempt_refresh,
logger=logger)
if not aud:
raise ValueError("must provide at least one audience")
aud = set(aud)
claims = core.validate_jwt(encoded_token, public_key, aud, issuers)
if purpose:
core.validate_purpose(claims, purpose)
return claims
def get_public_key(kid, iss=None, attempt_refresh=True, logger=None):
"""
Given a key id ``kid``, get the public key from the flask app belonging to
this key id. The key id is allowed to be None, in which case, use the the
first key in the OrderedDict.
- If current flask app is not holding public keys (ordered dictionary) or
key id is in token headers and the key id does not appear in those public
keys, refresh the public keys by calling ``refresh_jwt_public_keys()``
- If key id is provided in the token headers:
- If key id does not appear in public keys, fail
- Use public key with this key id
- If key id is not provided:
- Use first public key in the ordered dictionary
Args:
kid (str): the key id
attempt_refresh (bool):
whether to try to refresh the public keys of the flask app if
encountering a key id that does not exist in those keys; for fence
itself this should be ``False``, and for other services it should
be ``True``
Return:
str: the public key
Side Effects:
- From ``refresh_jwt_public_keys``: reassign
``flask.current_app.jwt_public_keys`` to the keys obtained from
``get_jwt_public_keys``.
Raises:
JWTValidationError:
if the key id is provided and public key with that key id is found
"""
iss = (iss or flask.current_app.config.get("OIDC_ISSUER")
or flask.current_app.config["USER_API"])
logger = logger or get_logger(__name__, log_level="info")
need_refresh = not hasattr(flask.current_app, "jwt_public_keys") or (
kid and kid not in flask.current_app.jwt_public_keys.get(iss, {}))
if need_refresh and attempt_refresh:
refresh_jwt_public_keys(iss, logger=logger)
if iss not in flask.current_app.jwt_public_keys:
raise JWTError("issuer not found: {}".format(iss))
iss_public_keys = flask.current_app.jwt_public_keys[iss]
try:
return iss_public_keys[kid]
except KeyError:
raise JWTError("no key exists with given key id: {}".format(kid))
def __init__(
self,
dbGaP,
DB,
project_mapping,
storage_credentials=None,
db_session=None,
is_sync_from_dbgap_server=False,
sync_from_local_csv_dir=None,
sync_from_local_yaml_file=None,
arborist=None,
):
"""
Syncs ACL files from dbGap to auth database and storage backends
Args:
dbGaP: a dict containing creds to access dbgap sftp
DB: database connection string
project_mapping: a dict containing how dbgap ids map to projects
storage_credentials: a dict containing creds for storage backends
sync_from_dir: path to an alternative dir to sync from instead of
dbGaP
arborist:
base URL for arborist service if the syncer should also create
resources in arborist
"""
self.sync_from_local_csv_dir = sync_from_local_csv_dir
self.sync_from_local_yaml_file = sync_from_local_yaml_file
self.is_sync_from_dbgap_server = is_sync_from_dbgap_server
if is_sync_from_dbgap_server:
self.server = dbGaP["info"]
self.protocol = dbGaP["protocol"]
self.dbgap_key = dbGaP["decrypt_key"]
self.parse_consent_code = dbGaP.get("parse_consent_code", True)
self.session = db_session
self.driver = SQLAlchemyDriver(DB)
self.project_mapping = project_mapping or {}
self._projects = dict()
self.logger = get_logger(
"user_syncer",
log_level="debug" if config["DEBUG"] == True else "info")
self.arborist_client = None
if arborist:
self.arborist_client = ArboristClient(arborist_base_url=arborist,
logger=self.logger)
if storage_credentials:
self.storage_manager = StorageManager(storage_credentials,
logger=self.logger)
def validate_request(aud, purpose="access", logger=None):
"""
Validate a ``flask.request`` by checking the JWT contained in the request
headers.
"""
logger = logger or get_logger(__name__, log_level="info")
# Get token from the headers.
try:
encoded_token = flask.request.headers["Authorization"].split(" ")[1]
except IndexError:
raise JWTError("could not parse authorization header")
except KeyError:
raise JWTError("no authorization header provided")
# Pass token to ``validate_jwt``.
return validate_jwt(encoded_token, aud, purpose, logger=logger)
def __init__(self, conn, logger=None, auto_migrate=True, **config):
'''
Initialize the SQLAlchemy database driver.
'''
super(SQLAlchemyAliasDriver, self).__init__(conn, **config)
self.logger = logger or get_logger('SQLAlchemyAliasDriver')
Base.metadata.bind = self.engine
self.Session = sessionmaker(bind=self.engine)
is_empty_db = is_empty_database(driver=self)
Base.metadata.create_all()
if is_empty_db:
init_schema_version(driver=self,
model=AliasSchemaVersion,
version=CURRENT_SCHEMA_VERSION)
if auto_migrate:
self.migrate_alias_database()
def __init__(
self,
logger=None,
arborist_base_url="http://arborist-service/",
authz_provider=None,
timeout=10,
):
self.logger = logger or get_logger("ArboristClient")
self._base_url = arborist_base_url.strip("/")
self._auth_url = self._base_url + "/auth/"
self._health_url = self._base_url + "/health"
self._policy_url = self._base_url + "/policy/"
self._bulk_policy_url = self._base_url + "/bulk/policy"
self._resource_url = self._base_url + "/resource"
self._role_url = self._base_url + "/role/"
self._user_url = self._base_url + "/user"
self._client_url = self._base_url + "/client"
self._group_url = self._base_url + "/group"
self._authz_provider = authz_provider
self._timeout = timeout
self._env = _Env()
