https://prefect.io logo
Join Slack
Powered by
Hi All, I only have one flow enabled at a single ...
# ask-community
m
Hi All, I only have one flow enabled at a single time using a local agent.
Copy code
[2021-05-12 12:26:05-0700] INFO - prefect.task_name | Waiting for next scheduled run at 2021-05-13T10:00:00+00:00
2021-05-12 12:26:05,221 - prefect.task_name - INFO - Waiting for next scheduled run at 2021-05-13T10:00:00+00:00
But the local agent somehow runs two of the same flow twice. How should I debug this issue?
k
Hi @Max Lei! How is this being run? “Quick Run” or scheduled?
m
@Kevin Kho They are being scheduled. The quick runs has no problem at all.
k
What does your schedule look like in the UI?
m
Do you mean in the upcoming runs? They look consecutive like Monday/Tuesday, etc and never on the same day.
k
Actually, this looks like it’s not a duplicate run, but two different loggers configured with Stream handlers.
m
I have a task that sends one email, but I’m getting two emails. Also the object in the memory location is also different, 0xf1 vs 0xf2
This is also a fresh install of prefect 0.14.17, deleted previous docker containers
I have a crontab that kills the previous flow task_name.py, does a git pull and reruns the same script again. I suspect that this has to do with the behavior. But checking ps -ef | grep task_name.py I only see one copy.
k
Do you cloud logs show doubles also?
m
No, only a single run. But if I output the flow to a file like task_name.py > log.txt. The log.txt shows a different result than the log on the UI.
k
We’re looking into this
z
Hey @Max Lei -- if you can reproduce this with debug level logs on we might get some more information. 
PREFECT__CLOUD__AGENT__LEVEL=DEBUG
m
Should I export this environment variable before running the agent or flow or both?
I think I follow:
Copy code
prefect agent <AGENT TYPE> start --env KEY=VALUE --env KEY2=VALUE2
In the docs
z
Before the command since you're setting it for your agent not the flow run
m
The log looks like:
Copy code
[2021-05-12 20:22:58,810] DEBUG - agent | Found flow runs ['734edd41-a9de-4ab9-86b4-aaf332fa1179'] (1 already submitting: ['734edd41-a9de-4ab9-86b4-aaf332fa1179'])
[2021-05-12 20:22:58,810] DEBUG - agent | Next query for flow runs in 0.5 seconds
[2021-05-12 20:22:59,311] DEBUG - agent | Querying for flow runs
[2021-05-12 20:22:59,331] DEBUG - agent | Found flow runs ['734edd41-a9de-4ab9-86b4-aaf332fa1179'] (1 already submitting: ['734edd41-a9de-4ab9-86b4-aaf332fa1179'])
[2021-05-12 20:22:59,331] DEBUG - agent | Next query for flow runs in 1.0 seconds
[2021-05-12 20:23:00,001] DEBUG - agent | Updating states for flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179
[2021-05-12 20:23:00,006] DEBUG - agent | Flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179 is in a Scheduled state, updating to Submitted
[2021-05-12 20:23:00,046] INFO - agent | Deploying flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179
[2021-05-12 20:23:00,050] DEBUG - agent | Submitted flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179 to process PID 31690
[2021-05-12 20:23:00,068] DEBUG - agent | Completed flow run submission (id: 734edd41-a9de-4ab9-86b4-aaf332fa1179)
Looks OK to me for now though. I think I’ll need to export this and just let it sit through tasks this week and see what happens.
z
Alright!
m
I do see a few [2021-05-11 203700,431] ERROR - agent | HTTPConnectionPool(host=‘localhost’, port=4200): Max retries exceeded with url: / (Caused by NewConnectionError(‘<urllib3.connection.HTTPConnection object at 0x7f28c0dba110>: Failed to establish a new connection: [Errno 101] Ne twork is unreachable’)) And then the agent icon appears again, and then seems to restart itself? Could this cause multiple runners to be active at the same time?
A little longer log:
Copy code
[2021-05-05 10:00:02,060] INFO - agent | Found 1 flow run(s) to submit for execution.
[2021-05-05 10:00:02,176] INFO - agent | Deploying flow run 87e78b14-dcf5-44e0-b7dd-e8d07340356e
[2021-05-05 22:11:45,212] ERROR - agent | HTTPConnectionPool(host='localhost', port=4200): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7efdb49b8450>: Failed to establish a new connection: [Errno 111] Co
nnection refused'))
[2021-05-05 22:11:55,214] ERROR - agent | HTTPConnectionPool(host='localhost', port=4200): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7efdb496fd90>: Failed to establish a new connection: [Errno 101] Ne
twork is unreachable'))

 ____            __           _        _                    _
|  _ \ _ __ ___ / _| ___  ___| |_     / \   __ _  ___ _ __ | |_
| |_) | '__/ _ \ |_ / _ \/ __| __|   / _ \ / _` |/ _ \ '_ \| __|
|  __/| | |  __/  _|  __/ (__| |_   / ___ \ (_| |  __/ | | | |_
|_|   |_|  \___|_|  \___|\___|\__| /_/   \_\__, |\___|_| |_|\__|
                                           |___/

[2021-05-05 22:14:19,077] INFO - agent | Starting LocalAgent with labels ['ml-build', 'azure-flow-storage', 'gcs-flow-storage', 's3-flow-storage', 'github-flow-storage', 'webhook-flow-storage', 'gitlab-flow-storage']
[2021-05-05 22:14:19,078] INFO - agent | Agent documentation can be found at <https://docs.prefect.io/orchestration/>
[2021-05-05 22:14:19,078] INFO - agent | Agent connecting to the Prefect API at <http://localhost:4200>
[2021-05-05 22:14:19,085] INFO - agent | Waiting for flow runs...
[2021-05-06 10:00:07,830] INFO - agent | Found 1 flow run(s) to submit for execution.
[2021-05-06 10:00:07,869] INFO - agent | Deploying flow run 69433bdb-981a-4135-af51-a495c44eeecf
[2021-05-06 14:00:02,978] INFO - agent | Found 1 flow run(s) to submit for execution.
[2021-05-06 14:00:03,012] INFO - agent | Deploying flow run c75e4314-9edd-4168-81ac-4fd86efc8acb
@Zanie @Kevin Kho It seems that I was able to reproduce it. Nothing particular wrong about the agent logs. From starting the new agent, there wasn’t any disconnects, but still had two runs.
z
Can you post the log?
Runs like this should be de-duplicated and the logs should shown where that's failing
m
Copy code
[2021-05-12 20:22:58,499] DEBUG - agent | Querying for flow runs
[2021-05-12 20:22:58,521] DEBUG - agent | Found flow runs ['734edd41-a9de-4ab9-86b4-aaf332fa1179']
[2021-05-12 20:22:58,522] DEBUG - agent | Querying flow run metadata
[2021-05-12 20:22:58,538] INFO - agent | Found 1 flow run(s) to submit for execution.
[2021-05-12 20:22:58,538] DEBUG - agent | Next query for flow runs in 0.25 seconds
[2021-05-12 20:22:58,789] DEBUG - agent | Querying for flow runs
[2021-05-12 20:22:58,810] DEBUG - agent | Found flow runs ['734edd41-a9de-4ab9-86b4-aaf332fa1179'] (1 already submitting: ['734edd41-a9de-4ab9-86b4-aaf332fa1179'])
[2021-05-12 20:22:58,810] DEBUG - agent | Next query for flow runs in 0.5 seconds
[2021-05-12 20:22:59,311] DEBUG - agent | Querying for flow runs
[2021-05-12 20:22:59,331] DEBUG - agent | Found flow runs ['734edd41-a9de-4ab9-86b4-aaf332fa1179'] (1 already submitting: ['734edd41-a9de-4ab9-86b4-aaf332fa1179'])
[2021-05-12 20:22:59,331] DEBUG - agent | Next query for flow runs in 1.0 seconds
[2021-05-12 20:23:00,001] DEBUG - agent | Updating states for flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179
[2021-05-12 20:23:00,006] DEBUG - agent | Flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179 is in a Scheduled state, updating to Submitted
[2021-05-12 20:23:00,046] INFO - agent | Deploying flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179
[2021-05-12 20:23:00,050] DEBUG - agent | Submitted flow run 734edd41-a9de-4ab9-86b4-aaf332fa1179 to process PID 31690
[2021-05-12 20:23:00,068] DEBUG - agent | Completed flow run submission (id: 734edd41-a9de-4ab9-86b4-aaf332fa1179)
[2021-05-12 20:23:00,332] DEBUG - agent | Querying for flow runs
z
So here we can see that the flow run is "found" 3 times but twice tracked as a run the agent was "already submitting" and you can see it is only "Submitted" once
Basically: It looks like your flow run was only executed once in this log
m
Hmmm… Looking at the schematics that node in the dag that sends the email is only fired off once. But I’m getting two results, the text log and the UI log are different.
If I click quick run, there’s no text log output from the flow, only UI logs are shown, and that there’s no duplicate runs.
Could it be that the agent and also the local direct mode is running at the same time?
z
Do you call 
flow.run()
in your flow script?
You'll want to place that in a 
if __name__ == "__main__":
block if so
m
Yes I do call 
flow.run()
in the script, but it’s inside an 
if ___name___
. For example:
Copy code
def run():
    with Flow() as flow:    
        flow.run()

if __name__ == '__main__':
    run()
z
You'll want to structure it more like
Copy code
with Flow() as flow:
   my_task()

if __name__ == '__main_':
   flow.run()
6 Views
Open in Slack
PreviousNext
Powered by