Model caching doesn't work

Get Help
1

Hi there,

I've developed a model, but I'm encountering an issue with Metabase where it consistently fails to create it after running 20 minutes. Interestingly, when I execute the same query as a question, it returns all the results within 5 seconds. What could be causing the model to fail?

Diagnostic:

{
  "browser-info": {
    "language": "fr-FR",
    "platform": "Win32",
    "userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "file.encoding": "Cp1252",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.23+9",
    "java.vendor": "Eclipse Adoptium",
    "java.vendor.url": "https://adoptium.net/",
    "java.version": "11.0.23",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.23+9",
    "os.name": "Windows Server 2016",
    "os.version": "10.0",
    "user.language": "fr",
    "user.timezone": "Europe/Paris"
  },
  "metabase-info": {
    "databases": [
      "postgres",
      "mysql"
    ],
    "hosting-env": "unknown",
    "application-database": "mysql",
    "application-database-details": {
      "database": {
        "name": "MySQL",
        "version": "8.0.36"
      },
      "jdbc-driver": {
        "name": "MariaDB Connector/J",
        "version": "2.7.10"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2024-04-22",
      "tag": "v0.49.7",
      "hash": "f0ff786"
    },
    "settings": {
      "report-timezone": "Europe/Paris"
    }
  }
}

Log:

[898adcdb-9061-4fca-a5d2-0bb71465b348] 2024-04-30T09:38:39+02:00 INFO metabase.task.persist-refresh Error refreshing persisting model with card-id 252,org.postgresql.util.PSQLException: ERREUR: annulation de la requête à cause du délai écoulé pour l'exécution de l'instruction, at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2725), at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2412), at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:371), at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:502), at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:419), at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:194), at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:155), at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:1502), at clojure.java.jdbc$db_do_execute_prepared_statement$fn__28507.invoke(jdbc.clj:1049), at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:860), at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776), at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:789), at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776), at clojure.java.jdbc$db_do_execute_prepared_statement.invokeStatic(jdbc.clj:1048), at clojure.java.jdbc$db_do_execute_prepared_statement.invoke(jdbc.clj:1042), at clojure.java.jdbc$db_do_prepared.invokeStatic(jdbc.clj:1080), at clojure.java.jdbc$db_do_prepared.invoke(jdbc.clj:1060), at clojure.java.jdbc$execute_BANG_$execute_helper__28581.invoke(jdbc.clj:1464), at clojure.java.jdbc$execute_BANG_.invokeStatic(jdbc.clj:1466), at clojure.java.jdbc$execute_BANG_.invoke(jdbc.clj:1435), at clojure.java.jdbc$execute_BANG_.invokeStatic(jdbc.clj:1456), at clojure.java.jdbc$execute_BANG_.invoke(jdbc.clj:1435), at metabase.driver.sql.ddl$execute_BANG_.invokeStatic(ddl.clj:27), at metabase.driver.sql.ddl$execute_BANG_.invoke(ddl.clj:24), at metabase.driver.postgres.ddl$fn__83890$fn__83892$fn__83893.invoke(ddl.clj:50), at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:807), at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776), at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:789), at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:776), at metabase.driver.postgres.ddl$fn__83890$fn__83892.invoke(ddl.clj:47), at metabase.driver.sql_jdbc.execute$fn__79197$fn__79198.invoke(execute.clj:389), at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invokeStatic(execute.clj:335), at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invoke(execute.clj:318), at metabase.driver.sql_jdbc.execute$fn__79197.invokeStatic(execute.clj:383), at metabase.driver.sql_jdbc.execute$fn__79197.invoke(execute.clj:381), at clojure.lang.MultiFn.invoke(MultiFn.java:244), at metabase.driver.postgres.ddl$fn__83890.invokeStatic(ddl.clj:42), at metabase.driver.postgres.ddl$fn__83890.invoke(ddl.clj:39), at clojure.lang.MultiFn.invoke(MultiFn.java:244), at metabase.task.persist_refresh$reify__84749.refresh_BANG_(persist_refresh.clj:55), at metabase.task.persist_refresh$refresh_with_stats_BANG_$fn__84752.invoke(persist_refresh.clj:75), at metabase.task.persist_refresh$refresh_with_stats_BANG_.invokeStatic(persist_refresh.clj:74), at metabase.task.persist_refresh$refresh_with_stats_BANG_.invoke(persist_refresh.clj:59), at clojure.lang.AFn.applyToHelper(AFn.java:165), at clojure.lang.AFn.applyTo(AFn.java:144), at clojure.core$apply.invokeStatic(core.clj:673), at clojure.core$partial$fn__5914.doInvoke(core.clj:2660), at clojure.lang.RestFn.invoke(RestFn.java:397), at metabase.task.persist_refresh$save_task_history_BANG_.invokeStatic(persist_refresh.clj:98), at metabase.task.persist_refresh$save_task_history_BANG_.invoke(persist_refresh.clj:93), at metabase.task.persist_refresh$refresh_individual_BANG_.invokeStatic(persist_refresh.clj:212), at metabase.task.persist_refresh$refresh_individual_BANG_.invoke(persist_refresh.clj:204), at metabase.task.persist_refresh$refresh_job_fn_BANG_.invokeStatic(persist_refresh.clj:229), at metabase.task.persist_refresh$refresh_job_fn_BANG_.invoke(persist_refresh.clj:223), at metabase.task.persist_refresh.PersistenceRefresh.execute(persist_refresh.clj:239), at org.quartz.core.JobRunShell.run(JobRunShell.java:202), at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)

[898adcdb-9061-4fca-a5d2-0bb71465b348] 2024-04-30T09:38:39+02:00 INFO metabase.task.persist-refresh Finished updated model-id 252 from persisted-info 150.

[898adcdb-9061-4fca-a5d2-0bb71465b348] 2024-04-30T09:39:27+02:00 DEBUG metabase.server.middleware.log GET /api/session/properties 200 23.3 ms (6 DB calls) App DB connections: 3/15 Jetty threads: 7/50 (3 idle, 0 queued) (116 total active threads) Queries in flight: 0 (0 queued)

[898adcdb-9061-4fca-a5d2-0bb71465b348] 2024-04-30T09:39:27+02:00 DEBUG metabase.server.middleware.log GET /api/user/current 200 43.7 ms (10 DB calls) App DB connections: 2/15 Jetty threads: 5/50 (2 idle, 0 queued) (117 total active threads) Queries in flight: 0 (0 queued)

[898adcdb-9061-4fca-a5d2-0bb71465b348] 2024-04-30T09:39:27+02:00 DEBUG metabase.server.middleware.log GET /api/database 200 9.2 ms (3 DB calls) App DB connections: 1/15 Jetty threads: 5/50 (3 idle, 0 queued) (117 total active threads) Queries in flight: 0 (0 queued)
2

Do you have the database logs to see what’s going on at the Postgres level?

3

I'm unable to access it directly, but when I execute my query through pgAdmin, it functions properly. However, when I try running it in the models, it fails. This has happened with two additional models now. In pgAdmin, the query took 14 minutes to run, but on the metabase model, it fails due to a 10-minute timeout.