[Pkg-puppet-devel] Bug#1104386: puppetserver: FTBFS randomly: make[1]: *** [debian/rules:66: override_dh_auto_test] Error 1

Lucas Nussbaum lucas at debian.org
Tue Apr 29 14:49:22 BST 2025


Source: puppetserver
Version: 8.7.0-4
Severity: important
Justification: FTBFS
Tags: trixie sid ftbfs
User: lucas at debian.org
Usertags: ftbfs-20250428 ftbfs-trixie ftbfs-randomly

Hi,

Your package fails to build randomly on amd64: In the exact same
environment, sometimes it builds fine, and sometimes it fails.

Relevant part (hopefully):
> make[1]: Entering directory '/build/reproducible-path/puppetserver-8.7.0'
> # make facter and puppet gems available to the testsuite
> # upstream uses git submodules here, but we can use Debian sources instead
> for component in facter puppet resource_api; do \
> 	mkdir -p ruby/${component}/lib; \
> 	if [ "$component" = "puppet" ]; then package=puppet-agent ; \
> 	elif [ "$component" = "resource_api" ]; then package=ruby-puppet-resource-api ; \
> 	else package=$component; fi; \
> 	dpkg -L $package | grep -Po "^/usr/lib/ruby/vendor_ruby/\K.*" | \
> 		while read file; do \
> 			if [ -d /usr/lib/ruby/vendor_ruby/$file ]; then \
> 				mkdir -p ruby/${component}/lib/$file; \
> 			else \
> 				ln -sf /usr/lib/ruby/vendor_ruby/$file ruby/${component}/lib/$file; \
> 			fi; \
> 		done; \
> done
> # symlink vendored gems to the test suite's custom gem-home
> # (see test/unit/puppetlabs/services/jruby/jruby_puppet_testutils.clj)
> mkdir -p /tmp/tmp.SxLxLHtjqL/.puppetlabs/opt/server/data/puppetserver
> ln -s /build/reproducible-path/puppetserver-8.7.0/target/vendored-jruby-gems /tmp/tmp.SxLxLHtjqL/.puppetlabs/opt/server/data/puppetserver/jruby-gems
> # regenerate tls certificates used in https tests
> cd dev-resources/puppetlabs && ( \
> 	for testdir in puppetserver/ruby/http_client_test puppetserver/certificate_authority_test/master/conf puppetserver/certificate_authority_test/update_crls services/ca/certificate_authority_core_test/update_crls services/certificate_authority/certificate_authority_int_test/ca_true_test/master/conf services/certificate_authority/certificate_authority_int_test/infracrl_test/master/conf; do \
> 		cp -a $testdir ${testdir}.clean; \
> 	done )
> ruby /build/reproducible-path/puppetserver-8.7.0/dev-resources/regen_certs.rb
> Regenerating PKI for puppetlabs.puppetserver.ruby.http-client-test ...
> Regenerating PKI for puppetlabs.puppetserver.certificate-authority-test ...
> Regenerating PKI for puppetlabs.puppetserver.certificate-authority-test/update-crls ...
> Regenerating PKI for puppetlabs.services.ca.certificate-authority-core-test ...
> Regenerating PKI for puppetlabs.services.certificate-authority.certificate-authority-int-test...
> # run unit and integration tests
> _JAVA_OPTIONS=-Duser.home=/tmp/tmp.SxLxLHtjqL lein test
> Picked up _JAVA_OPTIONS: -Duser.home=/tmp/tmp.SxLxLHtjqL
> Picked up _JAVA_OPTIONS: -Duser.home=/tmp/tmp.SxLxLHtjqL
> SLF4J: Class path contains multiple SLF4J bindings.
> SLF4J: Found binding in [jar:file:/usr/share/java/logback-classic.jar!/org/slf4j/impl/StaticLoggerBinder.class]
> SLF4J: Found binding in [jar:file:/usr/share/java/logback-classic-1.2.11.jar!/org/slf4j/impl/StaticLoggerBinder.class]
> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
> 02:17:05,169 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/build/reproducible-path/puppetserver-8.7.0/dev-resources/logback-test.xml]
> 02:17:05,170 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback-test.xml] occurs multiple times on the classpath.
> 02:17:05,170 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback-test.xml] occurs at [jar:file:/usr/share/java/trapperkeeper-metrics-1.5.0.jar!/logback-test.xml]
> 02:17:05,170 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback-test.xml] occurs at [jar:file:/usr/share/java/trapperkeeper-metrics-test-1.5.0.jar!/logback-test.xml]
> 02:17:05,170 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback-test.xml] occurs at [file:/build/reproducible-path/puppetserver-8.7.0/dev-resources/logback-test.xml]
> 02:17:05,228 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
> 02:17:05,233 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
> 02:17:05,236 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
> 02:17:05,240 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
> 02:17:05,280 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.eclipse.jetty] to WARN
> 02:17:05,280 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.http] to WARN
> 02:17:05,280 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to WARN
> 02:17:05,280 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
> 02:17:05,280 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
> 02:17:05,281 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator at 3e5beab5 - Registering current configuration as safe fallback point
> 
> SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]
> 
> lein test puppetlabs.general-puppet.general-puppet-int-test
> 
> lein test puppetlabs.puppetserver.auth-conf-test
> 
> lein test puppetlabs.puppetserver.bootstrap-int-test
> 
> lein test puppetlabs.puppetserver.certificate-authority-test
> 
> lein test puppetlabs.puppetserver.error-handling-int-test
> 
> lein test puppetlabs.puppetserver.ringutils-test
> 
> lein test puppetlabs.puppetserver.ruby.http-client-test
> 
> lein test puppetlabs.services.analytics.analytics-service-test
> 
> lein test puppetlabs.services.ca.certificate-authority-core-test
> 
> lein test puppetlabs.services.ca.certificate-authority-disabled-test
> 
> lein test puppetlabs.services.certificate-authority.certificate-authority-int-test
> 
> lein test puppetlabs.services.config.puppet-server-config-core-test
> 
> lein test puppetlabs.services.config.puppet-server-config-service-test
> 
> lein test puppetlabs.services.jruby.class-info-test
> 
> lein test puppetlabs.services.jruby.jruby-metrics-service-test
> 
> lein test puppetlabs.services.jruby.jruby-puppet-core-test
> 
> lein test puppetlabs.services.jruby.jruby-puppet-pool-int-test
> Profiling enabled; ^C shutdown will now dump profile info
> 
> lein test puppetlabs.services.jruby.jruby-puppet-service-test
> 
> lein test puppetlabs.services.jruby.module-info-test
> 
> lein test puppetlabs.services.jruby.puppet-environments-int-test
> 
> lein test puppetlabs.services.jruby.puppet-environments-test
> 
> lein test puppetlabs.services.jruby.request-handler-test
> 
> lein test puppetlabs.services.jruby.service-macros-test
> 
> lein test puppetlabs.services.jruby.tasks-test
> 
> lein test :only puppetlabs.services.jruby.tasks-test/puppetlabs.services.jruby.tasks-test
> 
> ERROR in (puppetlabs.services.jruby.tasks-test) (internal.clj:627)
> Uncaught exception in test fixture
> expected: nil
>   actual: clojure.lang.ExceptionInfo: Error during app shutdown!
> {:errors (#error {
>  :cause "Lock can't be granted because a pill has been inserted"
>  :via
>  [{:type java.lang.InterruptedException
>    :message "Lock can't be granted because a pill has been inserted"
>    :at [com.puppetlabs.jruby_utils.pool.JRubyPool lockWithTimeout "JRubyPool.java" 390]}]
>  :trace
>  [[com.puppetlabs.jruby_utils.pool.JRubyPool lockWithTimeout "JRubyPool.java" 390]
>   [jdk.internal.reflect.DirectMethodHandleAccessor invoke "DirectMethodHandleAccessor.java" 103]
>   [java.lang.reflect.Method invoke "Method.java" 580]
>   [clojure.lang.Reflector invokeMatchingMethod "Reflector.java" 196]
>   [clojure.lang.Reflector invokeInstanceMethodOfClass "Reflector.java" 106]
>   [clojure.lang.Reflector invokeInstanceMethod "Reflector.java" 98]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27028$borrow_all_jrubies__27033$fn__27034$fn__27035 invoke "jruby_agents.clj" 144]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27028$borrow_all_jrubies__27033$fn__27034 invoke "jruby_agents.clj" 143]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27028$borrow_all_jrubies__27033 invoke "jruby_agents.clj" 135]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27125$drain_and_refill_pool_BANG___27134$fn__27137 invoke "jruby_agents.clj" 215]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27125$drain_and_refill_pool_BANG___27134 invoke "jruby_agents.clj" 197]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27166$flush_pool_for_shutdown_BANG___27171$fn__27172 invoke "jruby_agents.clj" 236]
>   [puppetlabs.services.jruby_pool_manager.impl.jruby_agents$eval27166$flush_pool_for_shutdown_BANG___27171 invoke "jruby_agents.clj" 224]
>   [puppetlabs.services.jruby_pool_manager.impl.instance_pool$eval29364$fn__29389 invoke "instance_pool.clj" 20]
>   [puppetlabs.services.protocols.jruby_pool$eval27627$fn__27737$G__27616__27742 invoke "jruby_pool.clj" 3]
>   [puppetlabs.services.jruby_pool_manager.jruby_core$eval28255$flush_pool_for_shutdown_BANG___28260$fn__28261 invoke "jruby_core.clj" 251]
>   [puppetlabs.services.jruby_pool_manager.jruby_core$eval28255$flush_pool_for_shutdown_BANG___28260 invoke "jruby_core.clj" 246]
>   [puppetlabs.services.jruby.jruby_puppet_service$reify__38796$service_fnk__5972__auto___positional$reify__38810 stop "jruby_puppet_service.clj" 50]
>   [puppetlabs.trapperkeeper.services$eval5770$fn__5784$G__5762__5787 invoke "services.clj" 7]
>   [puppetlabs.trapperkeeper.services$eval5770$fn__5784$G__5761__5791 invoke "services.clj" 7]
>   [puppetlabs.trapperkeeper.internal$eval16292$run_lifecycle_fn_BANG___16299$fn__16300 invoke "internal.clj" 196]
>   [puppetlabs.trapperkeeper.internal$eval16292$run_lifecycle_fn_BANG___16299 invoke "internal.clj" 179]
>   [puppetlabs.trapperkeeper.internal$eval16878$shutdown_BANG___16883$fn__16884$shutdown_fn__16886$fn__16888 invoke "internal.clj" 464]
>   [clojure.core$keep$fn__8691 invoke "core.clj" 7533]
>   [clojure.lang.LazySeq force "LazySeq.java" 50]
>   [clojure.lang.LazySeq realize "LazySeq.java" 89]
>   [clojure.lang.LazySeq seq "LazySeq.java" 106]
>   [clojure.lang.RT seq "RT.java" 555]
>   [clojure.core$seq__5486 invokeStatic "core.clj" 139]
>   [clojure.core$dorun invokeStatic "core.clj" 3141]
>   [clojure.core$doall invokeStatic "core.clj" 3156]
>   [clojure.core$doall invoke "core.clj" 3156]
>   [puppetlabs.trapperkeeper.internal$eval16878$shutdown_BANG___16883$fn__16884$shutdown_fn__16886 invoke "internal.clj" 460]
>   [puppetlabs.trapperkeeper.internal$eval16366$initialize_lifecycle_worker__16377$fn__16378$fn__16541$state_machine__13528__auto____16566$fn__16569$fn__16591 invoke "internal.clj" 274]
>   [puppetlabs.trapperkeeper.internal$eval16366$initialize_lifecycle_worker__16377$fn__16378$fn__16541$state_machine__13528__auto____16566$fn__16569 invoke "internal.clj" 258]
>   [puppetlabs.trapperkeeper.internal$eval16366$initialize_lifecycle_worker__16377$fn__16378$fn__16541$state_machine__13528__auto____16566 invoke "internal.clj" 249]
>   [clojure.core.async.impl.ioc_macros$run_state_machine invokeStatic "ioc_macros.clj" 978]
>   [clojure.core.async.impl.ioc_macros$run_state_machine invoke "ioc_macros.clj" 977]
>   [clojure.core.async.impl.ioc_macros$run_state_machine_wrapped invokeStatic "ioc_macros.clj" 982]
>   [clojure.core.async.impl.ioc_macros$run_state_machine_wrapped invoke "ioc_macros.clj" 980]
>   [clojure.core.async$ioc_alts_BANG_$fn__13775 invoke "async.clj" 421]
>   [clojure.core.async$do_alts$fn__13706$fn__13709 invoke "async.clj" 288]
>   [clojure.core.async.impl.channels.ManyToManyChannel$fn__7449 invoke "channels.clj" 139]
>   [clojure.lang.AFn run "AFn.java" 22]
>   [java.util.concurrent.ThreadPoolExecutor runWorker "ThreadPoolExecutor.java" 1144]
>   [java.util.concurrent.ThreadPoolExecutor$Worker run "ThreadPoolExecutor.java" 642]
>   [clojure.core.async.impl.concurrent$counted_thread_factory$reify__7302$fn__7303 invoke "concurrent.clj" 29]
>   [clojure.lang.AFn run "AFn.java" 22]
>   [java.lang.Thread run "Thread.java" 1583]]})}
>  at puppetlabs.trapperkeeper.internal$eval16958$build_app_STAR___16967$fn$reify__16979.stop (internal.clj:627)
>     puppetlabs.services.jruby.tasks_test$with_running_server$fn__62283.invoke (tasks_test.clj:38)
>     clojure.core$with_redefs_fn.invokeStatic (core.clj:7706)
>     clojure.core$with_redefs_fn.invoke (core.clj:7690)
>     puppetlabs.services.jruby.tasks_test$with_running_server.invokeStatic (tasks_test.clj:38)
>     puppetlabs.services.jruby.tasks_test$with_running_server.invoke (tasks_test.clj:33)
>     clojure.test$compose_fixtures$fn__9888$fn__9889.invoke (test.clj:694)
>     clojure.test$default_fixture.invokeStatic (test.clj:687)
>     clojure.test$default_fixture.invoke (test.clj:683)
>     clojure.test$compose_fixtures$fn__9888.invoke (test.clj:694)
>     clojure.test$test_vars$fn__9920.invoke (test.clj:735)
>     schema.test$validate_schemas$fn46096__46105$fn__46106.invoke (test.cljc:12)
>     schema.test$validate_schemas$fn46096__46105.invoke (test.cljc:12)
>     clojure.lang.AFn.applyToHelper (AFn.java:152)
>     clojure.lang.AFn.applyTo (AFn.java:144)
>     clojure.lang.AFunction$1.doInvoke (AFunction.java:33)
>     clojure.lang.RestFn.invoke (RestFn.java:400)
>     schema.test$validate_schemas.invokeStatic (test.cljc:12)
>     schema.test$validate_schemas.invoke (test.cljc:7)
>     clojure.test$compose_fixtures$fn__9888$fn__9889.invoke (test.clj:694)
>     clojure.test$default_fixture.invokeStatic (test.clj:687)
>     clojure.test$default_fixture.invoke (test.clj:683)
>     clojure.test$compose_fixtures$fn__9888.invoke (test.clj:694)
>     clojure.test$test_vars.invokeStatic (test.clj:731)
>     clojure.test$test_all_vars.invokeStatic (test.clj:737)
>     clojure.test$test_ns.invokeStatic (test.clj:758)
>     clojure.test$test_ns.invoke (test.clj:743)
>     user$eval225$fn__288.invoke (form-init9294449238353913047.clj:1)
>     clojure.lang.AFn.applyToHelper (AFn.java:156)
>     clojure.lang.AFn.applyTo (AFn.java:144)
>     clojure.core$apply.invokeStatic (core.clj:669)
>     clojure.core$apply.invoke (core.clj:662)
>     leiningen.core.injected$compose_hooks$fn__152.doInvoke (form-init9294449238353913047.clj:1)
>     clojure.lang.RestFn.applyTo (RestFn.java:140)
>     clojure.core$apply.invokeStatic (core.clj:667)
>     clojure.core$apply.invoke (core.clj:662)
>     leiningen.core.injected$run_hooks.invokeStatic (form-init9294449238353913047.clj:1)
>     leiningen.core.injected$run_hooks.invoke (form-init9294449238353913047.clj:1)
>     leiningen.core.injected$prepare_for_hooks$fn__157$fn__158.doInvoke (form-init9294449238353913047.clj:1)
>     clojure.lang.RestFn.applyTo (RestFn.java:140)
>     clojure.lang.AFunction$1.doInvoke (AFunction.java:33)
>     clojure.lang.RestFn.invoke (RestFn.java:411)
>     clojure.core$map$fn__5954.invoke (core.clj:2772)
>     clojure.lang.LazySeq.force (LazySeq.java:50)
>     clojure.lang.LazySeq.realize (LazySeq.java:89)
>     clojure.lang.LazySeq.seq (LazySeq.java:106)
>     clojure.lang.Cons.next (Cons.java:41)
>     clojure.lang.RT.next (RT.java:733)
>     clojure.core$next__5470.invokeStatic (core.clj:64)
>     clojure.core$reduce1.invokeStatic (core.clj:946)
>     clojure.core$reduce1.invokeStatic (core.clj:936)
>     clojure.core$merge_with.invokeStatic (core.clj:3083)
>     clojure.core$merge_with.doInvoke (core.clj:3075)
>     clojure.lang.RestFn.applyTo (RestFn.java:142)
>     clojure.core$apply.invokeStatic (core.clj:669)
>     clojure.test$run_tests.invokeStatic (test.clj:768)
>     clojure.test$run_tests.doInvoke (test.clj:768)
>     clojure.lang.RestFn.applyTo (RestFn.java:140)
>     clojure.core$apply.invokeStatic (core.clj:667)
>     clojure.core$apply.invoke (core.clj:662)
>     user$eval225$fn__298$fn__331.invoke (form-init9294449238353913047.clj:1)
>     user$eval225$fn__298$fn__299.invoke (form-init9294449238353913047.clj:1)
>     user$eval225$fn__298.invoke (form-init9294449238353913047.clj:1)
>     user$eval225.invokeStatic (form-init9294449238353913047.clj:1)
>     user$eval225.invoke (form-init9294449238353913047.clj:1)
>     clojure.lang.Compiler.eval (Compiler.java:7700)
>     clojure.lang.Compiler.eval (Compiler.java:7690)
>     clojure.lang.Compiler.load (Compiler.java:8165)
>     clojure.lang.Compiler.loadFile (Compiler.java:8103)
>     clojure.main$load_script.invokeStatic (main.clj:476)
>     clojure.main$init_opt.invokeStatic (main.clj:478)
>     clojure.main$init_opt.invoke (main.clj:478)
>     clojure.main$initialize.invokeStatic (main.clj:509)
>     clojure.main$null_opt.invokeStatic (main.clj:543)
>     clojure.main$null_opt.invoke (main.clj:540)
>     clojure.main$main.invokeStatic (main.clj:665)
>     clojure.main$main.doInvoke (main.clj:617)
>     clojure.lang.RestFn.applyTo (RestFn.java:140)
>     clojure.lang.Var.applyTo (Var.java:707)
>     clojure.main.main (main.java:40)
> 
> lein test puppetlabs.services.master.environment-classes-int-test
> 
> lein test puppetlabs.services.master.environment-modules-int-test
> 2025-04-29 02:26:45,384 WARN  [pool-410-thread-1] [puppetserver] Puppet Could not retrieve either serverip or serverip6 fact
> 2025-04-29 02:26:45,425 WARN  [async-dispatch-38] [p.s.m.master-service] JDK 21.0.7 is neither tested nor supported. Please use JDK 11 or 17
> 
> lein test puppetlabs.services.master.environment-transports-int-test
> 
> lein test puppetlabs.services.master.master-core-test
> 2025-04-29 02:27:08,160 ERROR [main] [p.p.jruby-request] Error 400 on SERVER at /v4/catalog: Invalid input: {"environment" (not (puppetlabs.services.master.master-core/valid-env-name? ""))}
> 
> lein test puppetlabs.services.master.master-service-test
> 
> lein test puppetlabs.services.master.plans-int-test
> 
> lein test puppetlabs.services.master.tasks-int-test
> 
> lein test puppetlabs.services.puppet-admin.puppet-admin-int-test
> 
> lein test puppetlabs.services.puppet-profiler.puppet-profiler-core-test
> 
> lein test puppetlabs.services.puppet-profiler.puppet-profiler-service-test
> 
> lein test puppetlabs.services.request-handler.request-handler-core-test
> 2025-04-29 02:28:59,442 WARN  [async-dispatch-25] [p.s.m.master-service] JDK 21.0.7 is neither tested nor supported. Please use JDK 11 or 17
> 
> lein test puppetlabs.services.versioned-code-service.versioned-code-core-test
> 
> lein test puppetlabs.services.versioned-code-service.versioned-code-service-test
> 
> lein test puppetlabs.testutils.task-coordinator-test
> 
> Ran 218 tests containing 12741 assertions.
> 0 failures, 1 errors.
> Tests failed.
> make[1]: *** [debian/rules:66: override_dh_auto_test] Error 1


The full build log is available from:
http://qa-logs.debian.net/2025/04/28/puppetserver_8.7.0-4_unstable.log

You can find other build logs (including successful ones) in:
http://qa-logs.debian.net/2025/04/28/

All bugs filed during this archive rebuild are listed at:
https://bugs.debian.org/cgi-bin/pkgreport.cgi?tag=ftbfs-20250428;users=lucas@debian.org
or:
https://udd.debian.org/bugs/?release=na&merged=ign&fnewerval=7&flastmodval=7&fusertag=only&fusertagtag=ftbfs-20250428&fusertaguser=lucas@debian.org&allbugs=1&cseverity=1&ctags=1&caffected=1#results

A list of current common problems and possible solutions is available at
http://wiki.debian.org/qa.debian.org/FTBFS . You're welcome to contribute!

If you reassign this bug to another package, please mark it as 'affects'-ing
this package. See https://www.debian.org/Bugs/server-control#affects

If you fail to reproduce this, please provide a build log and diff it with mine
so that we can identify if something relevant changed in the meantime.



More information about the Pkg-puppet-devel mailing list