diff --git a/CHANGELOG.md b/CHANGELOG.md index 05013478..ac4c83af 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -77,6 +77,7 @@ v1.6.0 - unreleased - Enhancement: Added regex validation for alias username ([#764](https://github.com/Mailu/Mailu/issues/764)) - Enhancement: Update documentation - Enhancement: Include favicon package ([#801](https://github.com/Mailu/Mailu/issues/801), ([#802](https://github.com/Mailu/Mailu/issues/802)) +- Enhancement: Add logging at critical places in python start.py scripts. Implement LOG_LEVEL to control verbosity ([#588](https://github.com/Mailu/Mailu/issues/588)) - Upstream: Update Roundcube - Upstream: Update Rainloop - Bug: Rainloop fails with "domain not allowed" ([#93](https://github.com/Mailu/Mailu/issues/93)) diff --git a/core/dovecot/start.py b/core/dovecot/start.py index c97b8a05..15e370de 100755 --- a/core/dovecot/start.py +++ b/core/dovecot/start.py @@ -6,23 +6,40 @@ import socket import glob import multiprocessing import tenacity +import logging as log +import sys from tenacity import retry from podop import run_server +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) def start_podop(): os.setuid(8) - run_server(3 if "DEBUG" in os.environ else 0, "dovecot", "/tmp/podop.socket", [ + run_server(0, "dovecot", "/tmp/podop.socket", [ ("quota", "url", "http://admin/internal/dovecot/§"), ("auth", "url", "http://admin/internal/dovecot/§"), ("sieve", "url", "http://admin/internal/dovecot/§"), ]) -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) + +@retry( + stop=tenacity.stop_after_attempt(100), + wait=tenacity.wait_random(min=2, max=5), + before=tenacity.before_log(log.getLogger("tenacity.retry"), log.DEBUG), + before_sleep=tenacity.before_sleep_log(log.getLogger("tenacity.retry"), log.INFO), + after=tenacity.after_log(log.getLogger("tenacity.retry"), log.DEBUG) + ) +def resolve(hostname): + logger = log.getLogger("resolve()") + logger.info(hostname) + return socket.gethostbyname(hostname) # Actual startup script -resolve = retry(socket.gethostbyname, stop=tenacity.stop_after_attempt(100), wait=tenacity.wait_random(min=2, max=5)) os.environ["FRONT_ADDRESS"] = resolve(os.environ.get("FRONT_ADDRESS", "front")) os.environ["REDIS_ADDRESS"] = resolve(os.environ.get("REDIS_ADDRESS", "redis")) if os.environ["WEBMAIL"] != "none": diff --git a/core/nginx/config.py b/core/nginx/config.py index 07b7ea32..79370508 100755 --- a/core/nginx/config.py +++ b/core/nginx/config.py @@ -2,11 +2,18 @@ import jinja2 import os - -convert = lambda src, dst, args: open(dst, "w").write(jinja2.Template(open(src).read()).render(**args)) +import logging as log +import sys args = os.environ.copy() +log.basicConfig(stream=sys.stderr, level=args.get("LOG_LEVEL", "WARNING")) + +def convert(src, dst, args): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**args)) + # Get the first DNS server with open("/etc/resolv.conf") as handle: content = handle.read().split() diff --git a/core/postfix/start.py b/core/postfix/start.py index 86e9a827..a06b3833 100755 --- a/core/postfix/start.py +++ b/core/postfix/start.py @@ -7,14 +7,18 @@ import glob import shutil import tenacity import multiprocessing +import logging as log +import sys from tenacity import retry from podop import run_server +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) def start_podop(): os.setuid(100) - run_server(3 if "DEBUG" in os.environ else 0, "postfix", "/tmp/podop.socket", [ + # TODO: Remove verbosity setting from Podop? + run_server(0, "postfix", "/tmp/podop.socket", [ ("transport", "url", "http://admin/internal/postfix/transport/§"), ("alias", "url", "http://admin/internal/postfix/alias/§"), ("domain", "url", "http://admin/internal/postfix/domain/§"), @@ -23,11 +27,24 @@ def start_podop(): ("senderlogin", "url", "http://admin/internal/postfix/sender/login/§") ]) -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) + +@retry( + stop=tenacity.stop_after_attempt(100), + wait=tenacity.wait_random(min=2, max=5), + before=tenacity.before_log(log.getLogger("tenacity.retry"), log.DEBUG), + before_sleep=tenacity.before_sleep_log(log.getLogger("tenacity.retry"), log.INFO), + after=tenacity.after_log(log.getLogger("tenacity.retry"), log.DEBUG) + ) +def resolve(hostname): + logger = log.getLogger("resolve()") + logger.info(hostname) + return socket.gethostbyname(hostname) # Actual startup script -resolve = retry(socket.gethostbyname, stop=tenacity.stop_after_attempt(100), wait=tenacity.wait_random(min=2, max=5)) - os.environ["FRONT_ADDRESS"] = resolve(os.environ.get("FRONT_ADDRESS", "front")) os.environ["HOST_ANTISPAM"] = os.environ.get("HOST_ANTISPAM", "antispam:11332") os.environ["HOST_LMTP"] = os.environ.get("HOST_LMTP", "imap:2525") diff --git a/docs/compose/.env b/docs/compose/.env index 836e9dbf..f65c2f01 100644 --- a/docs/compose/.env +++ b/docs/compose/.env @@ -151,3 +151,6 @@ REAL_IP_FROM= # choose wether mailu bounces (no) or rejects (yes) mail when recipient is unknown (value: yes, no) REJECT_UNLISTED_RECIPIENT= + +# Log level threshold in start.py (value: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOTSET) +LOG_LEVEL=WARNING diff --git a/docs/configuration.rst b/docs/configuration.rst index b8f2a90c..ec114c97 100644 --- a/docs/configuration.rst +++ b/docs/configuration.rst @@ -91,6 +91,13 @@ The ``PASSWORD_SCHEME`` is the password encryption scheme. You should use the default value, unless you are importing password from a separate system and want to keep using the old password encryption scheme. +The ``LOG_LEVEL`` setting is used by the python start-up scripts as a logging threshold. +Log messages equal or higher than this priority will be printed. +Can be one of: CRITICAL, ERROR, WARNING, INFO, DEBUG or NOTSET. +See the `python docs`_ for more information. + +.. _`python docs`: https://docs.python.org/3.6/library/logging.html#logging-levels + Infrastructure settings ----------------------- diff --git a/optional/clamav/start.py b/optional/clamav/start.py index d4701d2d..56e1bcfe 100755 --- a/optional/clamav/start.py +++ b/optional/clamav/start.py @@ -1,12 +1,21 @@ #!/usr/bin/python3 import os +import logging as log +import sys + +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) +logger=log.getLogger(__name__) # Bootstrap the database if clamav is running for the first time -os.system("[ -f /data/main.cvd ] || freshclam") +if not os.path.isfile("/data/main.cvd"): + logger.info("Starting primary virus DB download") + os.system("freshclam") # Run the update daemon +logger.info("Starting the update daemon") os.system("freshclam -d -c 6") # Run clamav +logger.info("Starting clamav") os.system("clamd") diff --git a/services/rspamd/start.py b/services/rspamd/start.py index 0b3c48a8..744d4a9c 100755 --- a/services/rspamd/start.py +++ b/services/rspamd/start.py @@ -5,13 +5,31 @@ import os import socket import glob import tenacity +import logging as log +import sys + from tenacity import retry -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) + +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) + +@retry( + stop=tenacity.stop_after_attempt(100), + wait=tenacity.wait_random(min=2, max=5), + before=tenacity.before_log(log.getLogger("tenacity.retry"), log.DEBUG), + before_sleep=tenacity.before_sleep_log(log.getLogger("tenacity.retry"), log.INFO), + after=tenacity.after_log(log.getLogger("tenacity.retry"), log.DEBUG) + ) +def resolve(hostname): + logger = log.getLogger("resolve()") + logger.info(hostname) + return socket.gethostbyname(hostname) # Actual startup script -resolve = retry(socket.gethostbyname, stop=tenacity.stop_after_attempt(100), wait=tenacity.wait_random(min=2, max=5)) - os.environ["FRONT_ADDRESS"] = resolve(os.environ.get("FRONT_ADDRESS", "front")) if "HOST_REDIS" not in os.environ: os.environ["HOST_REDIS"] = "redis" diff --git a/services/unbound/start.py b/services/unbound/start.py index 6f494762..4dd5f3be 100755 --- a/services/unbound/start.py +++ b/services/unbound/start.py @@ -2,8 +2,16 @@ import jinja2 import os +import logging as log +import sys + +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) + +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) convert("/unbound.conf", "/etc/unbound/unbound.conf") os.execv("/usr/sbin/unbound", ["-c /etc/unbound/unbound.conf"]) diff --git a/setup/flavors/compose/mailu.env b/setup/flavors/compose/mailu.env index 6bdc5e21..2d2b8735 100644 --- a/setup/flavors/compose/mailu.env +++ b/setup/flavors/compose/mailu.env @@ -160,3 +160,6 @@ REAL_IP_FROM={{ real_ip_from }} # choose wether mailu bounces (no) or rejects (yes) mail when recipient is unknown (value: yes, no) REJECT_UNLISTED_RECIPIENT={{ reject_unlisted_recipient }} + +# Log level threshold in start.py (value: CRITICAL, ERROR, WARNING, INFO, DEBUG, NOTSET) +LOG_LEVEL=WARNING diff --git a/webmails/rainloop/start.py b/webmails/rainloop/start.py index 4c116e09..e2b917bf 100755 --- a/webmails/rainloop/start.py +++ b/webmails/rainloop/start.py @@ -3,8 +3,15 @@ import jinja2 import os import shutil +import logging as log +import sys -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) + +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) # Actual startup script os.environ["FRONT_ADDRESS"] = os.environ.get("FRONT_ADDRESS", "front") diff --git a/webmails/roundcube/start.py b/webmails/roundcube/start.py index 3a0bd0bc..4effd965 100755 --- a/webmails/roundcube/start.py +++ b/webmails/roundcube/start.py @@ -2,8 +2,15 @@ import os import jinja2 +import logging as log +import sys -convert = lambda src, dst: open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) +log.basicConfig(stream=sys.stderr, level=os.environ.get("LOG_LEVEL", "WARNING")) + +def convert(src, dst): + logger = log.getLogger("convert()") + logger.debug("Source: %s, Destination: %s", src, dst) + open(dst, "w").write(jinja2.Template(open(src).read()).render(**os.environ)) os.environ["MAX_FILESIZE"] = str(int(int(os.environ.get("MESSAGE_SIZE_LIMIT"))*0.66/1048576)) @@ -14,4 +21,4 @@ os.system("mkdir -p /data/gpg") os.system("chown -R www-data:www-data /data") # Run apache -os.execv("/usr/local/bin/apache2-foreground", ["apache2-foreground"]) \ No newline at end of file +os.execv("/usr/local/bin/apache2-foreground", ["apache2-foreground"])