Why no task logs in Prefect Cloud?

ChrisH · February 16, 2023, 2:42pm

I’m learning Prefect and am testing deployments in the cloud. When I looked to see the log output for a flow, I can see the flow-level logs, but not the task-level logs.

I have just one Task Run - log_task-0, and it says “This run didn’t generate logs”.

However, in the console where I ran the agent, I see the following Task logs:

The logs do appear in the local Prefect UI if I run the deployment locally.

What do I need to do to get those logs to show up in Prefect Cloud so I can troubleshoot problems on the very remote chance that things don’t work perfectly the first time.

yaiba · April 7, 2023, 7:52am

Have you managed to solve this? In my case I use print() then I can only see text printed when running locally (via python .py). That output is not recorded in flow run’s log when viewing on Web UI.

Jeff_Hale_Prefect · April 7, 2023, 11:13am

Use @flow(log_prints=True) and print statements should be logged.

yaiba · April 7, 2023, 11:35am

Thank you!

yaiba · April 8, 2023, 4:07pm

@Jeff_Hale_Prefect Is it possible to capture all the output of a flow run? For example when I use a Docker infrastructure as guided here Docker - Prefect Docs , in console (of agent) I can see container output including pip installation progress, but that information is not included in flow run’s log.

Jeff_Hale_Prefect · April 10, 2023, 4:40pm

If you set the default logging level environment variable to DEBUG that might pick them up.

PREFECT_LOGGING_LEVEL="DEBUG" .

yaiba · April 13, 2023, 11:52am

Hi @Jeff_Hale_Prefect , I’ve tried that but it still not included in flow run’s log on Web UI.

Jeff_Hale_Prefect · April 13, 2023, 12:19pm

If you upgrade to 2.10.3 (the latest Prefect version), does that help?

yaiba · April 13, 2023, 12:34pm

I’ll try that again layer today, thank you.

yaiba · April 13, 2023, 10:11pm

Hi Jeff,
I tried with latest 2.10.3 version but still now pip install output recorded on Web UI.
For the sake of clarity, this is log output on agent console:

Apr 13 22:03:59 photos prefect[18099]: 22:03:59.443 | INFO    | prefect.agent - Submitting flow run '0eaf99af-5532-4f3d-ace6-6bee54376451'
Apr 13 22:03:59 photos prefect[18099]: 22:03:59.560 | INFO    | prefect.infrastructure.docker-container - Creating Docker container 'venomous-caracara'...
Apr 13 22:03:59 photos prefect[18099]: 22:03:59.595 | INFO    | prefect.infrastructure.docker-container - Docker container 'venomous-caracara' has status 'created'
Apr 13 22:03:59 photos prefect[18099]: 22:03:59.933 | INFO    | prefect.infrastructure.docker-container - Docker container 'venomous-caracara' has status 'running'
Apr 13 22:03:59 photos prefect[18099]: 22:03:59.944 | INFO    | prefect.agent - Completed submission of flow run '0eaf99af-5532-4f3d-ace6-6bee54376451'
Apr 13 22:04:05 photos prefect[18099]: 22:04:05.718 | DEBUG   | prefect.agent - Checking for cancelled flow runs...
Apr 13 22:04:08 photos prefect[18099]: 22:02:48.715 | DEBUG   | Task run 'log_task-0' - Hello from another file
Apr 13 22:04:08 photos prefect[18099]: 22:02:48.719 | INFO    | Task run 'log_task-0' - Another message by print
Apr 13 22:04:08 photos prefect[18099]: 22:02:48.768 | INFO    | Task run 'log_task-0' - Finished in state Completed()
Apr 13 22:04:08 photos prefect[18099]: 22:02:48.815 | DEBUG   | prefect.task_runner.concurrent - Shutting down task runner...
Apr 13 22:04:08 photos prefect[18099]: 22:02:48.816 | INFO    | Flow run 'rampant-bear' - Finished in state Completed('All states completed.')
Apr 13 22:04:08 photos prefect[18099]: +pip install s3fs smbprotocol adlfs
Apr 13 22:04:08 photos prefect[18099]: Collecting s3fs
Apr 13 22:04:08 photos prefect[18099]:   Downloading s3fs-2023.4.0-py3-none-any.whl (28 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting smbprotocol
Apr 13 22:04:08 photos prefect[18099]:   Downloading smbprotocol-1.10.1-py3-none-any.whl (125 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 125.6/125.6 kB 5.7 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting adlfs
Apr 13 22:04:08 photos prefect[18099]:   Downloading adlfs-2023.1.0-py3-none-any.whl (25 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting fsspec==2023.4.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading fsspec-2023.4.0-py3-none-any.whl (153 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 154.0/154.0 kB 6.4 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting aiohttp!=4.0.0a0,!=4.0.0a1
Apr 13 22:04:08 photos prefect[18099]:   Downloading aiohttp-3.8.4-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (1.0 MB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.0/1.0 MB 7.0 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting aiobotocore~=2.5.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading aiobotocore-2.5.0-py3-none-any.whl (72 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 72.7/72.7 kB 5.6 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: cryptography>=2.0 in /usr/local/lib/python3.10/site-packages (from smbprotocol) (40.0.1)
Apr 13 22:04:08 photos prefect[18099]: Collecting pyspnego
Apr 13 22:04:08 photos prefect[18099]:   Downloading pyspnego-0.8.0-py3-none-any.whl (130 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 130.7/130.7 kB 6.0 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting azure-core<2.0.0,>=1.23.1
Apr 13 22:04:08 photos prefect[18099]:   Downloading azure_core-1.26.4-py3-none-any.whl (173 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 173.9/173.9 kB 6.4 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting azure-storage-blob>=12.12.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading azure_storage_blob-12.16.0-py3-none-any.whl (387 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 388.0/388.0 kB 7.1 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting azure-datalake-store<0.1,>=0.0.46
Apr 13 22:04:08 photos prefect[18099]:   Downloading azure_datalake_store-0.0.52-py2.py3-none-any.whl (61 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.7/61.7 kB 4.9 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting azure-identity
Apr 13 22:04:08 photos prefect[18099]:   Downloading azure_identity-1.12.0-py3-none-any.whl (135 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 135.5/135.5 kB 5.0 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting aioitertools>=0.5.1
Apr 13 22:04:08 photos prefect[18099]:   Downloading aioitertools-0.11.0-py3-none-any.whl (23 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting wrapt>=1.10.10
Apr 13 22:04:08 photos prefect[18099]:   Downloading wrapt-1.15.0-cp310-cp310-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (78 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 78.4/78.4 kB 5.2 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting botocore<1.29.77,>=1.29.76
Apr 13 22:04:08 photos prefect[18099]:   Downloading botocore-1.29.76-py3-none-any.whl (10.4 MB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 10.4/10.4 MB 7.6 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: attrs>=17.3.0 in /usr/local/lib/python3.10/site-packages (from aiohttp!=4.0.0a0,!=4.0.0a1->s3fs) (22.2.0)
Apr 13 22:04:08 photos prefect[18099]: Collecting frozenlist>=1.1.1
Apr 13 22:04:08 photos prefect[18099]:   Downloading frozenlist-1.3.3-cp310-cp310-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (149 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 149.6/149.6 kB 6.4 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting async-timeout<5.0,>=4.0.0a3
Apr 13 22:04:08 photos prefect[18099]:   Downloading async_timeout-4.0.2-py3-none-any.whl (5.8 kB)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: charset-normalizer<4.0,>=2.0 in /usr/local/lib/python3.10/site-packages (from aiohttp!=4.0.0a0,!=4.0.0a1->s3fs) (3.1.0)
Apr 13 22:04:08 photos prefect[18099]: Collecting multidict<7.0,>=4.5
Apr 13 22:04:08 photos prefect[18099]:   Downloading multidict-6.0.4-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (114 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 114.5/114.5 kB 5.9 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting aiosignal>=1.1.2
Apr 13 22:04:08 photos prefect[18099]:   Downloading aiosignal-1.3.1-py3-none-any.whl (7.6 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting yarl<2.0,>=1.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading yarl-1.8.2-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (264 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 264.0/264.0 kB 6.7 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: typing-extensions>=4.3.0 in /usr/local/lib/python3.10/site-packages (from azure-core<2.0.0,>=1.23.1->adlfs) (4.5.0)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: six>=1.11.0 in /usr/local/lib/python3.10/site-packages (from azure-core<2.0.0,>=1.23.1->adlfs) (1.16.0)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: requests>=2.18.4 in /usr/local/lib/python3.10/site-packages (from azure-core<2.0.0,>=1.23.1->adlfs) (2.28.2)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: cffi in /usr/local/lib/python3.10/site-packages (from azure-datalake-store<0.1,>=0.0.46->adlfs) (1.15.1)
Apr 13 22:04:08 photos prefect[18099]: Collecting adal>=0.4.2
Apr 13 22:04:08 photos prefect[18099]:   Downloading adal-1.2.7-py2.py3-none-any.whl (55 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 55.5/55.5 kB 4.7 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting isodate>=0.6.1
Apr 13 22:04:08 photos prefect[18099]:   Downloading isodate-0.6.1-py2.py3-none-any.whl (41 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 41.7/41.7 kB 4.1 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Collecting msal-extensions<2.0.0,>=0.3.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading msal_extensions-1.0.0-py2.py3-none-any.whl (19 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting msal<2.0.0,>=1.12.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading msal-1.21.0-py2.py3-none-any.whl (89 kB)
Apr 13 22:04:08 photos prefect[18099]:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 89.9/89.9 kB 4.1 MB/s eta 0:00:00
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: python-dateutil<3,>=2.1.0 in /usr/local/lib/python3.10/site-packages (from adal>=0.4.2->azure-datalake-store<0.1,>=0.0.46->adlfs) (2.8.2)
Apr 13 22:04:08 photos prefect[18099]: Collecting PyJWT<3,>=1.0.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading PyJWT-2.6.0-py3-none-any.whl (20 kB)
Apr 13 22:04:08 photos prefect[18099]: Collecting jmespath<2.0.0,>=0.7.1
Apr 13 22:04:08 photos prefect[18099]:   Downloading jmespath-1.0.1-py3-none-any.whl (20 kB)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: urllib3<1.27,>=1.25.4 in /usr/local/lib/python3.10/site-packages (from botocore<1.29.77,>=1.29.76->aiobotocore~=2.5.0->s3fs) (1.26.15)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: pycparser in /usr/local/lib/python3.10/site-packages (from cffi->azure-datalake-store<0.1,>=0.0.46->adlfs) (2.21)
Apr 13 22:04:08 photos prefect[18099]: Collecting portalocker<3,>=1.0
Apr 13 22:04:08 photos prefect[18099]:   Downloading portalocker-2.7.0-py2.py3-none-any.whl (15 kB)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: idna<4,>=2.5 in /usr/local/lib/python3.10/site-packages (from requests>=2.18.4->azure-core<2.0.0,>=1.23.1->adlfs) (3.4)
Apr 13 22:04:08 photos prefect[18099]: Requirement already satisfied: certifi>=2017.4.17 in /usr/local/lib/python3.10/site-packages (from requests>=2.18.4->azure-core<2.0.0,>=1.23.1->adlfs) (2022.12.7)
Apr 13 22:04:08 photos prefect[18099]: Installing collected packages: wrapt, PyJWT, portalocker, multidict, jmespath, isodate, fsspec, frozenlist, async-timeout, aioitertools, yarl, botocore, azure-core, aiosignal, pyspnego, azure-storage-blob, aiohttp, adal, smbprotocol, msal, azure-datalake-store, aiobotocore, s3fs, msal-extensions, azure-identity, adlfs
Apr 13 22:04:08 photos prefect[18099]:   Attempting uninstall: fsspec
Apr 13 22:04:08 photos prefect[18099]:     Found existing installation: fsspec 2023.1.0
Apr 13 22:04:08 photos prefect[18099]:     Uninstalling fsspec-2023.1.0:
Apr 13 22:04:08 photos prefect[18099]:       Successfully uninstalled fsspec-2023.1.0
Apr 13 22:04:11 photos prefect[18099]: 22:04:11.914 | INFO    | prefect.infrastructure.docker-container - Docker container 'venomous-caracara' has status 'removing'
Apr 13 22:04:11 photos prefect[18099]: 22:04:11.917 | INFO    | prefect.infrastructure.docker-container - Docker container 'venomous-caracara' has status 'removing'

And this is log output on Web UI, it doesn’t include pip install output from console’s log.

Thank you.

Jeff_Hale_Prefect · April 13, 2023, 10:15pm

Ah, ok. I see. Starting with the following line:

Apr 13 22:04:08 photos prefect[18099]: +pip install s3fs smbprotocol adlfs

That section is not logged by Prefect. It’s just showing up in your terminal because it’s being installed in the infrastructure you are using. That pip install isn’t logged by Prefect.