Skip to content

Commit

Permalink
(PE-37252) discontinue use of logback-access
Browse files Browse the repository at this point in the history
This disables the use of logback-access because logback-access is not
compatible with Jetty 10.  See jetty/jetty.project#5996

This changes the implementation to use a CustomRequestLog in jetty with the SLF4JLogWriter
until a better solution can be determined.  This means that logging won't obey the
logback-access configuration specified.
  • Loading branch information
jonathannewman committed Nov 29, 2023
1 parent cf7cea8 commit d542fe8
Show file tree
Hide file tree
Showing 3 changed files with 49 additions and 39 deletions.
4 changes: 4 additions & 0 deletions CHANGELOG.md
@@ -1,5 +1,9 @@
## unreleased changes

## 1.0.6
* route logging through a SLF4J Custom logger as logback-access no longer works with jetty10. This is a work around until full featured logging is developed.


## 1.0.5
* add the [`Response`](https://www.eclipse.org/jetty/javadoc/jetty-10/org/eclipse/jetty/server/Response.html) under the `:response` key in the request for ring-handlers.

Expand Down
11 changes: 7 additions & 4 deletions src/puppetlabs/trapperkeeper/services/webserver/jetty10_core.clj
Expand Up @@ -29,9 +29,9 @@
(org.eclipse.jetty.io ClientConnectionFactory$Info ClientConnector)
(org.eclipse.jetty.jmx MBeanContainer)
(org.eclipse.jetty.proxy ProxyServlet)
(org.eclipse.jetty.server AbstractConnectionFactory ConnectionFactory Handler HttpConfiguration
(org.eclipse.jetty.server AbstractConnectionFactory ConnectionFactory CustomRequestLog Handler HttpConfiguration
HttpConnectionFactory Request
Server ServerConnector SymlinkAllowedResourceAliasChecker)
Server ServerConnector Slf4jRequestLogWriter SymlinkAllowedResourceAliasChecker)
(org.eclipse.jetty.server.handler AbstractHandler ContextHandler
ContextHandlerCollection HandlerCollection
HandlerWrapper StatisticsHandler)
Expand Down Expand Up @@ -737,7 +737,8 @@
options))
^Server s (create-server webserver-context config)
^HandlerCollection hc (HandlerCollection.)
log-handler (config/maybe-init-log-handler options)]
;; PE_37252 was (config/maybe-init-log-handler options)]
log-handler nil]
(.setHandlers hc (into-array Handler [(:handlers webserver-context)]))
(let [shutdown-timeout (* 1000 (:shutdown-timeout-seconds options config/default-shutdown-timeout-seconds))
maybe-zipped (if (:gzip-enable options true)
Expand All @@ -755,8 +756,10 @@
statistics-handler (if (or (nil? shutdown-timeout) (pos? shutdown-timeout))
(doto (StatisticsHandler.)
(.setHandler maybe-logged))
maybe-logged)]
maybe-logged)
log-writer (Slf4jRequestLogWriter.)]
(.setHandler s statistics-handler)
(.setRequestLog s (CustomRequestLog. log-writer CustomRequestLog/EXTENDED_NCSA_FORMAT))
(when shutdown-timeout
(log/info (i18n/trs "Server shutdown timeout set to {0} milliseconds" shutdown-timeout))
(.setStopTimeout s shutdown-timeout))
Expand Down
Expand Up @@ -718,41 +718,44 @@
(finally
(Files/delete link)))))

(deftest request-logging-test
(with-app-with-config
app
[jetty10-service hello-webservice]
{:webserver {:port 8080
;; Restrict the number of threads available to the webserver
;; so we can easily test whether thread-local values in the
;; MDC are cleaned up.
:acceptor-threads 1
:selector-threads 1 ; You actually end up with 2 threads.
:max-threads 4
:access-log-config "./dev-resources/puppetlabs/trapperkeeper/services/webserver/request-logging.xml"}}
(testing "request logging occurs when :access-log-config is configured"
(with-test-access-logging
(http-get "http://localhost:8080/hi_world/")
; Logging is done in a separate thread from Jetty and this test. As a result,
; we have to sleep the thread to avoid a race condition.
(Thread/sleep 10)
(let [list (TestListAppender/list)]
(is (re-find #"\"GET /hi_world/ HTTP/1.1\" 200" (first list))))))

(testing "Mapped Diagnostic Context values are available to the access logger"
(with-test-access-logging
(http-put "http://localhost:8080/mdc?mdc_key=mdc-test" {:body "hello"})
(Thread/sleep 10)
(let [list (TestListAppender/list)]
(is (str/ends-with? (first list) "hello\n")))))

(testing "Mapped Diagnostic Context values are cleared after each request"
(http-put "http://localhost:8080/mdc?mdc_key=mdc-persist" {:body "foo"})

;; Loop to ensure we hit all threads.
(let [responses (for [n (range 0 10)]
(http-get "http://localhost:8080/mdc?mdc_key=mdc-persist"))]
(is (every? #(not= "foo" %) (map :body responses)))))))

;; PE-37252 temporarily disable logging tests
;(deftest request-logging-test
; (with-app-with-config
; app
; [jetty10-service hello-webservice]
; {:webserver {:port 8080
; ;; Restrict the number of threads available to the webserver
; ;; so we can easily test whether thread-local values in the
; ;; MDC are cleaned up.
; :acceptor-threads 1
; :selector-threads 1 ; You actually end up with 2 threads.
; :max-threads 4
; :access-log-config "./dev-resources/puppetlabs/trapperkeeper/services/webserver/request-logging.xml"}}
;
; (testing "request logging occurs when :access-log-config is configured"
; (with-test-access-logging
; (http-get "http://localhost:8080/hi_world/")
; ; Logging is done in a separate thread from Jetty and this test. As a result,
; ; we have to sleep the thread to avoid a race condition.
; (Thread/sleep 10)
; (let [list (TestListAppender/list)]
; (is (re-find #"\"GET /hi_world/ HTTP/1.1\" 200" (first list))))))
;
; (testing "Mapped Diagnostic Context values are available to the access logger"
; (with-test-access-logging
; (http-put "http://localhost:8080/mdc?mdc_key=mdc-test" {:body "hello"})
; (Thread/sleep 10)
; (let [list (TestListAppender/list)]
; (is (str/ends-with? (first list) "hello\n")))))
;
; (testing "Mapped Diagnostic Context values are cleared after each request"
; (http-put "http://localhost:8080/mdc?mdc_key=mdc-persist" {:body "foo"})
;
; ;; Loop to ensure we hit all threads.
; (let [responses (for [n (range 0 10)]
; (http-get "http://localhost:8080/mdc?mdc_key=mdc-persist"))]
; (is (every? #(not= "foo" %) (map :body responses)))))))

(deftest graceful-shutdown-test
(testing "jetty10 webservers shut down gracefully by default"
Expand Down

0 comments on commit d542fe8

Please sign in to comment.