https://prefect.io logo
Join Slack
Powered by
How do I get `print()` statements to show up in th...
# prefect-server
j
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:
Copy code
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
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
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
Copy code
[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
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
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
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
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
@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:
Copy code
@task(log_stdout=True)
def simple_func():
    print('simple print statement')
j
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
Is 
log_to_cloud
still set to true in your config.toml?
j
I've run it with:
Copy code
[logging]
log_to_cloud = true
and with
Copy code
[logging]
log_to_cloud = false
and with
Copy code
[logging]
#log_to_cloud = true
They are give the same result: the log goes to the web browser.
n
If you modified the 
log_stdout
kwarg you'll need to reregister - did you already do that?
j
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
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
Here is my flow:
Copy code
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
Copy code
[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
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
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
Is it possible you have a different agent picking up the run?
j
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:
Copy code
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
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
Behavior remains the same after a reboot. I'll file a bug ticket.
n
Ok - feel free to link to this slack conversation in the ticket, it might be helpful context (you can also cc me @znicholasbrown )
j
Thanks for your help digging into this. Now I know what it should be doing 👍
n
Happy to help! The Core team will have more insight there, I'll follow along!
2 Views
Open in Slack
PreviousNext
Powered by