From bb673e118a9b68ca24bded0c66bc463e292d97ab Mon Sep 17 00:00:00 2001
From: "metabase-bot[bot]"
 <109303359+metabase-bot[bot]@users.noreply.github.com>
Date: Thu, 18 Apr 2024 12:16:19 +0000
Subject: [PATCH] =?UTF-8?q?=F0=9F=A4=96=20backported=20"Increase=20timeout?=
 =?UTF-8?q?=20for=20with-dynamic-redefs=20test"=20(#41569)?=
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Co-authored-by: Chris Truter <crisptrutski@users.noreply.github.com>
---
 test/metabase/test/util_test.clj | 34 +++++++++++++++++++++++---------
 test_config/log4j2-test.xml      |  1 +
 2 files changed, 26 insertions(+), 9 deletions(-)

diff --git a/test/metabase/test/util_test.clj b/test/metabase/test/util_test.clj
index ca1b9f15e4c..8fd89f271e8 100644
--- a/test/metabase/test/util_test.clj
+++ b/test/metabase/test/util_test.clj
@@ -7,8 +7,11 @@
    [metabase.test :as mt]
    [metabase.test.data :as data]
    [metabase.util :as u]
+   [metabase.util.log :as log]
    [toucan2.core :as t2])
-  (:import (java.util.concurrent CountDownLatch TimeUnit)))
+  (:import
+   (clojure.lang Agent)
+   (java.util.concurrent CountDownLatch ThreadPoolExecutor TimeUnit)))
 
 (set! *warn-on-reflection* true)
 
@@ -50,24 +53,35 @@
 
 (deftest ^:parallel with-dynamic-redefs-test
   (testing "Three threads can independently redefine a regular var"
-    (let [n-threads 3
-          latch (CountDownLatch. (inc n-threads))
-          take-latch  #(do
-                         (.countDown latch)
-                         (when-not (.await latch 100 TimeUnit/MILLISECONDS)
-                           (throw (ex-info "Timeout waiting on all threads to pull their latch" {:latch latch}))))]
+    (let [n-threads  3
+          ;; Note that .getId is deprecated in favor of .threadId, but that method is only introduced in Java 19
+          thread-id  #(.getId (Thread/currentThread))
+          latch      (CountDownLatch. (inc n-threads))
+          take-latch #(do
+                        (.countDown latch)
+                        ;; We give a generous timeout here in case there is heavy contention for the thread pool in CI
+                        (when-not (.await latch 30 TimeUnit/SECONDS)
+                          (throw (ex-info "Timeout waiting on all threads to pull their latch"
+                                          {:latch      latch
+                                           :thread-id  (thread-id)
+                                           :agent-pool (let [^ThreadPoolExecutor executor Agent/pooledExecutor]
+                                                         {:active-count (.getActiveCount executor)
+                                                          :pool-size    (.getPoolSize executor)
+                                                          :task-count   (.getTaskCount executor)})}))))]
 
       (testing "The original definition"
         (is (= "original" (clump "o" "riginal"))))
 
       (future
-        (testing "A thread that minds its own business"
+       (testing "A thread that minds its own business"
+          (log/debug "Starting no-op thread, thread-id:" (thread-id))
           (is (= "123" (clump 12 3)))
           (take-latch)
           (is (= "321" (clump 3 21)))))
 
       (future
         (testing "A thread that redefines it in reverse"
+          (log/debug "Starting reverse thread, thread-id:" (thread-id))
           (mt/with-dynamic-redefs [clump #(str %2 %1)]
             (is (= "ok" (clump "k" "o")))
             (take-latch)
@@ -75,7 +89,8 @@
 
       (future
         (testing "A thread that redefines it twice"
-          (mt/with-dynamic-redefs [clump #(str %2 %2)]
+          (log/debug "Starting double-redefining thread, thread-id:" (thread-id))
+          (mt/with-dynamic-redefs [clump (fn [_ y] (str y y))]
             (is (= "zz" (clump "a" "z")))
             (mt/with-dynamic-redefs [clump (fn [x _] (str x x))]
               (is (= "aa" (clump "a" "z")))
@@ -83,6 +98,7 @@
               (is (= "mm" (clump "m" "l"))))
             (is (= "bb" (clump "a" "b"))))))
 
+      (log/debug "Taking latch on main thread, thread-id:" (thread-id))
       (take-latch)
       (testing "The original definition survives"
         (is (= "original" (clump "orig" "inal")))))))
diff --git a/test_config/log4j2-test.xml b/test_config/log4j2-test.xml
index aa899da4e81..99d3b8741bf 100644
--- a/test_config/log4j2-test.xml
+++ b/test_config/log4j2-test.xml
@@ -10,6 +10,7 @@
     <Logger name="metabase-enterprise" level="FATAL"/>
     <Logger name="liquibase" level="FATAL"/>
     <Logger name="metabase.test.data.interface" level="INFO"/>
+    <Logger name="metabase.test.util-test" level="DEBUG" />
 
     <Root level="FATAL">
       <AppenderRef ref="Console"/>
-- 
GitLab