-
Notifications
You must be signed in to change notification settings - Fork 729
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Expose metaflow logger and monitor via singleton #1794
base: master
Are you sure you want to change the base?
Conversation
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Some initial comments.
metaflow/task.py
Outdated
pass | ||
system_current.logger.log( | ||
{ | ||
"log_type": "ERROR", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
could we have constants for these?
metaflow/metaflow_metrics_manager.py
Outdated
|
||
@contextmanager | ||
def measure(self, metric_name, qualifer_name=None): | ||
timer, counter = self.monitor.get_measure_metrics(metric_name) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
could we ideally make this look symetric for both?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
we can also just return a single "payload". Internally, the send_metric would know to stop the timer for example.
e35dd85
to
a5984a2
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
A few initial comments but I think this goes in the direction we agreed to so we shouldn't be too far.
metaflow/__init__.py
Outdated
@@ -100,6 +100,12 @@ class and related decorators. | |||
# current runtime singleton | |||
from .metaflow_current import current | |||
|
|||
# system monitor runtime singleton |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I would add a comment like (for internal metaflow use only). It's kind of explicit from the name but we can be extra explicit :)
metaflow/cli.py
Outdated
@@ -1066,6 +1068,10 @@ def start( | |||
if decospecs: | |||
decorators._attach_decorators(ctx.obj.flow, decospecs) | |||
|
|||
# We create an instance of SystemMonitor and SystemLogger respectively |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit, I would move this up to where ctx.obj.monitor and event_logger are created.
metaflow/metaflow_system_logger.py
Outdated
|
||
@property | ||
def flow_name(self): | ||
return self._flow_name |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
assumes that flow_name will not be called prior to flow which may not be correct. In general, I would have one init method that inits all 4 (flow, flow_name, environment and logger) and controlled by one single flag.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This comment is still not addressed I think.
metaflow/metaflow_system_logger.py
Outdated
return self._logger | ||
|
||
@logger.setter | ||
def logger(self, logger): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
we don't really want this to be settable independently do we? can we just keep set_logger and have things set directly on the _ names? Or is there a use you are thinking of of setting things independently?
metaflow/metaflow_system_logger.py
Outdated
from typing import Dict, Any | ||
|
||
|
||
class SystemLogger(object): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: please add type hints where appropriate.
metaflow/metaflow_system_monitor.py
Outdated
from contextlib import contextmanager | ||
|
||
|
||
class SystemMonitor(object): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same comments as for system_logger
metaflow/task.py
Outdated
"ts": round(time.time()), | ||
} | ||
logger.log(msg) | ||
with _system_monitor.count("metaflow.task.start"): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I would keep things the same here -- ie: use self.event_logger and self.logger
metaflow/task.py
Outdated
"flow_name": self.flow.name, | ||
} | ||
logger.log(tsk_msg) | ||
print("I am here in metaflow") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: remove.
metaflow/task.py
Outdated
"runtime": round(end), | ||
} | ||
logger.log(msg) | ||
_system_monitor.gauge("metaflow.task.duration", duration) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
A measure would be more appropriate here than a gauge.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Question is should we be measuring the task duration only until the task "ends" or consider the portion dealing with metadata register as part of the task duration as well?
If it's the former then it would be difficult to implement using the existing context manager construct - hence why we use the gauge metric.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That's a good point so we may need to add non-context specific ones for this. The issue is that a gauge isn't the same as a measure. Gauge are supposed to measure levels of things (like # of machines in a pool, etc) not disparate point measurements like this.
metaflow/metaflow_system_logger.py
Outdated
from typing import Dict, Any, Optional, Union | ||
|
||
|
||
class SystemLogger(object): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Consider moving this and monitor under metaflow/system
so that we can have a rather clean import - from metaflow.system import monitor
rather than from .metaflow_system_monitor import _system_monitor
or from metaflow import _system_monitor
metaflow/metaflow_system_logger.py
Outdated
|
||
class SystemLogger(object): | ||
def __init__(self): | ||
self._flow = None |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why both _flow
and _flow_name
?
metaflow/metaflow_system_logger.py
Outdated
from typing import Dict, Any, Optional, Union | ||
|
||
|
||
class SystemLogger(object): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It seems that the implementation of this file depends on its usage outside of the flow context. Can you add comments in the code with the use cases so that it is easier to review and maintain going forward?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Do we want it as part of the code or in a separate README?
metaflow/metaflow_system_logger.py
Outdated
self._logger = LOGGING_SIDECARS[DEFAULT_EVENT_LOGGER]( | ||
flow=self.flow, env=self.environment | ||
) | ||
self._debug("Started logger outside of a flow") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Would it be cleaner if self._logger
is started when logger
is constructed?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This would be the case when we access logger
outside of a flow. Otherwise it is started in cli.py
itself.
"project_flow_name": current.get("project_flow_name"), | ||
"trace_id": trace_id or None, | ||
} | ||
self.event_logger.send( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why use send
instead of log
? iirc send
was a workaround for a very specific use case (I need to dig through the slack conversations) and we would want to avoid introducing it too much in the code base.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
send
is used to update the event_logger
context so that we have all these values available as additional tags in the event stream. We thus log this event with message type set to MUST_SEND
instead of BEST_EFFORT
that is normally used in log
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, the intent is to set a "common set of tags" (in the lingo of the other measure thing (datadog)). I think it may make sense to actually have a specific method self.event_logger.set_common_tags()
or something like that. Backends would be free to do whatever they want with that. Internally, we could then use send to send a MUST_SEND message or just keep it around (the MUST_SEND was to avoid overloading the pipe to the sidecar with all the context all the time).
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I wonder if you did a simple self.event_logger.log(payload)
where the payload had the message and the context (common tags, etc.), and then in your internal implementation of the logger, you could make multiple calls with MUST_SEND
or BEST_EFFORT
as intended. Currently, it seems that this bit of logic in task.py is leaking implementation detail on how the logger backend works.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Maybe an in-person conversation might be quicker here - it is likely that we can preserve the same signature for self.event_logger.log(msg)
as before and move the complexity of handling what needs to be sent as MUST_SEND
or BEST_EFFORT
to your internal sidecar implementation. That way, these changes in task.py
are entirely decoupled from any changes in the sidecar implementation.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, lets discuss this in the call. What you said should be possible - depending on the presence of certain specific key/value pair in the payload we can use MUST_SEND
or BEST_EFFORT
appropriately. My only concern would be that if someone reads the code in cli.py
then it would be confusing for them as to why we use different message types for different payloads.
# initialize parameters (if they exist) | ||
# We take Parameter values from the first input, | ||
# which is always safe since parameters are read-only | ||
current._update_env( | ||
{ | ||
"parameter_names": self._init_parameters( | ||
inputs[0], passdown=False | ||
inputs[0], passdown=True |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
can you highlight the rationale for this change?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Seems to be an issue with the diff. I didn't change it and it's still False
as we can see on line number 601
.
metaflow/task.py
Outdated
"traceback": traceback.format_exc(), | ||
} | ||
) | ||
pass |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why is this needed?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Replace it with something like event_logger.log(msg="", type="")
.
metaflow/task.py
Outdated
"event_value": 1, | ||
} | ||
) | ||
pass |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same here - why is a pass
needed? is it to signify end of an indent block or something more? if the former, we can avoid introducing pass to maintain consistency of style in the code base
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Will remove in updated PR
metaflow/task.py
Outdated
with self.monitor.measure("metaflow.task.duration"): | ||
try: | ||
with self.monitor.count("metaflow.task.start"): | ||
self.event_logger.log( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
why is this log necessary?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We want the event to be available in the log stream in addition to our metrics.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Some comments. Let's discuss tomorrow and finalize.
|
||
Parameters | ||
---------- | ||
msg : str |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: Optional if they can be None (same for all others.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Also add type hints in the signature.
if self._flow_name == "not_a_real_flow": | ||
self.logger.terminate() | ||
|
||
def init_environment_outside_flow( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
missing return type?
------- | ||
None | ||
""" | ||
print("system logger: %s" % msg, file=sys.stderr) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: maybe squelch unless debug is turned on?
|
||
Parameters | ||
---------- | ||
msg : str, optional default None |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: optional, default None
if self._flow_name == "not_a_real_flow": | ||
self.monitor.terminate() | ||
|
||
def init_environment_outside_flow( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
this method does not depend on self. I would move it to a util or something since it is common across both logger and monitor.
self.monitor.gauge(gauge) | ||
|
||
|
||
_system_monitor = SystemMonitor() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Remove line -- no longer used since in init.py
task_id, | ||
) | ||
with _system_monitor.count("metaflow.task.clone"): | ||
self.event_logger.log_event( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: _system_logger to be consistent.
Parameters | ||
---------- | ||
msg : str, optional default None | ||
Message to log. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
What does it mean to log a "none" message, just empty? Maybe add a comment to that effect.
"project_flow_name": current.get("project_flow_name"), | ||
"trace_id": trace_id or None, | ||
} | ||
self.event_logger.send( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, the intent is to set a "common set of tags" (in the lingo of the other measure thing (datadog)). I think it may make sense to actually have a specific method self.event_logger.set_common_tags()
or something like that. Backends would be free to do whatever they want with that. Internally, we could then use send to send a MUST_SEND message or just keep it around (the MUST_SEND was to avoid overloading the pipe to the sidecar with all the context all the time).
78950dc
to
9f779ae
Compare
@@ -24,6 +24,31 @@ def log(self, payload): | |||
msg = Message(MessageTypes.BEST_EFFORT, payload) | |||
self._sidecar.send(msg) | |||
|
|||
def log_event(self, msg=None, event_name=None, log_stream=None, other_context=None): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
do we need this method? can we not reuse def log(self, payload)
where the payload contains the msg, event_name, log_stream and other_context?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We can reuse the method log(self, payload)
. But we had discussed previously that it would be better to expose a method like log_event
with explicit parameters so that it is clear in any logger implementation that it needs to use/ignore the fields msg
, event_name
, and log_stream
.
if self._flow_name == "not_a_real_flow": | ||
self.logger.terminate() | ||
|
||
def init_environment_outside_flow( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
can you add comments here for future readers as to why/how the logger needs to be/is constructed in this manner?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Will address
self._flow_name = flow_name | ||
self._logger = logger | ||
|
||
def init_logger_outside_flow(self): |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
do we expect this method to be used outside of this class? if not, consider adding a _
prefix.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Agreed - will address
Additional context to log with the event. The additional context will have to be handled by | ||
the event logger implementation. | ||
""" | ||
self.logger.log_event(msg, event_name, log_stream, other_context) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
maybe
self.logger.log_event(msg, event_name, log_stream, other_context) | |
self.logger.log({"msg": msg, | |
"event_name": event_name, | |
"log_stream": log_stream, | |
"other_context": other_context or {}, | |
}) |
if self._flow_name == "not_a_real_flow": | ||
self.logger.terminate() | ||
|
||
def init_environment_outside_flow( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it seems that this method exists to ensure the appropriate MetaflowEnvironment
is picked for constructing the logger (and monitor) object. Currently, the interface doesn't strictly expect an environment to be passed to the constructor. When using the system logger and monitor outside of a flow, the utility of recording the environment is limited - can you consider making the environment optional in your internal implementation of logger and monitor and using a dummy value as a default instead (nullEnvironment
)? It would clean up this implementation significantly.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think there is reasonable benefit for passing MetaflowEnvironment
when used outside of a flow as well. Primarily, the environment provides us with additional tags/context like the version of metaflow used, platform, the user name etc. With that in mind, I just referred to the way the logger/monitor were instantiated in cli.py
here.
with _system_monitor.count("metaflow.task.clone"): | ||
self.event_logger.log_event( | ||
event_name="metaflow.task.clone", | ||
msg=msg, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
is there a reason to drop task_id
, step_name
, run_id
, flow_name
and ts
from the payload here?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The task_id
, step_name
etc are not part of the payload of an event usually. They are added once at the beginning as additional tags and then are automatically added to all events. But yes, I should add another call to add these additional tags/context like we did in the run_step
function.
"project_flow_name": current.get("project_flow_name"), | ||
"trace_id": trace_id or None, | ||
} | ||
self.event_logger.send( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I wonder if you did a simple self.event_logger.log(payload)
where the payload had the message and the context (common tags, etc.), and then in your internal implementation of the logger, you could make multiple calls with MUST_SEND
or BEST_EFFORT
as intended. Currently, it seems that this bit of logic in task.py is leaking implementation detail on how the logger backend works.
"project_flow_name": current.get("project_flow_name"), | ||
"trace_id": trace_id or None, | ||
} | ||
self.event_logger.send( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Maybe an in-person conversation might be quicker here - it is likely that we can preserve the same signature for self.event_logger.log(msg)
as before and move the complexity of handling what needs to be sent as MUST_SEND
or BEST_EFFORT
to your internal sidecar implementation. That way, these changes in task.py
are entirely decoupled from any changes in the sidecar implementation.
Expose logger and monitor via a
system_current
singletonCurrently, users don't have the ability to use their implementation of logger and monitor sidecars in their own code. Additionally, if platform developers want to instrument their Metaflow extensions, they have to pass in the logger/monitor constructs to each one of their plugins, leading to code duplication.
This PR exposes two new singleton objects called
_system_logger
and_system_monitor
that can be used to access the monitor and the logger anywhere.metaflow.S3
, which is often used outside of a flow as well.Usage
The monitor/logger sidecar can be used in the following manner: