diff --git a/bin/pyntlm_auth/config_loader.py b/bin/pyntlm_auth/config_loader.py index 28c67c5f23be..79795d87d439 100644 --- a/bin/pyntlm_auth/config_loader.py +++ b/bin/pyntlm_auth/config_loader.py @@ -8,6 +8,7 @@ import config_generator import global_vars import utils +import log def get_boolean_value(v): @@ -38,45 +39,51 @@ def get_int_value(v): def config_load(): - global_vars.c_listen_port = os.getenv("LISTEN") - global_vars.c_domain_identifier = socket.gethostname() + " " + os.getenv("IDENTIFIER") + listen = os.getenv("LISTEN") + identifier = os.getenv("IDENTIFIER") - if global_vars.c_domain_identifier == "" or global_vars.c_listen_port == "": - print("Unable to start ntlm-auth-api: 'IDENTIFIER' or 'LISTEN' is missing.") + if not listen: + log.critical("unable to start ntlm-auth-api: missing environment variable 'LISTEN'") + exit(1) + if not identifier: + log.critical("unable to start ntlm-auth-api: missing environment variable 'IDENTIFIER'") exit(1) - print(f"ntlm-auth-api@{global_vars.c_domain_identifier} on port {global_vars.c_listen_port}...") + global_vars.c_listen_port = os.getenv("LISTEN") + global_vars.c_domain_identifier = socket.gethostname() + " " + os.getenv("IDENTIFIER") + + log.debug(f"ntlm-auth-api@{identifier} starting on port {global_vars.c_listen_port}") identifier = global_vars.c_domain_identifier conf_dm = "/usr/local/pf/conf/domain.conf" cp_dm = ConfigParser(interpolation=None) - print(f"Load domain config from {conf_dm}") + log.debug(f"Load domain config from {conf_dm}") try: with open(conf_dm, 'r') as file: cp_dm.read_file(file) if identifier not in cp_dm: - print(f" Section {identifier} does not exist in domain.conf. Terminated.") + log.critical(f"Section {identifier} does not exist in domain.conf. Terminated.") sys.exit(1) except FileNotFoundError: - print(f" {conf_dm} not found or unreadable. Terminated.") + log.critical(f"{conf_dm} not found or unreadable. Terminated.") sys.exit(1) except configparser.Error as e: - print(f" Error loading config from domain.conf: {e}. Terminated.") + log.critical(f"Error loading config from domain.conf: {e}. Terminated.") sys.exit(1) conf_db = f"/usr/local/pf/var/conf/ntlm-auth-api.d/db.ini" cp_db = ConfigParser(interpolation=None) - print(f"Load database config from {conf_db}") + log.debug(f"Load database config from {conf_db}") try: with open(conf_db, 'r') as file: cp_db.read_file(file) if 'DB' not in cp_db: - print(f" Section [DB] not found, ntlm-auth-api starts without NT Key caching capability.") + log.warning(f"Section [DB] not found, ntlm-auth-api starts without NT Key caching capability.") except FileNotFoundError: - print(f" {conf_db} not found, ntlm-auth-api@{identifier} starts without NT Key caching capability.") + log.warning(f"{conf_db} not found, ntlm-auth-api@{identifier} starts without NT Key caching capability.") except configparser.Error as e: - print(f" Error loading {conf_db}: {e}, ntlm-auth-api@{identifier} starts without NT Key caching capability.") + log.warning(f"Error loading {conf_db}: {e}, ntlm-auth-api@{identifier} starts without NT Key caching capability.") server_name_raw = cp_dm.get(identifier, 'server_name') server_name_or_hostname = server_name_raw @@ -111,12 +118,11 @@ def config_load(): c_db_pass = cp_db.get('DB', "DB_PASS", fallback=None) c_db = cp_db.get('DB', "DB", fallback=None) c_db_unix_socket = cp_db.get('DB', 'DB_UNIX_SOCKET', fallback=None) - print(f" {c_db_user}:{utils.mask_password(c_db_pass)}@{c_db_host}:{c_db_port}/{c_db}") + log.debug(f"db config: {c_db_user}:{utils.mask_password(c_db_pass)}@{c_db_host}:{c_db_port}/{c_db}") # validate domain.conf - print(f"starting ntlm-auth-api@{identifier}") if ad_fqdn == "": - print(" 'ad_fqdn' is not set. NTLM Auth API wasn't able to start") + log.critical("'ad_fqdn' is not set. NTLM Auth API wasn't able to start") sys.exit(1) if dns_servers != "": @@ -124,33 +130,33 @@ def config_load(): time.sleep(1) ip, err_msg = utils.dns_lookup(ad_fqdn, "") if ip != "" and err_msg == "": - print(f" AD FQDN: {ad_fqdn} resolved with IP: {ip}.") + log.debug(f"AD FQDN: {ad_fqdn} resolved with IP: {ip}.") else: if utils.is_ipv4(ad_server): # if it's not resolvable, we use static IP provided in domain.conf - print(f" AD FQDN resolving failed. Starting with static hosts entry: {ad_server} {ad_fqdn}.") + log.debug(f"AD FQDN resolving failed. Starting with static hosts entry: {ad_server} {ad_fqdn}.") config_generator.generate_hosts_entry(ad_server, ad_fqdn) else: - print(" Failed to retrieve IP address of AD server. Terminated.") + log.critical("Failed to retrieve IP address of AD server. Terminated.") sys.exit(1) else: if utils.is_ipv4(ad_server): config_generator.generate_hosts_entry(ad_server, ad_fqdn) - print(f" DNS servers not available, Starting using static hosts entry: {ad_server} {ad_fqdn}.") + log.warning(f"DNS servers not available, Starting using static hosts entry: {ad_server} {ad_fqdn}.") else: - print(" Unable to start NTLM Auth API. 'ad_server' must be a valid IPv4 if DNS servers not specified.") + log.critical("Unable to start NTLM Auth API. 'ad_server' must be a valid IPv4 if DNS servers not specified.") sys.exit(1) - print("NTLM Auth API started with the following parameters:") - print(f" ad_fqdn : {ad_fqdn}") - print(f" ad_server : {ad_server}") - print(f" server_name : {server_name_raw}") - print(f" server_name (parsed) : {server_name_or_hostname}") - print(f" dns_name : {realm}") - print(f" workgroup : {workgroup}") - print(f" machine_account_password : {utils.mask_password(password)}") - print(f" dns_servers : {dns_servers}") - print(f" nt_key_cache_enabled : {nt_key_cache_enabled}") - print(f" nt_key_cache_expire : {nt_key_cache_expire}") + log.debug("NTLM Auth API started with the following parameters:") + log.debug(f" ad_fqdn : {ad_fqdn}") + log.debug(f" ad_server : {ad_server}") + log.debug(f" server_name : {server_name_raw}") + log.debug(f" server_name (parsed) : {server_name_or_hostname}") + log.debug(f" dns_name : {realm}") + log.debug(f" workgroup : {workgroup}") + log.debug(f" machine_account_password : {utils.mask_password(password)}") + log.debug(f" dns_servers : {dns_servers}") + log.debug(f" nt_key_cache_enabled : {nt_key_cache_enabled}") + log.debug(f" nt_key_cache_expire : {nt_key_cache_expire}") # validate NT Key cache configuration nt_key_cache_enabled = get_boolean_value(nt_key_cache_enabled) @@ -159,29 +165,29 @@ def config_load(): for i in range(1): nt_key_cache_expire, error = get_int_value(nt_key_cache_expire) if error is not None: - print(" NT Key cache: can not parse 'nt_key_cache_expire', cache disabled.") + log.warning(" NT Key cache: can not parse 'nt_key_cache_expire', cache disabled.") nt_key_cache_enabled = False break if nt_key_cache_expire < 60: - print(f" NT key cache: expire value '{nt_key_cache_expire}' too small, set to minimum value: 60") + log.warning(f" NT key cache: expire value '{nt_key_cache_expire}' too small, set to minimum value: 60") nt_key_cache_expire = 60 if nt_key_cache_expire > 864000: - print(f" NT key cache: expire value '{nt_key_cache_expire}' too large, set to maximum value: 864000") + log.warning(f" NT key cache: expire value '{nt_key_cache_expire}' too large, set to maximum value: 864000") nt_key_cache_expire = 864000 ad_old_password_allowed_period, error = get_int_value(ad_old_password_allowed_period) if error is not None: - print(f" NT Key cache: unable to parse 'ad_old_password_allowed_period', cache disabled.") + log.warning(f" NT Key cache: unable to parse 'ad_old_password_allowed_period', cache disabled.") nt_key_cache_enabled = False break if ad_old_password_allowed_period < 0 or ad_old_password_allowed_period > 99999: - print(f" NT Key cache: 'ad_old_password_allowed_period' ranges from 0..99999, cache disabled.") + log.warning(f" NT Key cache: 'ad_old_password_allowed_period' ranges from 0..99999, cache disabled.") nt_key_cache_enabled = False break ad_account_lockout_threshold, error = get_int_value(ad_account_lockout_threshold) if error is not None: - print(" NT Key cache: can not parse 'ad_account_lockout_threshold', cache disabled.") + log.warning(" NT Key cache: can not parse 'ad_account_lockout_threshold', cache disabled.") nt_key_cache_enabled = False break if ad_account_lockout_threshold == 0: @@ -193,33 +199,33 @@ def config_load(): if error is not None: ad_old_password_allowed_period = 0 break if ad_account_lockout_threshold < 2 or ad_account_lockout_threshold > 999: - print(f" NT Key cache: 'ad_account_lock_threshold' ranges from 2..999, cache disabled.") + log.warning(f" NT Key cache: 'ad_account_lock_threshold' ranges from 2..999, cache disabled.") nt_key_cache_enabled = False break ad_account_lockout_duration, error = get_int_value(ad_account_lockout_duration) if error is not None: - print(f" NT Key cache: can not parse 'account_lockout_duration', cache disabled.") + log.warning(f" NT Key cache: can not parse 'account_lockout_duration', cache disabled.") nt_key_cache_enabled = False break if ad_account_lockout_duration < 1 or ad_account_lockout_duration > 99999: - print(f" NT Key cache: 'ad_account_lockout_duration' ranges from 1..99999, cache disabled.") + log.warning(f" NT Key cache: 'ad_account_lockout_duration' ranges from 1..99999, cache disabled.") nt_key_cache_enabled = False break ad_reset_account_lockout_count_after, error = get_int_value(ad_reset_account_lockout_count_after) if error is not None: - print(f" NT Key cache: can not parse 'ad_reset_account_lockout_after', cache disabled.") + log.warning(f" NT Key cache: can not parse 'ad_reset_account_lockout_after', cache disabled.") nt_key_cache_enabled = False break if ad_reset_account_lockout_count_after < 1 or ad_reset_account_lockout_count_after > 99999: - print(f" NT Key cache: 'ad_reset_account_lockout_counter_after' ranges from 1..99999, cache disabled.") + log.warning(f" NT Key cache: 'ad_reset_account_lockout_counter_after' ranges from 1..99999, cache disabled.") nt_key_cache_enabled = False break if ad_reset_account_lockout_count_after > ad_account_lockout_duration: s_reset = 'ad_reset_account_lockout_counter_after' s_duration = 'ad_account_lockout_duration' - print(f" NT Key cache: '{s_reset}' larger than '{s_duration}', cache disabled.") + log.warning(f" NT Key cache: '{s_reset}' larger than '{s_duration}', cache disabled.") nt_key_cache_enabled = False break @@ -227,25 +233,25 @@ def config_load(): s_device = 'max_allowed_attempts_per_device' s_threshold = 'ad_account_lockout_threshold' if error is not None: - print(f" NT Key cache: unable to parse '{s_device}', set to '{s_threshold}' by default.") + log.warning(f" NT Key cache: unable to parse '{s_device}', set to '{s_threshold}' by default.") max_allowed_attempts_per_device = ad_account_lockout_threshold break if max_allowed_attempts_per_device < 0 or max_allowed_attempts_per_device > 999: - print(f" NT Key cache: '{s_device}' ranges from 0..999, set to '{s_threshold}' by default.") + log.warning(f" NT Key cache: '{s_device}' ranges from 0..999, set to '{s_threshold}' by default.") break if max_allowed_attempts_per_device > ad_account_lockout_threshold: - print(f" NT Key cache: '{s_device}' larger than '{s_threshold}', set to '{s_threshold}' by default.") + log.warning(f" NT Key cache: '{s_device}' larger than '{s_threshold}', set to '{s_threshold}' by default.") if None in (c_db_host, c_db_port, c_db_user, c_db_pass, c_db, c_db_unix_socket): - print(f" DB config: Missing settings, NT Key cache will be disabled") + log.warning(f" DB config: Missing settings, NT Key cache will be disabled") nt_key_cache_enabled = False - print("NT Key caching:") - print(f" ad_account_lockout_threshold : {ad_account_lockout_threshold}") - print(f" ad_account_lockout_duration (in minutes) : {ad_account_lockout_duration}") - print(f" ad_reset_account_lockout_counter_after (in minutes) : {ad_reset_account_lockout_count_after}") - print(f" ad_old_password_allowed_period (in minutes) : {ad_old_password_allowed_period}") - print(f" max_allowed_password_attempts_per_device : {max_allowed_attempts_per_device}") + log.debug("NT Key caching:") + log.debug(f" ad_account_lockout_threshold : {ad_account_lockout_threshold}") + log.debug(f" ad_account_lockout_duration (in minutes) : {ad_account_lockout_duration}") + log.debug(f" ad_reset_account_lockout_counter_after (in minutes) : {ad_reset_account_lockout_count_after}") + log.debug(f" ad_old_password_allowed_period (in minutes) : {ad_old_password_allowed_period}") + log.debug(f" max_allowed_password_attempts_per_device : {max_allowed_attempts_per_device}") global_vars.c_server_name = ad_fqdn global_vars.c_ad_server = ad_server diff --git a/bin/pyntlm_auth/log.py b/bin/pyntlm_auth/log.py new file mode 100644 index 000000000000..6a82159d968e --- /dev/null +++ b/bin/pyntlm_auth/log.py @@ -0,0 +1,46 @@ +import logging + + +def init_logging(): + default_logging_level = logging.DEBUG + + logger = logging.getLogger("ntlm-auth") + logger.setLevel(default_logging_level) + + console_handler = logging.StreamHandler() + console_handler.setLevel(default_logging_level) + + # file_handler = logging.FileHandler("app.log") + # file_handler.setLevel(default_logging_level) + + formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s', datefmt="%Y-%m-%d %H:%M:%S") + console_handler.setFormatter(formatter) + # file_handler.setFormatter(formatter) + + logger.addHandler(console_handler) + # logger.addHandler(file_handler) + + return logger + + +def debug(msg): + logger.debug(msg) + + +def info(msg): + logger.info(msg) + + +def warning(msg): + logger.info(msg) + + +def error(msg): + logger.error(msg) + + +def critical(msg): + logger.critical(msg) + + +logger = init_logging() diff --git a/bin/pyntlm_auth/t_api.py b/bin/pyntlm_auth/t_api.py index e38e756e6e65..ac79ceb9104d 100644 --- a/bin/pyntlm_auth/t_api.py +++ b/bin/pyntlm_auth/t_api.py @@ -1,11 +1,17 @@ import logging import pymysql -from flask import Flask, g, request +from flask import Flask, g from flaskext.mysql import MySQL import config_loader import global_vars import handlers +import os + + +class HealthCheckFilter(logging.Filter): + def filter(self, record): + return 'GET /ping' not in record.getMessage() def api(): @@ -14,13 +20,12 @@ def api(): app = Flask(__name__) werkzeug_logger = logging.getLogger('werkzeug') + werkzeug_logger.addFilter(HealthCheckFilter()) - @app.before_request - def register_logger(): - if request.path.startswith("/ping"): - werkzeug_logger.setLevel(logging.CRITICAL) - else: - werkzeug_logger.setLevel(logging.INFO) + if app.logger.hasHandlers(): + f = logging.Formatter('[%(asctime)s] %(levelname)s in %(module)s: %(message)s', datefmt="%Y-%m-%d %H:%M:%S") + for handler in app.logger.handlers: + handler.setFormatter(f) for i in range(1): if not global_vars.c_nt_key_cache_enabled: @@ -49,7 +54,8 @@ def before_request(): except Exception as e: e_code = e.args[0] e_msg = str(e) - print(f" error while init database: {e_code}, {e_msg}. Started without NT Key cache capability.") + app.logger.warning(f"error {e_code}: {e_msg} when initializing database.") + app.logger.warning(f"ntlm-auth-api@{os.getenv('IDENTIFIER')} started without NT Key cache capability.") @app.teardown_request def teardown_request(exception=None):