metabase / metabase

The simplest, fastest way to get business intelligence and analytics to everyone in your company :yum:
https://metabase.com
Other
38.33k stars 5.08k forks source link

BE flakes: "java.util.ConcurrentModificationException" in H2 #41259

Open calherries opened 5 months ago

calherries commented 5 months ago

I hit this flake but admittedly have no idea how frequent it is. I suspect it's not tied to any test in particular so will probably be really difficult to track its frequency. It seems like a bug with H2, and may be related to this issue.

Example run: https://github.com/metabase/metabase/actions/runs/8631518868/job/23660129347?pr=41249#step:10:1548

This test runs in parallel and the query executes on H2.

The important part of the stack trace is here:

    originalMessage: "General error: \"java.util.ConcurrentModificationException\""
java.util.ConcurrentModificationException: 
                                                           java.util.HashMap$HashIterator.nextNode                HashMap.java: 1511
                                                              java.util.HashMap$ValueIterator.next                HashMap.java: 1539
                                                        org.h2.engine.SessionLocal.cleanTempTables           SessionLocal.java:  965
                                                                 org.h2.engine.SessionLocal.commit           SessionLocal.java:  681
                                                                       org.h2.command.Command.stop                Command.java:  157
                                                              org.h2.command.CommandContainer.stop       CommandContainer.java:  259
                                                               org.h2.command.Command.executeQuery                Command.java:  229

SessionLocal.java:965 is here: https://github.com/h2database/h2database/blob/version-2.1.214/h2/src/main/org/h2/engine/SessionLocal.java#L965

full stack trace:

metabase.query-processor-test.parameters-test/ignore-parameters-for-unparameterized-native-query-test (execute.clj:707)
Parameters passed for unparameterized queries should get ignored
expected: (=
           (->
            (qp/process-query query)
            (m/dissoc-in [:data :results_metadata :checksum]))
           (->
            (qp/process-query
             (assoc
              query
              :parameters
              [{:target [:dimension
                         [:field
                          (mt/id :categories :id)
                          {:source-field (mt/id :venues :category_id)}]],
                :type "category",
                :value [:param-value]}]))
            (m/dissoc-in [:data :native_form :params])
            (m/dissoc-in [:data :results_metadata :checksum])))
  actual: 
               clojure.lang.ExceptionInfo: Error executing query: General error: "java.util.ConcurrentModificationException" [50000-214]
    driver: :h2
    params: nil
       sql: ["-- Metabase" "select" "  111 as my_number," "  'foo' as my_string"]
      type: :invalid-query
 org.h2.jdbc.JdbcSQLNonTransientException: General error: "java.util.ConcurrentModificationException" [50000-214]
           SQLState: "HY000"
          errorCode: 50000
    originalMessage: "General error: \"java.util.ConcurrentModificationException\""
java.util.ConcurrentModificationException: 
                                                           java.util.HashMap$HashIterator.nextNode                HashMap.java: 1511
                                                              java.util.HashMap$ValueIterator.next                HashMap.java: 1539
                                                        org.h2.engine.SessionLocal.cleanTempTables           SessionLocal.java:  965
                                                                 org.h2.engine.SessionLocal.commit           SessionLocal.java:  681
                                                                       org.h2.command.Command.stop                Command.java:  157
                                                              org.h2.command.CommandContainer.stop       CommandContainer.java:  259
                                                               org.h2.command.Command.executeQuery                Command.java:  229
                                                         org.h2.jdbc.JdbcStatement.executeInternal          JdbcStatement.java:  247
                                                                 org.h2.jdbc.JdbcStatement.execute          JdbcStatement.java:  223
                                                com.mchange.v2.c3p0.impl.NewProxyStatement.execute      NewProxyStatement.java:   75
                                                    metabase.driver.sql-jdbc.execute/eval108245/fn                 execute.clj:  560
                                                                                               ...                                  
                         metabase.driver.sql-jdbc.execute/execute-statement-or-prepared-statement!                 execute.clj:  568
                                    metabase.driver.sql-jdbc.execute/execute-reducible-query/fn/fn                 execute.clj:  705
                                       metabase.driver.sql-jdbc.execute/execute-reducible-query/fn                 execute.clj:  704
                                                               metabase.driver.h2/eval110477/fn/fn                      h2.clj:  546
                                                            metabase.driver.sql-jdbc.execute/fn/&f                 execute.clj:  335
                                                            metabase.driver.sql-jdbc.execute/fn/fn                 execute.clj:  318
                                                                  metabase.driver.h2/eval110477/fn                      h2.clj:  537
                                                                                               ...                                  
                                          metabase.driver.sql-jdbc.execute/execute-reducible-query                 execute.clj:  698
                                          metabase.driver.sql-jdbc.execute/execute-reducible-query                 execute.clj:  695
                                                            metabase.driver.sql-jdbc/eval109441/fn                sql_jdbc.clj:   78
                                                                  metabase.driver.h2/eval110233/fn                      h2.clj:  272
                                                                                               ...                                  
                                                       metabase.query-processor.pipeline/*execute*                pipeline.clj:   47
                                                           metabase.query-processor.pipeline/*run*                pipeline.clj:   88
                                                              metabase.query-processor.execute/run                 execute.clj:   45
                            metabase.query-processor.execute/add-native-form-to-result-metadata/fn                 execute.clj:   21
metabase.query-processor.middleware.cache/maybe-return-cached-results/maybe-return-cached-results*                   cache.clj:  242
                        metabase.query-processor.middleware.permissions/check-query-permissions/fn             permissions.clj:  118
           metabase.query-processor.middleware.enterprise/check-download-permissions-middleware/fn              enterprise.clj:   51
 metabase.query-processor.middleware.enterprise/maybe-apply-column-level-perms-check-middleware/fn              enterprise.clj:   64
                                                         metabase.query-processor.execute/fn/&f/fn                 execute.clj:   74
                                                              metabase.query-processor.setup/fn/&f                   setup.clj:  215
                                                              metabase.query-processor.setup/fn/fn                   setup.clj:  206
                                                            metabase.query-processor.execute/fn/&f                 execute.clj:   73
                                                            metabase.query-processor.execute/fn/fn                 execute.clj:   64
                                                          metabase.query-processor/process-query**         query_processor.clj:   47
     metabase.query-processor.middleware.enterprise/eval84647/handle-audit-app-internal-queries/fn              enterprise.clj:   96
    metabase.query-processor.middleware.enterprise/handle-audit-app-internal-queries-middleware/fn              enterprise.clj:  103
                               metabase.query-processor.middleware.process-userland-query/fn/&f/&f  process_userland_query.clj:  157
                               metabase.query-processor.middleware.process-userland-query/fn/&f/fn  process_userland_query.clj:  154
                                     metabase.query-processor.middleware.catch-exceptions/fn/&f/&f        catch_exceptions.clj:  121
                                     metabase.query-processor.middleware.catch-exceptions/fn/&f/fn        catch_exceptions.clj:  118
                                                                 metabase.query-processor/fn/&f/fn         query_processor.clj:   78
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  178
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  170
                                                        metabase.query-processor.setup/fn/&f/fn/fn                   setup.clj:  146
                                                                    metabase.driver/do-with-driver                  driver.clj:   97
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  145
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  155
                                                        metabase.query-processor.setup/fn/&f/fn/fn                   setup.clj:  131
                                                              metabase.query-processor.store/fn/&f                   store.clj:  170
                                                              metabase.query-processor.store/fn/fn                   store.clj:  150
                                                              metabase.query-processor.store/fn/&f                   store.clj:  159
                                                              metabase.query-processor.store/fn/fn                   store.clj:  150
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  130
                                                           metabase.query-processor.setup/fn/&f/&f                   setup.clj:  108
                                                           metabase.query-processor.setup/fn/&f/fn                   setup.clj:  102
                                                              metabase.query-processor.setup/fn/&f                   setup.clj:  222
                                                              metabase.query-processor.setup/fn/fn                   setup.clj:  206
                                                                    metabase.query-processor/fn/&f         query_processor.clj:   76
                                                                    metabase.query-processor/fn/fn         query_processor.clj:   69
                                                                    metabase.query-processor/fn/&f         query_processor.clj:   72
                                                                    metabase.query-processor/fn/fn         query_processor.clj:   69
                                                  metabase.query-processor-test.parameters-test/fn         parameters_test.clj:  378
                                                                          clojure.test/test-var/fn                    test.clj:  717
                                                                             clojure.test/test-var                    test.clj:  717
                                                                             mb.hawk.core/run-test                    core.clj:  151
                                                                     eftest.runner/test-vars/fn/fn                  runner.clj:  106
                                                                      clojure.test/default-fixture                    test.clj:  687
                                                                        eftest.runner/test-vars/fn                  runner.clj:   98
                                                             eftest.runner/wrap-test-with-timer/fn                  runner.clj:   38
                                                                         eftest.runner/pmap*/fn/fn                  runner.clj:   72
                                                                                               ...                                  
                                                                                clojure.core/apply                    core.clj:  667
                                                                       clojure.core/with-bindings*                    core.clj: 1990 (repeats 2 times)
                                                                                               ...                                  
                                                           eftest.runner/bound-callback/reify/call                  runner.clj:   55
                                                               java.util.concurrent.FutureTask.run             FutureTask.java:  264
                                                 java.util.concurrent.ThreadPoolExecutor.runWorker     ThreadPoolExecutor.java: 1128
                                                java.util.concurrent.ThreadPoolExecutor$Worker.run     ThreadPoolExecutor.java:  628
                                                                              java.lang.Thread.run                 Thread.java:  829
calherries commented 5 months ago

From Cam on slack:

I'm guessing it's an upstream H2 bug, most be a race condition because this is the first time I've ever seen it. Seems like it would only be an issue when running a lot of threads simultaneously (e.g. parallel tests)... Most people in prod hopefully aren't using H2 or at least not with a ton of simultaneous users so I wouldn't be worried about this affecting prod too much.