Che: Java LS server initialization was failed

Created on 19 Aug 2019 · 12Comments · Source: eclipse/che

Describe the bug

There are E2E Happy path tests which fail on "Language server validation > Java LS initialization" step https://codeready-workspaces-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/che-regular-tests/view/K8S/job/CHE-7-Happy-Path-Tests/1117/console

Browser logs: https://gist.github.com/dmytro-ndp/37e036eb1afa39ddad74fb780f43a81b
Test execution screencast: https://codeready-workspaces-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/che-regular-tests/view/K8S/job/CHE-7-Happy-Path-Tests/1117/artifact/e2e/report/executionScreencast/

It could be related to commit https://github.com/eclipse/che/commit/c3b0abbe5dd8bffff197705e0803dd57da1fe82c#diff-4b31cfc6b318b13ea51fcb1b2d1c11ce

Che version

[ ] latest
[x] nightly
[ ] other: please specify

Che Config map



  CHE_API: http://che-che.10.0.151.216.nip.io/api

  CHE_CORS_ALLOW__CREDENTIALS: "false"

  CHE_CORS_ALLOWED__ORIGINS: '*'

  CHE_CORS_ENABLED: "true"

  CHE_DEBUG_SERVER: "true"

  CHE_HOST: che-che.10.0.151.216.nip.io

  CHE_INFRA_KUBERNETES_BOOTSTRAPPER_BINARY__URL: http://che-che.10.0.151.216.nip.io/agent-binaries/linux_amd64/bootstrapper/bootstrapper

  CHE_INFRA_KUBERNETES_INGRESS_ANNOTATIONS__JSON: '{"kubernetes.io/ingress.class":

    "nginx", "nginx.ingress.kubernetes.io/rewrite-target": "/","nginx.ingress.kubernetes.io/ssl-redirect":

    "false","nginx.ingress.kubernetes.io/proxy-connect-timeout": "3600","nginx.ingress.kubernetes.io/proxy-read-timeout":

    "3600"}'

  CHE_INFRA_KUBERNETES_INGRESS_DOMAIN: 10.0.151.216.nip.io

  CHE_INFRA_KUBERNETES_MACHINE__START__TIMEOUT__MIN: "5"

  CHE_INFRA_KUBERNETES_MASTER__URL: ""

  CHE_INFRA_KUBERNETES_NAMESPACE: che

  CHE_INFRA_KUBERNETES_POD_SECURITY__CONTEXT_FS__GROUP: "1724"

  CHE_INFRA_KUBERNETES_POD_SECURITY__CONTEXT_RUN__AS__USER: "1724"

  CHE_INFRA_KUBERNETES_PVC_PRECREATE__SUBPATHS: "true"

  CHE_INFRA_KUBERNETES_PVC_QUANTITY: 1Gi

  CHE_INFRA_KUBERNETES_PVC_STRATEGY: common

  CHE_INFRA_KUBERNETES_SERVER__STRATEGY: multi-host

  CHE_INFRA_KUBERNETES_SERVICE__ACCOUNT__NAME: che-workspace

  CHE_INFRA_KUBERNETES_TLS__ENABLED: "false"

  CHE_INFRA_KUBERNETES_TLS__SECRET: ""

  CHE_INFRA_KUBERNETES_TRUST__CERTS: "false"

  CHE_INFRA_KUBERNETES_WORKSPACE__START__TIMEOUT__MIN: "15"

  CHE_INFRASTRUCTURE_ACTIVE: kubernetes

  CHE_LIMITS_WORKSPACE_IDLE_TIMEOUT: "-1"

  CHE_LOCAL_CONF_DIR: /etc/conf

  CHE_LOG_LEVEL: INFO

  CHE_LOGGER_CONFIG: ""

  CHE_LOGS_APPENDERS_IMPL: plaintext

  CHE_LOGS_DIR: /data/logs

  CHE_METRICS_ENABLED: "false"

  CHE_MULTIUSER: "false"

  CHE_OAUTH_GITHUB_CLIENTID: ""

  CHE_OAUTH_GITHUB_CLIENTSECRET: ""

  CHE_PORT: "8080"

  CHE_PREDEFINED_STACKS_RELOAD__ON__START: "false"

  CHE_TRACING_ENABLED: "false"

  CHE_WEBSOCKET_ENDPOINT: ws://che-che.10.0.151.216.nip.io/api/websocket

  CHE_WEBSOCKET_ENDPOINT__MINOR: ws://che-che.10.0.151.216.nip.io/api/websocket-minor

  CHE_WORKSPACE_AUTO_START: "false"

  CHE_WORKSPACE_DEVFILE__REGISTRY__URL: http://devfile-registry-che.10.0.151.216.nip.io

  CHE_WORKSPACE_HTTP__PROXY: ""

  CHE_WORKSPACE_HTTPS__PROXY: ""

  CHE_WORKSPACE_JAVA__OPTIONS: -Xmx2000m

  CHE_WORKSPACE_MAVEN__OPTIONS: -Xmx20000m

  CHE_WORKSPACE_NO__PROXY: ""

  CHE_WORKSPACE_PLUGIN__REGISTRY__URL: http://plugin-registry-che.10.0.151.216.nip.io/v3

  CHE_WSAGENT_CORS_ALLOW__CREDENTIALS: "true"

  CHE_WSAGENT_CORS_ALLOWED__ORIGINS: "NULL"

  CHE_WSAGENT_CORS_ENABLED: "true"

  JAEGER_ENDPOINT: http://jaeger-collector:14268/api/traces

  JAEGER_REPORTER_MAX_QUEUE_SIZE: "10000"

  JAEGER_SAMPLER_MANAGER_HOST_PORT: jaeger:5778

  JAEGER_SAMPLER_PARAM: "1"

  JAEGER_SAMPLER_TYPE: const

  JAEGER_SERVICE_NAME: che-server

  JAVA_OPTS: '-XX:MaxRAMFraction=2 -XX:+UseParallelGC -XX:MinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=20

    -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:+UnlockExperimentalVMOptions

    -XX:+UseCGroupMemoryLimitForHeap -Dsun.zip.disableMemoryMapping=true -Xms20m '

Steps to reproduce

14:30:35   Validation of workspace start
14:30:36     ✓ Open workspace (1298ms)
14:31:57     ✓ Wait workspace running state (80789ms)
14:32:04     ✓ Wait until project is imported (6565ms)
14:32:04 
14:32:04   Language server validation
14:35:28     1) Java LS initialization
14:35:28 
14:35:28 
14:35:28   3 passing (5m)
14:35:28   1 failing
14:35:28 
14:35:28   1) Language server validation
14:35:28        Java LS initialization:
14:35:28      TimeoutError: Wait timed out after 180012ms
14:35:28       at /home/e2e/node_modules/selenium-webdriver/lib/promise.js:2201:17
14:35:28       at ManagedPromise.invokeCallback_ (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:1376:14)
14:35:28       at TaskQueue.execute_ (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:3084:14)
14:35:28       at TaskQueue.executeNext_ (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:3067:27)
14:35:28       at asyncRun (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:2927:27)
14:35:28       at /home/e2e/node_modules/selenium-webdriver/lib/promise.js:668:7
14:35:28       at <anonymous>
14:35:28       at process._tickCallback (internal/process/next_tick.js:188:7)
14:35:28   From: Task: <anonymous wait>
14:35:28       at scheduleWait (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:2188:20)
14:35:28       at ControlFlow.wait (/home/e2e/node_modules/selenium-webdriver/lib/promise.js:2517:12)
14:35:28       at thenableWebDriverProxy.wait (/home/e2e/node_modules/selenium-webdriver/lib/webdriver.js:934:29)
14:35:28       at Ide.<anonymous> (/home/e2e/dist/pageobjects/ide/Ide.js:156:49)
14:35:28       at Generator.next (<anonymous>)
14:35:28       at /home/e2e/dist/pageobjects/ide/Ide.js:19:71
14:35:28       at new Promise (<anonymous>)
14:35:28       at __awaiter (/home/e2e/dist/pageobjects/ide/Ide.js:15:12)
14:35:28       at Ide.waitStatusBarContains (/home/e2e/dist/pageobjects/ide/Ide.js:154:16)
14:35:28       at Ide.<anonymous> (/home/e2e/dist/pageobjects/ide/Ide.js:196:28)
14:35:28       at Generator.next (<anonymous>)
14:35:28       at fulfilled (/home/e2e/dist/pageobjects/ide/Ide.js:16:58)
14:35:28       at <anonymous>
14:35:28       at process._tickCallback (internal/process/next_tick.js:188:7)

Runtime

[ ] kubernetes (include output of kubectl version)
[ ] Openshift (include output of oc version)
[x] minikube (include output of minikube version and kubectl version)
[ ] minishift (include output of minishift version and oc version)
[ ] docker-desktop + K8S (include output of docker version and kubectl version)
[ ] other: (please specify)

Screencast

out

Installation method

[x] chectl (stable, 7.0.0)

 /usr/local/bin/chectl server:start \
    --k8spodreadytimeout=180000 \
    -t=${WORKSPACE}/deploy/ \
    --listr-renderer=verbose \
    --cheimage=eclipse/che-server:nightly

[ ] che-operator
[ ] minishift-addon
[ ] I don't know

Environment

[ ] my computer
- [ ] Windows
- [x] Linux
- [ ] macOS
[ ] Cloud
- [ ] Amazon
- [ ] Azure
- [ ] GCE
- [ ] other (please specify)
[ ] other: please specify

Additional context

kinbug severitblocker teaplugins

Source

dmytro-ndp

All 12 comments

@vparfonov looks related to https://github.com/redhat-developer/rh-che/issues/1565
Could we switch back to 7.0.0 or 7.0.0-next - https://github.com/eclipse/che-plugin-registry/commit/191df1e76efdc1db993947d66a23f8aaff8b5eec ?

ibuziuk on 19 Aug 2019

@vparfonov looks related to redhat-developer/rh-che#1565
Could we switch back to 7.0.0 or 7.0.0-next - eclipse/che-plugin-registry@191df1e ?

https://github.com/eclipse/che/pull/14278

vparfonov on 19 Aug 2019

❤1

@vparfonov this is a great hot fix for upstream for the time being, but it will fix neither prod-preview nor nightly of the plugin registry. Could we consider reverting [1] or switching to 7.0.0 all the images in the plugin registry? I believe we should switch plugins in the plugin-registry to next only once we verify that it works against che master (which is not the case atm)

[1] https://github.com/eclipse/che-plugin-registry/commit/191df1e76efdc1db993947d66a23f8aaff8b5eec

ibuziuk on 19 Aug 2019

@ibuziuk Yes, you are totally right we should to switch to the next ASAP

vparfonov on 19 Aug 2019

We need to fix Happy path tests to switch the next Theia version https://github.com/eclipse/che/issues/14248. The work is in progress.

dmytro-ndp on 19 Aug 2019

@dmytro-ndp yeah, but https://github.com/eclipse/che/issues/14248 is not enough to make LS work, smth got broken in the next version of plugins and this is not related to missing p-TabBar-content

ibuziuk on 19 Aug 2019

😕1

@ibuziuk : could you, please, be more specific about what got broken in the next version of plugins, because AFAIK @musienko-maxim didn't encounter any additional problem, but https://github.com/eclipse/che/issues/14282 ?

dmytro-ndp on 19 Aug 2019

@dmytro-ndp What is the actual condition that is failing (or timing out, to be more precise)? Are checking a log message or are you observing some change in the UI?
Also, would it be possible to have source maps enabled in the tests to have real source locations? It would make analysis much easier.

tsmaeder on 20 Aug 2019

@tsmaeder: Happy path tests failed because it didn't receive notification "Starting Java Language Server" after opening petclinic project during the 18 seconds, and refresh of browser page didn't help:
out

Browser logs: https://gist.github.com/dmytro-ndp/37e036eb1afa39ddad74fb780f43a81b

Che Config map



  CHE_API: http://che-che.10.0.151.216.nip.io/api

  CHE_CORS_ALLOW__CREDENTIALS: "false"

  CHE_CORS_ALLOWED__ORIGINS: '*'

  CHE_CORS_ENABLED: "true"

  CHE_DEBUG_SERVER: "true"

  CHE_HOST: che-che.10.0.151.216.nip.io

  CHE_INFRA_KUBERNETES_BOOTSTRAPPER_BINARY__URL: http://che-che.10.0.151.216.nip.io/agent-binaries/linux_amd64/bootstrapper/bootstrapper

  CHE_INFRA_KUBERNETES_INGRESS_ANNOTATIONS__JSON: '{"kubernetes.io/ingress.class":

    "nginx", "nginx.ingress.kubernetes.io/rewrite-target": "/","nginx.ingress.kubernetes.io/ssl-redirect":

    "false","nginx.ingress.kubernetes.io/proxy-connect-timeout": "3600","nginx.ingress.kubernetes.io/proxy-read-timeout":

    "3600"}'

  CHE_INFRA_KUBERNETES_INGRESS_DOMAIN: 10.0.151.216.nip.io

  CHE_INFRA_KUBERNETES_MACHINE__START__TIMEOUT__MIN: "5"

  CHE_INFRA_KUBERNETES_MASTER__URL: ""

  CHE_INFRA_KUBERNETES_NAMESPACE: che

  CHE_INFRA_KUBERNETES_POD_SECURITY__CONTEXT_FS__GROUP: "1724"

  CHE_INFRA_KUBERNETES_POD_SECURITY__CONTEXT_RUN__AS__USER: "1724"

  CHE_INFRA_KUBERNETES_PVC_PRECREATE__SUBPATHS: "true"

  CHE_INFRA_KUBERNETES_PVC_QUANTITY: 1Gi

  CHE_INFRA_KUBERNETES_PVC_STRATEGY: common

  CHE_INFRA_KUBERNETES_SERVER__STRATEGY: multi-host

  CHE_INFRA_KUBERNETES_SERVICE__ACCOUNT__NAME: che-workspace

  CHE_INFRA_KUBERNETES_TLS__ENABLED: "false"

  CHE_INFRA_KUBERNETES_TLS__SECRET: ""

  CHE_INFRA_KUBERNETES_TRUST__CERTS: "false"

  CHE_INFRA_KUBERNETES_WORKSPACE__START__TIMEOUT__MIN: "15"

  CHE_INFRASTRUCTURE_ACTIVE: kubernetes

  CHE_LIMITS_WORKSPACE_IDLE_TIMEOUT: "-1"

  CHE_LOCAL_CONF_DIR: /etc/conf

  CHE_LOG_LEVEL: INFO

  CHE_LOGGER_CONFIG: ""

  CHE_LOGS_APPENDERS_IMPL: plaintext

  CHE_LOGS_DIR: /data/logs

  CHE_METRICS_ENABLED: "false"

  CHE_MULTIUSER: "false"

  CHE_OAUTH_GITHUB_CLIENTID: ""

  CHE_OAUTH_GITHUB_CLIENTSECRET: ""

  CHE_PORT: "8080"

  CHE_PREDEFINED_STACKS_RELOAD__ON__START: "false"

  CHE_TRACING_ENABLED: "false"

  CHE_WEBSOCKET_ENDPOINT: ws://che-che.10.0.151.216.nip.io/api/websocket

  CHE_WEBSOCKET_ENDPOINT__MINOR: ws://che-che.10.0.151.216.nip.io/api/websocket-minor

  CHE_WORKSPACE_AUTO_START: "false"

  CHE_WORKSPACE_DEVFILE__REGISTRY__URL: http://devfile-registry-che.10.0.151.216.nip.io

  CHE_WORKSPACE_HTTP__PROXY: ""

  CHE_WORKSPACE_HTTPS__PROXY: ""

  CHE_WORKSPACE_JAVA__OPTIONS: -Xmx2000m

  CHE_WORKSPACE_MAVEN__OPTIONS: -Xmx20000m

  CHE_WORKSPACE_NO__PROXY: ""

  CHE_WORKSPACE_PLUGIN__REGISTRY__URL: http://plugin-registry-che.10.0.151.216.nip.io/v3

  CHE_WSAGENT_CORS_ALLOW__CREDENTIALS: "true"

  CHE_WSAGENT_CORS_ALLOWED__ORIGINS: "NULL"

  CHE_WSAGENT_CORS_ENABLED: "true"

  JAEGER_ENDPOINT: http://jaeger-collector:14268/api/traces

  JAEGER_REPORTER_MAX_QUEUE_SIZE: "10000"

  JAEGER_SAMPLER_MANAGER_HOST_PORT: jaeger:5778

  JAEGER_SAMPLER_PARAM: "1"

  JAEGER_SAMPLER_TYPE: const

  JAEGER_SERVICE_NAME: che-server

  JAVA_OPTS: '-XX:MaxRAMFraction=2 -XX:+UseParallelGC -XX:MinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=20

    -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:+UnlockExperimentalVMOptions

    -XX:+UseCGroupMemoryLimitForHeap -Dsun.zip.disableMemoryMapping=true -Xms20m '

dmytro-ndp on 20 Aug 2019

It looks like this issue has been fixed. I have tested:

using che nightly that currently use che-theia:7.0.0
starting a workspace with che-theia:next and a version of the plugin registry that uses che-theia-endpoint-runtime:next (https://github.com/eclipse/che-plugin-registry/commit/aee58cf6a4e385fa36f6e9660f8389bc0d9028d2).

and in both cases the LS was started and worked fine.

I believe the only missing piece to get back to che-theia:next is https://github.com/eclipse/che/issues/14248 and the work is in progress (https://github.com/eclipse/che/pull/14285)

@dmytro-ndp @vparfonov @rhopp do you confirm?

l0rd on 21 Aug 2019

Yes, looks like on che-theia:next this problem is not actual. On this job the LS init works.:
https://codeready-workspaces-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/job/Single-Che-PR-check-E2E-Happy-path-tests-against-k8s-on-codenvy-slave

musienko-maxim on 21 Aug 2019

At the same time we encountered too big _Java LS server initialization_ time (more than 30 minutes) on Jenkins slave _codenvy-slave9_, where we were running fixed Che version https://codeready-workspaces-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/blue/organizations/jenkins/Single-Che-PR-check-E2E-Happy-path-tests-against-k8s-on-codenvy-slave9/detail/Single-Che-PR-check-E2E-Happy-path-tests-against-k8s-on-codenvy-slave9/175/pipeline/101 :
screenshot-Java_LS_initialization (2)

Happy path test logs



  Validation of workspace start

    ✓ Open workspace (2199ms)

    ✓ Wait workspace running state (106212ms)

    ✓ Wait until project is imported (10280ms)

Language server validation

    1) Java LS initialization

3 passing (22m)

  1 failing

1) Language server validation

       Java LS initialization:

     Error: Timeout of 1200000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/home/e2e/dist/tests/e2e_happy_path/HappyPath.spec.js)

      at Test.Runnable._timeoutError (/home/e2e/node_modules/mocha/lib/runnable.js:455:10)

      at Timeout. (/home/e2e/node_modules/mocha/lib/runnable.js:266:24)

      at ontimeout (timers.js:475:11)

      at tryOnTimeout (timers.js:310:5)

      at Timer.listOnTimeout (timers.js:270:5)