[Bug] python log_reporter_level='INFO' is not work when start with django uWSGI

[ysy1418899560]

Search before asking

• [X] I had searched in the issues and found no similar issues.

Apache SkyWalking Component

Python Agent (apache/skywalking-python)

What happened

The params log_reporter_level='INFO' is not work when start with django uWSGI，on the UI only collect ERROR log, but cant collect INFO log。 python==3.7.9 django==3.2.7 uwsgi==2.0.19.1 apache-skywalking==0.7.0 skywalking version is 8.7.0

This is my code: from skywalking import agent, config from uwsgidecorators import postfork

@postfork def init_tracing(): config.init(collector_address='127.0.0.1:11800', service_name='video_processor', log_reporter_active=True, log_reporter_level='INFO', django_collect_http_params=True) agent.start()

What you expected to happen

I hope set the params log_reporter_level='INFO' can collect info level log, and clicking the trace id will jump to the tracking interface when statr with django uWSGI。

How to reproduce

python==3.7.9 django==3.2.7 uwsgi==2.0.19.1 apache-skywalking==0.7.0 skywalking version is 8.7.0

Below is my code: from skywalking import agent, config from uwsgidecorators import postfork

@postfork def init_tracing(): config.init(collector_address='127.0.0.1:11800', service_name='video_processor', log_reporter_active=True, log_reporter_level='INFO', django_collect_http_params=True) agent.start()

Anything else

No response

Are you willing to submit PR?

• [ ] Yes I am willing to submit a PR!

Code of Conduct

• [X] I agree to follow this project's Code of Conduct

[Superskyyy]

@ysy1418899560 Hello, thank you for reporting the potential bug! I will be looking into this and try reproduce the problem.

[Superskyyy]

@ysy1418899560 Can you confirm that bare django without uwsgi works fine on your side? I just did a quick test without uwsgi and it is fine.

[ysy1418899560]

It can collects info level log without uwsgi on my side，but the generated trace id is different between on log interface and tracking interface。Trace id is '8074295ba1f11eca9c6f8281960ba1c' on tracking interfacee，but on log interface is 'ec28b995ba1f11ec91def8281960ba1c'。Pages cannot jump to each other。

[Superskyyy]

It can collects info level log without uwsgi on my side，but the generated trace id is different between on log interface and tracking interface。Trace id is '8074295ba1f11eca9c6f8281960ba1c' on tracking interfacee，but on log interface is 'ec28b995ba1f11ec91def8281960ba1c'。Pages cannot jump to each other。

Thanks for the update, I'll be looking into this issue.

[Superskyyy]

@ysy1418899560 Hello, I think I kinda know the cause, it is not quite related to SkyWalking agent, rather it is a behaviour when uwsgi causes the spawned workers to somehow "lose" logging handler abilities - that is a log record emitted in a uwsgi worker is entirely ignored (not even passed to the base handler). The behaviour is different from that of using logging without uwsgi.

The workaround is simply set in your postfork function for now. logging.basicConfig(level='INFO')

I will need to understand the thing further to ~~make a proper enhancement~~.

[ysy1418899560]

Thanks for you，l will try this method。Please help to solve another issues that the trace id is inconsistency without uwsgi。Pages cannot jump to each other by trace id。

[Superskyyy]

Thanks for you，l will try this method。Please help to solve another issues that the trace id is inconsistency without uwsgi。Pages cannot jump to each other by trace id。

I will also look into this one.

BTW I just took another look at the level issue. And I realized that setting your logger to INFO level is a proper way not just a workaround, because you need to first let the logging.logger.handler receive the logRecord before it can be intercepted (this is how logging library is written).

The reason why it is acting differently inside uwsgi is that the particular logger in Django core code is disabled for some reason (performance I suppose), then nothing at the INFO level shows up anymore. In bare django settings, it will output much more INFO level logs (server logs) like here. So if you need these INFO level logs collected, you need to find a way to reenable the Django loggers, but this is not related to SkyWalking anymore.

TLDR, the proper way to deal with this is to make your logger level at least the same as the level you set in agent so that it can be intercepted.

[Superskyyy]

Todo for me: enhance document on the reporter level config.

[Superskyyy]

The invalid traceID problem is solved in https://github.com/apache/skywalking-python/pull/272 and other parts are coming in the pre-fork support. So closing this issue.