Database has unrun migrations. Waiting for migration lock to

@sagun.garg I don’t know what the problem is with your Fargate setup. Try waiting for 20 minutes during startup.
Try the 0.38.0-preview. Give more memory and CPU as a test.

@flamber thankyou for prompt response.

Thanks tried the new Image v0.38.0-preview. It still dosen't spawn the instance at all..I have left it for 20minutes like you have advised. Also here is the initial error logs witnessed. I have given 2048 CPU Units and 8192 MB Ram for this one task

I am also passing environment variable in Docker container Task definition

JAVA_OPTS = -Dlog4j.configuration=https://log4j.us/templates/metabase?trace=metabase.sync

@sagun.garg It looks like it’s starting normally within 40 seconds.
Don’t parse any options. 0.37 uses Log4j2, which uses a different type of configuration file.

@flamber Same instance works (some how magically catches my old login: didn’t have to setup a new one like I had to on previous instance here is the log dump, also mentioning the diagnostics file at the bottom along with troubleshooting)

LOG DUMP

2020-12-15 19:10:49

11:10:49.281 [streaming-response-thread-pool-2] ERROR metabase.query-processor.middleware.catch-exceptions - Error processing query: null

2020-12-15 19:10:49

{:database_id 2,

2020-12-15 19:10:49

:started_at #t "2020-12-15T11:10:48.638213Z[GMT]",

2020-12-15 19:10:49

:error_type :invalid-query,

2020-12-15 19:10:49

:json_query {:database 2, :query {:source-table 141}, :type "query", :parameters [], :middleware {:js-int-to-string? true, :add-default-userland-constraints? true}},

2020-12-15 19:10:49

:native nil,

2020-12-15 19:10:49

:status :failed,

2020-12-15 19:10:49

:class clojure.lang.ExceptionInfo,

2020-12-15 19:10:49

:stacktrace

2020-12-15 19:10:49

["--> query_processor.middleware.add_implicit_clauses$fn__38071$sorted_implicit_fields_for_table__38076$fn__38077.invoke(add_implicit_clauses.clj:42)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$fn__38071$sorted_implicit_fields_for_table__38076.invoke(add_implicit_clauses.clj:36)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$fn__38167$add_implicit_fields__38172$fn__38176.invoke(add_implicit_clauses.clj:87)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$fn__38167$add_implicit_fields__38172.invoke(add_implicit_clauses.clj:80)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$add_implicit_mbql_clauses.invokeStatic(add_implicit_clauses.clj:124)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$add_implicit_mbql_clauses.invoke(add_implicit_clauses.clj:120)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$maybe_add_implicit_clauses.invokeStatic(add_implicit_clauses.clj:134)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$maybe_add_implicit_clauses.invoke(add_implicit_clauses.clj:131)"

2020-12-15 19:10:49

"query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__38257.invoke(add_implicit_clauses.clj:141)"

2020-12-15 19:10:49

"query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__38655.invoke(add_source_metadata.clj:105)"

2020-12-15 19:10:49

"query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__45829.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"

2020-12-15 19:10:49

"query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__42973.invoke(auto_bucket_datetimes.clj:140)"

2020-12-15 19:10:49

"query_processor.middleware.resolve_source_table$resolve_source_tables$fn__43949.invoke(resolve_source_table.clj:46)"

2020-12-15 19:10:49

"query_processor.middleware.parameters$substitute_parameters$fn__45614.invoke(parameters.clj:114)"

2020-12-15 19:10:49

"query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__44001.invoke(resolve_referenced.clj:80)"

2020-12-15 19:10:49

"query_processor.middleware.expand_macros$expand_macros$fn__44620.invoke(expand_macros.clj:158)"

2020-12-15 19:10:32

"async.streaming_response$do_f_STAR_.invoke(streaming_response.clj:64)"

2020-12-15 19:10:32

"async.streaming_response$do_f_async$fn__24637.invoke(streaming_response.clj:85)"],

2020-12-15 19:10:32

:context :ad-hoc,

2020-12-15 19:10:32

:error "No fields found for table \"vessel_schedule_predictions\".",

2020-12-15 19:10:32

:row_count 0,

2020-12-15 19:10:32

:running_time 0,

2020-12-15 19:10:32

:preprocessed nil,

2020-12-15 19:10:32

:ex-data {:table-id 99, :type :invalid-query},

2020-12-15 19:10:32

:data {:rows [], :cols []}}

2020-12-15 19:10:32

11:10:32.489 [streaming-response-thread-pool-1] ERROR metabase.query-processor.middleware.catch-exceptions - Error processing query: null

2020-12-15 19:10:32

{:database_id 2,

2020-12-15 19:10:32

:started_at #t "2020-12-15T11:10:31.490896Z[GMT]",

2020-12-15 19:10:32

:error_type :invalid-query,

2020-12-15 19:10:32

:json_query {:database 2, :query {:source-table 99}, :type "query", :parameters [], :middleware {:js-int-to-string? true, :add-default-userland-constraints? true}},

2020-12-15 19:10:32

:native nil,

2020-12-15 19:10:32

:status :failed,

2020-12-15 19:10:32

:class clojure.lang.ExceptionInfo,

2020-12-15 19:10:32

:stacktrace

2020-12-15 19:10:32

["--> query_processor.middleware.add_implicit_clauses$fn__38071$sorted_implicit_fields_for_table__38076$fn__38077.invoke(add_implicit_clauses.clj:42)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$fn__38071$sorted_implicit_fields_for_table__38076.invoke(add_implicit_clauses.clj:36)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$fn__38167$add_implicit_fields__38172$fn__38176.invoke(add_implicit_clauses.clj:87)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$fn__38167$add_implicit_fields__38172.invoke(add_implicit_clauses.clj:80)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$add_implicit_mbql_clauses.invokeStatic(add_implicit_clauses.clj:124)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$add_implicit_mbql_clauses.invoke(add_implicit_clauses.clj:120)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$maybe_add_implicit_clauses.invokeStatic(add_implicit_clauses.clj:134)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$maybe_add_implicit_clauses.invoke(add_implicit_clauses.clj:131)"

2020-12-15 19:10:32

"query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__38257.invoke(add_implicit_clauses.clj:141)"

2020-12-15 19:10:32

"query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__38655.invoke(add_source_metadata.clj:105)"

2020-12-15 19:10:32

"query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__45829.invoke(reconcile_breakout_and_order_by_bucketing.clj:98)"

2020-12-15 19:10:32

"query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__42973.invoke(auto_bucket_datetimes.clj:140)"

2020-12-15 19:10:32

"query_processor.middleware.resolve_source_table$resolve_source_tables$fn__43949.invoke(resolve_source_table.clj:46)"

2020-12-15 19:10:32

"query_processor.middleware.parameters$substitute_parameters$fn__45614.invoke(parameters.clj:114)"

2020-12-15 19:10:32

"query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__44001.invoke(resolve_referenced.clj:80)"

2020-12-15 19:10:32

"query_processor.middleware.expand_macros$expand_macros$fn__44620.invoke(expand_macros.clj:158)"

2020-12-15 19:10:32

"query_processor.middleware.add_timezone_info$add_timezone_info$fn__38686.invoke(add_timezone_info.clj:15)"

2020-12-15 19:10:32

"query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__46550.invoke(splice_params_in_response.clj:32)"

2020-12-15 19:10:32

"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__45840$fn__45844.invoke(resolve_database_and_driver.clj:33)"

2020-12-15 19:10:32

"driver$do_with_driver.invokeStatic(driver.clj:61)"

2020-12-15 19:10:32

"driver$do_with_driver.invoke(driver.clj:57)"

2020-12-15 19:10:32

"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__45840.invoke(resolve_database_and_driver.clj:27)"

2020-12-15 19:10:32

"query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__44838.invoke(fetch_source_query.clj:267)"

2020-12-15 19:10:32

"query_processor.middleware.store$initialize_store$fn__46559$fn__46560.invoke(store.clj:11)"

2020-12-15 19:10:32

"query_processor.store$do_with_store.invokeStatic(store.clj:46)"

2020-12-15 19:10:32

"query_processor.store$do_with_store.invoke(store.clj:40)"

2020-12-15 19:10:32

"query_processor.middleware.store$initialize_store$fn__46559.invoke(store.clj:10)"

2020-12-15 19:10:32

"query_processor.middleware.cache$maybe_return_cached_results$fn__43878.invoke(cache.clj:214)"

2020-12-15 19:10:32

"query_processor.middleware.validate$validate_query$fn__46568.invoke(validate.clj:10)"

2020-12-15 19:10:32

"query_processor.middleware.normalize_query$normalize$fn__44962.invoke(normalize_query.clj:22)"

2020-12-15 19:10:32

"query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__38524.invoke(add_rows_truncated.clj:36)"

2020-12-15 19:10:32

"query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__46535.invoke(results_metadata.clj:147)"

2020-12-15 19:10:32

"query_processor.middleware.constraints$add_default_userland_constraints$fn__44241.invoke(constraints.clj:42)"

2020-12-15 19:10:32

"query_processor.middleware.process_userland_query$process_userland_query$fn__45703.invoke(process_userland_query.clj:136)"

2020-12-15 19:10:32

"query_processor.middleware.catch_exceptions$catch_exceptions$fn__44184.invoke(catch_exceptions.clj:174)"

2020-12-15 19:10:32

"query_processor.reducible$async_qp$qp_STAR___37313$thunk__37314.invoke(reducible.clj:103)"

2020-12-15 19:10:32

"query_processor.reducible$async_qp$qp_STAR___37313.invoke(reducible.clj:109)"

2020-12-15 19:10:32

"query_processor.reducible$sync_qp$qp_STAR___37322$fn__37325.invoke(reducible.clj:135)"

2020-12-15 19:10:32

"query_processor.reducible$sync_qp$qp_STAR___37322.invoke(reducible.clj:134)"

2020-12-15 19:10:32

"query_processor$process_userland_query.invokeStatic(query_processor.clj:237)"

2020-12-15 19:10:32

"query_processor$process_userland_query.doInvoke(query_processor.clj:233)"

2020-12-15 19:10:32

"query_processor$fn__46726$process_query_and_save_execution_BANG___46735$fn__46738.invoke(query_processor.clj:249)"

2020-12-15 19:10:32

"query_processor$fn__46726$process_query_and_save_execution_BANG___46735.invoke(query_processor.clj:241)"

2020-12-15 19:10:32

"query_processor$fn__46770$process_query_and_save_with_max_results_constraints_BANG___46779$fn__46782.invoke(query_processor.clj:261)"

2020-12-15 19:10:32

"query_processor$fn__46770$process_query_and_save_with_max_results_constraints_BANG___46779.invoke(query_processor.clj:254)"

2020-12-15 19:10:32

"api.dataset$fn__47916$fn__47919.invoke(dataset.clj:59)"

2020-12-15 19:10:32

"query_processor.streaming$streaming_response_STAR_$fn__47897$fn__47898.invoke(streaming.clj:73)"

2020-12-15 19:10:32

"query_processor.streaming$streaming_response_STAR_$fn__47897.invoke(streaming.clj:72)"

2020-12-15 19:10:32

"async.streaming_response$do_f_STAR_.invokeStatic(streaming_response.clj:66)"

2020-12-15 18:50:54

e[32mDatabase setup took 5.4 se[0m

2020-12-15 18:50:48

e[32mLoad driver :postgres took 414.5 mse[0m

2020-12-15 18:50:48

e[32mLoad driver :sql-jdbc took 180.4 mse[0m

2020-12-15 18:50:48

e[32mLoad driver :sql took 168.5 mse[0m

2020-12-15 18:50:36

ERROR StatusLogger Reconfiguration failed: No configuration found for '8ff5094' at 'null' in 'null'

2020-12-15 18:50:19

ERROR StatusLogger Reconfiguration failed: No configuration found for 'Default' at 'null' in 'null'

2020-12-15 18:50:17

WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.

2020-12-15 18:50:17

Warning: environ value jdk-11.0.7+10 for key :java-version has been overwritten with 11.0.7 

Diagnostics file

{
  "browser-info": {
    "language": "en-GB",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.7+10",
    "java.vendor": "AdoptOpenJDK",
    "java.vendor.url": "https://adoptopenjdk.net/",
    "java.version": "11.0.7",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.7+10",
    "os.name": "Linux",
    "os.version": "4.14.193-149.317.amzn2.x86_64",
    "user.language": "en",
    "user.timezone": "GMT"
  },
  "metabase-info": {
    "databases": [
      "postgres",
      "h2"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "12.4"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.2.8"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2020-12-08",
      "tag": "v0.38.0-preview",
      "branch": "master",
      "hash": "ae50a80"
    },
    "settings": {
      "report-timezone": null
    }
  }
}

Logs from troubleshooting

@flamber I am giving it some time, as seems to be processing some data for logs and is giving a new error on the UI

Which probably means it is importing the data schema and the data I guess (the whole scan + sync game)

@sagun.garg I don’t understand how anyone can work with a reversed log, but I cannot read it.
But you are still starting with Log4j1 configuration on a 0.37+ instance, so most of the log information is not shown.
You have to manually start the sync+scan process, since you have bad sync data - Admin > Databases.

@flamber :money_mouth_face: :money_mouth_face: :heart_eyes: :heart_eyes: :money_mouth_face: guess what I hit the jackpot finally. “I see tables”, “I see data” and now begins my journey.

God Bless You Man…you have been super supportive to get this bootstrapped in last one week. But yes it took me a week to get it up and running. Thanks a ton at-least now I can evaluate this :slight_smile:

Diagnostic File WORKS on AWS Fargate 8Gb, 2048 CPU Units with PostgreSQL DB 12.4
Image Version: metabase/metabase:v0.38.0-preview

{
  "browser-info": {
    "language": "en-GB",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36",
    "vendor": "Google Inc."
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.7+10",
    "java.vendor": "AdoptOpenJDK",
    "java.vendor.url": "https://adoptopenjdk.net/",
    "java.version": "11.0.7",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.7+10",
    "os.name": "Linux",
    "os.version": "4.14.193-149.317.amzn2.x86_64",
    "user.language": "en",
    "user.timezone": "GMT"
  },
  "metabase-info": {
    "databases": [
      "postgres",
      "h2"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "12.4"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.2.8"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2020-12-08",
      "tag": "v0.38.0-preview",
      "branch": "master",
      "hash": "ae50a80"
    },
    "settings": {
      "report-timezone": null
    }
  }
}
1 Like

@sagun.garg Congrats! How did you make sure that Metabase utilizes all the 8Gb of provided memory and uses all the provided CPU cores?

@tovbinm When Metabase starts, it tells you how much RAM the Java process can consume in one of the first lines in the log.
Otherwise you can specify that manually: https://www.metabase.com/docs/latest/troubleshooting-guide/running.html
As for CPU, the Java process uses all available cores. Affinity is controlled by the OS.