def start_tracing(self):
# Messaging tracing
CallTracer.set_formatter("MSG.out", self._msg_trace_formatter)
CallTracer.set_formatter("MSG.in", self._msg_trace_formatter)
from pyon.net import endpoint
endpoint.callback_msg_out = self.trace_message_out
endpoint.callback_msg_in = self.trace_message_in
def _msg_out_callback(self, msg, headers, env):
log_entry = dict(status="SENT %s bytes" % len(msg),
headers=headers,
env=env,
content_length=len(msg),
content=str(msg)[:self.SAVE_MSG_MAX])
CallTracer.log_scope_call("MSG.out", log_entry, include_stack=False)
self._call_callbacks("MSG", "out", log_entry)
def setUp(self):
self.server_type = CFG.get_safe("container.datastore.default_server", "couchdb")
if self.server_type.startswith("couch"):
self.ds_class = CouchPyonDataStore
elif self.server_type == "postgresql":
self.ds_class = PostgresPyonDataStore
# We're running outside of a container - configure the tracer
CallTracer.configure(CFG.get_safe("container.tracer", {}))
def trace_message_out(msg, headers, env):
log_entry = dict(
status="SENT %s bytes" % len(msg),
headers=headers,
env=env,
content_length=len(msg),
content=str(msg)[: ContainerTracer.SAVE_MSG_MAX],
)
CallTracer.log_scope_call("MSG.out", log_entry, include_stack=False)
def _activate_collection(self):
CallTracer.set_formatter("MSG.out", self._msg_trace_formatter)
CallTracer.set_formatter("MSG.in", self._msg_trace_formatter)
from pyon.net import endpoint
endpoint.callback_msg_out = self._msg_out_callback
endpoint.callback_msg_in = self._msg_in_callback
from pyon.datastore.postgresql.base_store import set_db_stats_callback
set_db_stats_callback(self._db_callback)
from ion.services.service_gateway import sg_instance
if sg_instance:
# This container may not run the service gateway
sg_instance.register_request_callback(self._sg_callback)
from pyon.ion.process import set_process_stats_callback
set_process_stats_callback(self._proc_callback)
def _activate_collection(self):
CallTracer.set_formatter("MSG.out", self._msg_trace_formatter)
CallTracer.set_formatter("MSG.in", self._msg_trace_formatter)
from pyon.net import endpoint
endpoint.callback_msg_out = self._msg_out_callback
endpoint.callback_msg_in = self._msg_in_callback
from pyon.datastore.postgresql.base_store import set_db_stats_callback
set_db_stats_callback(self._db_callback)
from ion.service.service_gateway import sg_instance
if sg_instance:
# This container may not run the service gateway
sg_instance.register_request_callback(self._sg_callback)
from pyon.ion.process import set_process_stats_callback
set_process_stats_callback(self._proc_callback)
def _msg_trace_formatter(log_entry, **kwargs):
# Warning: Make sure this code is reentrant. Will be called multiple times for the same entry
frags = []
msg_type = "UNKNOWN"
sub_type = ""
try:
content = log_entry.get("content", "")
headers = dict(log_entry.get("headers", {}))
env = log_entry.get("env", {})
if "sender" in headers or "sender-service" in headers:
# Case RPC msg
sender_service = headers.get('sender-service', '')
sender = headers.pop('sender', '').split(",", 1)[-1]
sender_name = headers.pop('sender-name', '')
sender_txt = (sender_name or sender_service) + " (%s)" % sender if sender else ""
recv = headers.pop('receiver', '?').split(",", 1)[-1]
op = "op=%s" % headers.pop('op', '?')
sub_type = op
stat = "status=%s" % headers.pop('status_code', '?')
conv_seq = headers.get('conv-seq', '0')
if conv_seq == 1:
msg_type = "RPC REQUEST"
frags.append("%s %s -> %s %s" % (msg_type, sender_txt, recv, op))
else:
msg_type = "RPC REPLY"
frags.append("%s %s -> %s %s" % (msg_type, sender_txt, recv, stat))
try:
import msgpack
msg = msgpack.unpackb(content)
frags.append("\n C:")
frags.append(str(msg))
except Exception as ex:
pass
else:
# Case event/other msg
try:
import msgpack
msg = msgpack.unpackb(content)
ev_type = msg["type_"] if isinstance(msg, dict) and "type_" in msg else "?"
msg_type = "EVENT"
sub_type = ev_type
frags.append("%s %s" % (msg_type, ev_type))
frags.append("\n C:")
frags.append(str(msg))
except Exception:
msg_type = "UNKNOWN"
frags.append(msg_type)
frags.append("\n C:")
frags.append(content)
frags.append("\n H:")
frags.append(str(headers))
frags.append("\n E:")
frags.append(str(env))
except Exception as ex:
frags = ["ERROR parsing message: %s" % str(ex)]
log_entry["statement"] = "".join(frags)
log_entry["msg_type"] = msg_type
log_entry["sub_type"] = sub_type
return CallTracer._default_formatter(log_entry, **kwargs)
def _db_callback(self, scope, log_entry):
CallTracer.log_scope_call(scope, log_entry, include_stack=True)
self._call_callbacks("DB", scope, log_entry)
def _msg_out_callback(self, msg, headers, env):
log_entry = dict(status="SENT %s bytes" % len(msg), headers=headers, env=env,
content_length=len(msg), content=str(msg)[:self.SAVE_MSG_MAX])
CallTracer.log_scope_call("MSG.out", log_entry, include_stack=False)
self._call_callbacks("MSG", "out", log_entry)
def _msg_trace_formatter(log_entry, **kwargs):
# Warning: Make sure this code is reentrant. Will be called multiple times for the same entry
frags = []
msg_type = "UNKNOWN"
sub_type = ""
try:
content = log_entry.get("content", "")
headers = dict(log_entry.get("headers", {}))
env = log_entry.get("env", {})
if "sender" in headers or "sender-service" in headers:
# Case RPC msg
sender_service = headers.get('sender-service', '')
sender = headers.pop('sender', '').split(",", 1)[-1]
sender_name = headers.pop('sender-name', '')
sender_txt = (sender_name or sender_service
) + " (%s)" % sender if sender else ""
recv = headers.pop('receiver', '?').split(",", 1)[-1]
op = "op=%s" % headers.pop('op', '?')
sub_type = op
stat = "status=%s" % headers.pop('status_code', '?')
conv_seq = headers.get('conv-seq', '0')
if conv_seq == 1:
msg_type = "RPC REQUEST"
frags.append("%s %s -> %s %s" %
(msg_type, sender_txt, recv, op))
else:
msg_type = "RPC REPLY"
frags.append("%s %s -> %s %s" %
(msg_type, sender_txt, recv, stat))
try:
import msgpack
msg = msgpack.unpackb(content)
frags.append("\n C:")
frags.append(str(msg))
except Exception as ex:
pass
else:
# Case event/other msg
try:
import msgpack
msg = msgpack.unpackb(content)
ev_type = msg["type_"] if isinstance(
msg, dict) and "type_" in msg else "?"
msg_type = "EVENT"
sub_type = ev_type
frags.append("%s %s" % (msg_type, ev_type))
frags.append("\n C:")
frags.append(str(msg))
except Exception:
msg_type = "UNKNOWN"
frags.append(msg_type)
frags.append("\n C:")
frags.append(content)
frags.append("\n H:")
frags.append(str(headers))
frags.append("\n E:")
frags.append(str(env))
except Exception as ex:
frags = ["ERROR parsing message: %s" % str(ex)]
log_entry["statement"] = "".join(frags)
log_entry["msg_type"] = msg_type
log_entry["sub_type"] = sub_type
return CallTracer._default_formatter(log_entry, **kwargs)
def _db_callback(self, scope, log_entry):
CallTracer.log_scope_call(scope, log_entry, include_stack=True)
self._call_callbacks("DB", scope, log_entry)