Python jaeger-client tracer not reporting on reuse

Question

Tracing tasks in celery 4.1.1 using sample code. Each worker runs:

import logging
from jaeger_client import Config
import opentracing 

def get_tracer(service="Vienna"):
    config = Config(
        config={

            'sampler': {
                'type': 'const',
                'param': 1,
            },
            'logging': True,
        },
        service_name=service,
    )
    return config.initialize_tracer() or opentracing.global_tracer()

When I first start celery and run tasks each worker gets a working tracer and there is a log output for each of:

[2019-07-04 19:17:00,527: INFO/ForkPoolWorker-2] Initializing Jaeger Tracer with UDP reporter
[2019-07-04 19:17:00,546: INFO/ForkPoolWorker-2] opentracing.tracer initialized to <jaeger_client.tracer.Tracer object at 0x7f804d079c10>[app_name=SocketIOTask]

Any task that runs after the initial gets the global tracer from Config.initialze_tracer (which returns None) and a log warning Jaeger tracer already initialized, skipping.

Watching tcpdump on the console shows that the UDP packets aren't being sent, I think I'm getting an uninitialized default tracer and it's using the noop reporter.

I've pored over the code in opentracing and jaeger_client and I can't find a canonical way around this.

Hey Mark, how are you reporting spans to jaeger agent/collector ? — Mohit Chawla, Sep 12 '19 at 20:42
Had any luck with this? My case is even worse - debugger shows global tracer is totally there, just nothing reaches collector. — Lauri Elias, Mar 23 '20 at 15:40

Shubham Bakshi · Answer 1 · 2019-12-17T08:16:44.843

2

from jaeger_client import Config
def get_tracer(service="Vienna"):

    config = Config(
        config={
            'sampler': {
                'type': 'const',
                'param': 1,
            },
            'logging': True,
        },
        service_name=service,
     )

    tracer = config.initialize_tracer()
    if tracer is None:
        Config._initialized = False
        tracer = config.initialize_tracer()
    return tracer

edited Dec 17 '19 at 08:16

answered Dec 17 '19 at 08:11

Shubham Bakshi

156
6

11

Hi and welcome to stackoverflow, and thank you for your answer. Rather than just posting a block of code, can you give a short explanation to what the issue is you solved and how you solved it? This will help people who find this question in the future to better understand the issue and how to deal with it. – Plutian Dec 17 '19 at 08:18

score 1 · Answer 2 · answered Apr 30 '21 at 11:23

Celery forks multiple processes by default (--pool=prefork). The problem is that jaeger_client performs that actual message sending in a separate thread. This thread is created before forking and not available in the subprocesses. As the result, logging from subprocesses doesn't work.

The most obvious solution is to use --pool=solo, -pool=threads etc. But in the case of CPU-bound tasks, we still need to use --pool=prefork. In this case, we get another issue.

On the one side, jaeger_client is designed to be used as a singleton. It opens file descriptors but never closes them (even close() is more flush than close). On the other side, we need to create a separate tracer for every celery process.

In order to solve the issue, I used the following workaround:

tracer = None
tracer_owner_pid = 0

def get_jaeger_tracer():
    global tracer_owner_pid
    global tracer

    pid = os.getpid()
    if tracer_owner_pid == pid:
        return tracer

    logging.getLogger('').handlers = []
    logging.basicConfig(format='%(message)s', level=logging.DEBUG)
    config = Config(
        config={
            'sampler': {
                'type': 'const',
                'param': 1,
            },
            'logging': True,
        },
        service_name='foo',
    )

    tracer = config.new_tracer()
    tracer_owner_pid = pid
    return tracer

Python jaeger-client tracer not reporting on reuse

2 Answers2