Hello everyone, After upgrading my development ins...
# troubleshoot
g
Hello everyone, After upgrading my development instance of DataHub to version 0.9.5, I started to receive errors in my GMS instance that I wasn't receiving before. Examples bellow: 1.
ERROR c.l.m.s.e.query.ESSearchDAO:72 - Search query failed
java.lang.RuntimeException: error while performing request
...
Caused by: java.util.concurrent.TimeoutException: Connection lease request time out
2.
ERROR c.l.d.g.r.r.ListRecommendationsResolver:66 - Failed to get recommendations for input com.linkedin.datahub.graphql.generated.ListRecommendationsInput@361dc5ce
java.lang.RuntimeException: error while performing request
...
Caused by: java.util.concurrent.TimeoutException: Connection lease request time out
3.
[ThreadPoolTaskExecutor-1] INFO c.l.m.k.t.DataHubUsageEventTransformer:74 - Invalid event type: HomePageViewEvent
140700.296 [ThreadPoolTaskExecutor-1] WARN c.l.m.k.DataHubUsageEventsProcessor:56 - Failed to apply usage events transform to record: {"type":"HomePageViewEvent","actorUrn":"urnlicorpuser:patrick.braz","timestamp":1672236418541,"date":"Wed Dec 28 2022 110658 GMT-0300 (Horário Padrão de Brasília)","userAgent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36","browserId":"a449948d-c76e-4545-8bf1-6aac1047583d"}
Could anyone please help me understandd why?
✅ 1
Details about deployment: Using: Helm (I developed my own Helm chart based on the community chart) Deployed: GKE (kubernetes version 1.21) Extra dependencies: • MySQL version 8.0 hosted on Google Cloud SQL ( no problems ) • Elasticsearch ( 3 nodes with 1 master node ) version 7.17.3 ( no problems ) • Kafka (2 nodes) version 3.2.0 ( no problems )
b
1. The first error is a timeout to elasticsearch from GMS, I’d check network connectivity between the pod and ES. 2. This is likely a side effect of #1 3. This is a warning and indicates that some usage event is not being tracked, can be ignored for now.
If not network connectivity then check the elasticsearch environment variables in the GMS pod to make sure they are set to values you expect.
g
Thanks @brainy-tent-14503. I'm looking at metadata service configurations, and I found distinct values on my Helm charts that could cause some problems. Example: In this configuration I was passing the following value: "/datahub/datahub-gms/resources/entity-registry.yml"
I'm updating and verifying everything before testing the connections in the Kubernetes environment.
@brainy-tent-14503 If this is an issue, It will also need to update the community graph: https://github.com/acryldata/datahub-helm/blob/master/charts/datahub/subcharts/datahub-gms/templates/deployment.yaml#L93
Caused by:
java.io.FileNotFoundException: ../../metadata-models/src/main/resources/entity-registry.yml (No such file or directory)
🤔
b
GMS should have
/datahub/datahub-gms/resources/entity-registry.yml
for the entity registry yml. If this was causing an issue there would be a spring bean initialization error. This file is part of the GMS image and is added to the image in this dockerfile.
The relative path only works for unit tests and that is why its a default.
g
My question is, why in a previous version (0.9.3) can GMS connect to Elasticsearch, and in this version is it having problems? (I downgraded to test) It doesn't make much sense to me. Impossible for me to migrate the production environment to version 0.9.5.
No problems with Services communication
175208.445 [Thread-625] ERROR c.l.d.g.r.s.SearchAcrossEntitiesResolver:84 - Failed to execute search for multiple entities: entity types [], query order, filters: [], start: 0, count: 10
175208.446 [Thread-625] ERROR c.l.d.g.e.DataHubDataFetcherExceptionHandler:21 - Failed to execute DataFetcher
java.util.concurrent.CompletionException: java.lang.RuntimeException: Failed to execute search: entity types [], query order, filters: [], start: 0, count: 10
at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1702)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.RuntimeException: Failed to execute search: entity types [], query order, filters: [], start: 0, count: 10
at com.linkedin.datahub.graphql.resolvers.search.SearchAcrossEntitiesResolver.lambda$get$0(SearchAcrossEntitiesResolver.java:88)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
... 1 common frames omitted
Caused by: java.util.concurrent.CompletionException: com.datahub.util.exception.ESQueryException: Search query failed:
at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1702)
... 1 common frames omitted
Caused by: com.datahub.util.exception.ESQueryException: Search query failed:
at com.linkedin.metadata.search.elasticsearch.query.ESSearchDAO.executeAndExtract(ESSearchDAO.java:73)
at com.linkedin.metadata.search.elasticsearch.query.ESSearchDAO.search(ESSearchDAO.java:100)
at com.linkedin.metadata.search.elasticsearch.ElasticSearchService.search(ElasticSearchService.java:97)
at com.linkedin.metadata.search.client.CachingEntitySearchService.getRawSearchResults(CachingEntitySearchService.java:196)
at com.linkedin.metadata.search.client.CachingEntitySearchService.lambda$getCachedSearchResults$0(CachingEntitySearchService.java:117)
at com.linkedin.metadata.search.cache.CacheableSearcher.getBatch(CacheableSearcher.java:97)
at com.linkedin.metadata.search.cache.CacheableSearcher.getSearchResults(CacheableSearcher.java:55)
at com.linkedin.metadata.search.client.CachingEntitySearchService.getCachedSearchResults(CachingEntitySearchService.java:118)
at com.linkedin.metadata.search.client.CachingEntitySearchService.search(CachingEntitySearchService.java:54)
at com.linkedin.metadata.search.aggregator.AllEntitiesSearchAggregator.lambda$getSearchResultsForEachEntity$2(AllEntitiesSearchAggregator.java:161)
at com.linkedin.metadata.utils.ConcurrencyUtils.lambda$transformAndCollectAsync$0(ConcurrencyUtils.java:24)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
... 1 common frames omitted
Caused by: java.lang.RuntimeException: error while performing request
at org.elasticsearch.client.RestClient.extractAndWrapCause(RestClient.java:859)
at org.elasticsearch.client.RestClient.performRequest(RestClient.java:259)
at org.elasticsearch.client.RestClient.performRequest(RestClient.java:246)
at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1613)
at org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:1583)
at org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:1553)
at org.elasticsearch.client.RestHighLevelClient.search(RestHighLevelClient.java:1069)
at com.linkedin.metadata.search.elasticsearch.query.ESSearchDAO.executeAndExtract(ESSearchDAO.java:60)
... 12 common frames omitted
Caused by: java.util.concurrent.TimeoutException: Connection lease request time out
175206.941 [Thread-606] ERROR c.l.d.g.r.search.AutocompleteUtils:48 - Failed to execute autocomplete all: field null, query order, filters: null, limit: 10 Auto complete query failed:
175206.940 [Thread-609] ERROR c.l.m.s.e.query.ESSearchDAO:144 - Auto complete query failed:error while performing request
175206.941 [Thread-612] ERROR c.l.m.s.e.query.ESSearchDAO:144 - Auto complete query failed:error while performing request
175208.049 [pool-13-thread-1] INFO c.l.m.filter.RestliLoggingFilter:55 - GET /entitiesV2?ids=List(urn%3Ali%3Acorpuser%3Apatrick.braz) - batchGet - 200 - 5ms
175208.441 [Thread-653] ERROR c.l.m.s.e.query.ESSearchDAO:72 - Search query failed
java.lang.RuntimeException: error while performing request
If I downgrade to version 0.9.3, these issues go away.
b
Something with the query here must be timing out, not due to networking, perhaps a poorly performing query. I am not sure what changes there are in the search query path between 0.9.3 and 0.9.4-5 but it must be some regression there.
I haven’t seen this locally, in our staging or demo environments which are running 0.9.5. The sizes of the indices are not large….
g
Could you send me the environment variables of GMS and the standalone consumers?
b
GMS with standalone consumers:
Copy code
PE_CONSUMER_ENABLED=true
EBEAN_DATASOURCE_DRIVER=com.mysql.jdbc.Driver
ENTITY_REGISTRY_CONFIG_PATH=/datahub/datahub-gms/resources/entity-registry.yml
HOME=/home/datahub
KAFKA_SCHEMAREGISTRY_URL=<http://schema-registry:8081>
DATAHUB_TELEMETRY_ENABLED=true
GRAPH_SERVICE_DIFF_MODE_ENABLED=true
JMX_OPTS=
EBEAN_DATASOURCE_PASSWORD=datahub
MAE_CONSUMER_ENABLED=true
ELASTICSEARCH_HOST=elasticsearch
EBEAN_DATASOURCE_HOST=mysql:3306
MCE_CONSUMER_ENABLED=true
EBEAN_DATASOURCE_URL=jdbc:<mysql://mysql:3306/datahub?verifyServerCertificate=false&useSSL=true&useUnicode=yes&characterEncoding=UTF-8>
ELASTICSEARCH_PORT=9200
JAVA_OPTS=-Xms1g -Xmx1g
ES_BULK_REFRESH_POLICY=WAIT_UNTIL
DOCKERIZE_VERSION=v0.6.1
KAFKA_BOOTSTRAP_SERVER=broker:29092
EBEAN_DATASOURCE_USERNAME=datahub
GRAPH_SERVICE_IMPL=elasticsearch
Let me get GMS with standalone consumers …
With standalone
Copy code
PE_CONSUMER_ENABLED=true
EBEAN_DATASOURCE_DRIVER=com.mysql.jdbc.Driver
ENTITY_REGISTRY_CONFIG_PATH=/datahub/datahub-gms/resources/entity-registry.yml
DATAHUB_SERVER_TYPE=quickstart
KAFKA_SCHEMAREGISTRY_URL=<http://schema-registry:8081>
DATAHUB_TELEMETRY_ENABLED=true
GRAPH_SERVICE_DIFF_MODE_ENABLED=true
JMX_OPTS=
EBEAN_DATASOURCE_PASSWORD=datahub
MAE_CONSUMER_ENABLED=false
EBEAN_DATASOURCE_HOST=mysql:3306
ELASTICSEARCH_HOST=elasticsearch
MCE_CONSUMER_ENABLED=false
EBEAN_DATASOURCE_URL=jdbc:<mysql://mysql:3306/datahub?verifyServerCertificate=false&useSSL=true&useUnicode=yes&characterEncoding=UTF-8>
ELASTICSEARCH_PORT=9200
JAVA_OPTS=-Xms1g -Xmx1g
ES_BULK_REFRESH_POLICY=WAIT_UNTIL
DOCKERIZE_VERSION=v0.6.1
KAFKA_BOOTSTRAP_SERVER=broker:29092
EBEAN_DATASOURCE_USERNAME=datahub
GRAPH_SERVICE_IMPL=elasticsearch
MCE Consumer
Copy code
PE_CONSUMER_ENABLED=false
UI_INGESTION_ENABLED=false
ENTITY_REGISTRY_CONFIG_PATH=/datahub/datahub-mce-consumer/resources/entity-registry.yml
EBEAN_DATASOURCE_DRIVER=com.mysql.jdbc.Driver
DATAHUB_SERVER_TYPE=quickstart
ENTITY_SERVICE_ENABLE_RETENTION=true
KAFKA_SCHEMAREGISTRY_URL=<http://schema-registry:8081>
DATAHUB_TELEMETRY_ENABLED=true
GRAPH_SERVICE_DIFF_MODE_ENABLED=true
JMX_OPTS=
EBEAN_DATASOURCE_PASSWORD=datahub
MAE_CONSUMER_ENABLED=false
EBEAN_DATASOURCE_HOST=mysql:3306
ELASTICSEARCH_HOST=elasticsearch
MCE_CONSUMER_ENABLED=true
EBEAN_DATASOURCE_URL=jdbc:<mysql://mysql:3306/datahub?verifyServerCertificate=false&useSSL=true&useUnicode=yes&characterEncoding=UTF-8>
ELASTICSEARCH_PORT=9200
JAVA_OPTS=-Xms1g -Xmx1g
ES_BULK_REFRESH_POLICY=WAIT_UNTIL
DATAHUB_SYSTEM_CLIENT_ID=__datahub_system
DOCKERIZE_VERSION=v0.6.1
KAFKA_BOOTSTRAP_SERVER=broker:29092
DATAHUB_SYSTEM_CLIENT_SECRET=xxx
EBEAN_DATASOURCE_USERNAME=datahub
GRAPH_SERVICE_IMPL=elasticsearch
MAE Consumer
Copy code
PE_CONSUMER_ENABLED=true
ENTITY_REGISTRY_CONFIG_PATH=/datahub/datahub-mae-consumer/resources/entity-registry.yml
KAFKA_SCHEMAREGISTRY_URL=<http://schema-registry:8081>
JMX_OPTS=
MAE_CONSUMER_ENABLED=true
ELASTICSEARCH_HOST=elasticsearch
ELASTICSEARCH_PORT=9200
JAVA_OPTS=
ES_BULK_REFRESH_POLICY=WAIT_UNTIL
DOCKERIZE_VERSION=v0.6.1
KAFKA_BOOTSTRAP_SERVER=broker:29092
DATAHUB_GMS_HOST=datahub-gms
GRAPH_SERVICE_IMPL=elasticsearch
DATAHUB_GMS_PORT=8080
g
Thanks!
I'll compare with my env
@brainy-tent-14503 I checked here, and everything is correct. There's nothing really different. Can I pass you my GMS environment variables (without standalone consumers) for you to check?
kubectl describe pod returns:
Copy code
Containers:
  datahub-gms:
    Image:          acryldata/datahub-gms:v0.9.5
    Image ID:       <http://docker.io/acryldata/datahub-gms@sha256:70b0af560ffd8ce6782449e596f01908abb3f07afeeae5acfb6b0af64c109a67|docker.io/acryldata/datahub-gms@sha256:70b0af560ffd8ce6782449e596f01908abb3f07afeeae5acfb6b0af64c109a67>
    Ports:          8080/TCP, 4318/TCP
    Host Ports:     0/TCP, 0/TCP
    State:          Running
      Started:      Thu, 29 Dec 2022 10:40:52 -0300
    Ready:          True
    Restart Count:  0
    Limits:
      cpu:     500m
      memory:  2Gi
    Requests:
      cpu:      100m
      memory:   2Gi
    Liveness:   http-get http://:gms-port/health delay=60s timeout=1s period=30s #success=1 #failure=8
    Readiness:  http-get http://:gms-port/health delay=60s timeout=1s period=30s #success=1 #failure=8
    Environment:
      LINEAGE_SEARCH_CACHE_ENABLED:                          true
      ENABLE_ENTITY_CHANGE_EVENTS_HOOK:                      true
      VIEWS_ENABLED:                                         true
      ENTITY_CLIENT_RETRY_INTERVAL:                          2
      ENTITY_CLIENT_NUM_RETRIES:                             5
      USAGE_CLIENT_RETRY_INTERVAL:                           2
      USAGE_CLIENT_NUM_RETRIES:                              5
      UPGRADE_DEFAULT_BROWSE_PATHS_ENABLED:                  true
      METADATA_TESTS_ENABLED:                                true
      REACT_APP_FAVICON_URL:                                 -----
      AUTH_POLICIES_ENABLED:                                 true
      POLICY_CACHE_REFRESH_INTERVAL_SECONDS:                 120
      ENABLE_SIBLING_HOOK:                                   true
      SHOW_SIMPLIFIED_HOMEPAGE_BY_DEFAULT:                   false
      GRAPH_SERVICE_DIFF_MODE_ENABLED:                       true
      ENABLE_PROMETHEUS:                                     true
      ENABLE_OTEL:                                           true
      OTEL_METRICS_EXPORTER:                                 none
      OTEL_TRACES_EXPORTER:                                  prometheus
      OTEL_EXPORTER_PROMETHEUS_PORT:                         4318
      OTEL_SERVICE_NAME:                                     datahub-dev-gms
      MCE_CONSUMER_ENABLED:                                  true
      MAE_CONSUMER_ENABLED:                                  true
      PE_CONSUMER_ENABLED:                                   true
      ENTITY_REGISTRY_CONFIG_PATH:                           /datahub/datahub-gms/resources/entity-registry.yml
      ENTITY_REGISTRY_CONFIG_CLASSPATH:                      classpath:/entity-registry.yml
      DATAHUB_ANALYTICS_ENABLED:                             true
      ANALYTICS_ENABLED:                                     true
      EBEAN_DATASOURCE_USERNAME:                             datahub-dev
      CLI_TELEMETRY_ENABLED:                                 true
      INGESTION_REPORTING_ENABLED:                           false
      ENABLE_THIRD_PARTY_LOGGING:                            false
      DATAHUB_TELEMETRY_ENABLED:                             true
      JAVA_OPTS:                                             -Xms1g -Xmx1g
      SEARCH_SERVICE_BATCH_SIZE:                             200
      SEARCH_SERVICE_ENABLE_CACHE:                           true
      EBEAN_WAIT_TIMEOUT_MILLIS:                             60000
      EBEAN_MAX_CONNECTIONS:                                 100
      EBEAN_MIN_CONNECTIONS:                                 10
      maxInactiveTimeSeconds:                                3600
      EBEAN_MAX_AGE_MINUTES:                                 360
      EBEAN_LEAK_TIME_MINUTES:                               120
      ELASTICSEARCH_THREAD_COUNT:                            2
      ES_BULK_ASYNC:                                         true
      ELASTICSEARCH_CONNECTION_REQUEST_TIMEOUT:              30
      ES_BULK_REQUESTS_LIMIT:                                1000
      ES_BULK_FLUSH_PERIOD:                                  2
      ES_BULK_NUM_RETRIES:                                   5
      ES_BULK_RETRY_INTERVAL:                                5
      ELASTICSEARCH_INDEX_BUILDER_REFRESH_INTERVAL_SECONDS:  1
      ELASTICSEARCH_INDEX_BUILDER_SETTINGS_REINDEX:          false
      EBEAN_DATASOURCE_PASSWORD:                             -----
      FAILED_METADATA_CHANGE_PROPOSAL_TOPIC_NAME:            FailedMetadataChangeProposal_v1
      METADATA_CHANGE_PROPOSAL_TOPIC_NAME:                   MetadataChangeProposal_v1
      METADATA_AUDIT_EVENT_NAME:                             MetadataAuditEvent_v4
      METADATA_CHANGE_EVENT_NAME:                            MetadataChangeEvent_v4
      FAILED_METADATA_CHANGE_EVENT_NAME:                     FailedMetadataChangeEvent_v4
      METADATA_CHANGE_LOG_VERSIONED_TOPIC_NAME:              MetadataChangeLog_Versioned_v1
      METADATA_CHANGE_LOG_TIMESERIES_TOPIC_NAME:             MetadataChangeLog_Timeseries_v1
      DATAHUB_USAGE_EVENT_NAME:                              DataHubUsageEvent_v1
      DATAHUB_TRACKING_TOPIC:                                DataHubUsageEvent_v1
      EBEAN_DATASOURCE_HOST:                                 -----:3306
      EBEAN_DATASOURCE_URL:                                  jdbc:<mysql://----->-?verifyServerCertificate=false&useSSL=true&useUnicode=yes&characterEncoding=UTF-8
      EBEAN_DATASOURCE_DRIVER:                               com.mysql.jdbc.Driver
      DATASET_ENABLE_SCSI:                                   false
      KAFKA_BOOTSTRAP_SERVER:                                datahub-dev-kafka:9092
      KAFKA_LISTENER_CONCURRENCY:                            1
      KAFKA_PRODUCER_RETRY_COUNT:                            3
      KAFKA_PRODUCER_DELIVERY_TIMEOUT:                       30000
      KAFKA_PRODUCER_REQUEST_TIMEOUT:                        3000
      KAFKA_PRODUCER_BACKOFF_TIMEOUT:                        500
      KAFKA_SCHEMAREGISTRY_URL:                              <http://datahub-dev-cp-schema-registry:8081>
      SCHEMA_REGISTRY_TYPE:                                  KAFKA
      ELASTICSEARCH_HOST:                                    datahub-dev-elasticsearch-master
      HOME:                                                  /home/datahub
      ELASTICSEARCH_PORT:                                    9200
      ELASTICSEARCH_USE_SSL:                                 false
      SKIP_ELASTICSEARCH_CHECK:                              true
      GRAPH_SERVICE_IMPL:                                    elasticsearch
      UI_INGESTION_DEFAULT_CLI_VERSION:                      0.9.5.0
      UI_INGESTION_ENABLED:                                  false
      REACT_APP_LOGO_URL:                                    -----
      DATAHUB_SERVER_TYPE:                                   dev
      PLUGIN_SECURITY_MODE:                                  RESTRICTED
      ENTITY_REGISTRY_PLUGIN_PATH:                           /etc/datahub/plugins/models
      RETENTION_PLUGIN_PATH:                                 /etc/datahub/plugins/retention
      AUTH_PLUGIN_PATH:                                      /etc/datahub/plugins/auth
      ENTITY_SERVICE_IMPL:                                   ebean
      ES_BULK_REFRESH_POLICY:                                WAIT_UNTIL
      ENTITY_SERVICE_ENABLE_RETENTION:                       true
      ENTITY_SERVICE_APPLY_RETENTION_BOOTSTRAP:              false
a
@gentle-camera-33498 is this issue still affecting you?
g
Yes!
b
@brainy-tent-14503 Since you have a bit of context, can you take another pass here?
b
Hmm, I am a little surprised to see
LINEAGE_SEARCH_CACHE_ENABLED
, this is not recommended however I doubt its related. Hopefully not running
ENABLE_OTEL
enabled all the time, there is a reported memory leak from tracing and is only enabled for relatively short debugging in non-production. However nothing that jumps out as related to a timeout per se.
g
So, I'm using this file as a reference for all possible configurations for GMS. It would be great to have detailed documentation about the configuration values and what, and why, should not be enabled in a production environment. Today, I'm just testing different configurations in development enviornment and adfter some tests, I upgrade the production environment. With you said above, i have some questions: 1. If can i only use the ENABLE_OTEL for debug purposes, how can i monitor my production environemnt? 2. Why LINEAGE_SEARCH_CACHE_ENABLED is not recomended?
b
1. It has been reported that OTEL has a memory leak when running for long periods of time. This is not our primary monitoring stack which is enabled for monitoring which uses prometheus jmx exporter. 2. Depending on the size of the graphs it can cause exceptions, although there is a PR to compress first. This feature is experimental The plan to document these as configuration options in helm. An example of the approach is here where some options are exposed with some explanation of what they control. In the case of this example there will also be documentation on the search reindexing as we rollout some search improvements, pr.
g
Hello @brainy-tent-14503 and @big-carpet-38439 I'm still having the same problem. I'll share a gif of the issue in our development environment. I tested the elasticsearch connection in GMS, and everything is well. No error logs in our elasticsearch. There is recomended resources for a production environment elasticsearch cluster? OBS: This error does not occur when i downgrade to version 0.9.3 OBS2: We can navigate through entities, but searching across all entities is not possible Resources used by elasticsearch: Request per pod: 1 vCPU and 3 Gb Limits per pod: 2 vCPU and 5 Gb Resources used by GMS: Request per pod: 0.2 vCPU and 1 Gb Limits per pod: 0.5 vCPU and 2 Gb
b
Resources seem fine. Can you share a complete unbroken stackstrace from the log? Ideally you run the curl command that the chrome debugger gives you for just the searchAcrossLineage graphql call and capture the full stack in the log for just that one call. The UI shows autocomplete returning results which means that there shouldn’t be an error in the autocomplete call like shown in one of the very first log snippets.
g
I did a few searches and extracted the logs since the last minute of the operation. Here the file: Is it what you needed?
b
Yeah, that is what I am looking for. It is very odd, it definitely appears to just be a lot of timeout errors. I also see successful writes to elasticsearch as well that would also fail if it reaches a timeout threshold.
g
I saw that I can change some elasticsearch client configurations, but I'm not able to change request timeout ou any retry strategy. It could be a networking issue (like the communication between services)?
b
Technically, yes. The issue I have is that it worked fine with the previous version, and it’s all the same infrastructure and configuration from what I know. We have never had to adjust the ES timeouts though, in any environment that I’ve seen. Which makes me doubt that we would have to adjust those timeouts here.
g
I understand. It would be incredible to enable developers to configure the elasticsearch timeouts via environment variables. With that, people can change their DataHub implementation behavior without forcing new default values for the entire platform.
So, do you have any idea of tests that I can do to give more context about this error? How can I help you? There is anything I could do?
b
Certainly would accept a PR to adjust the timeouts for elastic, I’d start debugging further by running curl requests from gms to elasticsearch for like a simple match all request against one or more of the indices. At the very least this should help to determine what the expected timeout values should be. If everything for those requests are very fast then likely, has something to do with the more complex query.
g
@brainy-tent-14503 Could it be a parsing error? There are no errors in elasticsearch to retrieve the data.
datahub CLI is failing to delete entities:
I just downgraded my development environment to 0.9.3, and everything works fine. Including deleting entities:
I'll do a detailed search for diffs between version 0.9.3 and 0.9.5 and see if I find the possible cause for this issue.
b
The first curl command is that the request is not properly quoted since the
&
character was interpreted by bash instead of passed in the query. That said it does appear to have returned data without those and while it’s not clear from the timing perspective, I assume it was fast. The next query would be to use the wildcard index batch to query all entity indices instead of just one. That would looking like
*indev_v2
which would run against all entity indices. If you happen to have 0.9.5 running again at some point this curl would be a good test across all the entity indices
g
Running curl with "*index_v2" pattern from GMS in DataHub version 0.9.6
I disabled the searchService's cache just for a test. But I'm receiving the same errors. Things that I already tested: * Disabled caches * Disabled OTEL environment variables (as you said they could cause memory leak) * Increased GMS and Frontend resources * Increased Elasticsearch resources * Increased the number of replicas (1 to 2) of all components
Things that I noted with logs: The errors happen a few milliseconds after elasticsearch's response. What I can suppose is that the elasticsearch connection and execution are ok, but seems that GMS is having problems operating in retrieved data from elasticsearch. I saw the versions' diff, but Search Service components are not changed since Aug 2022. So, I don't have more ideas of what is causing these problems.
@brainy-tent-14503 Do you have any other ideas of what I could test to bring more context?
b
When GMS starts is there any indication that the newer version would like to run
reindex
but it is disabled? I am wondering if the newer queries are incompatible with the index mappings and your error is somehow related to that.
g
I did not find these logs. So, what i did: I uninstalled the chart, deleted the es, kafka and zookeeper storages, and reinstalled the chart. Besides, I configured the ELASTICSEARCH_INDEX_BUILDER_SETTINGS_REINDEX env variable to "true". GMS started with no problem, but when I tried the first login: NOTE: I ran the restore indices job
b
So the logs attached here is with the reindex enabled? The reindex logs would be shortly after GMS startup, I don’t see them in the attached log here. I also don’t see anything related to login issues which is likely on the frontend log, not GMS logs. Feel free to send the logs in DM, especially for login/frontend.
g
I'm not having errors with the logging process, but I receive errors from GMS when frontend tries to fetch the recommendation list, entities count, etc. When I try to search, the error screen shows up on my front end with an error 500 message. I will send you my booting-up GMS logs in DM.
b
I’ve reviewed the logs and everything looks as I would expect up until the errors. I see GMS bootup and create the indices since they didn’t exist. I see ingestion activity with no errors and documents being indexed. Which all seems fine. Not until searching … can you share details on the total size of your indices. I may have based my assumptions on a smaller dataset for the elasticsearch resources. Per the earlier message doesn’t go into details about the number of data nodes and replicas. Also we didn’t dive into the java parameters for Xmx (
esJavaOpts
), in the helm chart these are configured here.
Copy code
Resources used by elasticsearch:
 Request per pod:
 1 vCPU and 3 Gb
Limits per pod:
2 vCPU and 5 Gb
g
GMS: replicas: 1 javaOpts: "-Xms1g -Xmx1g" Front: replicas: 1 javaOpts: "-Xms1g -Xmx1g" Elasticsearch: javaOpts: "-Xms3g -Xmx3g" replicas: 2 Indexes details:
datahub-dev-gms-server-6b7c8bc666-2ggtb:/$ curl http://datahub-dev-elasticsearch-master:9200/_cat/indices
green open datajobindex_v2 95qxkfvARe2He5DocbSD2w 1 1 508 3043 3.5mb 1.7mb
green open chart_chartusagestatisticsaspect_v1 vAko7TAcTmG77dh1zmTG8A 1 1 0 0 452b 226b
green open mlmodelgroupindex_v2 wQPTIbADSeGv9yV6FxB7-Q 1 1 0 0 452b 226b
green open dataflowindex_v2 vlibBqS8Rk67zfSfgtLFpg 1 1 32 155 320.4kb 163kb
green open assertionindex_v2 2F-K2oN2RK6UKYFoxz1wDg 1 1 537 1074 300.8kb 155.1kb
green open dataprocessindex_v2 I8nXCNpnTwGS9Ve-7FqZJA 1 1 0 0 452b 226b
green open globalsettingsindex_v2 2qQMJbxDT3-eOS2PyZvIbw 1 1 0 0 452b 226b
green open chartindex_v2 Upz6krtaRp6GVZVhQBJLgQ 1 1 2711 16082 9.4mb 4.7mb
green open tagindex_v2 85wbraJtSeGcAyeGubBY9g 1 1 3 2 28.7kb 17.3kb
green open dataplatforminstanceindex_v2 oRpZhtnmQ8GaGcA12l5v5Q 1 1 0 0 452b 226b
green open telemetryindex_v2 9mYWzUO1QMyanrJGGJPLnw 1 1 0 0 452b 226b
green open datajob_datahubingestionrunsummaryaspect_v1 C52mg0_cTieIe7UXvRs6wQ 1 1 0 0 452b 226b
green open dataplatformindex_v2 ov2alLqxT827M55tqSR_Sw 1 1 55 0 42.2kb 21.1kb
green open dataprocessinstanceindex_v2 eBg0JdjbTD2uREaP9t1c3g 1 1 41142 24 63.9mb 31.9mb
green open invitetokenindex_v2 2ntQEtW-QUu5jpP3RVLmKA 1 1 1 0 7.7kb 3.8kb
green open graph_service_v1 1QRE_wi7Sr2w6hcMewV4WA 1 1 57354 26 19.3mb 9.6mb
green open system_metadata_service_v1 SsWTQWh7TZ623sxk9fgiXQ 1 1 157400 3 36mb 18mb
green open dataset_operationaspect_v1 erpTMIKnR2OqRBRbEwjTdA 1 1 0 0 452b 226b
green open containerindex_v2 0ivL5x1MTyCXEVIqBYW_WA 1 1 73 303 195.1kb 99.7kb
green open schemafieldindex_v2 hXdr7ZTDSJqWpzw6EkIc0Q 1 1 0 0 452b 226b
green open domainindex_v2 seV1NCwmRKKbBUA_6jAifQ 1 1 12 11 32.3kb 19.3kb
green open notebookindex_v2 zR0q-iOJRzysJesMr3f1Mg 1 1 0 0 452b 226b
green open datahubupgradeindex_v2 kBd9nbvETr-lmfmXJ32Z_g 1 1 0 0 452b 226b
green open datahubroleindex_v2 6-GU33nOQWeffvzms-b0pw 1 1 3 0 15.5kb 7.7kb
green open glossarytermindex_v2 AuJORd-iQ4STM_2F3RPEOg 1 1 6 13 57kb 31.1kb
green open postindex_v2 3y-CpojiQnW1jcVyqgykYw 1 1 4 0 14.3kb 7.1kb
green open dataset_datasetusagestatisticsaspect_v1 8JCC6s-0SlGBRwC9Z2hZLQ 1 1 0 0 452b 226b
green open datahubsecretindex_v2 fX9Exb_0SdGjRBJj2M3VhA 1 1 0 0 452b 226b
green open dataset_datasetprofileaspect_v1 dmqUUYeMS_CnYom7W48PpQ 1 1 0 0 452b 226b
green open datahubexecutionrequestindex_v2 ISfB8RoAReOvwaWlmB3TZQ 1 1 9 8 26kb 16.4kb
green open mlmodelindex_v2 XdgGdYRVRKu7c32i3zhpWw 1 1 1 5 34.4kb 19.9kb
green open datahubpolicyindex_v2 jM6LTsIFRqiZeN69BkLB7g 1 1 14 0 75kb 37.5kb
green open corpuserindex_v2 UYHCCxraSzu92mSm05F-3A 1 1 14 40 57.2kb 30.7kb
green open datahubstepstateindex_v2 _3BmavkJQXyUX1Czvu0gSQ 1 1 0 0 452b 226b
green open .geoip_databases IbvddMU1Q8WJ8jiz-btf8Q 1 1 41 0 78.2mb 39.1mb
green open datahubviewindex_v2 KTBqpQvhR16xGKZDc3WVvA 1 1 0 0 452b 226b
green open mlmodeldeploymentindex_v2 K-5yg-niRNedMiWtdvYQRw 1 1 0 0 452b 226b
green open datajob_datahubingestioncheckpointaspect_v1 39yt1TZJRVuQoDQW6W3-_w 1 1 0 0 452b 226b
green open dashboardindex_v2 2WSO2i0GTTG3fy4KkfORjg 1 1 342 1756 1.1mb 606.2kb
green open assertion_assertionruneventaspect_v1 0JTozqarSgOe2xovNzZrNg 1 1 0 0 452b 226b
green open datasetindex_v2 PqiPd5mbSGykBXJM1KceLA 1 1 673 5012 10.9mb 5.5mb
green open mlfeatureindex_v2 mn3tTPwqQVagmvfhuOZGvQ 1 1 0 0 452b 226b
green open dashboard_dashboardusagestatisticsaspect_v1 yRdDskG6T-OPOxv2-z2cbg 1 1 0 0 452b 226b
green open glossarynodeindex_v2 t5KRnFTqRJe32KN6i6xX5A 1 1 4 5 46.8kb 27.5kb
green open datahubingestionsourceindex_v2 hig99eFDR0SB_2lLqoz9lg 1 1 1 0 11.1kb 5.5kb
green open .ds-datahub_usage_event-2023.01.23-000001 VQmLMXNWS0u3TZ3UITpiAg 1 1 22 0 207.8kb 103.9kb
green open datahubretentionindex_v2 neT6YflcS6WmMFkIWkSWvw 1 1 0 0 452b 226b
green open dataprocessinstance_dataprocessinstanceruneventaspect_v1 I-k7GX5hQ3SlrE1Hj815ww 1 1 140 0 187.7kb 93.8kb
green open datahubaccesstokenindex_v2 tL_bqdPgQPmGvIimIWn7uw 1 1 0 0 452b 226b
green open testindex_v2 scO92XNdRaOjqosBEcTP5w 1 1 1 0 13.9kb 6.9kb
green open mlfeaturetableindex_v2 V_yaIsBzRfqKDzdyQvdhrg 1 1 0 0 452b 226b
green open mlprimarykeyindex_v2 18BPNbjrQNSBMOTghKoYAA 1 1 0 0 452b 226b
green open corpgroupindex_v2 7qsQE1pSRUSheAWq6qlang 1 1 5 10 46kb 26.4kb
b
That all seems fine. I am out of ideas here, the logs just doesn’t make sense where all of a sudden it starts throwing those timeouts after previously having no apparent issues. @orange-night-91387 - another set of eyes on this search error might help.
g
I'm here to help. Anything I could do, please, tell me.
o
Hmm, can you send over the mappings/settings?
g
What mappings/settings? Do you want me to share the "kubectl describe pod" results?
o
The index mappings & settings from ElasticSearch
g
From GMS env:
```FAILED_METADATA_CHANGE_PROPOSAL_TOPIC_NAME: FailedMetadataChangeProposal_v1
METADATA_CHANGE_PROPOSAL_TOPIC_NAME: MetadataChangeProposal_v1
METADATA_AUDIT_EVENT_NAME: MetadataAuditEvent_v4
METADATA_CHANGE_EVENT_NAME: MetadataChangeEvent_v4
FAILED_METADATA_CHANGE_EVENT_NAME: FailedMetadataChangeEvent_v4
METADATA_CHANGE_LOG_VERSIONED_TOPIC_NAME: MetadataChangeLog_Versioned_v1
METADATA_CHANGE_LOG_TIMESERIES_TOPIC_NAME: MetadataChangeLog_Timeseries_v1
DATAHUB_USAGE_EVENT_NAME: DataHubUsageEvent_v1
DATAHUB_TRACKING_TOPIC: DataHubUsageEvent_v1
ELASTICSEARCH_THREAD_COUNT: 2
ELASTICSEARCH_CONNECTION_REQUEST_TIMEOUT: 60
ELASTICSEARCH_PORT: 9200
ELASTICSEARCH_USE_SSL: false```
Elasticsearch parameters in values.yaml:
# -- Elasticsearch configuration. See https://artifacthub.io/packages/helm/elastic/elasticsearch for more information
elasticsearch:
# -- Set this to false, if you want to provide your own ES instance.
enabled: true
# -- Kubernetes replica count for the StatefulSet (i.e. how many pods)
replicas: 2
minimumMasterNodes: 1
clusterName: "datahub-dev-elasticsearch"
service:
labelsHeadless:
app: datahub
labels:
app: datahub
resources:
requests:
cpu: "1000m"
memory: "3Gi"
limits:
cpu: "2000m"
memory: "6Gi"
esJavaOpts: "-Xmx3g -Xms3g"
es_mapping_request.json
Above is the result of 'curl http://datahub-dev-elasticsearch-master:9200/_mapping' (executed from GMS pod)
Do you need more information, @orange-night-91387?
o
Can you try setting these two to be the defaults?:
```ELASTICSEARCH_THREAD_COUNT: 2
ELASTICSEARCH_CONNECTION_REQUEST_TIMEOUT: 60```
You have it set to timeout after 60 milliseconds
g
Yes. I can. Let me upgrade my deployment.
same...
image.png
OBS: running version v0.9.6.1
Now with 3 replicas of ES (heap size 3Gb):
Where can I find the timeout values for elasticsearch requests? It would be incredible to change these values.
1. Increase the timeout value for the Elasticsearch request. 2. Check the health of the Elasticsearch cluster, and make sure it is running properly. (DONE) 3. Check if there is any network issue, if yes then check if firewall or proxy is causing any issue. (DONE) 4. check if there is any memory or CPU pressure on the Elasticsearch nodes. (DONE) 5. Increase the number of nodes in the Elasticsearch cluster, if necessary. (DONE) 6. check index settings for the index you are trying to query. (DONE) 7. check if there are too many shards in an index 8. check if there is any plugin causing the issue.
I'm following the steps above
I'm comparing my Helm chart with the community Helm chart to find possible issues. I'll make sure to send feedback here if I solve it.
o
The configuration changed above,
ELASTICSEARCH_CONNECTION_REQUEST_TIMEOUT
, should be controlling the lease timeout from my understanding. Setting it to 0 (the default) should result in the timeout being unlimited so it's definitely puzzling how you get the same error 🤔
g
I'm sorry @brainy-tent-14503 and @orange-night-91387. I think it was my fault. I manage our Helm chart, but it hasn't been updated since version 0.9.0. Yesterday, I spent all-day synchronizing the community charts updates in our helm chart. I can't figure out the exact update that corrects this problem, but my intuition says it could be that my entity model wasn't respecting the model schemas. After updating everything, running the build indices job, and restoring everything, It works. I'm thankful for your help.
o
Glad you were able to sort it out 😄 this was definitely a perplexing one.