puppetdb icon indicating copy to clipboard operation
puppetdb copied to clipboard

Puppetdb restarts because of java.lang.NoSuchMethodError

Open ochnerd opened this issue 11 months ago • 12 comments

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

  • Version 7.17.1
  • Platform RHEL 8.9
  • Java Version (openjdk): 1.8.0_402

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.

ochnerd avatar Feb 28 '24 09:02 ochnerd

We are also having this problem since updating puppetdb

StanvanHoorn avatar Mar 04 '24 09:03 StanvanHoorn

we are also running into this

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

KoenDierckx avatar Mar 05 '24 10:03 KoenDierckx

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.

austb avatar Mar 05 '24 22:03 austb

Migrated issue to PDB-5730

github-actions[bot] avatar Mar 05 '24 23:03 github-actions[bot]

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 <[email protected]> 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 <[email protected]> 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)

KoenDierckx avatar Mar 06 '24 08:03 KoenDierckx

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

austb avatar Mar 06 '24 18:03 austb

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

waipeng avatar Mar 07 '24 07:03 waipeng

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.

ochnerd avatar Mar 07 '24 08:03 ochnerd

@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.

austb avatar Mar 07 '24 23:03 austb

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!

jplindquist avatar Mar 25 '24 22:03 jplindquist

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!

ochnerd avatar May 16 '24 13:05 ochnerd

@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

waipeng avatar May 16 '24 23:05 waipeng