summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorJose M. Guisado <jguisado@soleta.eu>2022-06-06 14:45:41 +0200
committerJose M. Guisado <jguisado@soleta.eu>2022-06-08 10:27:06 +0200
commit30fdcceea3efbd264b00d78fb0f86fd5a2ff8831 (patch)
treece0f5c1cf19fd19049ee5d51bdb8137c1bc974b2
parent1ab981a539f3553021b3cf1642619338f2782af1 (diff)
src: improve logging
Adds new logging handler redirecting messages to the log file located in the Samba shared directory (applies to live mode clients, i.e: ogLive) Parses log level configuration from ogclient.json. See: { "opengnsys": { ... "log": "INFO", ... } ... } Adds --debug option to set root logger level to DEBUG when starting ogClient. Overrides log level from config file. In addition: - Replaces any occurence of print with a corresponding logging function. - Unsets log level for handlers, use root logger level instead. - Default level for root logger is INFO. - Replaces level from response log messages to debug (ogRest)
-rw-r--r--cfg/ogclient.json2
-rwxr-xr-xogclient10
-rw-r--r--src/live/ogOperations.py27
-rw-r--r--src/log.py40
-rw-r--r--src/ogClient.py19
-rw-r--r--src/ogRest.py4
-rw-r--r--src/restRequest.py6
-rw-r--r--src/utils/cache.py3
-rw-r--r--src/virtual/poweroffd.py9
9 files changed, 93 insertions, 27 deletions
diff --git a/cfg/ogclient.json b/cfg/ogclient.json
index 1a43d1b..b1f1f43 100644
--- a/cfg/ogclient.json
+++ b/cfg/ogclient.json
@@ -2,7 +2,7 @@
"opengnsys": {
"ip": "127.0.0.1",
"port": 8889,
- "log": "DEBUG",
+ "log": "INFO",
"mode": "live",
"url": "https://127.0.0.1/opengnsys/varios/menubrowser.php",
"url_log": "http://localhost/cgi-bin/httpd-log.sh"
diff --git a/ogclient b/ogclient
index be7a7f1..8798ed6 100755
--- a/ogclient
+++ b/ogclient
@@ -46,6 +46,9 @@ def create_parser():
parser.add_argument('-c', '--config', default="",
help='ogClient JSON config file path')
+ parser.add_argument('--debug', default=False,
+ action='store_true',
+ help='enables debug log level')
return parser
@@ -73,12 +76,17 @@ def main():
MODE = CONFIG['opengnsys']['mode']
URL = CONFIG['opengnsys']['url']
+ LOGLEVEL = CONFIG['opengnsys']['log']
+
if MODE == 'live':
proc = subprocess.Popen(["browser", "-qws", URL])
if MODE != 'windows':
signal.signal(SIGPIPE, SIG_DFL)
- configure_logging(MODE)
+ configure_logging(MODE, LOGLEVEL)
+
+ if args.debug:
+ logging.getLogger().setLevel('DEBUG')
client = ogClient(config=CONFIG)
client.connect()
diff --git a/src/live/ogOperations.py b/src/live/ogOperations.py
index efdc813..5533312 100644
--- a/src/live/ogOperations.py
+++ b/src/live/ogOperations.py
@@ -6,6 +6,7 @@
# Free Software Foundation; either version 3 of the License, or
# (at your option) any later version.
+import logging
import os
import subprocess
@@ -115,6 +116,7 @@ class OgLiveOperations:
return parsed
def poweroff(self):
+ logging.info('Powering off client')
if os.path.exists('/scripts/oginit'):
cmd = f'source {ogClient.OG_PATH}etc/preinit/loadenviron.sh; ' \
f'{ogClient.OG_PATH}scripts/poweroff'
@@ -123,6 +125,7 @@ class OgLiveOperations:
subprocess.call(['/sbin/poweroff'])
def reboot(self):
+ logging.info('Rebooting client')
if os.path.exists('/scripts/oginit'):
cmd = f'source {ogClient.OG_PATH}etc/preinit/loadenviron.sh; ' \
f'{ogClient.OG_PATH}scripts/reboot'
@@ -143,8 +146,14 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running "shell run" subprocess')
raise ValueError('Error: Incorrect command value')
+ if ogRest.proc.returncode != 0:
+ logging.warn('Non zero exit code when running: %s', ' '.join(cmds))
+ else:
+ logging.info('Shell run command OK')
+
self.refresh(ogRest)
return output.decode('utf-8')
@@ -161,8 +170,10 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running session subprocess')
raise ValueError('Error: Incorrect command value')
+ logging.info('Starting OS at disk %s partition %s', disk, partition)
return output.decode('utf-8')
def software(self, request, path, ogRest):
@@ -181,6 +192,7 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running software inventory subprocess')
raise ValueError('Error: Incorrect command value')
self._restartBrowser(self._url)
@@ -188,6 +200,8 @@ class OgLiveOperations:
software = ''
with open(path, 'r') as f:
software = f.read()
+
+ logging.info('Software inventory command OK')
return software
def hardware(self, path, ogRest):
@@ -201,10 +215,12 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running hardware inventory subprocess')
raise ValueError('Error: Incorrect command value')
self._restartBrowser(self._url)
+ logging.info('Hardware inventory command OK')
return output.decode('utf-8')
def setup(self, request, ogRest):
@@ -231,8 +247,10 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running setup subprocess')
raise ValueError('Error: Incorrect command value')
+ logging.info('Setup command OK')
result = self.refresh(ogRest)
return result
@@ -259,10 +277,12 @@ class OgLiveOperations:
if (ogRest.proc.returncode):
raise Exception
except:
+ logging.error('Exception when running image restore subprocess')
raise ValueError('Error: Incorrect command value')
self.refresh(ogRest)
+ logging.info('Image restore command OK')
return output.decode('utf-8')
def image_create(self, path, request, ogRest):
@@ -284,6 +304,7 @@ class OgLiveOperations:
executable=OG_SHELL)
(output, error) = ogRest.proc.communicate()
except:
+ logging.error('Exception when running software inventory subprocess')
raise ValueError('Error: Incorrect command value')
if ogRest.terminated:
@@ -296,9 +317,11 @@ class OgLiveOperations:
executable=OG_SHELL)
ogRest.proc.communicate()
except:
+ logging.error('Exception when running "image create" subprocess')
raise ValueError('Error: Incorrect command value')
if ogRest.proc.returncode != 0:
+ logging.warn('Image creation failed')
raise ValueError('Error: Image creation failed')
with open('/tmp/image.info') as file_info:
@@ -316,6 +339,7 @@ class OgLiveOperations:
self._restartBrowser(self._url)
+ logging.info('Image creation command OK')
return image_info
def refresh(self, ogRest):
@@ -332,7 +356,7 @@ class OgLiveOperations:
}
for num_disk, disk in enumerate(get_disks(), start=1):
- print(disk)
+ logging.debug('refresh: processing %s', disk)
part_setup = {}
try:
cxt = fdisk.Context(device=f'/dev/{disk}')
@@ -352,6 +376,7 @@ class OgLiveOperations:
generate_cache_txt()
self._restartBrowser(self._url)
+ logging.info('Sending response to refresh request')
return parsed
def probe(self, ogRest):
diff --git a/src/log.py b/src/log.py
index 9d379eb..bf00c71 100644
--- a/src/log.py
+++ b/src/log.py
@@ -1,5 +1,8 @@
import logging
import logging.config
+import os
+
+from src.utils.net import getifaddr
DEFAULT_LOGGING_LINUX = {
'version': 1,
@@ -15,25 +18,34 @@ DEFAULT_LOGGING_LINUX = {
'format': '[{levelname}] - {message}',
'style': '{',
},
+ 'formatter.syslogtime': {
+ '()': 'logging.Formatter',
+ 'datefmt': '%Y-%m-%d %H:%M:%S',
+ 'format': '({asctime}) ogClient: [{levelname}] - {message}',
+ 'style': '{',
+ },
},
'handlers': {
'console': {
- 'level': 'INFO',
'class': 'logging.StreamHandler',
'formatter': 'formatter.console',
'stream': 'ext://sys.stdout',
},
'syslog': {
- 'level': 'DEBUG',
'class': 'logging.handlers.SysLogHandler',
'formatter': 'formatter.syslog',
'address': '/dev/log',
},
+ 'samba': {
+ 'class': 'logging.FileHandler',
+ 'formatter': 'formatter.syslogtime',
+ 'filename': f'/opt/opengnsys/log/{getifaddr(os.getenv("DEVICE"))}.log',
+ },
},
'loggers': {
'': {
'handlers': ['syslog', 'console'],
- 'level': 'DEBUG',
+ 'level': 'INFO',
},
}
}
@@ -64,9 +76,23 @@ DEFAULT_LOGGING_WIN = {
}
}
-def configure_logging(mode):
+def configure_logging(mode, level):
+ """
+ Receives a ogClient operating mode.
+
+ Configures the default logger according to the operating mode.
+
+ For example, in the case of running live mode it will activate
+ logging to the expected samba shared log file ({ip}.txt.log).
+ """
if mode == 'windows':
- DEFAULT_LOGGING = DEFAULT_LOGGING_WIN
+ logconfig = DEFAULT_LOGGING_WIN
else:
- DEFAULT_LOGGING = DEFAULT_LOGGING_LINUX
- logging.config.dictConfig(DEFAULT_LOGGING)
+ logconfig = DEFAULT_LOGGING_LINUX
+
+ if mode == 'live':
+ logconfig['loggers']['']['handlers'].append('samba')
+
+ logconfig['loggers']['']['level'] = level
+
+ logging.config.dictConfig(logconfig)
diff --git a/src/ogClient.py b/src/ogClient.py
index 67e0d51..04b6d01 100644
--- a/src/ogClient.py
+++ b/src/ogClient.py
@@ -11,6 +11,7 @@ import select
import socket
import time
import email
+import logging
from io import StringIO
from src.restRequest import *
@@ -30,6 +31,7 @@ class ogClient:
self.mode = self.CONFIG['opengnsys']['mode']
if self.mode not in {'virtual', 'live', 'linux', 'windows'}:
+ logging.critical('Invalid ogClient mode')
raise ValueError('Mode not supported.')
if self.mode in {'linux', 'windows'}:
self.event_sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
@@ -58,19 +60,20 @@ class ogClient:
def send_event_hint(self, message):
try:
event, action, user = message.split(" ")
- logging.warning("%s, %s, %s", event, action, user)
+ logging.debug('Sending event: %s, %s, %s', event, action, user)
except:
- logging.warning("Error parsing session datagram")
+ logging.warning('Error parsing session datagram')
return
if (event != "session" or
action not in ['start', 'stop'] or
not user):
- logging.warning("Invalid value in session datagram: %s", message)
+ logging.warning('Invalid value in session datagram: %s', message)
payload = jsonBody({'event': event, 'action': action, 'user': user})
response = restResponse(ogResponses.EARLY_HINTS, payload)
self.send(response.get())
+ logging.debug('Sending event OK')
def cleanup(self):
self.data = ""
@@ -79,7 +82,7 @@ class ogClient:
self.trailer = False
def connect(self):
- print('connecting...')
+ logging.debug('Connecting...')
self.sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
self.sock.setblocking(0)
self.sock.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1)
@@ -107,11 +110,11 @@ class ogClient:
self.sock.connect((self.ip, self.port))
except socket.error as err:
if err.errno == errno.EISCONN:
- print('connected')
+ logging.debug('Connected')
self.state = State.RECEIVING
else:
time.sleep(1)
- print('connection refused, retrying...')
+ logging.warning('Connection refused, retrying...')
self.state = State.CONNECTING
self.sock.close()
self.connect()
@@ -121,7 +124,7 @@ class ogClient:
data = self.sock.recv(1024).decode('utf-8')
except socket.error as err:
data = ''
- print('failed to received ' + str(err))
+ logging.warning('Receive failed: %s', str(err))
if len(data) == 0:
self.sock.close()
@@ -185,4 +188,4 @@ class ogClient:
message = event_sock.recv(4096).decode('utf-8').rstrip()
self.send_event_hint(message)
else:
- print('wrong state, not ever happen!' + str(state))
+ logging.critical('Invalid state: %s', str(state))
diff --git a/src/ogRest.py b/src/ogRest.py
index 0207af0..8e54612 100644
--- a/src/ogRest.py
+++ b/src/ogRest.py
@@ -60,7 +60,7 @@ class restResponse():
return self.msg
if response in {ogResponses.OK, ogResponses.IN_PROGRESS}:
- LOGGER.info(self.msg[:ogRest.LOG_LENGTH])
+ LOGGER.debug(self.msg[:ogRest.LOG_LENGTH])
else:
LOGGER.warn(self.msg[:ogRest.LOG_LENGTH])
@@ -281,7 +281,7 @@ class ogRest():
method = request.get_method()
URI = request.get_uri()
- LOGGER.debug('%s%s', method, URI[:ogRest.LOG_LENGTH])
+ LOGGER.debug('Incoming request: %s%s', method, URI[:ogRest.LOG_LENGTH])
if (not "stop" in URI and
not "reboot" in URI and
diff --git a/src/restRequest.py b/src/restRequest.py
index 9a9c624..61d64c6 100644
--- a/src/restRequest.py
+++ b/src/restRequest.py
@@ -7,8 +7,10 @@
# (at your option) any later version.
import email
-from io import StringIO
import json
+import logging
+
+from io import StringIO
class restRequest:
def __init__(self):
@@ -57,7 +59,7 @@ class restRequest:
try:
json_param = json.loads(body)
except ValueError as e:
- print ("Error: Json message incomplete")
+ logging.error("JSON message incomplete")
return
if "run" in json_param:
diff --git a/src/utils/cache.py b/src/utils/cache.py
index 150a5df..3bd4053 100644
--- a/src/utils/cache.py
+++ b/src/utils/cache.py
@@ -6,6 +6,7 @@
# Free Software Foundation; either version 3 of the License, or
# (at your option) any later version.
+import logging
import os
from src.utils.fs import mount_mkdir, umount
@@ -45,7 +46,7 @@ def write_cache_txt(content):
"""
client_ip = getifaddr(os.getenv('DEVICE'))
with open(OGCLIENT_LOG_CACHE.format(ip=client_ip), 'w') as f:
- print("About to write")
+ logging.debug('Writing cache contents to %s.cache.txt', client_ip)
f.write(content)
def generate_cache_txt():
diff --git a/src/virtual/poweroffd.py b/src/virtual/poweroffd.py
index 63d08e1..83adee1 100644
--- a/src/virtual/poweroffd.py
+++ b/src/virtual/poweroffd.py
@@ -6,6 +6,7 @@
# Free Software Foundation; either version 3 of the License, or
# (at your option) any later version.
+import logging
from src.virtual.qmp import QEMUMonitorProtocol
from src.virtual.qmp import QMPCapabilitiesError, QMPConnectError
@@ -26,10 +27,10 @@ def init(host=QMP_DEFAULT_HOST, port=QMP_DEFAULT_PORT):
try:
qmpconn.connect()
except ConnectionRefusedError:
- print("Critical err: Connection refused")
+ logging.critical('poweroffd: Connection refused')
return None
except QMPCapabilitiesError as e:
- print("Error negotiating capabilities")
+ logging.critical('poweroffd: Error negotiating capabilities')
return None
return qmpconn
@@ -41,11 +42,11 @@ def run(qmpconn):
try:
qmp_ev = qmpconn.pull_event(wait=True)
except QMPConnectError as e:
- print("Error trying to pull an event")
+ logging.critical('Error trying to pull an event')
ret = -1
break
if is_shutdown_event(qmp_ev):
- print("Detected guest shutdown, let's go")
+ logging.info('Detected guest shutdown, powering off')
ret = 0
break