From 2648c1d2dc2bc1458c6fcfc2aa956b2f85b315eb Mon Sep 17 00:00:00 2001
From: Tim Greene <tim.g.greene@gmail.com>
Date: Fri, 22 Jan 2021 13:35:06 +0000
Subject: [PATCH] Limit logging of 501 Not Implemented errors

For public facing websites it's not uncommon to have exploitation suites run
random strings as methods in small batches of requests. This commit channels
501s away from errors logs into info logs as we may still want to know that
unknown methods are being used, typically though it's a part of the normal
course of operation and don't want it to fill logging with high priority
messages and potentially fall through into alerting for some users.
---
 src/yada/handler.clj           | 13 +++++++++----
 test/yada/interceptor_test.clj | 30 ++++++++++++++++++++++++------
 2 files changed, 33 insertions(+), 10 deletions(-)

diff --git a/src/yada/handler.clj b/src/yada/handler.clj
index c5edf7cb..fefc4507 100644
--- a/src/yada/handler.clj
+++ b/src/yada/handler.clj
@@ -2,7 +2,7 @@
 
 (ns yada.handler
   (:require
-   [clojure.tools.logging :refer [errorf]]
+   [clojure.tools.logging :refer [errorf infof]]
    [manifold.deferred :as d]
    [schema.core :as s]
    [schema.utils :refer [error?]]
@@ -31,9 +31,14 @@
   (let [data (error-data e)]
     (when-not (::disable-error-logging? data)
       (when-not (and (-> data :status number?) (< (:status data) 500))
-        (when (instance? java.lang.Throwable e)
-          (errorf e "Internal Error %s" (or (some-> data :status str) "")))
-        (when data (errorf "ex-data: %s" (dissoc data :ctx)))))))
+        (if (= 501 (:status data))
+          (infof "Unknown method %s %s"
+                 (get-in data [:ctx :method])
+                 (get-in data [:ctx :request :uri]))
+          (do
+            (when (instance? java.lang.Throwable e)
+              (errorf e "Internal Error %s" (or (some-> data :status str) "")))
+            (when data (errorf "ex-data: %s" (dissoc data :ctx)))))))))
 
 ;; Response
 
diff --git a/test/yada/interceptor_test.clj b/test/yada/interceptor_test.clj
index f20a1786..62d74f03 100644
--- a/test/yada/interceptor_test.clj
+++ b/test/yada/interceptor_test.clj
@@ -1,12 +1,14 @@
 ;; Copyright © 2014-2017, JUXT LTD.
 
 (ns yada.interceptor-test
-  (:require
-   [clojure.test :refer :all :exclude [deftest]]
-   [schema.test :refer [deftest]]
-   [yada.handler
-    :refer
-    [append-interceptor insert-interceptor prepend-interceptor]]))
+  (:require [clojure.test :refer :all :exclude [deftest]]
+            clojure.tools.logging
+            [ring.mock.request :as ring-mock]
+            [schema.test :refer [deftest]]
+            [yada.handler
+             :refer
+             [append-interceptor handler insert-interceptor prepend-interceptor]]
+            [yada.resource :refer [as-resource]]))
 
 (deftest prepend-interceptor-test
   (let [res {:interceptor-chain [:b :c :d :e]}]
@@ -29,3 +31,19 @@
         (= expected (:interceptor-chain f))
       (append-interceptor res :c :c1 :c2) [:b :c :c1 :c2 :d :e]
       (append-interceptor res :z :d1 :d2) [:b :c :d :e])))
+
+(deftest known-method-logging-test
+  (let [logs (atom [])]
+    (with-redefs [clojure.tools.logging/log*
+                  (fn [_ level _ message]
+                    (swap! logs conj [level message]))]
+      (let [resource "Hello World!"
+            h (handler (merge (as-resource resource)
+                              {:produces {:media-type "text/plain"
+                                          :charset "UTF-8"}}))
+            request (ring-mock/request :foo "/")
+            response @(h request)
+            headers (:headers response)]
+
+        (is (= [[:info "Unknown method :foo /"]] @logs))
+        (is (= 501 (:status response)))))))