deepjavalibrary / deepjavalibrary/djl-serving

Server crashes when using TensorRT-LLM engine

Open
#2,859 1 comment 0 reactions 0 assignees View on GitHub
bug stale
Dominant language
Java
Stars
253
Forks
96
Avg merge
23h 6m
Merged PRs (30d)
3

Description

Hello.
I have pulled 763104351884.dkr.ecr.us-west-2.amazonaws.com/djl-inference:0.33.0-tensorrtllm0.21.0-cu128 container to use it for serving of Llama based model.
Here is my serving.properties file content:
```
engine=MPI
option.rolling_batch=trtllm
option.trust_remote_code=true
option.max_input_len=32768
option.max_output_len=32768
option.max_num_tokens=32768
option.max_rolling_batch_size=32
option.tensor_parallel_degree=1
option.enable_streaming=false
```

Server is being started, launch is successful.
```
INFO WorkerPool scaling up min workers by 1 (from 0 to 1) workers. Total range is min 1 to max 1
INFO WorkerThread Starting worker thread WT-0001 for model mymodel (M-0001, READY) on device gpu(0)
INFO ModelServer Initialize BOTH server with: EpollServerSocketChannel.
INFO ModelServer BOTH API bind to: http://0.0.0.0:8080
```

Any request with valid/invalid schema causing server to crash:
For example :
```
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] [MemUsageChange] Allocated 4608.01 MiB for execution context memory.
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] gatherContextLogits: 0
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] gatherGenerationLogits: 0
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] [MemUsageChange] TensorRT-managed allocation in IExecutionContext creation: CPU +0, GPU +0, now: CPU 0, GPU 15380 (MiB)
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] [MemUsageChange] Allocated 95.78 MB GPU memory for runtime buffers.
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] [MemUsageChange] Allocated 128.63 MB GPU memory for decoder.
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Memory usage when calculating max tokens in paged kv cache: total: 44.52 GiB, available: 23.82 GiB, extraCostMemory: 0.00 GiB
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Number of blocks in KV cache primary pool: 5488
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Number of blocks in KV cache secondary pool: 0, onboard blocks to primary memory before reuse: true
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] before Create KVCacheManager cacheTransPreAllocaSize:0
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Max KV cache pages per sequence: 4096 [window size=131072]
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Number of tokens per block: 32.
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] [MemUsageChange] Allocated 21.44 GiB for max tokens in paged KV cache (175616).
INFO PyProcess W-123-mymodel-stdout: [1,0]:INFO::trtllm service initialized
INFO AsyncRequestManager process is not ready
INFO PyProcess Model [mymodel] initialized.
INFO PyModel mymodel model loaded in 58569 ms.
INFO WorkerPool scaling up min workers by 1 (from 0 to 1) workers. Total range is min 1 to max 1
INFO WorkerThread Starting worker thread WT-0001 for model chat_film (M-0001, READY) on device gpu(0)
INFO ModelServer Initialize BOTH server with: EpollServerSocketChannel.
INFO ModelServer BOTH API bind to: http://0.0.0.0:8080
INFO PyProcess W-123-mymodel-stdout: [1,0]:ERROR::Input parsing failed
INFO PyProcess W-123-mymodel-stdout: [1,0]:Traceback (most recent call last):
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/lmi_trtllm/trtllm_async_service.py", line 147, in inference
INFO PyProcess W-123-mymodel-stdout: [1,0]: processed_request = self.preprocess_requests(inputs)
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/lmi_trtllm/trtllm_async_service.py", line 123, in preprocess_requests
INFO PyProcess W-123-mymodel-stdout: [1,0]: request = ChatCompletionRequest(**decoded_payload)
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/usr/local/lib/python3.12/dist-packages/pydantic/main.py", line 253, in __init__
INFO PyProcess W-123-mymodel-stdout: [1,0]: validated_self = self.__pydantic_validator__.validate_python(data, self_instance=self)
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]:pydantic_core._pydantic_core.ValidationError: 1 validation error for ChatCompletionRequest
INFO PyProcess W-123-mymodel-stdout: [1,0]:model_name
INFO PyProcess W-123-mymodel-stdout: [1,0]: Extra inputs are not permitted [type=extra_forbidden, input_value='mymodel', input_type=str]
INFO PyProcess W-123-mymodel-stdout: [1,0]: For further information visit https://errors.pydantic.dev/2.11/v/extra_forbidden
ERROR Connection Exception reading Output from python process
java.lang.NullPointerException: Cannot invoke "ai.djl.python.engine.Request.addResponse(byte[], java.util.Map)" because "request" is null
at ai.djl.python.engine.AsyncRequestManager.sendInferenceResponse(AsyncRequestManager.java:129) ~[python-0.33.0.jar:?]
at ai.djl.python.engine.AsyncRequestManager.addOutput(AsyncRequestManager.java:86) ~[python-0.33.0.jar:?]
at ai.djl.python.engine.Connection$RequestHandler.channelRead0(Connection.java:460) ~[python-0.33.0.jar:?]
at ai.djl.python.engine.Connection$RequestHandler.channelRead0(Connection.java:443) ~[python-0.33.0.jar:?]
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) [netty-codec-4.1.119.Final.jar:4.1.119.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318) [netty-codec-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1357) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:868) [netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799) [netty-transport-classes-epoll-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.epoll.EpollDomainSocketChannel$EpollDomainUnsafe.epollInReady(EpollDomainSocketChannel.java:138) [netty-transport-classes-epoll-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:501) [netty-transport-classes-epoll-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:399) [netty-transport-classes-epoll-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998) [netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.119.Final.jar:4.1.119.Final]
at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
INFO PyProcess W-123-mymodel-stdout: [1,0]:ERROR::> failed. Details Connection disconnected
ERROR PyProcess predict[init=false] exception: java.util.concurrent.ExecutionException
INFO PyProcess Stop process: 0:123, failure=true
INFO PyProcess Failure count: 0
ERROR PyProcess Restarting python worker
INFO PyProcess W-123-mymodel-stdout: [1,0]:ERROR::> failed. Details
INFO PyProcess W-123-mymodel-stdout: [1,0]:ERROR::djl async engine terminated with error Traceback (most recent call last):
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/python_async_engine.py", line 121, in catch_all
INFO PyProcess W-123-mymodel-stdout: [1,0]: func()
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/python_async_engine.py", line 51, in receive_requests
INFO PyProcess W-123-mymodel-stdout: [1,0]: inputs, function_name = self._prepare_inputs()
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/python_sync_engine.py", line 101, in _prepare_inputs
INFO PyProcess W-123-mymodel-stdout: [1,0]: inputs.read(self.cl_socket)
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/inputs.py", line 221, in read
INFO PyProcess W-123-mymodel-stdout: [1,0]: prop_size = retrieve_short(conn)
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/inputs.py", line 60, in retrieve_short
INFO PyProcess W-123-mymodel-stdout: [1,0]: data = retrieve_buffer(conn, 2)
INFO PyProcess W-123-mymodel-stdout: [1,0]: ^^^^^^^^^^^^^^^^^^^^^^^^
INFO PyProcess W-123-mymodel-stdout: [1,0]: File "/tmp/.djl.ai/python/0.33.0/djl_python/inputs.py", line 36, in retrieve_buffer
INFO PyProcess W-123-mymodel-stdout: [1,0]: raise ValueError("Connection disconnected")
INFO PyProcess W-123-mymodel-stdout: [1,0]:ValueError: Connection disconnected
INFO PyProcess W-123-mymodel-stdout: [1,0]:
INFO PyProcess W-123-mymodel-stdout: [1,0]:INFO::djl async engine terminated
INFO PyProcess W-123-mymodel-stdout: [1,0]:INFO::128 - Python process finished
INFO PyProcess W-123-mymodel-stdout: [2,0]:[TensorRT-LLM][INFO] Refreshed the MPI local session
WARN PyProcess W-123-mymodel-stderr: --------------------------------------------------------------------------
WARN PyProcess W-123-mymodel-stderr: Primary job terminated normally, but 1 process returned
WARN PyProcess W-123-mymodel-stderr: a non-zero exit code. Per user-direction, the job has been aborted.
WARN PyProcess W-123-mymodel-stderr: --------------------------------------------------------------------------
WARN PyProcess W-123-mymodel-stderr: --------------------------------------------------------------------------
WARN PyProcess W-123-mymodel-stderr: mpirun detected that one or more processes exited with non-zero status, thus causing
WARN PyProcess W-123-mymodel-stderr: the job to be terminated. The first process to do so was:
WARN PyProcess W-123-mymodel-stderr:
WARN PyProcess W-123-mymodel-stderr: Process name: [[27905,1],0]
WARN PyProcess W-123-mymodel-stderr: Exit code: 1
WARN PyProcess W-123-mymodel-stderr: --------------------------------------------------------------------------
INFO PyProcess ReaderThread(0) stopped - W-123-mymodel-stdout
INFO PyProcess ReaderThread(0) stopped - W-123-mymodel-stderr
WARN InferenceRequestHandler RequestId=[6d0d67cc-fea0-44d1-8af2-d9563c16a490] Chunk reading interrupted
java.lang.IllegalStateException: Read chunk timeout.
at ai.djl.inference.streaming.ChunkedBytesSupplier.next(ChunkedBytesSupplier.java:79) ~[api-0.33.0.jar:?]
at ai.djl.inference.streaming.ChunkedBytesSupplier.nextChunk(ChunkedBytesSupplier.java:93) ~[api-0.33.0.jar:?]
at ai.djl.serving.http.InferenceRequestHandler.sendOutput(InferenceRequestHandler.java:418) ~[serving-0.33.0.jar:?]
at ai.djl.serving.http.InferenceRequestHandler.lambda$runJob$5(InferenceRequestHandler.java:313) ~[serving-0.33.0.jar:?]
at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) [?:?]
at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) [?:?]
at java.base/java.util.concurrent.CompletableFuture$Completion.exec(CompletableFuture.java:483) [?:?]
at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) [?:?]
at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) [?:?]
at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) [?:?]
at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) [?:?]
at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [?:?]
```

Contributor guide

Open the contributing guide

Research direction

Reproduce the crash with the supplied serving.properties and request, then start with djl_python/lmi_trtllm/trtllm_async_service.py at preprocess_requests and ai.djl.python.engine/AsyncRequestManager.java at sendInferenceResponse. Check how the Pydantic validation error for model_name is propagated; done means invalid input returns an error without disconnecting the process or crashing the server.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, java, python
Domain
api, backend, machine-learning
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.