https://prefect.io logo
Title
j

jack

12/15/2020, 2:32 AM
How do I get
print()
statements to show up in the web console at localhost:8080? Here's my example code that prints to the terminal, but does not now up in the web console:
from prefect import task, Flow

@task
def simple_func(log_stdout=True):
    print('simple print statement')


if __name__ == '__main__':
    with Flow('test-logging') as flow:
        simple_func()

    flow.register('test-log')
    flow.run()
n

nicholas

12/15/2020, 2:34 AM
Hi @jack - check out the docs on Logging; I think those will give you everything you need for that but let me know if not 🙂
j

jack

12/15/2020, 2:35 AM
Thanks for the link. That's where I started reading. Then searched the slack archives and read a few examples. Some people see to have simple logging working using the log_stdout=True kwarg, and others do not. It's not working yet for me.
Not sure if I'm supposed to set
log_to_cloud = true
in config.toml or not.
Is there a
log_to_server
option? I'm using the server backend
[2020-12-15 02:37:16+0000] CRITICAL - CloudHandler | Failed to write log with error: 400 Client Error: Bad Request for url: <http://localhost:4200/graphql>

The following error messages were provided by the GraphQL server:

    INTERNAL_SERVER_ERROR: Variable "$input" got invalid value null at
        "input.logs[0].flow_run_id"; Expected non-nullable type UUID! not to be null.

The GraphQL query was:

    mutation($input: write_run_logs_input!) {
            write_run_logs(input: $input) {
                success
        }
    }

The passed variables were:

    {"input": {"logs": [{"flow_run_id": null, "task_run_id": null, "timestamp": "2020-12-15T02:37:15.644721+00:00", "name": "prefect.FlowRunner", "message": "Beginning Flow run for 'test-alteryx-logging'", "level": "INFO", "info": {"msg": "Beginning Flow run for 'test-alteryx-logging'", "levelno": 20, "pathname": "/home/vagrant/p/ts-prefect-1.0/env/lib64/python3.7/site-packages/prefect/engine/flow_runner.py", "filename": "flow_runner.py", "module": "flow_runner", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 224, "funcName": "run", "msecs": 644.721269607544, "relativeCreated": 2320.8816051483154, "thread": 140260445312832, "threadName": "MainThread", "processName": "MainProcess", "process": 14188, "asctime": "2020-12-15 02:37:15+0000"}}, {"flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "task_run_id": "b2b390d0-bf27-42dc-9c50-2b076563fae6", "timestamp": "2020-12-15T02:37:15.929799+00:00", "name": "prefect.TaskRunner", "message": "Task 'simple_func': Starting task run...", "level": "INFO", "info": {"msg": "Task 'simple_func': Starting task run...", "levelno": 20, "pathname": "/home/vagrant/p/ts-prefect-1.0/env/lib64/python3.7/site-packages/prefect/engine/task_runner.py", "filename": "task_runner.py", "module": "task_runner", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 237, "funcName": "run", "msecs": 929.7986030578613, "relativeCreated": 2605.958938598633, "thread": 140260445312832, "threadName": "MainThread", "processName": "MainProcess", "process": 14188, "flow_name": "test-alteryx-logging", "flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "task_name": "simple_func", "task_slug": "simple_func-1", "task_run_id": "b2b390d0-bf27-42dc-9c50-2b076563fae6", "asctime": "2020-12-15 02:37:15+0000"}}, {"flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "task_run_id": "b2b390d0-bf27-42dc-9c50-2b076563fae6", "timestamp": "2020-12-15T02:37:16.045748+00:00", "name": "prefect.TaskRunner", "message": "Task 'simple_func': Finished task run for task with final state: 'Success'", "level": "INFO", "info": {"msg": "Task 'simple_func': Finished task run for task with final state: 'Success'", "levelno": 20, "pathname": "/home/vagrant/p/ts-prefect-1.0/env/lib64/python3.7/site-packages/prefect/engine/task_runner.py", "filename": "task_runner.py", "module": "task_runner", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 332, "funcName": "run", "msecs": 45.74751853942871, "relativeCreated": 2721.9078540802, "thread": 140260445312832, "threadName": "MainThread", "processName": "MainProcess", "process": 14188, "flow_name": "test-alteryx-logging", "flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "task_name": "simple_func", "task_slug": "simple_func-1", "task_run_id": "b2b390d0-bf27-42dc-9c50-2b076563fae6", "asctime": "2020-12-15 02:37:16+0000"}}, {"flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "task_run_id": null, "timestamp": "2020-12-15T02:37:16.048198+00:00", "name": "prefect.FlowRunner", "message": "Flow run SUCCESS: all reference tasks succeeded", "level": "INFO", "info": {"msg": "Flow run SUCCESS: all reference tasks succeeded", "levelno": 20, "pathname": "/home/vagrant/p/ts-prefect-1.0/env/lib64/python3.7/site-packages/prefect/engine/flow_runner.py", "filename": "flow_runner.py", "module": "flow_runner", "exc_info": null, "exc_text": null, "stack_info": null, "lineno": 685, "funcName": "determine_final_state", "msecs": 48.19774627685547, "relativeCreated": 2724.358081817627, "thread": 140260445312832, "threadName": "MainThread", "processName": "MainProcess", "process": 14188, "flow_name": "test-alteryx-logging", "flow_run_id": "9e720791-b7c1-406e-a773-f3ff23e4cb01", "asctime": "2020-12-15 02:37:16+0000"}}]}}

[2020-12-15 02:37:16+0000] CRITICAL - CloudHandler | Unable to write logs to Prefect Cloud
[2020-12-15 02:37:16+0000] CRITICAL - CloudHandler | Unable to write logs to Prefect Cloud
[2020-12-15 02:37:16+0000] CRITICAL - CloudHandler | Unable to write logs to Prefect Cloud
If I do set
log_to_cloud
to true, running the task throws an error:
n

nicholas

12/15/2020, 2:38 AM
log_to_cloud
will send to either Server or Cloud (whichever it's running against)
Hm that looks like a bug then, let me take a quick look at that code
Oh hold on - are you trying to log to Server from a local run? (using
flow.run()
)
j

jack

12/15/2020, 2:48 AM
When I call
flow.run()
I don't expect the log to show up in the browser. But after registering the flow and then running it from the browser, that's when I expect the log to show up in the browser. (But it doesn't)
n

nicholas

12/15/2020, 2:50 AM
Got it - the log you posted above is from the local run, right? (Trying to make sure I'm looking in the right place)
j

jack

12/15/2020, 2:51 AM
Just found additional documentation for logging: https://docs.prefect.io/core/idioms/logging.html
Yes, the log posted above is from the local run.
Also tried restarting the server and the agent after changing config.toml. Not sure if that makes a difference or not
n

nicholas

12/15/2020, 2:57 AM
@jack it looks like you're passing the
log_stdout
as a keyword to your task, instead of to the task decorator... your above code should be:
@task(log_stdout=True)
def simple_func():
    print('simple print statement')
j

jack

12/15/2020, 3:08 AM
Oh silly me... So I've moved the log_stdout kwarg to the task decorator. Now the printed line shows up in the browser regardless of whether log_to_cloud is true or false. So perhaps log_to_cloud is not being honored
n

nicholas

12/15/2020, 3:10 AM
Is
log_to_cloud
still set to true in your config.toml?
j

jack

12/15/2020, 3:13 AM
I've run it with:
[logging]
log_to_cloud = true
and with
[logging]
log_to_cloud = false
and with
[logging]
#log_to_cloud = true
They are give the same result: the log goes to the web browser.
n

nicholas

12/15/2020, 3:26 AM
If you modified the
log_stdout
kwarg you'll need to reregister - did you already do that?
j

jack

12/15/2020, 1:18 PM
I left the
log_stdout
kwarg in place, but just changed the config.toml.
To be clear, the print() statement now shows up as a prefect log. I just want to understand what
log_to_cloud
does so I can add it to the documentation. And for me the logs are showing up regardless of the
log_to_cloud
setting.
n

nicholas

12/15/2020, 5:13 PM
Ah ok - so then
log_to_cloud
will determine if any logs are sent to your Server... however changes to that will require that you restart your agent.
It only impacts
log_stdout
insofar as that uses the Prefect logger in general
j

jack

12/15/2020, 5:29 PM
Here is my flow:
from prefect import task, Flow

@task(log_stdout=True)
def simple_func():
    print('simple print statement')


if __name__ == '__main__':
    with Flow('simple-print-statement') as flow:
        simple_func()

    flow.register('test-log')
    flow.run()
and here is my ~/.prefect/config.toml
[logging]
log_to_cloud = false
extra_loggers = "['clone', 'special']"
and here is the log in the browser (which probably isn't expected to be there)
n

nicholas

12/15/2020, 5:39 PM
Hm, it looks like your agent isn't correctly picking up your config - this could happen if it doesn't have access to the config, wasn't restarted, or there's an environment variable overriding it
j

jack

12/15/2020, 5:46 PM
To test this out, I've removed the closing square bracket from
[logging]
in config.toml. Upon restarting the agent, it raises an exception inside /env/lib64/python3.7/site-packages/toml/decoder.py So it appears to be loading the config file.
n

nicholas

12/15/2020, 5:52 PM
Is it possible you have a different agent picking up the run?
j

jack

12/15/2020, 5:55 PM
I stopped the agent in terminal two just to see what would happen. Clicked "Quick Run" and waited about a minute---still hasn't run.
Then I started the agent in terminal two with this environment variable:
PREFECT__LOGGING__LOG_TO_CLOUD=false prefect agent local start
The flow ran about ten seconds after the agent was started, and it still has the
simple print statement
in the logs in the browser
I'm going to reboot my computer to see if that changes anything
n

nicholas

12/15/2020, 5:58 PM
Ok great, that's helpful. It seems like you've done all you can here - if after a restart you're still seeing those logs, let's open a bug ticket
j

jack

12/15/2020, 6:15 PM
Behavior remains the same after a reboot. I'll file a bug ticket.
n

nicholas

12/15/2020, 6:15 PM
Ok - feel free to link to this slack conversation in the ticket, it might be helpful context (you can also cc me @znicholasbrown )
j

jack

12/15/2020, 6:25 PM
Thanks for your help digging into this. Now I know what it should be doing 👍
n

nicholas

12/15/2020, 6:26 PM
Happy to help! The Core team will have more insight there, I'll follow along!