https://prefect.io logo
Channels
Powered by
#prefect-community
Title
# prefect-community
p

Philip MacMenamin

04/19/2022, 8:12 PM
Quietening down logs - if I'm mapping out to a lot of job, have a lot of params etc, it can be difficult to follow logs. Is there a way I can set logging such that I only see something if it's broken. If I 
export PREFECT__LOGGING__LEVEL=INFO
I see:
Copy code
python3 tmp/shell_task.py 
[2022-04-19 21:09:30+0100] INFO - prefect.FlowRunner | Beginning Flow run for 'My Flow'
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | Task 'MyShellTask': Starting task run...
[2022-04-19 21:09:30+0100] INFO - prefect.MyShellTask | lsto echo
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | Task 'MyShellTask': Finished task run for task with final state: 'Success'
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | Task 'problem': Starting task run...
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | FAIL signal raised: FAIL('Oh no!')
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | Task 'problem': Finished task run for task with final state: 'Failed'
[2022-04-19 21:09:30+0100] INFO - prefect.FlowRunner | Flow run FAILED: some reference tasks failed.
If I
Copy code
export PREFECT__LOGGING__LEVEL=ERROR
I see nothing. Ideally I'd like to only see messages about broken stuff. Ideas?
n

Nate

04/19/2022, 8:27 PM
@Philip MacMenamin if you're raising a caught exception (as a 
FAIL
signal in this case), then its going to be 
INFO
level, as you can see in your logs
Copy code
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | FAIL signal raised: FAIL('Oh no!')
any unexpected errors should show up as 
ERROR
level logs - is that helpful?
p

Philip MacMenamin

04/19/2022, 8:30 PM
so I expected that, but if I set: 
export PREFECT__LOGGING__LEVEL=ERROR
I see nothing. WF runs out, reports nothing at all.
a

Anna Geller

04/19/2022, 11:07 PM
based on this log, the info that a flow run failed is still an INFO-level log, so that's expected:
Copy code
[2022-04-19 21:09:30+0100] INFO - prefect.FlowRunner | Flow run FAILED: some reference tasks failed.
this is much easier to configure in Prefect 2.0 - perhaps a good reason to run your flow on 2.0 already? check out this example
upvote 1
p

Philip MacMenamin

04/20/2022, 2:03 PM
@Anna Geller - I'm not sure I'm getting this. I raised a signal.FAIL in the task, and this elicited
Copy code
[2022-04-19 21:09:30+0100] INFO - prefect.TaskRunner | FAIL signal raised: FAIL('Oh no!')
Is is not expected behaviour that raising a FAIL would show up on an error level log?
a

Anna Geller

04/20/2022, 2:12 PM
nope - this only means that the task run ends with a failed state - the task runner log remains INFO. Can you explain what problem do you try to solve here?
p

Philip MacMenamin

04/20/2022, 2:16 PM
Default settings generate a very large amount of logs along the lines of:
Copy code
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'log': Finished task run for task with final state: 'Success'
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'update_adoc': Starting task run...
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'update_adoc': Finished task run for task with final state: 'Mapped'
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'update_adoc[0]': Starting task run...
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'update_adoc[0]': Finished task run for task with final state: 'Success'
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'create_brt_command': Starting task run...
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'create_brt_command': Finished task run for task with final state: 'Mapped'
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'create_brt_command[0]': Starting task run...
[2022-04-19 12:56:09-0600] INFO - prefect.TaskRunner | Task 'create_brt_command[0]': Finished task run for task with final state: 'Success'
[2022-04-19 12:56:10-0600] INFO - prefect.TaskRunner | Task 'log': Starting task run...
which gets to be crippling if you're mapping over a lot of stuff. I don't want to be told about all of this, I just want to know if anything broke, and ideally some kind of clue about what broke.
I'm not going to paste in an actual large log, but if I'm mapping to a couple of hundred items it becomes huge. (I'm mapping to one in the above). I don't want to be told about every event, and every 'Success', I'd like some way to turn that down to help me keep logs at a size that I don't have to use grep etc to search them.
Aside, I tested
Copy code
from prefect import flow, task
from logging import getLogger

logger = getLogger("my-logger")
logger.setLevel("INFO")


@task
def my_task():
    <http://logger.info|logger.info>("Hello from the task")


@flow
def my_flow():
    <http://logger.info|logger.info>("Hello from the flow")
    my_task()


my_flow()
running with 
PREFECT_LOGGING_LEVEL=WARNING PREFECT_LOGGING_EXTRA_LOGGERS=my-logger python3 flow2.py
gives me:
Copy code
Traceback (most recent call last):
  File "flow2.py", line 1, in <module>
    from prefect import flow, task
ImportError: cannot import name 'flow' from 'prefect' (/home/macmenaminpe/.local/lib/python3.8/site-packages/prefect/__init__.py)
writing as:
Copy code
cat flow.py 
from prefect import Flow, task
from logging import getLogger

logger = getLogger("my-logger")
logger.setLevel("INFO")


@task
def my_task():
    <http://logger.info|logger.info>("Hello from the task")

with Flow("My Flow") as f:
    <http://logger.info|logger.info>("Hello from the flow")
    my_task()

f.run()
works, but gives me:
Copy code
$ PREFECT_LOGGING_LEVEL=WARNING PREFECT_LOGGING_EXTRA_LOGGERS=my-logger python3 flow.py
[2022-04-20 15:50:10+0100] INFO - prefect.FlowRunner | Beginning Flow run for 'My Flow'
[2022-04-20 15:50:10+0100] INFO - prefect.TaskRunner | Task 'my_task': Starting task run...
[2022-04-20 15:50:10+0100] INFO - prefect.TaskRunner | Task 'my_task': Finished task run for task with final state: 'Success'
[2022-04-20 15:50:10+0100] INFO - prefect.FlowRunner | Flow run SUCCESS: all reference tasks succeeded
Ie, same as previous, too much logging.
(In the above case I'm not even seeing "Hello from the flow")
Copy code
$ prefect version
1.2.0
n

Nate

04/20/2022, 3:01 PM
with regard to this message about the failed import, that's because your prefect version is 1.2 but you're using the 
prefect>=2.0
syntax and imports, which aren't valid for 
prefect==1.x.x
upvote 1
p

Philip MacMenamin

04/20/2022, 3:02 PM
right, I suspected that was some versioning thing. Thanks Nate.
a

Anna Geller

04/20/2022, 3:02 PM
I just want to know if anything broke, and ideally some kind of clue about what broke.
The best way of solving that problem would be through state handlers or failure notifications that you could configure through Automation. This blog post discusses both
p

Philip MacMenamin

04/20/2022, 3:14 PM
@Anna Geller - this might be nice for a more final version. I'm just going through stuff coding and trying to work out bugs. Is this automation going to work on a locally hosted prefect server?
So, basically there isn't really a way of quietening down the logs I'm hearing, correct?
a

Anna Geller

04/20/2022, 3:38 PM
there is always a way to quiet down the logs - you could, e.g. use a log filter: https://prefect-community.slack.com/archives/C014Z8DPDSR/p1650365258707909?thread_ts=1650363875.537909&amp;cid=C014Z8DPDSR but I'm not sure if getting rid of logs is the right strategy. Logs are extremely helpful in troubleshooting, I think you need them! A better approach is to configure some hooks for failure notifications. Automations are Cloud only, but you could add a state handler on Server
p

Philip MacMenamin

04/20/2022, 3:44 PM
Logs are very helpful in trouble shooting, but if I have thousands of lines of logs, and 99.999% of them say "... Success" and buried in there there's something that's not working, I'd have thought there'd be a simple way to surface this.
As in, if I explicitly raise a FAIL, why is this not in a diff category? Why is that grouped in with the thousands of Successes. At the end of the day I'll have full logging, but as I'm writing stuff it's useful to run flows and see if there's anything wrong, quickly.
I mean, I guess I can pipe everything through grep too, but it just seems weird.
a

Anna Geller

04/20/2022, 3:52 PM
actually can you try running the same with the backend? I think the actual error in your tasks will be displayed as ERROR level, only the Flow and Task Runner are displayed as INFO
p

Philip MacMenamin

04/20/2022, 3:57 PM
I'm not following - what do you mean by running it with the backend?
registering it and running it through the web GUI?
a

Anna Geller

04/20/2022, 4:51 PM
yup exactly
10 Views
Powered by