search

quarkiverse / quarkus-langchain4j

Quarkus Langchain4j extension
https://docs.quarkiverse.io/quarkus-langchain4j/dev/index.html
Apache License 2.0
134 stars 79 forks source link

Unhelpful 'vertx thread blocked' errors in log if openai key is not set #927

Open holly-cummins opened 1 week ago

holly-cummins commented 1 week ago

If I run a simple application such as https://github.com/kdubois/quarkus-langchain4j-podman-ai-instructlab, but with the default openai base url and no export QUARKUS_LANGCHAIN4J_OPENAI_API_KEY=..., I get the following errors in the logs:

2024-09-25 18:54:00,888 WARN  [io.ver.cor.imp.BlockedThreadChecker] (vertx-blocked-thread-checker) Thread Thread[vert.x-worker-thread-4,5,main] has been blocked for 99893 ms, time limit is 60000 ms: io.vertx.core.VertxException: Thread blocked
        at java.base/jdk.internal.misc.Unsafe.park(Native Method)
        at java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:221)
        at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
        at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
        at java.base/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
        at java.base/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
        at io.quarkus.deployment.dev.RuntimeUpdatesProcessor.doScan(RuntimeUpdatesProcessor.java:462)
        at io.quarkus.deployment.dev.RuntimeUpdatesProcessor.doScan(RuntimeUpdatesProcessor.java:455)
        at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$6.call(VertxHttpHotReplacementSetup.java:161)
        at io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$6.call(VertxHttpHotReplacementSetup.java:148)
        at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$0(ContextImpl.java:178)
        at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:279)
        at io.vertx.core.impl.ContextImpl.lambda$internalExecuteBlocking$2(ContextImpl.java:210)
        at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
        at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1495)
        at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
        at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:1583)

It's not obvious that the root cause is missing configuration. I see this with 0.17.2 and 0.18.

geoand commented 1 week ago

@holly-cummins how are you reproducing this?

Asking because I am seeing:

Configuration validation failed:
        SRCFG00014: The config property quarkus.langchain4j.openai.api-key is required but it could not be found in any config source
holly-cummins commented 6 days ago

@holly-cummins how are you reproducing this?

Asking because I am seeing:

Configuration validation failed:
        SRCFG00014: The config property quarkus.langchain4j.openai.api-key is required but it could not be found in any config source

Right, that's what I expected to happen, too. :)

If I try and do a naive reproducer, I get the right message in the logs, and a relevant stack trace in the browser. Which I guess is reassuring.

I've just looked more carefully at my reproducer, and it seems to be adding the micrometer problem that exposes the issue. If I remove micrometer all is well. Even with micrometer, I do see the expected config message in the log, but it's overwhelmed by the vertx stack trace lower down. I do have to wait a few minutes for the vertx trace, but I get this immediately on startup:

2024-09-27 15:33:18,490 WARN  [io.net.uti.con.DefaultPromise] (vert.x-acceptor-thread-0) An exception was thrown by io.vertx.core.net.impl.TCPServerBase$$Lambda/0x00000070017a0448.operationComplete(): io.vertx.core.impl.NoStackTraceException: HttpBinderConfiguration was not found

Just quarkus create app and then quarkus ext add langchain4j-openai micrometer isn't enough to reproduce, so there must be something else in my reproducer that's creating the conditions for this to happen.

I've put my reproducer here: https://github.com/holly-cummins/quarkus-langchain4j-podman-ai-instructlab/tree/vertx-timeout-reproducer (ignore the repo name, I – confusingly – removed the config so that it's now using openai.)

geoand commented 6 days ago

Thanks, I'll have a look on Monday

geoand commented 3 days ago

Unfortunately I still can't reproduce this :(