search

puppetlabs / puppetdb

Centralized Puppet Storage
http://docs.puppetlabs.com/puppetdb
Apache License 2.0
298 stars 224 forks source link

Puppetdb restarts because of java.lang.NoSuchMethodError #3947

Open ochnerd opened 6 months ago

ochnerd commented 6 months ago

Describe the Bug

After the update from version 7.16.0 to version 7.17.1, Puppetdb restarts every minute. The error we see in the logs is the following:

2024-02-28T08:00:29.413+01:00 ERROR [p.p.utils] Requesting shutdown: java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
2024-02-28T08:00:29.420+01:00 INFO  [p.t.internal] Beginning shutdown sequence
2024-02-28T08:00:29.814+01:00 ERROR [p.p.utils] Requesting shutdown: java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
2024-02-28T08:00:30.153+01:00 ERROR [p.p.utils] Requesting shutdown: java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
2024-02-28T08:00:30.478+01:00 ERROR [p.p.utils] Requesting shutdown: java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
2024-02-28T08:00:30.800+01:00 ERROR [p.p.utils] Requesting shutdown: java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
2024-02-28T08:00:30.814+01:00 ERROR [p.p.threadpool] Reporting unexpected error from thread cmd-proc-thread-2 to stderr and log
java.lang.NoSuchMethodError: java.nio.ByteBuffer.position(I)Ljava/nio/ByteBuffer;
    at org.postgresql.jdbc.ArrayDecoding.readBinaryArray(ArrayDecoding.java:523)
    at org.postgresql.jdbc.PgArray.readBinaryArray(PgArray.java:175)
    at org.postgresql.jdbc.PgArray.getArrayImpl(PgArray.java:150)
    at org.postgresql.jdbc.PgArray.getArray(PgArray.java:111)
    at puppetlabs.puppetdb.jdbc$convert_any_sql_array.invokeStatic(jdbc.clj:262)
    at puppetlabs.puppetdb.jdbc$convert_any_sql_array.invoke(jdbc.clj:259)
    at puppetlabs.puppetdb.scf.storage$fn__26869$catalog_resources__26874$fn__26875$fn__26876$iter__26879__26883$fn__26884$fn__26889.invoke(storage.clj:560)
    at puppetlabs.kitchensink.core$mapvals$iter__4426__4430$fn__4431.invoke(core.clj:362)
    at clojure.lang.LazySeq.sval(LazySeq.java:42)
    at clojure.lang.LazySeq.seq(LazySeq.java:51)
    at clojure.lang.Cons.next(Cons.java:39)
    at clojure.lang.RT.next(RT.java:713)
    at clojure.core$next__5451.invokeStatic(core.clj:64)
    at clojure.core.protocols$fn__8249.invokeStatic(protocols.clj:169)
    at clojure.core.protocols$fn__8249.invoke(protocols.clj:124)
    at clojure.core.protocols$fn__8204$G__8199__8213.invoke(protocols.clj:19)
    at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:31)
    at clojure.core.protocols$fn__8236.invokeStatic(protocols.clj:75)
    at clojure.core.protocols$fn__8236.invoke(protocols.clj:75)
    at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
    at clojure.core$reduce.invokeStatic(core.clj:6886)
    at clojure.core$into.invokeStatic(core.clj:6958)
    at clojure.core$into.invoke(core.clj:6950)
    at puppetlabs.kitchensink.core$mapvals.invokeStatic(core.clj:362)
    at puppetlabs.kitchensink.core$mapvals.invoke(core.clj:356)
    at puppetlabs.puppetdb.scf.storage$fn__26869$catalog_resources__26874$fn__26875$fn__26876$iter__26879__26883$fn__26884.invoke(storage.clj:560)
    at clojure.lang.LazySeq.sval(LazySeq.java:42)
    at clojure.lang.LazySeq.seq(LazySeq.java:51)
    at clojure.lang.RT.seq(RT.java:535)
    at clojure.core$seq__5467.invokeStatic(core.clj:139)
    at clojure.core$zipmap.invokeStatic(core.clj:6619)
    at clojure.core$zipmap.invoke(core.clj:6619)
    at puppetlabs.puppetdb.scf.storage$fn__26869$catalog_resources__26874$fn__26875$fn__26876.invoke(storage.clj:558)
    at clojure.java.jdbc$execute_query_with_params.invokeStatic(jdbc.clj:1091)
    at clojure.java.jdbc$execute_query_with_params.invoke(jdbc.clj:1084)
    at clojure.java.jdbc$db_query_with_resultset_STAR_.invokeStatic(jdbc.clj:1106)
    at clojure.java.jdbc$db_query_with_resultset_STAR_.invoke(jdbc.clj:1093)
    at clojure.java.jdbc$db_query_with_resultset.invokeStatic(jdbc.clj:1140)
    at clojure.java.jdbc$db_query_with_resultset.invoke(jdbc.clj:1119)
    at clojure.java.jdbc$db_query_with_resultset.invokeStatic(jdbc.clj:1127)
    at clojure.java.jdbc$db_query_with_resultset.invoke(jdbc.clj:1119)
    at puppetlabs.puppetdb.jdbc$query_with_resultset.invokeStatic(jdbc.clj:236)
    at puppetlabs.puppetdb.jdbc$query_with_resultset.invoke(jdbc.clj:227)
    at puppetlabs.puppetdb.scf.storage$fn__26869$catalog_resources__26874$fn__26875.invoke(storage.clj:550)
    at puppetlabs.puppetdb.scf.storage$fn__26869$catalog_resources__26874.invoke(storage.clj:547)
    at puppetlabs.puppetdb.scf.storage$fn__27221$add_resources_BANG___27226$fn__27227.invoke(storage.clj:771)
    at puppetlabs.puppetdb.scf.storage$fn__27221$add_resources_BANG___27226.invoke(storage.clj:765)
    at puppetlabs.puppetdb.scf.storage$fn__27430$update_catalog_associations_BANG___27435$fn__27439$fn__27441.invoke(storage.clj:887)
    at puppetlabs.puppetdb.scf.storage.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
    at com.codahale.metrics.Timer.time(Timer.java:101)
    at puppetlabs.puppetdb.scf.storage$fn__27430$update_catalog_associations_BANG___27435$fn__27439.invoke(storage.clj:886)
    at puppetlabs.puppetdb.scf.storage$fn__27430$update_catalog_associations_BANG___27435.invoke(storage.clj:881)
    at puppetlabs.puppetdb.scf.storage$fn__27468$replace_existing_catalog__27473$fn__27474$fn__27475.invoke(storage.clj:905)
    at puppetlabs.puppetdb.scf.storage.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
    at com.codahale.metrics.Timer.time(Timer.java:101)
    at puppetlabs.puppetdb.scf.storage$fn__27468$replace_existing_catalog__27473$fn__27474.invoke(storage.clj:903)
    at puppetlabs.puppetdb.scf.storage$fn__27468$replace_existing_catalog__27473.invoke(storage.clj:891)
    at puppetlabs.puppetdb.scf.storage$fn__27529$replace_catalog_BANG___27538$fn__27544$fn__27546$fn__27547.invoke(storage.clj:945)
    at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:860)
    at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776)
    at puppetlabs.puppetdb.scf.storage$fn__27529$replace_catalog_BANG___27538$fn__27544$fn__27546.invoke(storage.clj:928)
    at puppetlabs.puppetdb.scf.storage.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
    at com.codahale.metrics.Timer.time(Timer.java:101)
    at puppetlabs.puppetdb.scf.storage$fn__27529$replace_catalog_BANG___27538$fn__27544.invoke(storage.clj:927)
    at puppetlabs.puppetdb.scf.storage$fn__27529$replace_catalog_BANG___27538.invoke(storage.clj:920)
    at puppetlabs.puppetdb.command$do_replace_catalog.invokeStatic(command.clj:345)
    at puppetlabs.puppetdb.command$do_replace_catalog.invoke(command.clj:343)
    at puppetlabs.puppetdb.command$exec_replace_catalog$fn__32624.invoke(command.clj:353)
    at puppetlabs.puppetdb.jdbc$retry_with_monitored_connection$fn__22102$fn__22115.invoke(jdbc.clj:553)
    at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:807)
    at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776)
    at puppetlabs.puppetdb.jdbc$retry_with_monitored_connection$fn__22102.invoke(jdbc.clj:549)
    at puppetlabs.puppetdb.jdbc$retry_sql$attempt__22082.invoke(jdbc.clj:497)
    at puppetlabs.puppetdb.jdbc$retry_sql.invokeStatic(jdbc.clj:507)
    at puppetlabs.puppetdb.jdbc$retry_sql.invoke(jdbc.clj:488)
    at puppetlabs.puppetdb.jdbc$retry_with_monitored_connection.invokeStatic(jdbc.clj:546)
    at puppetlabs.puppetdb.jdbc$retry_with_monitored_connection.invoke(jdbc.clj:541)
    at puppetlabs.puppetdb.command$exec_replace_catalog.invokeStatic(command.clj:350)
    at puppetlabs.puppetdb.command$exec_replace_catalog.invoke(command.clj:347)
    at puppetlabs.puppetdb.command$exec_command.invokeStatic(command.clj:525)
    at puppetlabs.puppetdb.command$exec_command.invoke(command.clj:510)
    at puppetlabs.puppetdb.command$attempt_exec_command$fn__32841.invoke(command.clj:611)
    at puppetlabs.puppetdb.command$call_with_quick_retry$fn__32830.invoke(command.clj:591)
    at puppetlabs.puppetdb.command$call_with_quick_retry.invokeStatic(command.clj:589)
    at puppetlabs.puppetdb.command$call_with_quick_retry.invoke(command.clj:587)
    at puppetlabs.puppetdb.command$attempt_exec_command.invokeStatic(command.clj:609)
    at puppetlabs.puppetdb.command$attempt_exec_command.invoke(command.clj:605)
    at puppetlabs.puppetdb.command$process_cmd$fn__32897$fn__32898.invoke(command.clj:732)
    at puppetlabs.puppetdb.command$process_cmd$fn__32897.invoke(command.clj:729)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_$fn__26314$fn__26315$fn__26316.invoke(metrics.clj:23)
    at puppetlabs.puppetdb.utils.metrics.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
    at com.codahale.metrics.Timer.time(Timer.java:101)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_$fn__26314$fn__26315.invoke(metrics.clj:23)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_$fn__26314$fn__26315$fn__26316.invoke(metrics.clj:23)
    at puppetlabs.puppetdb.utils.metrics.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
    at com.codahale.metrics.Timer.time(Timer.java:101)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_$fn__26314$fn__26315.invoke(metrics.clj:23)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_.invokeStatic(metrics.clj:26)
    at puppetlabs.puppetdb.utils.metrics$multitime_BANG__STAR_.invoke(metrics.clj:15)
    at puppetlabs.puppetdb.command$process_cmd.invokeStatic(command.clj:726)
    at puppetlabs.puppetdb.command$process_cmd.invoke(command.clj:712)
    at puppetlabs.puppetdb.command$process_message.invokeStatic(command.clj:819)
    at puppetlabs.puppetdb.command$process_message.invoke(command.clj:775)
    at puppetlabs.puppetdb.command$message_handler$fn__32931.invoke(command.clj:853)
    at puppetlabs.puppetdb.threadpool$dochan$fn__32512$fn__32513.invoke(threadpool.clj:115)
    at puppetlabs.puppetdb.threadpool$gated_execute$fn__32473.invoke(threadpool.clj:68)
    at clojure.lang.AFn.run(AFn.java:22)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)

Expected Behavior

Puppetdb does not restart every minute and runs without a problem

Steps to Reproduce

Steps to reproduce the behavior: Happens after a minute.

Environment

Additional Context

Our first hint what could be the issue was this change in clj-parent: https://github.com/puppetlabs/clj-parent/blob/5.6.11/project.clj#L100

Our workaround was a downgrade to version 7.16.0.

StanvanHoorn commented 5 months ago

We are also having this problem since updating puppetdb

KoenDierckx commented 5 months ago

we are also running into this

seems related to this bug: https://github.com/pgjdbc/pgjdbc/issues/3014 Perhaps a dependency upgrade is required ?

austb commented 5 months ago

Running PuppetDB with java 11 will avoid this issue. It's also preferable because our testing prioritizes that version on the 7.x branch.

I reproduced the issue on our pgjdbc version asked if the fix can be backported to 42.4.x, which is the stream of pgjdbc we are using in PuppetDB 7.x.

github-actions[bot] commented 5 months ago

Migrated issue to PDB-5730

KoenDierckx commented 5 months ago

Running PuppetDB with java 11 will avoid this issue. It's also preferable because our testing prioritizes that version on the 7.x branch. Ah, we did not know that

The FAQ also recommends JDK8 . Perhaps that needs to be updated then

https://www.puppet.com/docs/puppetdb/7/puppetdb-faq.html#which-versions-of-java-are-supported

Which versions of Java are supported? JDK 8 is officially supported, and JDK 10 is expected to work. Other versions may work, and issues will be addressed on a best-effort basis, but support is not guaranteed.

While looking it up we did notice that JDK11 is mentioned on the overview page https://www.puppet.com/docs/puppetdb/7/overview.html#nix-server-with-jvm-11

But the actual apt package still depends on openjdk-8-jre-headless

apt show puppetdb Package: puppetdb Version: 7.16.0-1focal Priority: optional Section: utils Maintainer: Puppet Labs <info@puppetlabs.com> Installed-Size: 59.2 MB Depends: openjdk-8-jre-headless, bash, net-tools, adduser, procps, puppet-agent (>= 5.99.0) Homepage: http://puppet.com License: ASL 2.0 Vendor: Puppet Labs <info@puppetlabs.com> Build-Depends: cdbs, bc, mawk, lsb-release, ruby | ruby-interpreter Download-Size: 52.1 MB APT-Manual-Installed: yes APT-Sources: http://apt.puppet.com focal/puppet7 amd64 Packages Description: Puppet Labs puppetdb Contains: Puppet-integrated catalog and fact storage (puppetlabs/puppetdb 7.16.0,org.bouncycastle/bcpkix-jdk18on 1.74,org.clojure/clojure 1.11.1,com.zaxxer/HikariCP 2.7.4,puppetlabs/puppetdb 7.16.0)

austb commented 5 months ago

Thanks for pointing out the FAQ updates were missed, I will look into getting that updated.

Yes, that package dependency issue was an oversight when we initially released Puppet Platform 7. I was not able to get permission to change it after the fact for fear we would break someones upgrade and leave them stuck on an old PuppetDB 7.x version. It is fixed in PuppetDB 8 and going forward I made our packaging force us to pick new java package versions for every major version.

By default, PuppetDB will use whatever java version it finds at /usr/bin/java so it can be controlled by RedHat's alternatives tool (or update-alternatives on Debian-based distros). You can see an example of that in the acceptance tests

waipeng commented 5 months ago

Hi can PuppetLabs release a new version of puppetdb 7.17.1 to use jdk11? As @KoenDierckx said

But the actual apt package still depends on openjdk-8-jre-headless

this Ubuntu package is built by PuppetLabs, so updating this shouldn't be too difficult?

Edit: On Ubuntu, instead of downgrading, installing openjdk-11-jre-headless fixes it too. It'll update /usr/bin/java.

# /usr/bin/java -version
openjdk version "11.0.22" 2024-01-16
ochnerd commented 5 months ago

If jdk11 ist mandatory for 7.17.1 their should be an Info in the documentation about that. So please at that to the change/releaselog if it is mandatory.

austb commented 5 months ago

@waipeng the pgjdbc maintainers are working on resolving the issue. If you'd like, you can follow along in https://github.com/pgjdbc/pgjdbc/issues/3014. I have verified their fix, so once they get a release out we will release a PuppetDB version with that update.

this Ubuntu package is built by PuppetLabs, so updating this shouldn't be too difficult?

No, it is not difficult (and I have wanted to update it), but I have been prevented from doing so when I attempted to do so. The compromise was my work in https://github.com/puppetlabs/ezbake/pull/611, which should prevent us from missing our java dependency update on major version boundaries in the future.

jplindquist commented 5 months ago

Is the recommended fix for this to upgrade to Java 11 or greater, or will there be a new package release soon including what appears to be the fix? We're right at a turning point where we're about to uplift the underlying OS and major Puppet version, so I'm just trying to determine a path forward since we had to roll back from 7.17.1 to 7.16.0 in the interim. Thanks!

ochnerd commented 3 months ago

Are their any new Infos about this? We stopped the puppetdb patches because of this issue. Would be good to know if the only fix is to upgrade to java 11. Thanks!

waipeng commented 3 months ago

@jplindquist @ochnerd I am not from Puppet; as a user we install jre11 and that worked. See https://github.com/puppetlabs/puppetdb/issues/3947#issuecomment-1982811973