bug: async calling of LangGraph with a LangFuse callback does not log the model invocations (Python client)

[zoltan-fedor]

Describe the bug

I am implementing the a ReAct agent in LangGraph (see https://github.com/roboticsocialism/langgraph_demo/blob/main/langgraph_demo.py) and use LangFuse for callbacks.

When I call the created LangGraph compiled graph with app.invoke(inputs, config={"callbacks": [langfuse_handler]}) then it properly register in LangFuse the model invocations part of the ReAct chain, but when I replace that call to be async (await app.ainvoke(inputs, config={"callbacks": [langfuse_handler]}) then the model invocations are no longer logged in LangFuse.

Trace when called sync ( app.invoke(inputs, config={"callbacks": [langfuse_handler]})):

Trace when the same compiled graph is called async (await app.ainvoke(inputs, config={"callbacks": [langfuse_handler]})):

To reproduce

Implement a ReAct graph in LangGraph (https://github.com/roboticsocialism/langgraph_demo/blob/main/langgraph_demo.py) and add LangFuse as callback to the invocation.
Try out both with the sync and async invocation and observe the difference in tracing in LangFuse.

Additional information

langgraph v0.0.39
langfuse Python client v2.27.3

Note: I am not sure whether should I have posted this against the Python SDK (https://github.com/langfuse/langfuse-python)?

[marcklingen]

Thanks for reporting this, we need to look into what causes this as ainvoke works for non-langgraph. Happy to support if you want to contribute to this fix

[marcklingen]

do you get any error logs from the sdk?

[zoltan-fedor]

I am not seeing any errors on normal verbosity, but let me try to increase that, maybe then something will visible

[zoltan-fedor]

@marcklingen

I ran it again with the langfuse logs set to DEBUG.
Lots of logs from LangFuse, no error.

Simply when making the async call then it makes fewer Langfuse calls (and so associated logs) and the RunnableSequence and those other missing spans are not created and no sign of them in the logs either.

Debug logs when running sync:

... [ this part is the same ] ...
DEBUG:langfuse:item size 604
DEBUG:langfuse:Event: on_chain_start, run_id: b632e, parent_run_id: d7026, inputs: {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}
DEBUG:langfuse:Creating span {'id': '6e40e021-9f75-4a46-b755-d176dc900bee', 'name': 'RunnableSequence', 'start_time': datetime.datetime(2024, 4, 30, 20, 40, 27, 450347, tzinfo=datetime.timezone.utc), 'metadata': None, 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'output': None, 'level': None, 'status_message': None, 'version': '0.0.39', 'end_time': None, 'trace_id': 'fb5fb442-9a57-413b-8083-68afb97a4f73'}...
DEBUG:langfuse:adding task {'id': '426cc63d-cad5-4469-9071-171c7f14d1c5', 'type': 'span-create', 'body': {'traceId': 'fb5fb442-9a57-413b-8083-68afb97a4f73', 'name': 'RunnableSequence', 'startTime': datetime.datetime(2024, 4, 30, 20, 40, 27, 450347, tzinfo=datetime.timezone.utc), 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'parentObservationId': 'cf41c025-f2bd-4c4f-9acc-8f40b4d7af50', 'version': '0.0.39', 'id': '6e40e021-9f75-4a46-b755-d176dc900bee'}}
DEBUG:langfuse:item size 573
DEBUG:langfuse:Event: on_chain_start, run_id: 82959, parent_run_id: b632e, inputs: {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}
DEBUG:langfuse:Creating span {'id': 'ef60e266-a1a4-4b0b-a4e8-4cf25a3979ea', 'name': 'RunnableAssign<agent_scratchpad>', 'start_time': datetime.datetime(2024, 4, 30, 20, 40, 27, 457208, tzinfo=datetime.timezone.utc), 'metadata': {'tags': ['seq:step:1']}, 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'output': None, 'level': None, 'status_message': None, 'version': '0.0.39', 'end_time': None, 'trace_id': 'fb5fb442-9a57-413b-8083-68afb97a4f73'}...
DEBUG:langfuse:adding task {'id': '7040e08a-93a7-445c-bc8e-6b88f1c85aab', 'type': 'span-create', 'body': {'traceId': 'fb5fb442-9a57-413b-8083-68afb97a4f73', 'name': 'RunnableAssign<agent_scratchpad>', 'startTime': datetime.datetime(2024, 4, 30, 20, 40, 27, 457208, tzinfo=datetime.timezone.utc), 'metadata': {'tags': ['seq:step:1']}, 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'parentObservationId': '6e40e021-9f75-4a46-b755-d176dc900bee', 'version': '0.0.39', 'id': 'ef60e266-a1a4-4b0b-a4e8-4cf25a3979ea'}}
DEBUG:langfuse:Event: on_chain_start, run_id: b3c74, parent_run_id: 82959, inputs: {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}
...

When running async, that whole section (where you have the RunnableSequence spans) is just missing:

... [ this part is the same ] ...
DEBUG:langfuse:item size 604
DEBUG:langfuse:uploading batch of 6 items
DEBUG:langfuse:uploading data: {'batch': [{'id': '7daa9597-e68a-486d-866f-0e956b0115b6', 'type': 'trace-create', 'body': {'id': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 737817, tzinfo=datetime.timezone.utc), 'name': 'LangGraph', 'userId': 'Zoltan Fedor', 'input': {'input': 'what is the weather in Taipei', 'chat_history': [], 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'return_direct': False}, 'sessionId': 'Dev-jupyter-notebook:20240430:203833', 'release': 'Dev', 'version': '0.0.39'}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 739890, tzinfo=datetime.timezone.utc)}, {'id': '03efcc77-248f-4efb-9c85-a2462eb649e2', 'type': 'span-create', 'body': {'traceId': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'name': 'LangGraph', 'startTime': datetime.datetime(2024, 4, 30, 20, 39, 18, 739960, tzinfo=datetime.timezone.utc), 'input': {'input': 'what is the weather in Taipei', 'chat_history': [], 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'return_direct': False}, 'version': '0.0.39', 'id': 'd2a92ba2-479c-4fc5-aa02-5f6a9cdaa865'}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 741878, tzinfo=datetime.timezone.utc)}, {'id': '8d1742fe-99d4-41e8-8642-9225a7c971f0', 'type': 'span-create', 'body': {'traceId': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'name': '__start__', 'startTime': datetime.datetime(2024, 4, 30, 20, 39, 18, 744535, tzinfo=datetime.timezone.utc), 'metadata': {'tags': ['graph:step:0', 'langsmith:hidden']}, 'input': {'input': 'what is the weather in Taipei', 'chat_history': [], 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'return_direct': False}, 'parentObservationId': 'd2a92ba2-479c-4fc5-aa02-5f6a9cdaa865', 'version': '0.0.39', 'id': '08db795f-b2fe-4e1a-bd9f-49211c3560a9'}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 746082, tzinfo=datetime.timezone.utc)}, {'id': '14d520d6-a41b-4c48-a14b-64308e8362f8', 'type': 'span-update', 'body': {'traceId': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'output': {'input': 'what is the weather in Taipei', 'chat_history': [], 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'return_direct': False}, 'version': '0.0.39', 'id': '08db795f-b2fe-4e1a-bd9f-49211c3560a9', 'endTime': datetime.datetime(2024, 4, 30, 20, 39, 18, 750556, tzinfo=datetime.timezone.utc)}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 752149, tzinfo=datetime.timezone.utc)}, {'id': 'f65f6913-be15-4ee0-b1bf-fd3e19164648', 'type': 'span-create', 'body': {'traceId': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'name': 'agent', 'startTime': datetime.datetime(2024, 4, 30, 20, 39, 18, 761704, tzinfo=datetime.timezone.utc), 'metadata': {'tags': ['graph:step:1']}, 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'parentObservationId': 'd2a92ba2-479c-4fc5-aa02-5f6a9cdaa865', 'version': '0.0.39', 'id': '234fbc1c-493a-4962-abb1-cd0cff023af7'}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 763015, tzinfo=datetime.timezone.utc)}, {'id': '4d94facf-0730-4769-a2cb-349dfcd260c9', 'type': 'span-create', 'body': {'traceId': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'name': 'run_agent', 'startTime': datetime.datetime(2024, 4, 30, 20, 39, 18, 765759, tzinfo=datetime.timezone.utc), 'metadata': {'tags': ['seq:step:1']}, 'input': {'input': 'what is the weather in Taipei', 'user_name': 'Zoltan Fedor', 'user_id': '1111111', 'chat_history': [], 'agent_outcome': None, 'return_direct': False, 'intermediate_steps': []}, 'parentObservationId': '234fbc1c-493a-4962-abb1-cd0cff023af7', 'version': '0.0.39', 'id': 'e6f85977-fa97-4a7d-9f5c-d86d7a6f1b7e'}, 'timestamp': datetime.datetime(2024, 4, 30, 20, 39, 18, 767177, tzinfo=datetime.timezone.utc)}], 'metadata': {'batch_size': 6, 'sdk_integration': 'langchain', 'sdk_name': 'python', 'sdk_version': '2.27.0', 'public_key': 'pk-lf-XXX-XXX-XXX-XXXX'}}
DEBUG:langfuse:making request: {"batch": [{"id": "7daa9597-e68a-486d-866f-0e956b0115b6", "type": "trace-create", "body": {"id": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "timestamp": "2024-04-30T20:39:18.737817Z", "name": "LangGraph", "userId": "Zoltan Fedor", "input": {"input": "what is the weather in Taipei", "chat_history": [], "user_name": "Zoltan Fedor", "user_id": "1111111", "return_direct": false}, "sessionId": "Dev-jupyter-notebook:20240430:203833", "release": "Dev", "version": "0.0.39"}, "timestamp": "2024-04-30T20:39:18.739890Z"}, {"id": "03efcc77-248f-4efb-9c85-a2462eb649e2", "type": "span-create", "body": {"traceId": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "name": "LangGraph", "startTime": "2024-04-30T20:39:18.739960Z", "input": {"input": "what is the weather in Taipei", "chat_history": [], "user_name": "Zoltan Fedor", "user_id": "1111111", "return_direct": false}, "version": "0.0.39", "id": "d2a92ba2-479c-4fc5-aa02-5f6a9cdaa865"}, "timestamp": "2024-04-30T20:39:18.741878Z"}, {"id": "8d1742fe-99d4-41e8-8642-9225a7c971f0", "type": "span-create", "body": {"traceId": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "name": "__start__", "startTime": "2024-04-30T20:39:18.744535Z", "metadata": {"tags": ["graph:step:0", "langsmith:hidden"]}, "input": {"input": "what is the weather in Taipei", "chat_history": [], "user_name": "Zoltan Fedor", "user_id": "1111111", "return_direct": false}, "parentObservationId": "d2a92ba2-479c-4fc5-aa02-5f6a9cdaa865", "version": "0.0.39", "id": "08db795f-b2fe-4e1a-bd9f-49211c3560a9"}, "timestamp": "2024-04-30T20:39:18.746082Z"}, {"id": "14d520d6-a41b-4c48-a14b-64308e8362f8", "type": "span-update", "body": {"traceId": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "output": {"input": "what is the weather in Taipei", "chat_history": [], "user_name": "Zoltan Fedor", "user_id": "1111111", "return_direct": false}, "version": "0.0.39", "id": "08db795f-b2fe-4e1a-bd9f-49211c3560a9", "endTime": "2024-04-30T20:39:18.750556Z"}, "timestamp": "2024-04-30T20:39:18.752149Z"}, {"id": "f65f6913-be15-4ee0-b1bf-fd3e19164648", "type": "span-create", "body": {"traceId": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "name": "agent", "startTime": "2024-04-30T20:39:18.761704Z", "metadata": {"tags": ["graph:step:1"]}, "input": {"input": "what is the weather in Taipei", "user_name": "Zoltan Fedor", "user_id": "1111111", "chat_history": [], "agent_outcome": null, "return_direct": false, "intermediate_steps": []}, "parentObservationId": "d2a92ba2-479c-4fc5-aa02-5f6a9cdaa865", "version": "0.0.39", "id": "234fbc1c-493a-4962-abb1-cd0cff023af7"}, "timestamp": "2024-04-30T20:39:18.763015Z"}, {"id": "4d94facf-0730-4769-a2cb-349dfcd260c9", "type": "span-create", "body": {"traceId": "ada78ca4-7999-4c8c-b5f3-4691061bac34", "name": "run_agent", "startTime": "2024-04-30T20:39:18.765759Z", "metadata": {"tags": ["seq:step:1"]}, "input": {"input": "what is the weather in Taipei", "user_name": "Zoltan Fedor", "user_id": "1111111", "chat_history": [], "agent_outcome": null, "return_direct": false, "intermediate_steps": []}, "parentObservationId": "234fbc1c-493a-4962-abb1-cd0cff023af7", "version": "0.0.39", "id": "e6f85977-fa97-4a7d-9f5c-d86d7a6f1b7e"}, "timestamp": "2024-04-30T20:39:18.767177Z"}], "metadata": {"batch_size": 6, "sdk_integration": "langchain", "sdk_name": "python", "sdk_version": "2.27.0", "public_key": "pk-lf-a9ab5b0c-8475-4ddf-84d6-0979d1c29600"}} to https://qa.langfuse.int.refinitiv.com/api/public/ingestion
DEBUG:langfuse:received response: {"errors":[],"successes":[{"id":"7daa9597-e68a-486d-866f-0e956b0115b6","status":201},{"id":"03efcc77-248f-4efb-9c85-a2462eb649e2","status":201},{"id":"8d1742fe-99d4-41e8-8642-9225a7c971f0","status":201},{"id":"14d520d6-a41b-4c48-a14b-64308e8362f8","status":201},{"id":"f65f6913-be15-4ee0-b1bf-fd3e19164648","status":201},{"id":"4d94facf-0730-4769-a2cb-349dfcd260c9","status":201}]}
DEBUG:langfuse:successfully uploaded batch of 6 items
DEBUG:langfuse:Event: on_chain_end, run_id: fabe1, parent_run_id: 15832, outputs: {'agent_outcome': AgentAction(tool='internet_search(search_term="site:weather.com Taipei weather", tool_id="Weather Search")', tool_input='', log='I need to get the current weather information for Taipei.\n\nAction: internet_search(search_term="site:weather.com Taipei weather", tool_id="Weather Search")\n')}
DEBUG:langfuse:Update span {'id': 'e6f85977-fa97-4a7d-9f5c-d86d7a6f1b7e', 'trace_id': 'ada78ca4-7999-4c8c-b5f3-4691061bac34', 'name': None, 'start_time': None, 'metadata': None, 'input': None, 'output': {'agent_outcome': AgentAction(tool='internet_search(search_term="site:weather.com Taipei weather", tool_id="Weather Search")', tool_input='', log='I need to get the current weather information for Taipei.\n\nAction: internet_search(search_term="site:weather.com Taipei weather", tool_id="Weather Search")\n')}, 'level': None, 'status_message': None, 'version': '0.0.39', 'end_time': datetime.datetime(2024, 4, 30, 20, 39, 20, 833869, tzinfo=datetime.timezone.utc)}...
...