1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
|
import logging
import queue
import requests
import threading
import time
import urllib3.exceptions
from odoo.addons.hw_drivers.tools import helpers
from odoo.netsvc import DBFormatter
_logger = logging.getLogger(__name__)
IOT_LOG_TO_SERVER_CONFIG_NAME = 'iot_log_to_server' # config name in odoo.conf
class AsyncHTTPHandler(logging.Handler):
"""
Custom logging handler which send IoT logs using asynchronous requests.
To avoid spamming the server, we send logs by batch each X seconds
"""
_MAX_QUEUE_SIZE = 1000
"""Maximum queue size. If a log record is received but the queue if full it will be discarded"""
_MAX_BATCH_SIZE = 50
"""Maximum number of sent logs batched at once. Used to avoid too heavy request. Log records still in the queue will
be handle in future flushes"""
_FLUSH_INTERVAL = 0.5
"""How much seconds it will sleep before checking for new logs to send"""
_REQUEST_TIMEOUT = 0.5
"""Amount of seconds to wait per log to send before timeout"""
_DELAY_BEFORE_NO_SERVER_LOG = 5 * 60 # 5 minutes
"""Minimum delay in seconds before we log a server disconnection.
Used in order to avoid the IoT log file to have a log recorded each _FLUSH_INTERVAL (as this value is very small)"""
def __init__(self, odoo_server_url, active):
"""
:param odoo_server_url: Odoo Server URL
"""
super().__init__()
self._odoo_server_url = odoo_server_url
self._log_queue = queue.Queue(self._MAX_QUEUE_SIZE)
self._flush_thread = None
self._active = None
self._next_disconnection_time = None
self.toggle_active(active)
def toggle_active(self, is_active):
"""
Switch it on or off the handler (depending on the IoT setting) without the need to close/reset it
"""
self._active = is_active
if self._active and self._odoo_server_url:
# Start the thread to periodically flush logs
self._flush_thread = threading.Thread(target=self._periodic_flush, name="ThreadServerLogSender", daemon=True)
self._flush_thread.start()
else:
self._flush_thread and self._flush_thread.join() # let a last flush
def _periodic_flush(self):
odoo_session = requests.Session()
while self._odoo_server_url and self._active: # allow to exit the loop on thread.join
time.sleep(self._FLUSH_INTERVAL)
self._flush_logs(odoo_session)
def _flush_logs(self, odoo_session):
def convert_to_byte(s):
return bytes(s, encoding="utf-8") + b'<log/>\n'
def convert_server_line(log_level, line_formatted):
return convert_to_byte(f"{log_level},{line_formatted}")
def empty_queue():
yield convert_to_byte(f"mac {helpers.get_mac_address()}")
for _ in range(self._MAX_BATCH_SIZE):
# Use a limit to avoid having too heavy requests & infinite loop of the queue receiving new entries
try:
log_record = self._log_queue.get_nowait()
yield convert_server_line(log_record.levelno, self.format(log_record))
except queue.Empty:
break
# Report to the server if the queue is close from saturation
if queue_size >= .8 * self._MAX_QUEUE_SIZE:
log_message = "The IoT {} queue is saturating: {}/{} ({:.2f}%)".format(
self.__class__.__name__, queue_size, self._MAX_QUEUE_SIZE,
100 * queue_size / self._MAX_QUEUE_SIZE)
_logger.warning(log_message) # As we don't log our own logs, this will be part of the IoT logs
# In order to report this to the server (on the current batch) we will append it manually
yield convert_server_line(logging.WARNING, log_message)
queue_size = self._log_queue.qsize() # This is an approximate value
if not self._odoo_server_url or queue_size == 0:
return
try:
odoo_session.post(
self._odoo_server_url + '/iot/log',
data=empty_queue(),
timeout=self._REQUEST_TIMEOUT
).raise_for_status()
self._next_disconnection_time = None
except (requests.exceptions.ConnectTimeout, requests.exceptions.ConnectionError, urllib3.exceptions.NewConnectionError) as request_errors:
now = time.time()
if not self._next_disconnection_time or now >= self._next_disconnection_time:
_logger.info("Connection with the server to send the logs failed. It is likely down: %s", request_errors)
self._next_disconnection_time = now + self._DELAY_BEFORE_NO_SERVER_LOG
except Exception as _:
_logger.exception('Unexpected error happened while sending logs to server')
def emit(self, record):
# This is important that this method is as fast as possible.
# The log calls will be waiting for this function to finish
if not self._active:
return
try:
self._log_queue.put_nowait(record)
except queue.Full:
pass
def close(self):
self.toggle_active(False)
super().close()
def close_server_log_sender_handler():
_server_log_sender_handler.close()
def get_odoo_config_log_to_server_option():
return helpers.get_conf(IOT_LOG_TO_SERVER_CONFIG_NAME, section='options') or True # Enabled by default
def check_and_update_odoo_config_log_to_server_option(new_state):
"""
:return: wherever the config file need to be updated or not
"""
if get_odoo_config_log_to_server_option() != new_state:
helpers.update_conf({IOT_LOG_TO_SERVER_CONFIG_NAME, new_state}, section='options')
_server_log_sender_handler.toggle_active(new_state)
return True
return False
def _server_log_sender_handler_filter(log_record):
def _filter_my_logs():
"""Filter out our own logs (to avoid infinite loop)"""
return log_record.name == __name__
def _filter_frequent_irrelevant_calls():
"""Filter out this frequent irrelevant HTTP calls, to avoid spamming the server with useless logs"""
return log_record.name == 'werkzeug' and log_record.args and len(log_record.args) > 0 and log_record.args[0].startswith('GET /hw_proxy/hello ')
return not (_filter_my_logs() or _filter_frequent_irrelevant_calls())
# The server URL is set once at initlialisation as the IoT will always restart if the URL is changed
# The only other possible case is when the server URL value is "Cleared",
# in this case we force close the log handler (as it does not make sense anymore)
_server_log_sender_handler = AsyncHTTPHandler(helpers.get_odoo_server_url(), get_odoo_config_log_to_server_option())
_server_log_sender_handler.setFormatter(DBFormatter('%(asctime)s %(pid)s %(levelname)s %(dbname)s %(name)s: %(message)s %(perf_info)s'))
_server_log_sender_handler.addFilter(_server_log_sender_handler_filter)
# Set it in the 'root' logger, on which every logger (including odoo) is a child
logging.getLogger().addHandler(_server_log_sender_handler)
|
