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

TypeError in elasticapm.context.contextvars #2056

Open
jahendry opened this issue Jun 3, 2024 · 9 comments · May be fixed by #2179
Open

TypeError in elasticapm.context.contextvars #2056

jahendry opened this issue Jun 3, 2024 · 9 comments · May be fixed by #2179
Labels
agent-python community Issues opened by the community triage Issues awaiting triage

Comments

@jahendry
Copy link

jahendry commented Jun 3, 2024

I'm getting an unhandled TypeError from the set span method of the elasticapm.context.contextvars.ContextVar here

The spans variable is of type None and is throwing an unhandled exception.

I have been unable to find the root causes on this as it is happening in production sporadically without a clear way to reproduce it.

We are running this within a django/celery app with the following version numbers

django: 3.2.24
celery: 5.3.6
apm-agent-python: 6.20.0

Could we possibly add some type guards within this method or exception handling for this case?

Thanks,
Jamie

@github-actions github-actions bot added agent-python community Issues opened by the community triage Issues awaiting triage labels Jun 3, 2024
@xrmx
Copy link
Member

xrmx commented Jun 3, 2024

Thanks for reporting, could you provide the stacktrace please? Feel free to remove any eventual information you don't want to share from the file paths.

@jahendry
Copy link
Author

jahendry commented Jun 4, 2024

Thanks for getting back so quickly, see a recent stack trace attatched:
apm-exception.txt

	2024-06-04T04:15:59.011Z	Traceback (most recent call last):
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 477, in trace_task
	2024-06-04T04:15:59.011Z	R = retval = fun(*args, **kwargs)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery_once/tasks.py", line 75, in __call__
	2024-06-04T04:15:59.011Z	return super(QueueOnce, self).__call__(*args, **kwargs)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 760, in __protected_call__
	2024-06-04T04:15:59.011Z	return self.run(*args, **kwargs)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/autoretry.py", line 38, in run
	2024-06-04T04:15:59.011Z	return task._orig_run(*args, **kwargs)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 1079, in decorated
	2024-06-04T04:15:59.011Z	with self:
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 1085, in __enter__
	2024-06-04T04:15:59.011Z	return self.handle_enter(self.sync)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 1095, in handle_enter
	2024-06-04T04:15:59.011Z	return transaction.begin_span(
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 351, in begin_span
	2024-06-04T04:15:59.011Z	return self._begin_span(
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 319, in _begin_span
	2024-06-04T04:15:59.011Z	execution_context.set_span(span)
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/context/contextvars.py", line 82, in set_span
	2024-06-04T04:15:59.011Z	self.elasticapm_spans_var.set(spans + (span,))
	2024-06-04T04:15:59.011Z	~~~~~~^~~~~~~~~
	2024-06-04T04:15:59.011Z	TypeError: unsupported operand type(s) for +: 'NoneType' and 'tuple'
	2024-06-04T04:15:59.011Z	During handling of the above exception, another exception occurred:
	2024-06-04T04:15:59.011Z	Traceback (most recent call last):
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 494, in trace_task
	2024-06-04T04:15:59.011Z	I, R, state, retval = on_error(task_request, exc)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 399, in on_error
	2024-06-04T04:15:59.011Z	R = I.handle_error_state(
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 178, in handle_error_state
	2024-06-04T04:15:59.011Z	return {
	2024-06-04T04:15:59.011Z	^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/app/trace.py", line 230, in handle_failure
	2024-06-04T04:15:59.011Z	task.backend.mark_as_failure(
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/backends/base.py", line 167, in mark_as_failure
	2024-06-04T04:15:59.011Z	self.store_result(task_id, exc, state,
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/backends/base.py", line 526, in store_result
	2024-06-04T04:15:59.011Z	self._store_result(task_id, result, state, traceback,
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/backends/base.py", line 973, in _store_result
	2024-06-04T04:15:59.011Z	current_meta = self._get_task_meta_for(task_id)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/backends/base.py", line 995, in _get_task_meta_for
	2024-06-04T04:15:59.011Z	meta = self.get(self.get_key_for_task(task_id))
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/celery/backends/redis.py", line 376, in get
	2024-06-04T04:15:59.011Z	return self.client.get(key)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/redis/commands/core.py", line 1816, in get
	2024-06-04T04:15:59.011Z	return self.execute_command("GET", name)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/instrumentation/packages/base.py", line 213, in call_if_sampling
	2024-06-04T04:15:59.011Z	return self.call(module, method, wrapped, instance, args, kwargs)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/instrumentation/packages/redis.py", line 65, in call
	2024-06-04T04:15:59.011Z	with capture_span(wrapped_name, span_type="db", span_subtype="redis", span_action="query", leaf=True):
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 1085, in __enter__
	2024-06-04T04:15:59.011Z	return self.handle_enter(self.sync)
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 1095, in handle_enter
	2024-06-04T04:15:59.011Z	return transaction.begin_span(
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 351, in begin_span
	2024-06-04T04:15:59.011Z	return self._begin_span(
	2024-06-04T04:15:59.011Z	^^^^^^^^^^^^^^^^^
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/traces.py", line 319, in _begin_span
	2024-06-04T04:15:59.011Z	execution_context.set_span(span)
	2024-06-04T04:15:59.011Z	File "/usr/local/lib/python3.11/site-packages/elasticapm/context/contextvars.py", line 82, in set_span
	2024-06-04T04:15:59.011Z	self.elasticapm_spans_var.set(spans + (span,))
	2024-06-04T04:15:59.011Z	~~~~~~^~~~~~~~~
	2024-06-04T04:15:59.011Z	TypeError: unsupported operand type(s) for +: 'NoneType' and 'tuple'

@xrmx
Copy link
Member

xrmx commented Jun 4, 2024

Is this log coming from celery workers right? What kind of workers are you using?

@jahendry
Copy link
Author

jahendry commented Jun 4, 2024

It is celery yeah, we are using prefork workers

@xrmx
Copy link
Member

xrmx commented Jun 5, 2024

@jahendry what version of python are you using?

@jahendry
Copy link
Author

jahendry commented Jun 5, 2024

Hey,

We're using 3.11, specifically this image here

@xrmx
Copy link
Member

xrmx commented Jun 5, 2024

Thanks, which tag? It's interesting to check the micro version too.

@jahendry
Copy link
Author

jahendry commented Jun 5, 2024

Ah sorry, it's 3.11.9

duck-nukem added a commit to duck-nukem/apm-agent-python that referenced this issue Dec 16, 2024
…xtVars

to avoid accidentally trying to merge a None with a tuple of Spans

Related to elastic#2056
@duck-nukem
Copy link

We also face a similar issue, it seems to happen when exceptions are raised and aren't properly caught - not sure if that's the exact reason, this is what I gather from our sentry events.

  • Python 3.11.9
  • Django 4.2.17
  • Celery 5.3.1
  • Elastic APM 6.23.0

I've created a pull request that'd handle the case where spans from the ContextVar is None, but I couldn't find a root cause for this to be able to make a more proper fix. Suggestions welcome if anyone has investigated this issue more in depth already

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
agent-python community Issues opened by the community triage Issues awaiting triage
Projects
None yet
3 participants