Fixed healthcheck for classic (non Kubernetes) Docker (broken with default-ipv6 "::" listen ip) #89

Added multi-ip healthcheck support
Cleanup of logging inside container-scripts
Removed "nc" from containers

docker/docker-py3-kms-minimal/Dockerfile

@@ -22,7 +22,6 @@ bash \
   ca-certificates \
   shadow \
   tzdata \
-  netcat-openbsd \
   && pip3 install --no-cache-dir -r /home/py-kms/requirements.txt \
   && adduser -S py-kms -G users -s /bin/bash \
   && chown py-kms:users /home/py-kms \
@@ -31,14 +30,14 @@ bash \
 
 COPY ./py-kms /home/py-kms
 COPY docker/entrypoint.py /usr/bin/entrypoint.py
+COPY docker/healthcheck.py /usr/bin/healthcheck.py
 COPY docker/start.py /usr/bin/start.py
-
-RUN chmod 755 /usr/bin/entrypoint.py
+RUN chmod 555 /usr/bin/entrypoint.py /usr/bin/healthcheck.py /usr/bin/start.py
 
 WORKDIR /home/py-kms
 
 EXPOSE ${PORT}/tcp
 
-HEALTHCHECK --interval=5m --timeout=3s --start-period=10s --retries=4 CMD echo | nc -z ${IP%% *} ${PORT} || exit 1
+HEALTHCHECK --interval=5m --timeout=10s --start-period=10s --retries=3 CMD /usr/bin/python3 /usr/bin/healthcheck.py
 
 ENTRYPOINT ["/usr/bin/python3", "-u", "/usr/bin/entrypoint.py"]

docker/docker-py3-kms/Dockerfile

@@ -27,7 +27,6 @@ RUN apk add --no-cache --update \
   ca-certificates \
   tzdata \
   shadow \
-  netcat-openbsd \
   && pip3 install --no-cache-dir -r /home/py-kms/requirements.txt \
   #&& apk del git build-base python3-dev \
   && mkdir /db/ \
@@ -38,19 +37,19 @@ RUN apk add --no-cache --update \
 
 COPY py-kms /home/py-kms/
 COPY docker/entrypoint.py /usr/bin/entrypoint.py
+COPY docker/healthcheck.py /usr/bin/healthcheck.py
 COPY docker/start.py /usr/bin/start.py
+RUN chmod 555 /usr/bin/entrypoint.py /usr/bin/healthcheck.py /usr/bin/start.py
 
 # Web-interface specifics
 COPY LICENSE /LICENSE
 RUN echo "$BUILD_COMMIT" > /VERSION && echo "$BUILD_BRANCH" >> /VERSION
 
-RUN chmod 755 /usr/bin/entrypoint.py
-
 WORKDIR /home/py-kms
 
 EXPOSE ${PORT}/tcp
 EXPOSE 8080/tcp
 
-HEALTHCHECK --interval=5m --timeout=3s --start-period=10s --retries=4 CMD echo | nc -z ${IP%% *} ${PORT} || exit 1
+HEALTHCHECK --interval=5m --timeout=10s --start-period=10s --retries=3 CMD /usr/bin/python3 /usr/bin/healthcheck.py
 
 ENTRYPOINT [ "/usr/bin/python3", "-u", "/usr/bin/entrypoint.py" ]

docker/entrypoint.py

@@ -13,22 +13,10 @@ import time
 
 PYTHON3 = '/usr/bin/python3'
 dbPath = os.path.join(os.sep, 'home', 'py-kms', 'db') # Do not include the database file name, as we must correct the folder permissions (the db file is recursively reachable)
-log_level_bootstrap = log_level = os.getenv('LOGLEVEL', 'INFO')
-if log_level_bootstrap == "MININFO":
-  log_level_bootstrap = "INFO"
-loggersrv = logging.getLogger('logsrv')
-loggersrv.setLevel(log_level_bootstrap)
-streamhandler = logging.StreamHandler(sys.stdout)
-streamhandler.setLevel(log_level_bootstrap)
-formatter = logging.Formatter(fmt = '\x1b[94m%(asctime)s %(levelname)-8s %(message)s',
-                              datefmt = '%a, %d %b %Y %H:%M:%S',)
-streamhandler.setFormatter(formatter)
-loggersrv.addHandler(streamhandler)
 
-
-def change_uid_grp():
+def change_uid_grp(logger):
   if os.geteuid() != 0:
-    loggersrv.info(f'not root user, cannot change uid/gid.')
+    logger.info(f'not root user, cannot change uid/gid.')
     return None
   user_db_entries = pwd.getpwnam("py-kms")
   user_grp_db_entries = grp.getgrnam("users")
@@ -40,43 +28,52 @@ def change_uid_grp():
   os.chown("/usr/bin/start.py", new_uid, new_gid)
   if os.path.isdir(dbPath):
     # Corret permissions recursively, as to access the database file, also its parent folder must be accessible
-    loggersrv.debug(f'Correcting owner permissions on {dbPath}.')
+    logger.debug(f'Correcting owner permissions on {dbPath}.')
     os.chown(dbPath, new_uid, new_gid)
     for root, dirs, files in os.walk(dbPath):
       for dName in dirs:
         dPath = os.path.join(root, dName)
-        loggersrv.debug(f'Correcting owner permissions on {dPath}.')
+        logger.debug(f'Correcting owner permissions on {dPath}.')
         os.chown(dPath, new_uid, new_gid)
       for fName in files:
         fPath = os.path.join(root, fName)
-        loggersrv.debug(f'Correcting owner permissions on {fPath}.')
+        logger.debug(f'Correcting owner permissions on {fPath}.')
         os.chown(fPath, new_uid, new_gid)
-    loggersrv.debug(subprocess.check_output(['ls', '-la', dbPath]).decode())
+    logger.debug(subprocess.check_output(['ls', '-la', dbPath]).decode())
   if 'LOGFILE' in os.environ and os.path.exists(os.environ['LOGFILE']):
     # Oh, the user also wants a custom log file -> make sure start.py can access it by setting the correct permissions (777)
     os.chmod(os.environ['LOGFILE'], 0o777)
-    loggersrv.error(str(subprocess.check_output(['ls', '-la', os.environ['LOGFILE']])))
-  loggersrv.info("Setting gid to '%s'." % str(new_gid))
+    logger.error(str(subprocess.check_output(['ls', '-la', os.environ['LOGFILE']])))
+  logger.info("Setting gid to '%s'." % str(new_gid))
   os.setgid(new_gid)
 
-  loggersrv.info("Setting uid to '%s'." % str(new_uid))
+  logger.info("Setting uid to '%s'." % str(new_uid))
   os.setuid(new_uid)
 
-
-def change_tz():
+def change_tz(logger):
   tz = os.getenv('TZ', 'etc/UTC')
   # TZ is not symlinked and defined TZ exists
   if tz not in os.readlink('/etc/localtime') and os.path.isfile('/usr/share/zoneinfo/' + tz) and hasattr(time, 'tzset'):
-    loggersrv.info("Setting timzeone to %s" % tz )
+    logger.info("Setting timzeone to %s" % tz )
     # time.tzet() should be called on Unix, but doesn't exist on Windows.
     time.tzset()
 
-# Main
-if (__name__ == "__main__"):
+if __name__ == "__main__":
+  log_level_bootstrap = log_level = os.getenv('LOGLEVEL', 'INFO')
+  if log_level_bootstrap == "MININFO":
+    log_level_bootstrap = "INFO"
+  loggersrv = logging.getLogger('entrypoint.py')
+  loggersrv.setLevel(log_level_bootstrap)
+  streamhandler = logging.StreamHandler(sys.stdout)
+  streamhandler.setLevel(log_level_bootstrap)
+  formatter = logging.Formatter(fmt = '\x1b[94m%(asctime)s %(levelname)-8s %(message)s', datefmt = '%a, %d %b %Y %H:%M:%S',)
+  streamhandler.setFormatter(formatter)
+  loggersrv.addHandler(streamhandler)
   loggersrv.info("Log level: %s" % log_level)
   loggersrv.debug("user id: %s" % os.getuid())
-  change_tz()
-  childProcess = subprocess.Popen(PYTHON3 + " -u /usr/bin/start.py", preexec_fn=change_uid_grp(), shell=True)
+
+  change_tz(loggersrv)
+  childProcess = subprocess.Popen(PYTHON3 + " -u /usr/bin/start.py", preexec_fn=change_uid_grp(loggersrv), shell=True)
   def shutdown(signum, frame):
     loggersrv.info("Received signal %s, shutting down..." % signum)
     childProcess.terminate() # This will also cause communicate() from below to continue

docker/healthcheck.py

@@ -0,0 +1,37 @@
+#!/usr/bin/python3 -u
+import os
+import sys
+import logging
+
+def do_check(logger):
+  import socket
+  listen_ip = os.environ.get('IP', '::').split()
+  listen_ip.insert(0, '127.0.0.1') # always try to connect to localhost first
+  listen_port = os.environ.get('PORT', '1688')
+  for ip in listen_ip:
+    try:
+      s = socket.socket(socket.AF_INET6 if ':' in ip else socket.AF_INET, socket.SOCK_STREAM)
+      s.settimeout(1) # 1 second timeout
+      address = ip if ':' in ip else (ip, int(listen_port))
+      logger.debug(f"Trying to connect to {address}...")
+      s.connect(address)
+      s.close()
+      return True
+    except:
+      pass
+  return False # no connection could be established
+
+
+if __name__ == '__main__':
+  log_level_bootstrap = log_level = os.getenv('LOGLEVEL', 'INFO')
+  if log_level_bootstrap == "MININFO":
+    log_level_bootstrap = "INFO"
+  loggersrv = logging.getLogger('healthcheck.py')
+  loggersrv.setLevel(log_level_bootstrap)
+  streamhandler = logging.StreamHandler(sys.stdout)
+  streamhandler.setLevel(log_level_bootstrap)
+  formatter = logging.Formatter(fmt='\x1b[94m%(asctime)s %(levelname)-8s %(message)s', datefmt='%a, %d %b %Y %H:%M:%S')
+  streamhandler.setFormatter(formatter)
+  loggersrv.addHandler(streamhandler)
+  
+  sys.exit(0 if do_check(loggersrv) else 1)

docker/start.py

@@ -21,15 +21,12 @@ argumentVariableMapping = {
 }
 
 db_path = os.path.join(os.sep, 'home', 'py-kms', 'db', 'pykms_database.db')
-log_level_bootstrap = log_level = os.environ.get('LOGLEVEL', 'INFO')
-if log_level_bootstrap == "MININFO":
-  log_level_bootstrap = "INFO"
 log_file = os.environ.get('LOGFILE', 'STDOUT')
 listen_ip = os.environ.get('IP', '::').split()
 listen_port = os.environ.get('PORT', '1688')
 want_webui = os.environ.get('WEBUI', '0') == '1' # if the variable is not provided, we assume the user does not want the webui
 
-def start_kms():
+def start_kms(logger):
   # Make sure the full path to the db exists
   if want_webui and not os.path.exists(os.path.dirname(db_path)):
     os.makedirs(os.path.dirname(db_path), exist_ok=True)
@@ -49,7 +46,7 @@ def start_kms():
       command.append("-n")
       command.append(listen_ip[i] + "," + listen_port)
 
-  loggersrv.debug("server_cmd: %s" % (" ".join(str(x) for x in command).strip()))
+  logger.debug("server_cmd: %s" % (" ".join(str(x) for x in command).strip()))
   pykms_process = subprocess.Popen(command)
   pykms_webui_process = None
 
@@ -63,7 +60,7 @@ def start_kms():
       pykms_webui_env['PYKMS_VERSION_PATH'] = '/VERSION'
       pykms_webui_process = subprocess.Popen(['gunicorn', '--log-level', os.environ.get('LOGLEVEL'), 'pykms_WebUI:app'], env=pykms_webui_env)
   except Exception as e:
-    loggersrv.error("Failed to start webui (ignoring and continuing anyways): %s" % e)
+    logger.error("Failed to start webui (ignoring and continuing anyways): %s" % e)
 
   try:
     pykms_process.wait()
@@ -79,14 +76,17 @@ def start_kms():
 
 
 # Main
-if (__name__ == "__main__"):
-  loggersrv = logging.getLogger('logsrv')
+if __name__ == "__main__":
+  log_level_bootstrap = log_level = os.environ.get('LOGLEVEL', 'INFO')
+  if log_level_bootstrap == "MININFO":
+    log_level_bootstrap = "INFO"
+  loggersrv = logging.getLogger('start.py')
   loggersrv.setLevel(log_level_bootstrap)
   streamhandler = logging.StreamHandler(sys.stdout)
   streamhandler.setLevel(log_level_bootstrap)
-  formatter = logging.Formatter(fmt='\x1b[94m%(asctime)s %(levelname)-8s %(message)s',
-                                datefmt='%a, %d %b %Y %H:%M:%S')
+  formatter = logging.Formatter(fmt='\x1b[94m%(asctime)s %(levelname)-8s %(message)s', datefmt='%a, %d %b %Y %H:%M:%S')
   streamhandler.setFormatter(formatter)
   loggersrv.addHandler(streamhandler)
   loggersrv.debug("user id: %s" % os.getuid())
-  start_kms()
+
+  start_kms(loggersrv)