Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

C# language server fails with timeout initializing error during selenium test session #10789

Closed
musienko-maxim opened this issue Aug 15, 2018 · 1 comment
Assignees
Labels
kind/bug Outline of a bug - must adhere to the bug report template.

Comments

@musienko-maxim
Copy link
Contributor

musienko-maxim commented Aug 15, 2018

Description

Reproduced only on CI jobs
Related test: CSharpRenamingTest

Reproduction Steps

The test performs next scenario:

  1. Create a workspace based on DotNet stack. Create dot-net-web.
  2. Opens the Program.cs file
  3. Wait message about initialization like: 018-08-15 15:36:08,235[rverInitializer] [INFO ] [.a.l.LanguageServerInitializer 129] - Finished language servers initialization, file path '/...
  4. Set cursor to the end of Build(); and remove ; symbol
    Expected behavior:
    Should start codevalidation feature, in the string with just deleted symbol, should appear error marker.
    In the first lines info marker should present.
    )

Observed behavior:
The codevalidation is not enabled. In the Event we have error from LS like: Timeout initializing error

OS and version: Openshift on CI, upstream. Job link: https://ci.codenvycorp.com/view/qa/job/che-integration-tests-multiuser-master-ocp/, chrome browser.

org eclipse che selenium languageserver csharpfileeditingtest checkcodeediting_cefxzpn6

ws-agent-logs:
-------------------------
2018-08-15 00:08:42,211[main]             [INFO ] [o.a.c.s.VersionLoggerListener 89]    - Server version:        Apache Tomcat/8.5.23
2018-08-15 00:08:42,217[main]             [INFO ] [o.a.c.s.VersionLoggerListener 91]    - Server built:          Sep 28 2017 10:30:11 UTC
2018-08-15 00:08:42,218[main]             [INFO ] [o.a.c.s.VersionLoggerListener 93]    - Server number:         8.5.23.0
2018-08-15 00:08:42,218[main]             [INFO ] [o.a.c.s.VersionLoggerListener 95]    - OS Name:               Linux
2018-08-15 00:08:42,219[main]             [INFO ] [o.a.c.s.VersionLoggerListener 97]    - OS Version:            3.10.0-514.16.1.el7.x86_64
2018-08-15 00:08:42,219[main]             [INFO ] [o.a.c.s.VersionLoggerListener 99]    - Architecture:          amd64
2018-08-15 00:08:42,219[main]             [INFO ] [o.a.c.s.VersionLoggerListener 101]   - Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre
2018-08-15 00:08:42,220[main]             [INFO ] [o.a.c.s.VersionLoggerListener 103]   - JVM Version:           1.8.0_171-8u171-b11-0ubuntu0.16.04.1-b11
2018-08-15 00:08:42,220[main]             [INFO ] [o.a.c.s.VersionLoggerListener 105]   - JVM Vendor:            Oracle Corporation
2018-08-15 00:08:42,220[main]             [INFO ] [o.a.c.s.VersionLoggerListener 107]   - CATALINA_BASE:         /home/user/che/ws-agent
2018-08-15 00:08:42,221[main]             [INFO ] [o.a.c.s.VersionLoggerListener 109]   - CATALINA_HOME:         /home/user/che/ws-agent
2018-08-15 00:08:42,221[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.config.file=/home/user/che/ws-agent/conf/logging.properties
2018-08-15 00:08:42,221[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2018-08-15 00:08:42,222[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:MaxRAM=600m
2018-08-15 00:08:42,222[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:MaxRAMFraction=1
2018-08-15 00:08:42,222[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:+UseParallelGC
2018-08-15 00:08:42,223[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:MinHeapFreeRatio=10
2018-08-15 00:08:42,223[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:MaxHeapFreeRatio=20
2018-08-15 00:08:42,223[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:GCTimeRatio=4
2018-08-15 00:08:42,224[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -XX:AdaptiveSizePolicyWeight=90
2018-08-15 00:08:42,225[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dsun.zip.disableMemoryMapping=true
2018-08-15 00:08:42,225[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Xms50m
2018-08-15 00:08:42,226[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dfile.encoding=UTF8
2018-08-15 00:08:42,226[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.security.egd=file:/dev/./urandom
2018-08-15 00:08:42,226[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.dir=/workspace_logs/ws-agent
2018-08-15 00:08:42,227[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.logs.level=INFO
2018-08-15 00:08:42,227[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djuli-logback.configurationFile=file:/home/user/che/ws-agent/conf/tomcat-logger.xml
2018-08-15 00:08:42,227[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
2018-08-15 00:08:42,227[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
2018-08-15 00:08:42,228[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -agentlib:jdwp=transport=dt_socket,address=4403,server=y,suspend=n
2018-08-15 00:08:42,228[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote
2018-08-15 00:08:42,229[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.ssl=false
2018-08-15 00:08:42,230[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
2018-08-15 00:08:42,231[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dche.local.conf.dir=/home/user/che/ws-agent/conf/
2018-08-15 00:08:42,231[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.base=/home/user/che/ws-agent
2018-08-15 00:08:42,232[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Dcatalina.home=/home/user/che/ws-agent
2018-08-15 00:08:42,232[main]             [INFO ] [o.a.c.s.VersionLoggerListener 115]   - Command line argument: -Djava.io.tmpdir=/home/user/che/ws-agent/temp
2018-08-15 00:08:42,409[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 573]  - Initializing ProtocolHandler ["http-nio-4401"]
2018-08-15 00:08:42,443[main]             [INFO ] [o.a.t.util.net.NioSelectorPool 67]   - Using a shared selector for servlet write/read
2018-08-15 00:08:42,447[main]             [INFO ] [o.a.catalina.startup.Catalina 632]   - Initialization processed in 777 ms
2018-08-15 00:08:42,477[main]             [INFO ] [c.m.JmxRemoteLifecycleListener 336]  - The JMX Remote Listener has configured the registry on port [32002] and the server on port [32102] for the [Platform] server
2018-08-15 00:08:42,478[main]             [INFO ] [o.a.c.core.StandardService 416]      - Starting service [Catalina]
2018-08-15 00:08:42,478[main]             [INFO ] [o.a.c.core.StandardEngine 259]       - Starting Servlet Engine: Apache Tomcat/8.5.23
2018-08-15 00:08:42,747[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 959]        - Deploying web application archive [/home/user/che/ws-agent/webapps/ROOT.war]
2018-08-15 00:08:52,151[ost-startStop-1]  [INFO ] [o.a.c.startup.HostConfig 1023]       - Deployment of web application archive [/home/user/che/ws-agent/webapps/ROOT.war] has finished in [9,402] ms
2018-08-15 00:08:52,168[main]             [INFO ] [o.a.c.http11.Http11NioProtocol 632]  - Starting ProtocolHandler ["http-nio-4401"]
2018-08-15 00:08:52,189[main]             [INFO ] [o.a.catalina.startup.Catalina 683]   - Server startup in 9742 ms
browser js console logs:

2018-08-15 12:08:55,984 WARNING http://keycloak-eclipse-che.172.30.3.247.nip.io/auth/realms/che/protocol/openid-connect/auth?client_id=che-public&redirect_uri=http%3A%2F%2Fche-eclipse-che.172.30.3.247.nip.io%2Fuser1534290142904%2Fworkspaceks9zt0&state=b55783e7-8521-4254-9746-0ae34d807597&nonce=925bf284-f007-4ecd-a86f-7bc537fb5a8f&response_mode=fragment&response_type=code&scope=openid - This page includes a password or credit card input in a non-secure context. A warning will be added to the URL bar in Chrome 56 (Jan 2017). For more information, see https://goo.gl/zmWq3m.
2018-08-15 12:08:58,675 INFO http://keycloak-eclipse-che.172.30.3.247.nip.io/auth/js/keycloak.js 684:28 "[KEYCLOAK] Estimated time difference between browser and server is 0 seconds
browser network logs:
-------------------------
2018-08-15 12:08:55,792 (id: 3674.5) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/keycloak/settings
2018-08-15 12:08:55,813 (id: 3674.5) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/keycloak/settings
2018-08-15 12:08:58,515 (id: 3674.28) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/keycloak/settings
2018-08-15 12:08:58,524 (id: 3674.28) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/keycloak/settings
2018-08-15 12:09:02,330 (id: 3674.45) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/project-template/all
2018-08-15 12:09:02,330 (id: 3674.46) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/profile/
2018-08-15 12:09:02,339 (id: 3674.45) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/project-template/all
2018-08-15 12:09:02,396 (id: 3674.46) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/profile/
2018-08-15 12:09:02,397 (id: 3674.50) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/preferences
2018-08-15 12:09:02,410 (id: 3674.50) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/preferences
2018-08-15 12:09:02,445 (id: 3674.51) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/user1534290142904/workspaceks9zt0
2018-08-15 12:09:02,784 (id: 3674.51) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/user1534290142904/workspaceks9zt0
2018-08-15 12:09:04,410 (id: 3674.91) [WEBSOCKET_CREATED] ws://che-eclipse-che.172.30.3.247.nip.io/api/websocket?token=eyJhbGciOiJSUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICJlMjNGc3kzRlI5dnRUZms3TGlkX1lQOGU0cDNoY0psM20wQTRnckIzNnJJIn0.eyJqdGkiOiIyMzU0YThhMC1lOWY0LTQ4MGEtOWNkZC1kOGMyYjliNTY5NTciLCJleHAiOjE1MzQyOTIwMzgsIm5iZiI6MCwiaWF0IjoxNTM0MjkxNzM4LCJpc3MiOiJodHRwOi8va2V5Y2xvYWstZWNsaXBzZS1jaGUuMTcyLjMwLjMuMjQ3Lm5pcC5pby9hdXRoL3JlYWxtcy9jaGUiLCJhdWQiOiJjaGUtcHVibGljIiwic3ViIjoiYTg0OTE1ODMtYjM2My00OWRlLWE5ZmEtYjEzM2NmNmJiODMyIiwidHlwIjoiQmVhcmVyIiwiYXpwIjoiY2hlLXB1YmxpYyIsIm5vbmNlIjoiOTI1YmYyODQtZjAwNy00ZWNkLWE4NmYtN2JjNTM3ZmI1YThmIiwiYXV0aF90aW1lIjoxNTM0MjkxNzM4LCJzZXNzaW9uX3N0YXRlIjoiNTc3ZGQ1ZDEtMmIwMi00OWUxLTk1YWQtODQwOGNmZTVhMjg2IiwiYWNyIjoiMSIsImFsbG93ZWQtb3JpZ2lucyI6WyJodHRwOi8vY2hlLWVjbGlwc2UtY2hlLjE3Mi4zMC4zLjI0Ny5uaXAuaW8iXSwicmVhbG1fYWNjZXNzIjp7InJvbGVzIjpbInVtYV9hdXRob3JpemF0aW9uIiwidXNlciJdfSwicmVzb3VyY2VfYWNjZXNzIjp7ImJyb2tlciI6eyJyb2xlcyI6WyJyZWFkLXRva2VuIl19LCJhY2NvdW50Ijp7InJvbGVzIjpbIm1hbmFnZS1hY2NvdW50IiwibWFuYWdlLWFjY291bnQtbGlua3MiLCJ2aWV3LXByb2ZpbGUiXX19LCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJ1c2VyMTUzNDI5MDE0MjkwNCIsImVtYWlsIjoidXNlcjE1MzQyOTAxNDI5MDRAMS5jb20ifQ.OBYTS18dcpaes0yFaykKFfuweaZQj9LrYPjtIJIJKU6wc7cPkR2kdsAWkXMAhokU4LVUjRZEqCYink4qd5dn8ZTicOrxylSHDGa8uQV6nulDqDeKjKtpTG35EECrKGsqYJEsqJI3tqZG5zxPOuT_cH2pLkMsVqPhU_AMVCaYqRPmCwmU-fFZeAh59zJ_nzxSAMfBXxt_r5CgHeB7y0zjG_CL1PCq0er53SJJW4V9K-OIPDHk_D476-k2zbnPlxBGkDmyfi8EyIyQ7ccax9sNuMo9-h4IM_GQUlsFkm7qWfCfIUBd8zyZaMzRLZdmzR4t7Gif4Jh737ATAU9CilZz9A
2018-08-15 12:09:04,711 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"workspace/statusChanged","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,711 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"machine/statusChanged","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,711 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"server/statusChanged","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,712 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"machine/log","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,712 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"installer/log","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,712 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"subscribe","params":{"method":"installer/statusChanged","scope":{"workspaceId":"workspace4vdaudv69c0sf5k0"}}}
2018-08-15 12:09:04,712 (id: 3674.91) [WEBSOCKET_REQUEST] {"jsonrpc":"2.0","method":"websocketIdService/getId","id":"4"}
2018-08-15 12:09:04,712 (id: 3674.94) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:04,799 (id: 3674.95) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/installer
2018-08-15 12:09:05,162 (id: 3674.91) [WEBSOCKET_RESPONSE] {"jsonrpc":"2.0","id":"4","result":["1194939296"]}
2018-08-15 12:09:05,164 (id: 3674.94) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:05,192 (id: 3674.95) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/installer
2018-08-15 12:09:05,376 (id: 3674.108) [REQUEST]  GET http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:05,534 (id: 3674.108) [RESPONSE] 200 http://che-eclipse-che.172.30.3.247.nip.io/api/workspace/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:05,665 (id: 3674.91) [WEBSOCKET_RESPONSE] {"jsonrpc":"2.0","method":"installer/log","params":{"text":"2018/08/15 00:09:05 Start new terminal.","time":"2018-08-15T00:09:05.494733252Z","runtimeId":{"ownerId":"a8491583-b363-49de-a9fa-b133cf6bb832","envName":"workspaceks9zt0","workspaceId":"workspace4vdaudv69c0sf5k0"},"installer":"org.eclipse.che.terminal","stream":"STDOUT","machineName":"dev-machine"}}
2018-08-15 12:09:22,065 (id: 3674.91) [WEBSOCKET_RESPONSE] {"jsonrpc":"2.0","method":"installer/log","params":{"text":"2018-08-15 00:09:20,927[rverInitializer]  [INFO ] [.a.l.LanguageServerInitializer 113]  - Started language servers initialization, file path '/AspProjectta1i/Program.cs'","time":"2018-08-15T00:09:20.927752574Z","runtimeId":{"ownerId":"a8491583-b363-49de-a9fa-b133cf6bb832","envName":"workspaceks9zt0","workspaceId":"workspace4vdaudv69c0sf5k0"},"installer":"org.eclipse.che.ws-agent","stream":"STDOUT","machineName":"dev-machine"}}
2018-08-15 12:09:35,330 (id: 3674.174) [REQUEST]  PUT http://che-eclipse-che.172.30.3.247.nip.io/api/activity/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:35,330 (id: 3674.174) [RESPONSE] 204 http://che-eclipse-che.172.30.3.247.nip.io/api/activity/workspace4vdaudv69c0sf5k0
2018-08-15 12:09:58,266 (id: 3674.91) [WEBSOCKET_RESPONSE] {"jsonrpc":"2.0","method":"installer/log","params":{"text":"2018-08-15 00:09:57,749[rverInitializer]  [INFO ] [.a.l.LanguageServerInitializer 220]  - Initialized language server 'org.eclipse.che.plugin.csharp.languageserver'","time":"2018-08-15T00:09:57.753631437Z","runtimeId":{"ownerId":"a8491583-b363-49de-a9fa-b133cf6bb832","envName":"workspaceks9zt0","workspaceId":"workspace4vdaudv69c0sf5k0"},"installer":"org.eclipse.che.ws-agent","stream":"STDOUT","machineName":"dev-machine"}}
2018-08-15 12:09:58,266 (id: 3674.91) [WEBSOCKET_RESPONSE] {"jsonrpc":"2.0","method":"installer/log","params":{"text":"2018-08-15 00:09:57,750[rverInitializer]  [INFO ] [.a.l.LanguageServerInitializer 129]  - Finished language servers initialization, file path '/AspProjectta1i/Program.cs'","time":"2018-08-15T00:09:57.753687539Z","runtimeId":{"ownerId":"a8491583-b363-49de-a9fa-b133cf6bb832","envName":"workspaceks9zt0","workspaceId":"workspace4vdaudv69c0sf5k0"},"installer":"org.eclipse.che.ws-agent","stream":"STDOUT","machineName":"dev-machine"}}
2018-08-15 12:10:06,039 (id: 3674.205) [REQUEST]  PUT http://che-eclipse-che.172.30.3.247.nip.io/api/activity/workspace4vdaudv69c0sf5k0
2018-08-15 12:10:06,040 (id: 3674.205) [RESPONSE] 204 http://che-eclipse-che.172.30.3.247.nip.io/api/activity/workspace4vdaudv69c0sf5k0
@musienko-maxim musienko-maxim added the kind/bug Outline of a bug - must adhere to the bug report template. label Aug 15, 2018
musienko-maxim added a commit that referenced this issue Aug 15, 2018
* Add know issue in the CSharpFileEditingTest
@tsmaeder
Copy link
Contributor

I have noticed what is likely the same behaviour when opening Php files. Refreshing the browser fixes the problem, so likely it's a gwt-ide problem.

@vparfonov vparfonov added sprint/current status/analyzing An issue has been proposed and it is currently being analyzed for effort and implementation approach labels Aug 23, 2018
@sunix sunix added target/che6 and removed sprint/current status/analyzing An issue has been proposed and it is currently being analyzed for effort and implementation approach labels Jul 4, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Outline of a bug - must adhere to the bug report template.
Projects
None yet
Development

No branches or pull requests

5 participants