add proper logger to entrypoint and start

docker/entrypoint.py

@@ -3,31 +3,43 @@
 # Need root privileges to change timezone, and user uid/gid, file/folder ownernship
 
 import grp
+import logging
 import os
 import pwd
 import subprocess
+import sys
 
 PYTHON3 = '/usr/bin/python3'
 dbPath = os.path.join(os.sep, 'home', 'py-kms', 'db', 'pykms_database.db')
 log_level = os.getenv('LOGLEVEL', 'INFO')
 
+loggersrv = logging.getLogger('logsrv')
+loggersrv.setLevel(log_level)
+streamhandler = logging.StreamHandler(sys.stdout)
+streamhandler.setLevel(log_level)
+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():
   user_db_entries = pwd.getpwnam("py-kms")
   user_grp_db_entries = grp.getgrnam("power_users")
-  uid = user_db_entries.pw_uid
+  uid = int(user_db_entries.pw_uid)
-  gid = user_grp_db_entries.gr_gid
+  gid = int(user_grp_db_entries.gr_gid)
   new_gid = int(os.getenv('GID', str(gid)))
   new_uid = int(os.getenv('UID', str(uid)))
   os.chown("/home/py-kms", new_uid, new_gid)
   os.chown("/usr/bin/start.py", new_uid, new_gid)
   if os.path.isfile(dbPath): os.chown(dbPath, new_uid, new_gid)
-  os.system("ls -al /usr/bin/start.py")
+  loggersrv.debug("%s" %str(subprocess.check_output("ls -al " + dbPath, shell=True)))
   if gid != new_gid:
-    print("Setting gid to " + str(new_gid))
+    loggersrv.info("Setting gid to '%s'." % str(new_gid))
     os.setgid(gid)
+
   if uid != new_uid:
-    print("Setting uid to " + str(new_uid))
+    loggersrv.info("Setting uid to '%s'." % str(new_uid))
     os.setuid(uid)
 
 
@@ -35,12 +47,13 @@ def change_tz():
   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):
-    print("Setting timezone to " + tz)
+    loggersrv.info("Setting timzeone to %s" % tz )
     os.remove('/etc/localtime')
     os.symlink(os.path.join('/usr/share/zoneinfo/', tz), '/etc/localtime')
 
 
 # Main
 if (__name__ == "__main__"):
+  loggersrv.info("Log level: %s" % log_level)
   change_tz()
   subprocess.call(PYTHON3 + " -u /usr/bin/start.py", preexec_fn=change_uid_grp(), shell=True)

docker/start.py

@@ -1,8 +1,10 @@
 #!/usr/bin/python3 -u
 
 # This replaces the old start.sh and ensures all arguments are bound correctly from the environment variables...
+import logging
 import os
 import subprocess
+import sys
 import time
 
 PYTHON3 = '/usr/bin/python3'
@@ -27,50 +29,45 @@ log_level = os.getenv('LOGLEVEL', 'INFO')
 def start_kms_client():
   if not os.path.isfile(dbPath):
     # Start a dummy activation to ensure the database file is created
-    client_cmd = [PYTHON3,'-u', 'pykms_Client.py', os.environ.get('IP', "0.0.0.0"), os.environ.get('PORT', 1688),
+    client_cmd = [PYTHON3, '-u', 'pykms_Client.py', os.environ.get('IP', "0.0.0.0"), os.environ.get('PORT', 1688),
                   '-m', 'Windows10', '-n', 'DummyClient', '-c', 'ae3a27d1-b73a-4734-9878-70c949815218',
                   '-V', os.environ.get('LOGLEVEL', 'INFO'), '-F', os.environ.get('LOGFILE', 'STDOUT')]
     if os.environ.get('LOGSIZE', '') != "":
       client_cmd.append('-S')
       client_cmd.append(os.environ.get('LOGSIZE'))
 
-    if log_level.lower() in ['info', 'debug']:
+    loggersrv.info("Starting a dummy activation to ensure the database file is created")
-      print("Starting a dummy activation to ensure the database file is created")
+    loggersrv.debug("client_cmd: %s" % (" ".join(str(x) for x in client_cmd).strip()))
-    if log_level.lower() == 'debug':
-      print("client_cmd: " + str(client_cmd))
 
     subprocess.run(client_cmd)
 
 
 def start_kms():
+  sqlite_process = None
   # Build the command to execute
-  command = [PYTHON3,'-u', 'pykms_Server.py', os.environ.get('IP'), os.environ.get('PORT')]
+  command = [PYTHON3, '-u', 'pykms_Server.py', os.environ.get('IP'), os.environ.get('PORT')]
   for (arg, env) in argumentVariableMapping.items():
     if env in os.environ and os.environ.get(env) != '':
       command.append(arg)
       command.append(os.environ.get(env))
 
   if enableSQLITE:
-    print('Storing database file to ' + dbPath)
+    loggersrv.info("Storing database file to %s" % dbPath)
     command.append('-s')
     command.append(dbPath)
 
-  if log_level.lower() == 'debug':
+  loggersrv.debug("server_cmd: %s" % (" ".join(str(x) for x in command).strip()))
-    print("server_cmd: " + str(command))
-
   pykms_process = subprocess.Popen(command)
 
   # In case SQLITE is defined: Start the web interface
   if enableSQLITE:
     time.sleep(5)  # The server may take a while to start
-    os.system('ls -al ' + dbPath)
     start_kms_client()
-    sqlite_cmd = [PYTHON3,'-u', '/home/sqlite_web/sqlite_web.py', '-H', os.environ.get('IP'), '--read-only', '-x', dbPath,
+    sqlite_cmd = [PYTHON3, '-u', '/home/sqlite_web/sqlite_web.py', '-H', os.environ.get('IP'), '--read-only', '-x',
+                  dbPath,
                   '-p', os.environ.get('SQLITE_PORT')]
 
-    if log_level.lower() == 'debug':
+    loggersrv.debug("sqlite_cmd: %s" % (" ".join(str(x) for x in sqlite_cmd).strip()))
-      print("sqlite_cmd: " + str(sqlite_cmd))
-
     sqlite_process = subprocess.Popen(sqlite_cmd)
 
   try:
@@ -80,10 +77,18 @@ def start_kms():
     pass
 
   if enableSQLITE:
-    sqlite_process.terminate()
+    if None != sqlite_process: sqlite_process.terminate()
     pykms_process.terminate()
 
 
 # Main
 if (__name__ == "__main__"):
+  loggersrv = logging.getLogger('logsrv')
+  loggersrv.setLevel(log_level)
+  streamhandler = logging.StreamHandler(sys.stdout)
+  streamhandler.setLevel(log_level)
+  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)
   start_kms()