Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] Logging level debug does not work in local or portal logs #735

Closed
ijoosong opened this issue Aug 14, 2020 · 13 comments · Fixed by #745
Closed

[BUG] Logging level debug does not work in local or portal logs #735

ijoosong opened this issue Aug 14, 2020 · 13 comments · Fixed by #745

Comments

@ijoosong
Copy link

Investigative information

Please provide the following:

In any python function, log level debug does not display in both local and portal logs.

Repro steps

Provide the steps required to reproduce the problem:

Expected behavior

Provide a description of the expected behavior.

Actual behavior

Provide a description of the actual behavior observed.

Known workarounds

Provide a description of any known workarounds.

Contents of the requirements.txt file:

Provide the requirements.txt file to help us find out module related issues.

Related information

Provide any related information
  • Links to source
  • Bindings used
@ijoosong
Copy link
Author

image

@Hazhzeng
Copy link
Contributor

Hazhzeng commented Sep 1, 2020

Just synced with my team offline @vrmdr and @stefanushinardi

The debug level log was controlled by the azure-functions-host --log-level flag. https://github.com/Azure/azure-functions-python-worker/blob/dev/azure_functions_worker/main.py#L21

I think the debug level was reserved for the python worker log in old days. We're currently following up the function-host team to ensure if the debug level is no longer used.

Thanks for reporting this issue.

@pragnagopa
Copy link
Member

pragnagopa commented Sep 3, 2020

@ijoosong - can you please share your host.json

Default log level is set to information for anything else you need to update host.json with the loglevel. For debug, your host.json should look like this:

{
	"version": "2.0",
	"logging": {
		"LogLevel": {
			"Default": "Debug"
		}
	},
	"extensionBundle": {
		"id": "Microsoft.Azure.Functions.ExtensionBundle",
		"version": "[1.*, 2.0.0)"
	}
}

@anthonychu
Copy link
Member

I was investigating this with @ijoosong a while back. Changing host.json doesn’t make a difference In this case because the worker currently hardcodes function logs to INFO as @vrdmr discovered.

@ijoosong
Copy link
Author

ijoosong commented Sep 3, 2020

@pragnagopa I've tried this and it doesn't work :(

@vrdmr
Copy link
Member

vrdmr commented Sep 3, 2020

@ijoosong We've figured out the fix and I'll send out the fix post-testing.

@Hazhzeng
Copy link
Contributor

Hazhzeng commented Sep 3, 2020

Thanks @pragnagopa, @vrdmr and @stefanushinardi for the offline sync up.
We determine that there're two places blocking the logging from emitting debug level logs:

  1. When the worker process is created, the host is not passing --log-level flag into the argument, thus the Python worker will only emit the INFO log into console. https://github.com/Azure/azure-functions-python-worker/blob/dev/azure_functions_worker/main.py#L21
  2. After the worker establishes GRPC channel to the host, the root logger will stop using console log and switch to GRPC log which is pinned to INFO https://github.com/Azure/azure-functions-python-worker/blob/dev/azure_functions_worker/dispatcher.py#L125

Since the GRPC logging handler is attached onto the root logger, currently we have a concern on the performance when dropping the INFO level constrain, since some third-party libraries are using DEBUG level logs (e.g. azure-storage-blob https://github.com/Azure/azure-sdk-for-python/blob/master/sdk/storage/azure-storage-blob/azure/storage/blob/_shared/policies.py#L201-L203).

@vrdmr
Copy link
Member

vrdmr commented Sep 3, 2020

@Hazhzeng

When the worker process is created, the host is not passing --log-level flag into the argument, thus the Python worker will only emit the INFO log into console. https://github.com/Azure/azure-functions-python-worker/blob/dev/azure_functions_worker/main.py#L21

How do we configure debug logging for workers logs from the host side? Is there an app setting that the host can pass in?

@Hazhzeng
Copy link
Contributor

Hazhzeng commented Sep 3, 2020

@vrdmr The host redirect all stdout and stderr from the Python process into asp.net logging infra. They don't control logging level in Python worker, they're just filtering the worker logs.

@ijoosong
Copy link
Author

Awesome thanks @vrdmr when will this change go live?

@vrdmr
Copy link
Member

vrdmr commented Sep 25, 2020

We are planning to get the new releases of the Python worker to go out by next week, I'll update you once that is done.

@ijoosong
Copy link
Author

@vrdmr is this out now?

@YunchuWang
Copy link
Member

@ijoosong it is released in function runtime v4 right now. Please refer to https://docs.microsoft.com/en-us/azure/azure-functions/functions-app-settings#python_enable_debug_logging for more details how to turn on user function debug logging.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants