reactiverse / es4x

🚀 fast JavaScript 4 Eclipse Vert.x
https://reactiverse.io/es4x/
Apache License 2.0
877 stars 75 forks source link

pg-client now throwing unhandled exception on previously running code #571

Open binarytide opened 2 years ago

binarytide commented 2 years ago

at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineException.illegalState(PolyglotEngineException.java:129)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.throwDeniedThreadAccess(PolyglotContextImpl.java:940)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.checkAllThreadAccesses(PolyglotContextImpl.java:799)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.enterThreadChanged(PolyglotContextImpl.java:629)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.enterCached(PolyglotEngineImpl.java:1885)
at org.graalvm.truffle/com.oracle.truffle.polyglot.HostToGuestRootNode.execute(HostToGuestRootNode.java:112)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.executeRootNode(OptimizedCallTarget.java:650)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.profiledPERoot(OptimizedCallTarget.java:622)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.callBoundary(OptimizedCallTarget.java:555)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.doInvoke(OptimizedCallTarget.java:539)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.callIndirect(OptimizedCallTarget.java:463)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.call(OptimizedCallTarget.java:444)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotFunctionProxyHandler.invoke(PolyglotFunctionProxyHandler.java:154)
at com.sun.proxy.$Proxy45.handle(Unknown Source)
at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:153)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Mapping.onFailure(Mapping.java:45)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Composition$1.onFailure(Composition.java:66)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FailedFuture.addListener(FailedFuture.java:98)
at io.vertx.core.impl.future.Composition.onFailure(Composition.java:55)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:40)
at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: Attached Guest Language Frames (1)```
binarytide commented 2 years ago

pg code in question:


import { PgPool } from '@vertx/pg-client'
import { PgConnectOptions } from '@vertx/pg-client/options'
import { PoolOptions } from '@vertx/sql-client/options'
import { makeSuccess, makeError, document, nv } from '/opt/vertx/base.mjs'
import { log } from '/opt/vertx/log.mjs'
const eb = vertx.eventBus()

const config = vertx.getOrCreateContext().config()
console.log('config check:', config)

const connectOptions = new PgConnectOptions()
  .setUser(config.user)
  .setPassword(config.password)
  .setHost(config.host)
  .setDatabase(config.database)
  .setPort(config.port)

const poolOptions = new PoolOptions().setMaxSize(5)
const client = PgPool.pool(vertx, connectOptions, poolOptions)

const dbHandler = (message) => {

  let sql = ''
  // Get SQL statement from message body
  if (message && message.body()) sql = new String(message.body().sql).trim()
  // Return error if no SQL
  if (!sql) {
    log('in DB verticle: No SQL received by the database verticle')
    //message.reply('No SQL received by the database verticle')
    message.reply(makeError('No SQL received by the database verticle'))
    return
  }

  console.log('sql -- test:', sql)

  client.withConnection(connection => {
    connection.query(sql).execute((fut) => {
      fut.onComplete((x) => {
        console.log('onComplete x:', x)
        let reply = {}
        try {
          if (fut.succeeded()) {
            console.log('fut.succeeded()')
            let conn = fut.result()
            if (conn.iterator().hasNext()) {
              reply = makeSuccess('', JSON.parse(JSON.stringify(conn.iterator().next().getValue('result'), function (key, value) {
                if (typeof value === 'bigint') {
                  return value.toString()
                } else {
                  return value
                }
              })))
            } else {
              reply = makeSuccess('', [])
            }
          } else {
            let exc = fut.cause()
            // const parsed = exc.getMessage()
            // const parsed = JSON.parse(exc.getMessage())
            // document(exc, 'exc')
            const excMessage = nv(exc.getMessage())
            const parsed = excMessage.charAt(0) === '{' ? JSON.parse(excMessage) : excMessage
            const errMessage = exc.getErrorMessage ? nv(exc.getErrorMessage()) : 'error with no stacktrace'
            reply = makeError(errMessage, parsed)
            log('controlled printing of stacktrace: for message:', message.body())
            exc.printStackTrace()
          }
        } catch (e) {
          reply = makeError('pg client catch: ' + e.toString() + '\nerror from query: ' + sql)
        } finally {
          log('REPLY!!!!!')
          connection.close()
          message.reply(reply)
        }
      })
    })
  })
}

if (typeof config.address === 'string') {
  eb.consumer(config.address, dbHandler)
} else {
  Array.from(config.address).forEach(address => {
    eb.consumer(address, dbHandler)
  })
}```
pmlopes commented 2 years ago

@binarytide can you point in the code where this exception is being thrown? I'm trying to figure out which callback is on the wrong thread, but I see you are also using eventbus messaging.

I'm not sure which callback is the offender.

binarytide commented 2 years ago

the exception happens at deployment. we have some wrapper code around deployment but that has been stable and untouched to this point.

pmlopes commented 2 years ago

I'm looking at the changes, and in 0.15.0 the startup become an execute blocking:

https://github.com/reactiverse/es4x/blob/0.15.0/es4x/src/main/java/io/reactiverse/es4x/impl/JSVerticleFactory.java#L79-L94

To avoid annoying logs at startup that the event loop was blocked. This could be the reason, as the deployment is happening on a thread pool.

But you're saying that you were on 0.16.1 and it worked... I can create a test branch you can build and test with that change reverted, would that work for you? @binarytide

binarytide commented 2 years ago

I def remember seeing logs about blocking so I know that was something happening for me during startup, how it's only now turning into a brick wall is weird. but yes I can try a test branch.

pmlopes commented 2 years ago

In this zip file there's a jar file, that the local build of: https://github.com/reactiverse/es4x/tree/issues/disable-blockingexecute

es4x-0.16.4-SNAPSHOT.zip

Just replace the current:

~/node_modules/.lib/es4x-0.16.?.jar

With the one in the zip, or build that branch locally.

If this works, then I think we need to live with the warnings if any as we can't disable the thread strictness from graaljs.

binarytide commented 2 years ago

still throwing:

Unhandled exception caused by java.lang.IllegalStateException: Multi threaded access requested by thread Thread[vert.x-eventloop-thread-1,5,main] but is not allowed for language(s) js.
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineException.illegalState(PolyglotEngineException.java:129)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.throwDeniedThreadAccess(PolyglotContextImpl.java:940)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.checkAllThreadAccesses(PolyglotContextImpl.java:799)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.enterThreadChanged(PolyglotContextImpl.java:629)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.enterCached(PolyglotEngineImpl.java:1885)
at org.graalvm.truffle/com.oracle.truffle.polyglot.HostToGuestRootNode.execute(HostToGuestRootNode.java:112)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.executeRootNode(OptimizedCallTarget.java:650)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.profiledPERoot(OptimizedCallTarget.java:622)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.callBoundary(OptimizedCallTarget.java:555)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.doInvoke(OptimizedCallTarget.java:539)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.callIndirect(OptimizedCallTarget.java:463)
at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.call(OptimizedCallTarget.java:444)
at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotFunctionProxyHandler.invoke(PolyglotFunctionProxyHandler.java:154)
at com.sun.proxy.$Proxy45.handle(Unknown Source)
at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:153)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Mapping.onFailure(Mapping.java:45)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Composition$1.onFailure(Composition.java:66)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FailedFuture.addListener(FailedFuture.java:98)
at io.vertx.core.impl.future.Composition.onFailure(Composition.java:55)
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:40)
at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:834)
 Caused by: Attached Guest Language Frames (1)

after I confirmed that I replaced the jar both globally and within node_modules still getting the same result

binarytide commented 2 years ago

ok, so it turns out the test branch gets me what I needed, but in the course of modifying I uncommented code that gave the same amount of those exceptions but different root cause. so to confirm test branch does work.

bkoripalli commented 2 years ago

@binarytide @pmlopes Please confirm is it still an issue. I was facing similar issue on es4x 0.17.1

pmlopes commented 2 years ago

Hi @bkoripalli if you're facing the same issue, please share where is it happening. There are a couple of things here:

I believe there was an issue reported upstream to graal about some of these exceptions being thrown wrongly.

Second, it could be an issue in vert.x itself, which isn't noticed in java but probably should be fixed.

bkoripalli commented 2 years ago

@pmlopes I think there is no issue with fetching data from db replaying to event bus, All of sudden I got below error.

ERROR io.vertx.core.impl.ContextImpl - Unhandled exception java.lang.IllegalStateException: Multi threaded access requested by thread Thread[vert.x-eventloop-thread-13,5,main] but is not allowed for language(s) js. -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineException.illegalState(PolyglotEngineException.java:129) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.throwDeniedThreadAccess(PolyglotContextImpl.java:1034) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.checkAllThreadAccesses(PolyglotContextImpl.java:893) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.enterThreadChanged(PolyglotContextImpl.java:723) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.enterCached(PolyglotEngineImpl.java:1991) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.HostToGuestRootNode.execute(HostToGuestRootNode.java:110) -> at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.executeRootNode(OptimizedCallTarget.java:655) -> at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.profiledPERoot(OptimizedCallTarget.java:627) -> at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.doInvoke(OptimizedCallTarget.java:544) -> at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.callIndirect(OptimizedCallTarget.java:468) -> at jdk.internal.vm.compiler/org.graalvm.compiler.truffle.runtime.OptimizedCallTarget.call(OptimizedCallTarget.java:449) -> at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotFunctionProxyHandler.invoke(PolyglotFunctionProxyHandler.java:154) -> at com.sun.proxy.$Proxy69.handle(Unknown Source) -> at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141) -> at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60) -> at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211) -> at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23) -> at io.vertx.core.Promise.complete(Promise.java:66) -> at io.vertx.core.eventbus.impl.ReplyHandler.dispatch(ReplyHandler.java:97) -> at io.vertx.core.eventbus.impl.HandlerRegistration$InboundDeliveryContext.next(HandlerRegistration.java:169) -> at io.vertx.core.eventbus.impl.HandlerRegistration$InboundDeliveryContext.dispatch(HandlerRegistration.java:134) -> at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:111) -> at io.vertx.core.eventbus.impl.HandlerRegistration.dispatch(HandlerRegistration.java:105) -> at io.vertx.core.eventbus.impl.ReplyHandler.doReceive(ReplyHandler.java:81) -> at io.vertx.core.eventbus.impl.HandlerRegistration.lambda$receive$0(HandlerRegistration.java:56) -> at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) -> at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) -> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503) -> at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) -> at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) -> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) -> at java.base/java.lang.Thread.run(Thread.java:829) -> Caused by: com.oracle.truffle.api.TruffleStackTrace$LazyStackTrace: null ->