Elastic search failing on clean k3d install #20
Description
I am performing a clean install under k3d v5.2.2 (with k3s v1.21.7-k3s1). Everything seems to deploy fine: I can open the main page fine:
However, the Organisations page shows the following error:
After setting up an admin user and digging a little more, I found that I cannot select a Country when attempting to create a data set, and then I cannot select an Organization, so I cannot complete a data set upload either.
Digging into the k8s logs I see the following when anything that needs the search-api:
kubectl -n magda logs deployment/search-api
03:06:16,229 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
03:06:16,229 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
03:06:16,229 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/app/lib/au.csiro.data61.magda-search-api-0.0.59.jar!/logback.xml]
03:06:16,230 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath.
03:06:16,230 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [jar:file:/app/lib/au.csiro.data61.magda-search-api-0.0.59.jar!/logback.xml]
03:06:16,230 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [jar:file:/app/lib/au.csiro.data61.magda-scala-common-0.0.59.jar!/logback.xml]
03:06:16,242 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@5adb0db3 - URL [jar:file:/app/lib/au.csiro.data61.magda-search-api-0.0.59.jar!/logback.xml] is not of type file
03:06:16,416 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
03:06:16,417 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
03:06:16,423 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
03:06:16,455 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
03:06:16,457 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ASYNC]
03:06:16,457 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to ch.qos.logback.classic.AsyncAppender[ASYNC]
03:06:16,457 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Attaching appender named [STDOUT] to AsyncAppender.
03:06:16,457 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Setting discardingThreshold to 51
03:06:16,458 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [ch.qos.logback] to ERROR
03:06:16,458 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.sksamuel] to ERROR
03:06:16,458 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
03:06:16,458 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ASYNC] to Logger[ROOT]
03:06:16,458 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
03:06:16,459 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@3f270e0a - Registering current configuration as safe fallback point
[INFO] [01/08/2022 03:06:16.462] [main] [MagdaApp$(akka://search-api)] Starting Search API on port 80
[INFO] [01/08/2022 03:06:16.498] [search-api-akka.actor.default-dispatcher-6] [akka.actor.ActorSystemImpl(search-api)] Elastic Client server Url: elasticsearch://elasticsearch:9200?cluster.name=myesdb
[INFO] [01/08/2022 03:06:16.499] [search-api-akka.actor.default-dispatcher-6] [akka.actor.ActorSystemImpl(search-api)] Elastic Client maxRetryTimeout: 30000
[INFO] [01/08/2022 03:06:16.525] [search-api-akka.actor.default-dispatcher-6] [akka.actor.ActorSystemImpl(search-api)] Elastic Client connectTimeout: 30000
[INFO] [01/08/2022 03:06:16.525] [search-api-akka.actor.default-dispatcher-6] [akka.actor.ActorSystemImpl(search-api)] Elastic Client socketTimeout: 30000
[INFO] [01/08/2022 03:06:17.206] [search-api-akka.actor.default-dispatcher-6] [akka.actor.ActorSystemImpl(search-api)] Successfully made initial contact with the ES client (this doesn't mean we're fully connected yet!)
[ERROR] [01/08/2022 20:04:07.105] [search-api-akka.actor.default-dispatcher-27] [akka.actor.ActorSystemImpl(search-api)] Exception when searching
au.csiro.data61.magda.search.elasticsearch.Exceptions.ESException: search_phase_execution_exception: all shards failed
at au.csiro.data61.magda.search.elasticsearch.Exceptions.ESGenericException$.unapply(Exceptions.scala:109)
at au.csiro.data61.magda.search.elasticsearch.ElasticSearchQueryer.$anonfun$searchOrganisations$3(ElasticSearchQueryer.scala:963)
at scala.concurrent.Future.$anonfun$flatMap$1(Future.scala:307)
at scala.concurrent.impl.Promise.$anonfun$transformWith$1(Promise.scala:41)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)
at akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:92)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:85)
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:92)
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:41)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:49)
at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
The logs for the ES stateful set show something as well that's similar but not the same error:
kubectl -n magda logs statefulset/es-data
[2022-01-08T20:04:07,101][WARN ][r.suppressed ] [r1lL6eJ] path: /datasets46/_search, params: {index=datasets46}
org.elasticsearch.action.search.SearchPhaseExecutionException: all shards failed
at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseFailure(AbstractSearchAsyncAction.java:293) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:133) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseDone(AbstractSearchAsyncAction.java:254) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase.onShardFailure(InitialSearchPhase.java:101) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase.access$100(InitialSearchPhase.java:48) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase$2.lambda$onFailure$1(InitialSearchPhase.java:222) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase.maybeFork(InitialSearchPhase.java:176) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase.access$000(InitialSearchPhase.java:48) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.InitialSearchPhase$2.onFailure(InitialSearchPhase.java:222) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.SearchExecutionStatsCollector.onFailure(SearchExecutionStatsCollector.java:73) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.ActionListenerResponseHandler.handleException(ActionListenerResponseHandler.java:51) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.search.SearchTransportService$ConnectionCountingHandler.handleException(SearchTransportService.java:464) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.handleException(TransportService.java:1130) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.transport.TransportService$DirectResponseChannel.processException(TransportService.java:1247) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.transport.TransportService$DirectResponseChannel.sendResponse(TransportService.java:1221) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.transport.TaskTransportChannel.sendResponse(TaskTransportChannel.java:66) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.action.support.HandledTransportAction$ChannelActionListener.onFailure(HandledTransportAction.java:112) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService$2.onFailure(SearchService.java:347) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService$2.onResponse(SearchService.java:341) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService$2.onResponse(SearchService.java:335) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService$4.doRun(SearchService.java:1082) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:723) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:41) [elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-6.5.4.jar:6.5.4]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: org.elasticsearch.search.SearchContextException: no mapping found for `publisher.aggKeywords.keyword` in order to collapse on
at org.elasticsearch.search.collapse.CollapseBuilder.build(CollapseBuilder.java:234) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService.parseSource(SearchService.java:916) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService.createContext(SearchService.java:616) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService.createAndPutContext(SearchService.java:592) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:367) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService.access$100(SearchService.java:121) ~[elasticsearch-6.5.4.jar:6.5.4]
at org.elasticsearch.search.SearchService$2.onResponse(SearchService.java:339) ~[elasticsearch-6.5.4.jar:6.5.4]
... 9 more
Logs for the other components all seem fine I think, but I could have missed something since the error messages above seem vague to me.
Any ideas on what to try? It seems I am very close to getting everything working at this point...