Uploaded image for project: 'Puppet Server'
  1. Puppet Server
  2. SERVER-2466

Puppetserver fails to restart when enabling graphite metrics

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Normal
    • Resolution: Fixed
    • Affects Version/s: SERVER 5.3.6, SERVER 5.3.7
    • Fix Version/s: None
    • Component/s: Puppet Server
    • Labels:
      None
    • Template:
      PUP Bug Template
    • Method Found:
      Needs Assessment
    • QA Risk Assessment:
      Needs Assessment

      Description

      Puppet Version: 5.5.10
      Puppet Server Version: 5.3.7
      OS Name/Version: RHEL 7.6

      Describe your issue in as much detail as possible…

      When enabling the graphite metrics in /etc/puppetlabs/puppetserver/conf.d/metrics.conf :

       

      metrics: {
          # a server id that will be used as part of the namespace for metrics produced
          # by this server
          server-id: localhost
          registries: {
              puppetserver: {
                  # specify metrics to allow in addition to those in the default list
                  #metrics-allowed: ["compiler.compile.production"]            reporters: {
                      # enable or disable JMX metrics reporter
                      jmx: {
                          enabled: true
                      }
                       enable or disable Graphite metrics reporter
                      graphite: {
                          enabled: true
                      }
                  }        }
          }    # this section is used to configure settings for reporters that will send
          # the metrics to various destinations for external viewing
          reporters: {
              graphite: {
                  # graphite host
                  host: "tice-rhel7prod.jhuapl.edu"
                  # graphite metrics port
                  port: 3000
                  # how often to send metrics to graphite
                  update-interval-seconds: 5
              }
          }
      
      

      The puppetserver fails to restart. Here are the errors I noticed in the logs:

      2019-02-18 10:41:38,886 ERROR [qtp1501096310-66] [p.r.core] Internal Server Error: java.lang.InterruptedException
              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088)
              at com.puppetlabs.jruby_utils.pool.JRubyPool.borrowItemWithTimeout(JRubyPool.java:194)
              at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:498)
              at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:93)
              at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:28)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30528$borrow_with_timeout_fn__30533$fn__30534.invoke(jruby_internal.clj:133)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30528$borrow_with_timeout_fn__30533.invoke(jruby_internal.clj:130)
              at clojure.core$partial$fn__4759.invoke(core.clj:2515)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30891$borrow_from_pool_BANG__STAR___30896$fn__30897.invoke(jruby_internal.clj:271)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30891$borrow_from_pool_BANG__STAR___30896.invoke(jruby_internal.clj:264)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30938$borrow_from_pool_with_timeout__30943$fn__30944.invoke(jruby_internal.clj:312)
              at puppetlabs.services.jruby_pool_manager.impl.jruby_internal$eval30938$borrow_from_pool_with_timeout__30943.invoke(jruby_internal.clj:301)
              at puppetlabs.services.jruby_pool_manager.jruby_core$eval32153$borrow_from_pool_with_timeout__32158$fn__32159.invoke(jruby_core.clj:212)
              at puppetlabs.services.jruby_pool_manager.jruby_core$eval32153$borrow_from_pool_with_timeout__32158.invoke(jruby_core.clj:199)
              at puppetlabs.puppetserver.jruby_request$wrap_with_jruby_instance$fn__33241.invoke(jruby_request.clj:46)
              at puppetlabs.puppetserver.jruby_request$wrap_with_error_handling$fn__33237.invoke(jruby_request.clj:33)
              at puppetlabs.services.request_handler.request_handler_service$reify__33338$service_fnk__5266__auto___positional$reify__33353.handle_request(request_handler_service.clj:47)
              at puppetlabs.services.protocols.request_handler$eval29051$fn__29052$G__29043__29055.invoke(request_handler.clj:3)
              at puppetlabs.services.protocols.request_handler$eval29051$fn__29052$G__29042__29059.invoke(request_handler.clj:3)
              at clojure.core$partial$fn__4759.invoke(core.clj:2515)
              at puppetlabs.trapperkeeper.authorization.ring_middleware$eval40038$wrap_authorization_check__40047$fn__40050$fn__40051.invoke(ring_middleware.clj:284)
              at puppetlabs.ring_middleware.core$eval22014$wrap_bad_request__22023$fn__22026$fn__22032.invoke(core.clj:170)
              at puppetlabs.ring_middleware.core$eval22112$wrap_uncaught_errors__22121$fn__22124$fn__22129.invoke(core.clj:216)
              at puppetlabs.ring_middleware.core$eval21739$wrap_request_logging__21744$fn__21745$fn__21747.invoke(core.clj:47)
              at puppetlabs.i18n.core$locale_negotiator$fn__124.invoke(core.clj:357)
              at puppetlabs.ring_middleware.core$eval21768$wrap_response_logging__21773$fn__21774$fn__21775.invoke(core.clj:53)
              at puppetlabs.puppetserver.ringutils$wrap_with_puppet_version_header$fn__17457.invoke(ringutils.clj:83)
              at puppetlabs.services.master.master_core$eval38344$v3_ruby_routes__38349$fn__38350$fn__38357.invoke(master_core.clj:727)
              at bidi.ring$eval23056$fn__23057.invoke(ring.cljc:25)
              at bidi.ring$eval23035$fn__23036$G__23026__23045.invoke(ring.cljc:16)
              at puppetlabs.comidi$make_handler$fn__25166.invoke(comidi.clj:245)
              at puppetlabs.metrics.http$eval37522$wrap_with_request_metrics__37527$fn__37531$fn__37533$fn__37534$fn__37535.invoke(http.clj:152)
      at puppetlabs.metrics.http.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
              at com.codahale.metrics.Timer.time(Timer.java:101)
              at puppetlabs.metrics.http$eval37522$wrap_with_request_metrics__37527$fn__37531$fn__37533$fn__37534.invoke(http.clj:152)
              at puppetlabs.metrics.http.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
              at com.codahale.metrics.Timer.time(Timer.java:101)
              at puppetlabs.metrics.http$eval37522$wrap_with_request_metrics__37527$fn__37531$fn__37533.invoke(http.clj:148)
              at puppetlabs.comidi$eval25227$wrap_with_route_metadata__25232$fn__25233$fn__25235.invoke(comidi.clj:332)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_core$ring_handler$fn__35409.invoke(jetty9_core.clj:434)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_core.proxy$org.eclipse.jetty.server.handler.AbstractHandler$ff19274a.handle(Unknown Source)
              at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:498)
              at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:93)
              at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:28)
              at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers$eval34985$normalize_uri_handler__34990$fn__34991$fn__34992.invoke(normalized_uri_helpers.clj:74)
              at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
              at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
              at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317)
              at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:205)
              at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219)
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
              at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:219)
              at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
              at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:724)
              at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:56)
              at com.puppetlabs.trapperkeeper.services.webserver.jetty9.utils.MDCRequestLogHandler.handle(MDCRequestLogHandler.java:36)
              at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:169)
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
              at org.eclipse.jetty.server.Server.handle(Server.java:531)
              at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
              at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
              at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
              at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
              at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291)
              at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151)
              at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
              at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
              at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
              at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
              at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
              at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
              at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
              at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
              at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
              at java.lang.Thread.run(Thread.java:748)
      

      and

      2019-02-18 10:41:38,893 ERROR [async-dispatch-3] [p.t.s.w.jetty9-core] Web server failed to shut down gracefully in configured timeout period (30,000); cancelling remaining requests.
      java.util.concurrent.TimeoutException: null
              at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:128)
              at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:30)
              at org.eclipse.jetty.server.Server.doStop(Server.java:460)
              at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:89)
              at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:498)
              at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:93)
              at clojure.lang.Reflector.invokeNoArgInstanceMember(Reflector.java:313)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_core$eval35603$shutdown__35608$fn__35612$fn__35614.invoke(jetty9_core.clj:607)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_core$eval35603$shutdown__35608$fn__35612.invoke(jetty9_core.clj:606)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_core$eval35603$shutdown__35608.invoke(jetty9_core.clj:598)
              at puppetlabs.trapperkeeper.services.webserver.jetty9_service$reify__36516$service_fnk__5266__auto___positional$reify__36523.stop(jetty9_service.clj:71)
              at puppetlabs.trapperkeeper.services$eval5068$fn__5095$G__5060__5098.invoke(services.clj:9)
              at puppetlabs.trapperkeeper.services$eval5068$fn__5095$G__5059__5102.invoke(services.clj:9)
              at puppetlabs.trapperkeeper.internal$eval13835$run_lifecycle_fn_BANG___13842$fn__13843.invoke(internal.clj:198)
              at puppetlabs.trapperkeeper.internal$eval13835$run_lifecycle_fn_BANG___13842.invoke(internal.clj:181)
              at puppetlabs.trapperkeeper.internal$eval14258$shutdown_BANG___14263$fn__14264$shutdown_fn__14266$fn__14277.invoke(internal.clj:440)
              at puppetlabs.trapperkeeper.internal$eval14258$shutdown_BANG___14263$fn__14264$shutdown_fn__14266.invoke(internal.clj:439)
              at puppetlabs.trapperkeeper.internal$eval13905$initialize_lifecycle_worker__13916$fn__13917$fn__14013$state_machine__11875__auto____14014$fn__14016$fn__14029.invoke(internal.clj:276)
              at puppetlabs.trapperkeeper.internal$eval13905$initialize_lifecycle_worker__13916$fn__13917$fn__14013$state_machine__11875__auto____14014$fn__14016.invoke(internal.clj:260)
              at puppetlabs.trapperkeeper.internal$eval13905$initialize_lifecycle_worker__13916$fn__13917$fn__14013$state_machine__11875__auto____14014.invoke(internal.clj:251)
              at clojure.core.async.impl.ioc_macros$run_state_machine.invokeStatic(ioc_macros.clj:1012)
              at clojure.core.async.impl.ioc_macros$run_state_machine.invoke(ioc_macros.clj:1011)
              at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invokeStatic(ioc_macros.clj:1016)
              at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invoke(ioc_macros.clj:1014)
              at clojure.core.async$ioc_alts_BANG_$fn__12043.invoke(async.clj:383)
              at clojure.core.async$do_alts$fn__11989$fn__11992.invoke(async.clj:252)
              at clojure.core.async.impl.channels.ManyToManyChannel$fn__6813.invoke(channels.clj:135)
              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:748)
      

       

      Desired Behavior:

      After configuring the puppetserver to enable / send graphite metrics, the puppetserver should restart without errors.

      Actual Behavior:

      [root@puppet ~]# systemctl restart puppetserver
      Job for puppetserver.service failed because the control process exited with error code. See "systemctl status puppetserver.service" and "journalctl -xe" for details.

       

      I originally tried this in server 5.3.6 but then upgraded to 5.3.7 to see if that would help; no luck.

      To reproduce:

      1. Uncomment the necessary lines to enable graphite metrics in metrics.conf
      2. # systemctl restart puppetserver
      3. the command should fail.

       

       

       

        Attachments

        1. etc-sysconfig-puppetserver.txt
          1 kB
        2. puppet.conf
          0.9 kB
        3. puppetserver.conf
          3 kB
        4. puppetserver.log.gz
          4.23 MB

          Activity

            jsd-sla-details-panel

              People

              • Assignee:
                Unassigned
                Reporter:
                miketice22 Michael Tice
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: