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

After the last update the completion does not seem to work any more #71

Closed
gabesoft opened this issue Dec 6, 2020 · 49 comments
Closed

Comments

@gabesoft
Copy link

gabesoft commented Dec 6, 2020

please complete the following information:

  • OS version: [e.g. Win 10, Mac Catalina] MacOS Big Sur
  • Editor version (Output of vim --version): 8.2 (patches 1-539)
  • Programming language: [e.g. js, ts, c++]: javascript
  • TabNine extension version(Type TabNine::version in insert mode): 3.2.34

If the issue is related to TabNine failure, please provide log files:

Type TabNine::config in your editor, the logs are located at the bottom of the page.

Issue Details:

The YouCompleteMe server keeps crashing. Here's a log sample


Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 79, in HandleFuture
    return _JsonFromFuture( future )
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 239, in _JsonFromFuture
    response = future.result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 397, in result
    return self.__get_result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 356, in __get_result
    raise self._exception
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/unsafe_thread_pool_executor.py", line 43, in run
    result = self.fn( *self.args, **self.kwargs )
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 437, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /completions (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x11003f250>: Failed to establish a new connection: [Errno 61] Connection refused'))
2020-12-06 13:41:18,816 - ERROR - Unable to connect to server
Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 136, in _new_conn
    conn = connection.create_connection(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 91, in create_connection
    raise err
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 81, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 557, in urlopen
    httplib_response = self._make_request(conn, method, url,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 353, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1240, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1286, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1235, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1006, in _send_output
    self.send(msg)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 946, in send
    self.connect()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 162, in connect
    conn = self._new_conn()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 145, in _new_conn
    raise NewConnectionError(
requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.HTTPConnection object at 0x10d9dfa00>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 366, in send
    resp = conn.urlopen(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 608, in urlopen
    retries = retries.increment(method, url, error=e, _pool=self,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/retry.py", line 273, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
requests.packages.urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /completions (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10d9dfa00>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 79, in HandleFuture
    return _JsonFromFuture( future )
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 239, in _JsonFromFuture
    response = future.result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 397, in result
    return self.__get_result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 356, in __get_result
    raise self._exception
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/unsafe_thread_pool_executor.py", line 43, in run
    result = self.fn( *self.args, **self.kwargs )
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 437, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /completions (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10d9dfa00>: Failed to establish a new connection: [Errno 61] Connection refused'))
2020-12-06 13:43:40,040 - ERROR - Unable to connect to server
Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 136, in _new_conn
    conn = connection.create_connection(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 91, in create_connection
    raise err
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 81, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 557, in urlopen
    httplib_response = self._make_request(conn, method, url,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 353, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1240, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1286, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1235, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1006, in _send_output
    self.send(msg)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 946, in send
    self.connect()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 162, in connect
    conn = self._new_conn()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 145, in _new_conn
    raise NewConnectionError(
requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.HTTPConnection object at 0x10d6d7640>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 366, in send
    resp = conn.urlopen(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 608, in urlopen
    retries = retries.increment(method, url, error=e, _pool=self,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/retry.py", line 273, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
requests.packages.urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /healthy (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10d6d7640>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 79, in HandleFuture
    return _JsonFromFuture( future )
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 239, in _JsonFromFuture
    response = future.result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 404, in result
    return self.__get_result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 356, in __get_result
    raise self._exception
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/unsafe_thread_pool_executor.py", line 43, in run
    result = self.fn( *self.args, **self.kwargs )
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 437, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /healthy (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10d6d7640>: Failed to establish a new connection: [Errno 61] Connection refused'))
2020-12-06 13:44:56,091 - ERROR - Unable to connect to server
Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 136, in _new_conn
    conn = connection.create_connection(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 91, in create_connection
    raise err
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/connection.py", line 81, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 557, in urlopen
    httplib_response = self._make_request(conn, method, url,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 353, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1240, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1286, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1235, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 1006, in _send_output
    self.send(msg)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/http/client.py", line 946, in send
    self.connect()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 162, in connect
    conn = self._new_conn()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connection.py", line 145, in _new_conn
    raise NewConnectionError(
requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.HTTPConnection object at 0x10dbdfd30>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 366, in send
    resp = conn.urlopen(
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/connectionpool.py", line 608, in urlopen
    retries = retries.increment(method, url, error=e, _pool=self,
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/packages/urllib3/util/retry.py", line 273, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
requests.packages.urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /completions (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10dbdfd30>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 79, in HandleFuture
    return _JsonFromFuture( future )
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/client/base_request.py", line 239, in _JsonFromFuture
    response = future.result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 397, in result
    return self.__get_result()
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/pythonfutures/concurrent/futures/_base.py", line 356, in __get_result
    raise self._exception
  File "/Users/gabe/.vim/plugs/tabnine-vim/autoload/../python/ycm/unsafe_thread_pool_executor.py", line 43, in run
    result = self.fn( *self.args, **self.kwargs )
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/Users/gabe/.vim/plugs/tabnine-vim/third_party/ycmd/third_party/requests/requests/adapters.py", line 437, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='127.0.0.1', port=54996): Max retries exceeded with url: /completions (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x10dbdfd30>: Failed to establish a new connection: [Errno 61] Connection refused'))


@yonip23
Copy link

yonip23 commented Dec 7, 2020

Hello @gabesoft, thanks for reaching out!

Seems like Tabnine is crushing unexpectedly, can you run Tabnine's binary (located under the binaries folder in Tabnine's installation folder) directly from your terminal and attach the output here?

cd <Tabnine installation folder>/binaries
./TabNine --log_to_stderr

@gogoprog
Copy link

gogoprog commented Dec 7, 2020

Same issue here,
here is the ./TabNine --log_to_stderr output:

[2020-12-07][13:25:09][lunar_transport::controller][INFO] Creating lunar client...
[2020-12-07][13:25:09][frontend][INFO] Started.
[2020-12-07][13:25:09][lunar_local::bridge][INFO] TabNine Local communication thread started.
[2020-12-07][13:25:09][lunar_local::bridge][INFO] Loading model...
[2020-12-07][13:25:09][lunar_transport::controller][INFO] TabNine Cloud is disabled, communication thread is sleeping until configuration change...
[2020-12-07][13:25:09][lunar_local::locker][INFO] Trying to lock: "/tmp/model.lock"
[2020-12-07][13:25:09][lunar_local::locker][INFO] Lock acquired, performing the inner action
[2020-12-07][13:25:09][lunar_local::downloader][INFO] Starting download (last_failure=None).
[2020-12-07][13:25:09][lunar_local::downloader][INFO] Loaded cached metadata.
[2020-12-07][13:25:09][lunar_local::downloader][INFO] Trying to load cached model from "/home/gogoprog/.local/share/TabNine/models/b8373e4b.tabninemodel"
[2020-12-07][13:25:09][lunar_local::downloader][INFO] Checking for metadata update in background...
[2020-12-07][13:25:09][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:10][lunar_local::locker][INFO] Releasing lock: "/tmp/model.lock"
[2020-12-07][13:25:10][lunar_local::bridge][INFO] Done loading model (took 1.91 seconds).
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 19 ms to evaluate 1 token.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 19 ms to evaluate 1 token.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 18 ms to evaluate 1 token.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 18 ms to evaluate 1 token.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 19 ms to evaluate 2 tokens.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 22 ms to evaluate 3 tokens.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Selected 2 beams.
[2020-12-07][13:25:11][updater][INFO] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-07][13:25:11][lunar_local::tune][INFO] Model took 81 ms to evaluate 16 tokens.
[2020-12-07][13:25:11][lunar_local::tune][INFO] Selected context length of 112.
[2020-12-07][13:25:13][lunar_local::downloader][INFO] Downloaded model metadata [hash=b8373e4b].
[2020-12-07][13:25:13][lunar_transport::controller][INFO] Connecting to V4(35.186.213.204:443)
[2020-12-07][13:25:14][lunar_transport::controller][INFO] TabNine Cloud authentication successful.
[2020-12-07][13:25:14][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:20][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:28][updater][INFO] Making API request to https://api.tabnine.com/version/v1
[2020-12-07][13:25:29][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:29][updater][INFO] Server did not respond with version, so using default URL.
[2020-12-07][13:25:29][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:29][updater][INFO] Current version is 2.9.2, remote has version 3.2.28.
[2020-12-07][13:25:29][updater][INFO] Fetching update from https://update.tabnine.com/3.2.28/x86_64-unknown-linux-musl/TabNine.
[2020-12-07][13:25:32][updater][ERROR] updater error: there is already an executable at "/home/gogoprog/.vim/bundle/tabnine-vim/binaries/3.2.28/x86_64-unknown-linux-musl/TabNine"
[2020-12-07][13:25:41][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2
[2020-12-07][13:25:41][updater][INFO] Making API request to https://api.tabnine.com/api_key_info/v2

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

My log output looks similar to @gogoprog's. Adding here anyway just in case there are any differences.

[2020-12-07T10:22:59.076860-08:00][INFO][75226 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] ./TabNine --log_to_stderr
[2020-12-07T10:22:59.077481-08:00][INFO][75226 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T10:22:59.077632-08:00][WARN][75226 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T10:22:59.077684-08:00][INFO][75226 main][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(91)] config is BootstrapConfig { bootstrapper_enabled: true, api_endpoint: "https://api.tabnine.com/experiments/register/v2", registration_interval_seconds: 3600, bark_interval_seconds: 2, force_version: None }
[2020-12-07T10:22:59.077834-08:00][INFO][75226 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T10:22:59.080467-08:00][INFO][75226 main][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T10:22:59.603531-08:00][INFO][75226 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T10:22:59.693587-08:00][INFO][75226 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T10:22:59.771149-08:00][INFO][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T10:22:59.771353-08:00][INFO][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/tabnine_version_3.2.37.prefs.json")
[2020-12-07T10:22:59.771520-08:00][INFO][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T10:22:59.771617-08:00][WARN][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T10:22:59.771674-08:00][INFO][75226 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(197)] trying to start tabnine version Some("3.2.37")
[2020-12-07T10:22:59.771710-08:00][INFO][75226 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(272)] spawning tabnine with args ["./TabNine", "--log_to_stderr", "--no_bootstrap"]
[2020-12-07T10:22:59.772549-08:00][INFO][75226 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(276)] started tabnine process pid 75227 version Some("3.2.37"), desired version was Some("3.2.37") this version is Some("3.2.37")
[2020-12-07T10:22:59.772698-08:00][INFO][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T10:22:59.777075-08:00][INFO][75227 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] ./TabNine --log_to_stderr --no_bootstrap
[2020-12-07T10:22:59.777722-08:00][INFO][75227 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T10:22:59.945663-08:00][INFO][75227 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T10:22:59.945669-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Remote)
[2020-12-07T10:22:59.948510-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T10:23:00.014201-08:00][INFO][75227 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(75)] TabNine Local communication thread started.
[2020-12-07T10:23:00.014225-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Local)
[2020-12-07T10:23:00.014292-08:00][INFO][75227 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(13)] Loading model...
[2020-12-07T10:23:00.014347-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T10:23:00.014319-08:00][INFO][75227 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T10:23:00.014448-08:00][INFO][75227 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(15)] Trying to lock: "/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/model.lock"
[2020-12-07T10:23:00.014556-08:00][INFO][75227 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(17)] Lock acquired, performing the inner action
[2020-12-07T10:23:00.014555-08:00][INFO][75227 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/experiment_converged_default.prefs.json")
[2020-12-07T10:23:00.014587-08:00][INFO][75227 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(173)] Starting download (last_failure=None).
[2020-12-07T10:23:00.014741-08:00][WARN][75227 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T10:23:00.014820-08:00][INFO][75227 main][frontend][Some("tabnine/frontend/src/lib.rs")][Some(86)] Started.
[2020-12-07T10:23:00.015034-08:00][INFO][75227 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(719)] Loaded cached metadata.
[2020-12-07T10:23:00.015043-08:00][INFO][75227 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(715)] Checking for metadata update in background...
[2020-12-07T10:23:00.015072-08:00][INFO][75227 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(214)] Attempting to load deep model (attempt: #1)
[2020-12-07T10:23:00.015138-08:00][INFO][75227 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(352)] Trying to load cached model from "/Users/gabe/Library/Application Support/TabNine/models/b8373e4b.tabninemodel"
[2020-12-07T10:23:00.384639-08:00][INFO][75226 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(251)] current version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), spawned version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), remote version is Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }
[2020-12-07T10:23:00.484329-08:00][INFO][75226 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T10:23:00.484491-08:00][INFO][75226 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(323)] don't need to upgrade
[2020-12-07T10:23:00.553477-08:00][INFO][75227 metadata-updater][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-07T10:23:00.694366-08:00][INFO][75227 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(269)] Downloaded model metadata [hash=b8373e4b].
[2020-12-07T10:23:00.777726-08:00][INFO][75227 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T10:23:01.660243-08:00][INFO][75227 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(21)] Releasing lock: "/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/model.lock"
[2020-12-07T10:23:01.711240-08:00][INFO][75227 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(17)] Done loading model (took 1.70 seconds).
[2020-12-07T10:23:01.807793-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 32 ms to evaluate 1 token.
[2020-12-07T10:23:01.875327-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 22 ms to evaluate 1 token.
[2020-12-07T10:23:01.949909-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 24 ms to evaluate 1 token.
[2020-12-07T10:23:02.019827-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 23 ms to evaluate 1 token.
[2020-12-07T10:23:02.096625-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 25 ms to evaluate 2 tokens.
[2020-12-07T10:23:02.189437-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 30 ms to evaluate 3 tokens.
[2020-12-07T10:23:02.189529-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(25)] Selected 1 beams.
[2020-12-07T10:23:02.496965-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 102 ms to evaluate 16 tokens.
[2020-12-07T10:23:02.497056-08:00][INFO][75227 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(27)] Selected context length of 80.
[2020-12-07T10:23:19.808122-08:00][INFO][75227 update_loop][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/version/v1
[2020-12-07T10:23:19.912993-08:00][INFO][75227 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(662)] Server did not respond with version, so using default URL.
[2020-12-07T10:23:19.918837-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183[)] lunar settings detected config modified (Remote2020-12-07T10:23:19.918847-08:00)][
INFO][75226 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs[")][Some(697)2020-12-07T10:23:19.918853-08:00] ][config path: INFO/Users/gabe/Library/Preferences/TabNine/tabnine_config.json][
75227 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T10:23:19.918848-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T10:23:19.919031-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T10:23:19.919033-08:00][INFO][75227 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T10:23:19.919042-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T10:23:19.989195-08:00][INFO][75227 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(328)] Current version is 3.2.37, remote has version 3.1.17.
[[2020-12-07T10:23:20.021577-08:002020-12-07T10:23:20.021590-08:00][][INFOINFO][][7522675227  threadthread][][updater::global_configupdater::global_config][][SomeSome((""tabnine/updater/src/global_config.rstabnine/updater/src/global_config.rs""))][][SomeSome((697697))] ] config path: config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json/Users/gabe/Library/Preferences/TabNine/tabnine_config.json

[2020-12-07T10:23:20.021591-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-07T10:23:20.021594-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T10:23:20.021746-08:00][INFO][75227 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T10:23:20.021749-08:00][INFO][75227 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T10:23:20.021761-08:00][INFO][75227 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings

@yonip23
Copy link

yonip23 commented Dec 7, 2020

Thanks for the logs guys, we will investigate this and get back to you asap

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

This part of the log may be relevant. Looks like the process was killed because the memory exceeded.

[2020-12-07T10:28:23.320396-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(251)] killing process 75298-TabNine because memory exceeded: 2734718
[2020-12-07T10:28:31.905824-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 75297-TabNine
[2020-12-07T10:28:32.040242-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 75298-TabNine

Thats strange because I have lots of memory on my system
Screen Shot 2020-12-07 at 10 36 49 AM

@amircodota
Copy link
Collaborator

@gogoprog your log indicates that you ran the 2.9.2 version while you have newer versions in the binaries directory.
Can you list all the directories in your binaries directory, and then run TabNine --log_to_stderr from the latest version directory?

@amircodota
Copy link
Collaborator

@gabesoft TabNine has a watchdog component that will kill tabnine if it consumes too much memory. This can happen on occasion but it should not happen too often.
In your case, it seems you are running under pid 251, and killing pid 75298. So it seems it is killing some other tabnine process that you have running.

Do you see the tabnine process being killed and exit?
If you have some other tabnine process, do you know what version it is?
Does it constantly happen?

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

I think the other one was the one serving the config page. I had that open at the time.

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

It's been happening pretty often for me. I usually re-start the process by running YcmRestartServer in vim and after that the process only stays on for a bit before it crashes again.

@amircodota
Copy link
Collaborator

@gabesoft can you describe the issue. When you open vim - does tabnine immediately crash or does it run for a while before crashing?
Can you output the command line arguments that are given to the tabnine process? You can probably see it in ps or in /proc/{pid}/cmdline

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

It runs for a very short time before crashing. I usually restart it via YcmRestartServer but then it dies again after a few minutes or so.

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

It just happened again. I had re-started it a couple of mins ago and now it's already dead with the same log message

[2020-12-07T12:19:54.185145-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(251)] killing process 94540-TabNine because memory exceeded: 2498932
[2020-12-07T12:20:02.758447-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 94540-TabNine
[2020-12-07T12:20:04.321215-08:00][INFO][75226 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 94539-TabNine

Although, I wonder why there are two processes being killed. This time I didn't have the config running.

@amircodota
Copy link
Collaborator

Can you output the command line arguments that are given to the tabnine process? You can probably see it in ps or in /proc/{pid}/cmdline

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

Here's the output of ps aux

gabe             95589   0.0  1.1 10100844 2252736   ??  S    12:22PM   2:12.03 /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --no_bootstrap
gabe             95588   0.0  0.0  7937112  15152   ??  S    12:22PM   0:00.49 /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log

@amircodota
Copy link
Collaborator

can you run

/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --log_to_stderr

and paste the output here?

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

[I] ~/.v/p/t/b/3/x86_64-apple-darwin|master✓ ➤ /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --log_to_stderr
[2020-12-07T12:28:46.854250-08:00][INFO][96175 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --log_to_stderr
[2020-12-07T12:28:46.854911-08:00][INFO][96175 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T12:28:46.855051-08:00][WARN][96175 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:28:46.855102-08:00][INFO][96175 main][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(91)] config is BootstrapConfig { bootstrapper_enabled: true, api_endpoint: "https://api.tabnine.com/experiments/register/v2", registration_interval_seconds: 3600, bark_interval_seconds: 2, force_version: None }
[2020-12-07T12:28:46.855254-08:00][INFO][96175 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:28:46.858110-08:00][INFO][96175 main][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:28:47.382624-08:00][INFO][96175 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:28:47.481144-08:00][INFO][96175 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T12:28:47.521451-08:00][INFO][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:28:47.521604-08:00][INFO][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/tabnine_version_3.2.37.prefs.json")
[2020-12-07T12:28:47.521769-08:00][INFO][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T12:28:47.521872-08:00][WARN][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:28:47.521912-08:00][INFO][96175 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(197)] trying to start tabnine version Some("3.2.37")
[2020-12-07T12:28:47.521949-08:00][INFO][96175 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(272)] spawning tabnine with args ["/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine", "--client=vim", "--port=56895", "--options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll", "--log=info", "--idle_suicide_seconds=1800", "--stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log", "--stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log", "--log_to_stderr", "--no_bootstrap"]
[2020-12-07T12:28:47.522806-08:00][INFO][96175 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(276)] started tabnine process pid 96176 version Some("3.2.37"), desired version was Some("3.2.37") this version is Some("3.2.37")
[2020-12-07T12:28:47.522906-08:00][INFO][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:28:47.527161-08:00][INFO][96176 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --log_to_stderr --no_bootstrap
[2020-12-07T12:28:47.527917-08:00][INFO][96176 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T12:28:47.575898-08:00][INFO][96176 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(311)] Port 56895 was provided. Emulating YCMD.
[2020-12-07T12:28:47.667546-08:00][INFO][96176 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:28:47.667551-08:00][INFO][96176 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Remote)
[2020-12-07T12:28:47.670370-08:00][INFO][96176 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T12:28:47.733132-08:00][INFO][96176 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(75)] TabNine Local communication thread started.
[2020-12-07T12:28:47.733154-08:00][INFO][96176 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Local)
[2020-12-07T12:28:47.733212-08:00][INFO][96176 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(13)] Loading model...
[2020-12-07T12:28:47.733259-08:00][INFO][96176 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:28:47.733278-08:00][INFO][96176 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T12:28:47.733352-08:00][INFO][96176 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(15)] Trying to lock: "/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/model.lock"
[2020-12-07T12:28:47.733439-08:00][INFO][96176 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/experiment_converged_default.prefs.json")
[2020-12-07T12:28:47.733477-08:00][INFO][96176 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(17)] Lock acquired, performing the inner action
[2020-12-07T12:28:47.733606-08:00][INFO][96176 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(173)] Starting download (last_failure=None).
[2020-12-07T12:28:47.733601-08:00][WARN][96176 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:28:47.733694-08:00][INFO][96176 main][frontend::ycmd_emulation][Some("tabnine/frontend/src/ycmd_emulation/mod.rs")][Some(180)] Listening at 127.0.0.1:56895
[2020-12-07T12:28:47.733940-08:00][INFO][96176 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(719)] Loaded cached metadata.
[2020-12-07T12:28:47.733948-08:00][INFO][96176 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(715)] Checking for metadata update in background...
[2020-12-07T12:28:47.733977-08:00][INFO][96176 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(214)] Attempting to load deep model (attempt: #1)
[2020-12-07T12:28:47.734052-08:00][INFO][96176 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(352)] Trying to load cached model from "/Users/gabe/Library/Application Support/TabNine/models/b8373e4b.tabninemodel"
[2020-12-07T12:28:47.736082-08:00][ERROR][96176 main][panic_handling][Some("tabnine/panic_handling/src/lib.rs")][Some(25)] PanicInfo { payload: Any, message: Some(called `Result::unwrap()` on an `Err` value: Io(Os { code: 48, kind: AddrInUse, message: "Address already in use" })), location: Location { file: "/Users/build/BuildAgent/work/d809493a888d62cc/tabnine/frontend/src/ycmd_emulation/mod.rs", line: 182, col: 48 } }, stack backtrace:
   0: <unknown> (0x10d324d9c)
   1: <unknown> (0x10d32404a)
   2: <unknown> (0x10d73dafa)
   3: <unknown> (0x10d9e0de5)
   4: <unknown> (0x10d9e53ca)
   5: <unknown> (0x10dbafd8f)
   6: <unknown> (0x10dbb0305)
   7: <unknown> (0x10d2bb2b6)
   8: <unknown> (0x10d295e10)
   9: <unknown> (0x10d9fb6e6)
  10: <unknown> (0x10d29700c)
[2020-12-07T12:28:48.136514-08:00][INFO][96175 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(251)] current version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), spawned version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), remote version is Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }
[2020-12-07T12:28:48.231347-08:00][INFO][96175 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:28:48.231504-08:00][INFO][96175 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(323)] don't need to upgrade
[2020-12-07T12:28:48.259397-08:00][INFO][96176 metadata-updater][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-07T12:28:48.524339-08:00][INFO][96175 bs_monitor][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(312)] child process 96176 exited...

@amircodota
Copy link
Collaborator

amircodota commented Dec 7, 2020

Sorry, I used the same port as the other process. Let's change the port

/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56995 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stderr_sjeddcwq.log --log_to_stderr

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

[I] ~/.v/p/t/b/3/x86_64-apple-darwin|master✓ ➤ /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56995 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stderr_sjeddcwq.log --log_to_stderr
[2020-12-07T12:31:52.730736-08:00][INFO][96405 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56995 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stderr_sjeddcwq.log --log_to_stderr
[2020-12-07T12:31:52.731488-08:00][INFO][96405 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T12:31:52.731613-08:00][WARN][96405 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:31:52.731663-08:00][INFO][96405 main][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(91)] config is BootstrapConfig { bootstrapper_enabled: true, api_endpoint: "https://api.tabnine.com/experiments/register/v2", registration_interval_seconds: 3600, bark_interval_seconds: 2, force_version: None }
[2020-12-07T12:31:52.731786-08:00][INFO][96405 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:31:52.735070-08:00][INFO][96405 main][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:31:53.285178-08:00][INFO][96405 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:31:53.371609-08:00][INFO][96405 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T12:31:53.425857-08:00][INFO][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:31:53.426021-08:00][INFO][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/tabnine_version_3.2.37.prefs.json")
[2020-12-07T12:31:53.426190-08:00][INFO][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T12:31:53.426295-08:00][WARN][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:31:53.426355-08:00][INFO][96405 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(197)] trying to start tabnine version Some("3.2.37")
[2020-12-07T12:31:53.426391-08:00][INFO][96405 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(272)] spawning tabnine with args ["/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine", "--client=vim", "--port=56995", "--options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll", "--log=info", "--idle_suicide_seconds=1800", "--stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stdout_0wom12gc.log", "--stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stderr_sjeddcwq.log", "--log_to_stderr", "--no_bootstrap"]
[2020-12-07T12:31:53.427244-08:00][INFO][96405 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(276)] started tabnine process pid 96406 version Some("3.2.37"), desired version was Some("3.2.37") this version is Some("3.2.37")
[2020-12-07T12:31:53.427353-08:00][INFO][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:31:53.431552-08:00][INFO][96406 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56995 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56995_stderr_sjeddcwq.log --log_to_stderr --no_bootstrap
[2020-12-07T12:31:53.432262-08:00][INFO][96406 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T12:31:53.488723-08:00][INFO][96406 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(311)] Port 56995 was provided. Emulating YCMD.
[2020-12-07T12:31:53.580904-08:00][INFO][96406 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:31:53.580909-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Remote)
[2020-12-07T12:31:53.583623-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T12:31:53.646889-08:00][INFO][96406 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(75)] TabNine Local communication thread started.
[2020-12-07T12:31:53.646916-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Local)
[2020-12-07T12:31:53.646977-08:00][INFO][96406 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:31:53.646963-08:00][INFO][96406 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(13)] Loading model...
[2020-12-07T12:31:53.647035-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T12:31:53.647186-08:00][INFO][96406 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/experiment_converged_default.prefs.json")
[2020-12-07T12:31:53.647230-08:00][INFO][96406 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(15)] Trying to lock: "/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/model.lock"
[2020-12-07T12:31:53.647305-08:00][WARN][96406 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T12:31:53.647375-08:00][INFO][96406 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(17)] Lock acquired, performing the inner action
[2020-12-07T12:31:53.647422-08:00][INFO][96406 main][frontend::ycmd_emulation][Some("tabnine/frontend/src/ycmd_emulation/mod.rs")][Some(180)] Listening at 127.0.0.1:56995
[2020-12-07T12:31:53.647447-08:00][INFO][96406 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(173)] Starting download (last_failure=None).
[2020-12-07T12:31:53.647756-08:00][INFO][96406 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(719)] Loaded cached metadata.
[2020-12-07T12:31:53.647763-08:00][INFO][96406 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(715)] Checking for metadata update in background...
[2020-12-07T12:31:53.647795-08:00][INFO][96406 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(214)] Attempting to load deep model (attempt: #1)
[2020-12-07T12:31:53.647897-08:00][INFO][96406 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(352)] Trying to load cached model from "/Users/gabe/Library/Application Support/TabNine/models/b8373e4b.tabninemodel"
[2020-12-07T12:31:54.053478-08:00][INFO][96405 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(251)] current version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), spawned version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), remote version is Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }
[2020-12-07T12:31:54.138917-08:00][INFO][96405 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/Users/gabe/Library/Application Support/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T12:31:54.139079-08:00][INFO][96405 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(323)] don't need to upgrade
[2020-12-07T12:31:54.184894-08:00][INFO][96406 metadata-updater][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-07T12:31:54.328750-08:00][INFO][96406 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(269)] Downloaded model metadata [hash=b8373e4b].
[2020-12-07T12:31:54.436102-08:00][INFO][96406 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:31:55.286608-08:00][INFO][96406 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(21)] Releasing lock: "/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/model.lock"
[2020-12-07T12:31:55.335588-08:00][INFO][96406 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(17)] Done loading model (took 1.69 seconds).
[2020-12-07T12:31:55.385244-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 16 ms to evaluate 1 token.
[2020-12-07T12:31:55.430731-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 15 ms to evaluate 1 token.
[2020-12-07T12:31:55.477199-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 15 ms to evaluate 1 token.
[2020-12-07T12:31:55.520637-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 14 ms to evaluate 1 token.
[2020-12-07T12:31:55.589662-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 22 ms to evaluate 2 tokens.
[2020-12-07T12:31:55.647605-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 19 ms to evaluate 3 tokens.
[2020-12-07T12:31:55.647689-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(25)] Selected 1 beams.
[2020-12-07T12:31:55.849744-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 67 ms to evaluate 16 tokens.
[2020-12-07T12:31:55.849830-08:00][INFO][96406 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(27)] Selected context length of 128.
[2020-12-07T12:32:13.463780-08:00][INFO][96406 update_loop][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/version/v1
[2020-12-07T12:32:13.546354-08:00][INFO][96406 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(662)] Server did not respond with version, so using default URL.
[2020-12-07T12:32:13.571427-08:00][INFO][96406[ thread2020-12-07T12:32:13.571454-08:00][][updater::global_configINFO][][Some96405( "threadtabnine/updater/src/global_config.rs]["updater::global_config)][][SomeSome(("697)tabnine/updater/src/global_config.rs] "config path: )/Users/gabe/Library/Preferences/TabNine/tabnine_config.json][Some(697)
] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:32:13.571450-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T12:32:13.571432-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-07T12:32:13.571614-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T12:32:13.571616-08:00][INFO][96406 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:32:13.571626-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[[2020-12-07T12:32:13.675536-08:00][INFO2020-12-07T12:32:13.675535-08:00][][96405INFO ][thread96406][ updater::global_configthread][][Someupdater::global_config(]["Sometabnine/updater/src/global_config.rs("")][tabnine/updater/src/global_config.rsSome")][Some(697)(] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json[
2020-12-07T12:32:13.675626-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-07T12:32:13.675599-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T12:32:13.675729-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T12:32:13.675733-08:00][INFO][96406 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:32:13.675742-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T12:32:13.683358-08:00][INFO][96406 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(328)] Current version is 3.2.37, remote has version 3.1.17.
[2020-12-07T12:33:41.552411-08:00][INFO][96405 bs_main_autobarker][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(145)] Starting watchdog...
[2020-12-07T12:33:41.552557-08:00][INFO][96405 thread][watchdog_server][Some("tabnine/watchdog_server/src/lib.rs")][Some(55)] watchdog is locking path: /Users/gabe/Library/Application Support/TabNine/monitoring/watchdog.lock
[2020-12-07T12:33:42.141025-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 96406-TabNine
[2020-12-07T12:33:42.229561-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 96405-TabNine

@amircodota
Copy link
Collaborator

This should create two processes. Can you check how much memory they consume?

Let's give it a few minutes and see if it stays up

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

They already died:

[2020-12-07T12:35:27.007187-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 96628-TabNine
[2020-12-07T12:35:27.527865-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 96627-TabNine
[[2020-12-07T12:35:43.825825-08:002020-12-07T12:35:43.825836-08:00][][INFOINFO][][9640596406  threadthread][][updater::global_configupdater::global_config][][SomeSome((""tabnine/updater/src/global_config.rstabnine/updater/src/global_config.rs""))][][SomeSome((697697))] ] config path: config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json/Users/gabe/Library/Preferences/TabNine/tabnine_config.json

[2020-12-07T12:35:43.825873-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-07T12:35:43.825878-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T12:35:43.826066-08:00][INFO][96406 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:35:43.826092-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T12:35:43.826064-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[[2020-12-07T12:35:43.929228-08:002020-12-07T12:35:43.929235-08:00][][INFOINFO][][9640596406  threadthread][][updater::global_configupdater::global_config][][SomeSome("tabnine/updater/src/global_config.rs")][Some((697")tabnine/updater/src/global_config.rs] "config path: )/Users/gabe/Library/Preferences/TabNine/tabnine_config.json][
Some(697)] config path: /Users/gabe/Library/Preferences/TabNine/tabnine_config.json
[2020-12-07T12:35:43.929240-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-07T12:35:43.929235-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-07T12:35:43.929397-08:00][INFO][96406 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T12:35:43.929413-08:00][INFO][96406 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T12:35:44.337904-08:00][INFO][96406 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T12:37:28.792359-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(251)] killing process 96628-TabNine because memory exceeded: 3418669
[2020-12-07T12:37:37.349235-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 96628-TabNine
[2020-12-07T12:37:37.494652-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(192)] stop watching process 96627-TabNine

@gabesoft
Copy link
Author

gabesoft commented Dec 7, 2020

The one remaining process is using about 1GB

Screen Shot 2020-12-07 at 12 39 13 PM

@gogoprog
Copy link

gogoprog commented Dec 7, 2020

@gogoprog your log indicates that you ran the 2.9.2 version while you have newer versions in the binaries directory.
Can you list all the directories in your binaries directory, and then run TabNine --log_to_stderr from the latest version directory?

Directories in binaries:

± % ls                                                                                                                                                               
0.0.1   2.1.21  2.2.1  2.3.5  2.6.0  2.8.3  2.8.6  2.8.12  2.9.4  3.0.6  3.0.9   3.1.2  3.1.6  3.1.11  3.1.20  3.2.18  3.2.22  3.2.26  3.2.37
2.1.17  2.1.22  2.2.2  2.3.6  2.7.0  2.8.4  2.8.7  2.9.2   2.9.6  3.0.7  3.0.12  3.1.4  3.1.8  3.1.14  3.1.21  3.2.19  3.2.23  3.2.28  
2.1.20  2.2.0   2.3.4  2.3.7  2.8.2  2.8.5  2.8.9  2.9.3   3.0.4  3.0.8  3.1.1   3.1.5  3.1.9  3.1.19  3.2.13  3.2.20  3.2.25  3.2.34 

Command output:

± % ./TabNine --log_to_stderr                                                                                                                                             !10012
[2020-12-07T21:46:39.128188078+01:00][INFO][2111215 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] ./TabNine --log_to_stderr
[2020-12-07T21:46:39.128304118+01:00][INFO][2111215 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T21:46:39.128435918+01:00][WARN][2111215 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T21:46:39.128492958+01:00][INFO][2111215 main][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(91)] config is BootstrapConfig { bootstrapper_enabled: true, api_endpoint: "https://api.tabnine.com/experiments/register/v2", registration_interval_seconds: 3600, bark_interval_seconds: 2, force_version: None }
[2020-12-07T21:46:39.128655799+01:00][INFO][2111215 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-07T21:46:39.129296350+01:00][INFO][2111215 main][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T21:46:39.786716945+01:00][INFO][2111215 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T21:46:39.916761683+01:00][INFO][2111215 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T21:46:40.079922323+01:00][INFO][2111215 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(145)] Starting watchdog...
[2020-12-07T21:46:40.080313184+01:00][INFO][2111215 thread][watchdog_server][Some("tabnine/watchdog_server/src/lib.rs")][Some(55)] watchdog is locking path: /home/gogoprog/.config/TabNine/monitoring/watchdog.lock
[2020-12-07T21:46:40.080381094+01:00][INFO][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T21:46:40.080553485+01:00][INFO][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/tabnine_version_3.2.37.prefs.json")
[2020-12-07T21:46:40.082945191+01:00][INFO][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-07T21:46:40.083005821+01:00][WARN][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T21:46:40.083034981+01:00][INFO][2111215 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(197)] trying to start tabnine version Some("3.2.37")
[2020-12-07T21:46:40.083064721+01:00][INFO][2111215 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(272)] spawning tabnine with args ["./TabNine", "--log_to_stderr", "--no_bootstrap"]
[2020-12-07T21:46:40.086635830+01:00][INFO][2111215 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(276)] started tabnine process pid 2111256 version Some("3.2.37"), desired version was Some("3.2.37") this version is Some("3.2.37")
[2020-12-07T21:46:40.086809641+01:00][INFO][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T21:46:40.087319602+01:00][INFO][2111256 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] ./TabNine --log_to_stderr --no_bootstrap
[2020-12-07T21:46:40.087782523+01:00][INFO][2111256 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-07T21:46:40.252972279+01:00][INFO][2111215 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2111256-TabNine
[2020-12-07T21:46:40.389638283+01:00][INFO][2111215 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2111215-TabNine
[2020-12-07T21:46:40.412947071+01:00][INFO][2111256 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-07T21:46:40.415296467+01:00][INFO][2111256 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Remote)
[2020-12-07T21:46:40.415602648+01:00][INFO][2111256 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-07T21:46:40.476602152+01:00][INFO][2111256 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T21:46:40.476707352+01:00][INFO][2111256 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/experiment_converged_default.prefs.json")
[2020-12-07T21:46:40.476805732+01:00][WARN][2111256 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-07T21:46:40.476313591+01:00][INFO][2111256 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(75)] TabNine Local communication thread started.
[2020-12-07T21:46:40.476904852+01:00][INFO][2111256 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(13)] Loading model...
[2020-12-07T21:46:40.476849142+01:00][INFO][2111256 main][frontend][Some("tabnine/frontend/src/lib.rs")][Some(86)] Started.
[2020-12-07T21:46:40.476954663+01:00][INFO][2111256 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(15)] Trying to lock: "/tmp/model.lock"
[2020-12-07T21:46:40.476991663+01:00][INFO][2111256 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(17)] Lock acquired, performing the inner action
[2020-12-07T21:46:40.477013963+01:00][INFO][2111256 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(173)] Starting download (last_failure=None).
[2020-12-07T21:46:40.476894162+01:00][INFO][2111256 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Local)
[2020-12-07T21:46:40.477217423+01:00][INFO][2111256 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-07T21:46:40.480075240+01:00][INFO][2111256 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(719)] Loaded cached metadata.
[2020-12-07T21:46:40.480106970+01:00][INFO][2111256 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(214)] Attempting to load deep model (attempt: #1)
[2020-12-07T21:46:40.480143330+01:00][INFO][2111256 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(352)] Trying to load cached model from "/home/gogoprog/.local/share/TabNine/models/b8373e4b.tabninemodel"
[2020-12-07T21:46:40.480163500+01:00][INFO][2111256 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(715)] Checking for metadata update in background...
[2020-12-07T21:46:40.847474865+01:00][INFO][2111215 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(251)] current version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), spawned version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), remote version is Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }
[2020-12-07T21:46:40.993033591+01:00][INFO][2111215 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-07T21:46:40.993154282+01:00][INFO][2111215 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(323)] don't need to upgrade
[2020-12-07T21:46:41.092591022+01:00][INFO][2111256 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-07T21:46:41.118075086+01:00][INFO][2111256 metadata-updater][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-07T21:46:41.453213040+01:00][INFO][2111256 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(269)] Downloaded model metadata [hash=b8373e4b].
[2020-12-07T21:46:42.590443332+01:00][INFO][2111256 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(21)] Releasing lock: "/tmp/model.lock"
[2020-12-07T21:46:42.645359310+01:00][INFO][2111256 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(17)] Done loading model (took 2.17 seconds).
[2020-12-07T21:46:42.701925362+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 18 ms to evaluate 1 token.
[2020-12-07T21:46:42.754127674+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 17 ms to evaluate 1 token.
[2020-12-07T21:46:42.806905307+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 17 ms to evaluate 1 token.
[2020-12-07T21:46:42.860301121+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 17 ms to evaluate 1 token.
[2020-12-07T21:46:42.918060187+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 19 ms to evaluate 2 tokens.
[2020-12-07T21:46:42.981843087+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 21 ms to evaluate 3 tokens.
[2020-12-07T21:46:42.981936507+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(25)] Selected 1 beams.
[2020-12-07T21:46:43.255518746+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 91 ms to evaluate 16 tokens.
[2020-12-07T21:46:43.255601646+01:00][INFO][2111256 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(27)] Selected context length of 96.

@amircodota
Copy link
Collaborator

Both the logs seem fine.

@gogoprog Did the process exit or did it keep running?

@gabesoft In your case, your pid is 96405, and tabnine is killing another pid 96628, which exceeded memory.
Did 96405 just exit? did it output some error?
Any idea where 96628 came from? Do you have another vim open? If yes, is it a big project with many files? Can you give some data on its size?

[2020-12-07T12:37:28.792359-08:00][INFO][96405 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(251)] killing process 96628-TabNine because memory exceeded: 3418669

@gogoprog
Copy link

gogoprog commented Dec 8, 2020

Both the logs seem fine.

@gogoprog Did the process exit or did it keep running?

It kept running

@amircodota
Copy link
Collaborator

@gogoprog A few requests/questions:

  1. How long does it take for tabnine to crash? Does it happen immediately when you start vim or does it happen after a while? Can you share more details about your project? what language? Is it a big project? How many source files does it have roughly? Did something change in the project recently? For example, maybe the code size grew.

  2. can you run TabNine with the same arguments that the vim plugin does?
    The best way to achieve this is to open vim and then use ps or view /proc/{pid}/cmdline.
    Once you do, change the port number, and add --log_to_stderr.

For example, @gabesoft had

/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56895 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log

and he changed it to

/Users/gabe/.vim/plugs/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-apple-darwin/TabNine --client=vim --port=56995 --options_file=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/tmporfh9vll --log=info --idle_suicide_seconds=1800 --stdout=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stdout_0wom12gc.log --stderr=/var/folders/k3/8j6c46gj37ngfqk8g7cqhyl40000gn/T/ycmd_56895_stderr_sjeddcwq.log --log_to_stderr

Thanks

@gogoprog
Copy link

gogoprog commented Dec 8, 2020

@amircodota

  1. Not immediately, around 5 minutes after startup.
    It happens when doing very small C++ projects (advent of code, only 1 source code file). It also happens on medium-sized project using the language Haxe. So not related to code size.

  2. /home/gogoprog/.vim/bundle/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-unknown-linux-musl/TabNine --client=vim --port=54018 --options_file=/tmp/tmp7og00_d0 --log=info --idle_suicide_seconds=1800 --stdout=/tmp/ycmd_54017_stdout_qch7a7r7.log --stderr=/tmp/ycmd_54017_stderr_pafyh5kn.log --log_to_stderr outputs

[2020-12-08T10:41:29.733179487+01:00][INFO][2247138 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /home/gogoprog/.vim/bundle/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-unknown-linux-musl/TabNine --client=vim --port=54018 --options_file=/tmp/tmp7og00_d0 --log=info --idle_suicide_seconds=1800 --stdout=/tmp/ycmd_54017_stdout_qch7a7r7.log --stderr=/tmp/ycmd_54017_stderr_pafyh5kn.log --log_to_stderr
[2020-12-08T10:41:29.733287087+01:00][INFO][2247138 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-08T10:41:29.733447678+01:00][WARN][2247138 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-08T10:41:29.733535458+01:00][INFO][2247138 main][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(91)] config is BootstrapConfig { bootstrapper_enabled: true, api_endpoint: "https://api.tabnine.com/experiments/register/v2", registration_interval_seconds: 3600, bark_interval_seconds: 2, force_version: None }
[2020-12-08T10:41:29.733705858+01:00][INFO][2247138 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:41:29.734309320+01:00][INFO][2247138 main][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:41:30.365044160+01:00][INFO][2247138 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-08T10:41:30.482056444+01:00][INFO][2247138 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-08T10:41:30.743677573+01:00][INFO][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-08T10:41:30.743937224+01:00][INFO][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/tabnine_version_3.2.37.prefs.json")
[2020-12-08T10:41:30.744101154+01:00][INFO][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/bootstrapper_conf.prefs.json")
[2020-12-08T10:41:30.744268134+01:00][WARN][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-08T10:41:30.744378465+01:00][INFO][2247138 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(197)] trying to start tabnine version Some("3.2.37")
[2020-12-08T10:41:30.744447325+01:00][INFO][2247138 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(272)] spawning tabnine with args ["/home/gogoprog/.vim/bundle/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-unknown-linux-musl/TabNine", "--client=vim", "--port=54018", "--options_file=/tmp/tmp7og00_d0", "--log=info", "--idle_suicide_seconds=1800", "--stdout=/tmp/ycmd_54017_stdout_qch7a7r7.log", "--stderr=/tmp/ycmd_54017_stderr_pafyh5kn.log", "--log_to_stderr", "--no_bootstrap"]
[2020-12-08T10:41:30.748722604+01:00][INFO][2247138 bs_main_rlp][TabNine::bootstrap_support][Some("tabnine/frontend/src/bootstrap_support.rs")][Some(276)] started tabnine process pid 2247190 version Some("3.2.37"), desired version was Some("3.2.37") this version is Some("3.2.37")
[2020-12-08T10:41:30.748969145+01:00][INFO][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-08T10:41:30.749373116+01:00][INFO][2247190 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(346)] /home/gogoprog/.vim/bundle/tabnine-vim/python/ycm/../../binaries/3.2.37/x86_64-unknown-linux-musl/TabNine --client=vim --port=54018 --options_file=/tmp/tmp7og00_d0 --log=info --idle_suicide_seconds=1800 --stdout=/tmp/ycmd_54017_stdout_qch7a7r7.log --stderr=/tmp/ycmd_54017_stderr_pafyh5kn.log --log_to_stderr --no_bootstrap
[2020-12-08T10:41:30.749737577+01:00][INFO][2247190 main][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(47)] Initializing watchdog client...
[2020-12-08T10:41:30.942962362+01:00][INFO][2247190 main][TabNine][Some("tabnine/frontend/src/main.rs")][Some(311)] Port 54018 was provided. Emulating YCMD.
[2020-12-08T10:41:31.069029846+01:00][INFO][2247190 main][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:41:31.070236409+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Remote)
[2020-12-08T10:41:31.070479839+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:41:31.127186787+01:00][INFO][2247190 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(75)] TabNine Local communication thread started.
[2020-12-08T10:41:31.127261427+01:00][INFO][2247190 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-08T10:41:31.127332127+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(168)] lunar settings update thread started (Local)
[2020-12-08T10:41:31.127298257+01:00][INFO][2247190 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(13)] Loading model...
[2020-12-08T10:41:31.127577188+01:00][INFO][2247190 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(15)] Trying to lock: "/tmp/model.lock"
[2020-12-08T10:41:31.127609168+01:00][INFO][2247190 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(17)] Lock acquired, performing the inner action
[2020-12-08T10:41:31.127630668+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:41:31.127636588+01:00][INFO][2247190 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(173)] Starting download (last_failure=None).
[2020-12-08T10:41:31.127417328+01:00][INFO][2247190 main][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/experiment_converged_default.prefs.json")
[2020-12-08T10:41:31.128057369+01:00][WARN][2247190 main][defaults][Some("shared/defaults/src/lib.rs")][Some(109)] had an error deserializing object Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2020-12-08T10:41:31.128093359+01:00][INFO][2247190 main][frontend::ycmd_emulation][Some("tabnine/frontend/src/ycmd_emulation/mod.rs")][Some(180)] Listening at 127.0.0.1:54018
[2020-12-08T10:41:31.128192489+01:00][INFO][2247190 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(719)] Loaded cached metadata.
[2020-12-08T10:41:31.128218699+01:00][INFO][2247190 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(214)] Attempting to load deep model (attempt: #1)
[2020-12-08T10:41:31.128261669+01:00][INFO][2247190 local-forwarder][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(352)] Trying to load cached model from "/home/gogoprog/.local/share/TabNine/models/b8373e4b.tabninemodel"
[2020-12-08T10:41:31.128270369+01:00][INFO][2247190 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(715)] Checking for metadata update in background...
[2020-12-08T10:41:31.524744653+01:00][INFO][2247138 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(251)] current version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), spawned version is Some(Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }), remote version is Version { major: 3, minor: 2, patch: 37, pre: [], build: [] }
[2020-12-08T10:41:31.661333540+01:00][INFO][2247138 bs_main_rlp][defaults][Some("shared/defaults/src/lib.rs")][Some(99)] getting value from path Ok("/home/gogoprog/.config/TabNine/defaults/active_experiment.prefs.json")
[2020-12-08T10:41:31.661514441+01:00][INFO][2247138 bs_main_rlp][bootstrapper::bootstrapper_lib][Some("tabnine/bootstrapper/src/bootstrapper_lib.rs")][Some(323)] don't need to upgrade
[2020-12-08T10:41:31.753638458+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:41:31.829624930+01:00][INFO][2247190 metadata-updater][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/model_metadata/v1
[2020-12-08T10:41:32.198113320+01:00][INFO][2247190 metadata-updater][lunar_local::downloader][Some("deep/lunar_local/src/downloader.rs")][Some(269)] Downloaded model metadata [hash=b8373e4b].
[2020-12-08T10:41:32.988112989+01:00][INFO][2247190 local-forwarder][lunar_local::locker][Some("deep/lunar_local/src/locker.rs")][Some(21)] Releasing lock: "/tmp/model.lock"
[2020-12-08T10:41:33.046054230+01:00][INFO][2247190 local-forwarder][lunar_local::bridge][Some("deep/lunar_local/src/bridge.rs")][Some(17)] Done loading model (took 1.92 seconds).
[2020-12-08T10:41:33.108410990+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 20 ms to evaluate 1 token.
[2020-12-08T10:41:33.164081516+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 18 ms to evaluate 1 token.
[2020-12-08T10:41:33.220440923+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 18 ms to evaluate 1 token.
[2020-12-08T10:41:33.275636337+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 18 ms to evaluate 1 token.
[2020-12-08T10:41:33.335189581+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 19 ms to evaluate 2 tokens.
[2020-12-08T10:41:33.402355333+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 22 ms to evaluate 3 tokens.
[2020-12-08T10:41:33.402429813+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(25)] Selected 2 beams.
[2020-12-08T10:41:33.667066030+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(73)] Model took 88 ms to evaluate 16 tokens.
[2020-12-08T10:41:33.667150300+01:00][INFO][2247190 local-forwarder][lunar_local::tune][Some("deep/lunar_local/src/tune.rs")][Some(27)] Selected context length of 96.
[2020-12-08T10:41:50.854146950+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified ([Remote)
2020-12-08T10:41:50.854182720+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs"[)][Some(6972020-12-08T10:41:50.854161310+01:00)][] INFOconfig path: ][/home/gogoprog/.config/TabNine/tabnine_config.json2247190
 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:41:50.854146810+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:41:50.854582941+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:41:50.854622021+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:41:50.854595971+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:41:50.928093927+01:00][INFO][2247190 update_loop][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/version/v1
[2020-12-08T10:41:50.954521126+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:41:50.954673857+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:41:50.954784737+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:41:50.954797917+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-08T10:41:50.954847077+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:41:50.954855757+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:41:50.969277550+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:41:51.148504615+01:00][INFO][2247190 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(662)] Server did not respond with version, so using default URL.
[2020-12-08T10:41:51.260791898+01:00][INFO][2247190 update_loop][updater][Some("tabnine/updater/src/lib.rs")][Some(328)] Current version is 3.2.37, remote has version 3.1.17.
[2020-12-08T10:44:29.881625956+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:44:29.881731916+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:44:29.881739616+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-08T10:44:29.881742526+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:44:29.881956857+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:44:29.881964227+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:44:29.881990297+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:44:29.981807466+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:44:29.982051916+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-08T10:44:29.982050176+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:44:29.982140856+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:44:29.982225707+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:44:29.982289297+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:44:30.491932437+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:45:11.258484767+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:45:11.258556707+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:45:11.258570057+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:45:11.258552237+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-08T10:45:11.258746917+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:45:11.258797177+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:45:11.258826557+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:45:11.358657807+01:00][INFO][2247138 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:45:11.358779127+01:00][INFO][2247190 thread][updater::global_config][Some("tabnine/updater/src/global_config.rs")][Some(697)] config path: /home/gogoprog/.config/TabNine/tabnine_config.json
[2020-12-08T10:45:11.358796177+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Local)
[2020-12-08T10:45:11.358817868+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(183)] lunar settings detected config modified (Remote)
[2020-12-08T10:45:11.359011208+01:00][INFO][2247190 lunar settings update thread (Remote)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Remote lunar settings
[2020-12-08T10:45:11.359023578+01:00][INFO][2247190 lunar settings update thread (Local)][server::lunar_connection][Some("tabnine/server/src/lunar_connection.rs")][Some(175)] Successfully updated Local lunar settings
[2020-12-08T10:45:11.370197364+01:00][INFO][2247190 thread][http_requests][Some("shared/http_requests/src/lib.rs")][Some(73)] Making API request to https://api.tabnine.com/api_key_info/v3
[2020-12-08T10:46:00.764747003+01:00][INFO][2247138 bs_main_autobarker][watchdog_server::wd_temp_client][Some("tabnine/watchdog_server/src/wd_temp_client.rs")][Some(145)] Starting watchdog...
[2020-12-08T10:46:00.765147824+01:00][INFO][2247138 thread][watchdog_server][Some("tabnine/watchdog_server/src/lib.rs")][Some(55)] watchdog is locking path: /home/gogoprog/.config/TabNine/monitoring/watchdog.lock
[2020-12-08T10:46:01.512933234+01:00][INFO][2247138 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2247190-TabNine
[2020-12-08T10:46:01.670565598+01:00][INFO][2247138 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2249534-TabNine
[2020-12-08T10:46:01.824446734+01:00][INFO][2247138 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2247138-TabNine
[2020-12-08T10:46:01.973711179+01:00][INFO][2247138 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(205)] watching new process 2249483-TabNine

I can't find anything relevant in the logs. Also all the log files are empty.
Also, I often run multiple Vim instances at the same time. Maybe is it related?

@amircodota
Copy link
Collaborator

amircodota commented Dec 8, 2020

@gogoprog did the process exit after a few minutes or did it keep running?

@gogoprog
Copy link

gogoprog commented Dec 8, 2020

@gogoprog did the process exit after a few minutes or did it keep running?

Yes it kept running. This was the full log from Vim startup to TabNine error.

@amircodota
Copy link
Collaborator

I'm afraid this log does not give much. I need the log of TabNine running under vim.

To do this, we'll need to modify the plugin code a bit.

if you edit youcompleteme.py under the under python/ycm folder, you can add a --log-file-path parameter to the tabnine process.

this is the original code

args = [ '--client=vim',
             '--port={0}'.format( server_port ),
             '--options_file={0}'.format( options_file.name ),
             '--log={0}'.format( self._user_options[ 'log_level' ] ),
             '--idle_suicide_seconds={0}'.format(
                SERVER_IDLE_SUICIDE_SECONDS ) ]

you can change it to something like

args = [ '--client=vim',
            '--log-file-path=/home/gogoprog/t9.log',
             '--port={0}'.format( server_port ),
             '--options_file={0}'.format( options_file.name ),
             '--log={0}'.format( self._user_options[ 'log_level' ] ),
             '--idle_suicide_seconds={0}'.format(
                SERVER_IDLE_SUICIDE_SECONDS ) ]

@gogoprog
Copy link

gogoprog commented Dec 8, 2020

@amircodota here it is.
t9.log

Same scenario:
I was playing around with a single C++ file, and after a few minutes the autocompletion stopped working

@gabesoft
Copy link
Author

gabesoft commented Dec 8, 2020

@amircodota

I did have another instance of vim open

The size of the repo where tabnine keeps crashing is

count: 899
size: 4.77 MiB
in-pack: 1893795
packs: 1
size-pack: 4.39 GiB
prune-packable: 0
garbage: 0
size-garbage: 0 bytes

as output by git count-objects -vH

@gabesoft
Copy link
Author

gabesoft commented Dec 8, 2020

Is there a config setting or some other way to increase the memory threshold. On my system I have enough memory to be OK with a higher threshold.

@amircodota
Copy link
Collaborator

@gogoprog in your log, I see a lot of errors around the clang LSP. Can you disable semantic completions and see if the situation improves?

@gogoprog
Copy link

gogoprog commented Dec 8, 2020

@amircodota I will test but the same issue occurs with my Haxe projects in which there is no semantic completion afaik.

@amircodota
Copy link
Collaborator

@gabesoft I'm afraid no such setting exists. However, I do not think tabnine's memory should grow so much. So this usually indicates some kind of bug. I suspect increasing the memory will just cause tabnine's memory to keep growing. But I could be wrong.

In any case, can you also add --log-file-path to your vim plugin code and send the log file?

See this comment

@amircodota
Copy link
Collaborator

@gabesoft here's what I see in the log.

The process was started at 11:56:15.
After some initialization, tabnine began to index your project.
It continued to index it at least until 11:56:55 where I see the last message of the form

[2020-12-08T11:56:55.892891-08:00][ERROR][29008 TabNine-worker-22][server::pipeline::document_tracker][Some("tabnine/server/src/pipeline/document_tracker.rs")][Some(341)] Error reading "/Users/gabe/quip/uitest2/visual-regression/screenshots/chat-message/emoji.png": stream did not contain valid UTF-8

This means it is a fairly large project, taking so long to index.

Then, at 11:58:17 we get this message

[2020-12-08T11:58:17.247704-08:00][INFO][29006 thread][watchdog_server::monitor_loop][Some("tabnine/watchdog_server/src/monitor_loop.rs")][Some(251)] killing process 29008-TabNine because memory exceeded: 2840715

And the process is killed.

TabNine will only ever kill a process two minutes after it started, so I'm guessing the memory limit was reached sooner, and it just now passed the 2 minutes limit so it only killed it now.

One thing you can try is to exclude files from indexing. Do you have very large files in your project that are under git but should not be indexed?
In general, tabnine only indexes files that are under vcs, but you can exclude more files by adding a .tabnine_ignore file (see this)

@gabesoft
Copy link
Author

gabesoft commented Dec 9, 2020

Thanks @amircodota that seems to work. It's been more than 2min and the process is still up. I already had an .ignore file so I added more paths there.

@amircodota
Copy link
Collaborator

@gabesoft glad to hear

@gogoprog Any news on your end? Did you disable LSP?

@gogoprog
Copy link

@amircodota I don't remember how to disable LSP

@amircodota
Copy link
Collaborator

@gogoprog Type tabnine::no_sem in your editor

@gogoprog
Copy link

@amircodota it crashed again.

Very small repo, no semantic and I see a lot of errors in the log

t9.log

@amircodota
Copy link
Collaborator

@gogoprog The logs do not give much, I'm afraid.
It seems the process just exits - no error is given in the log at the time of the exit.

There are a lot of these errors

[2020-12-11T11:17:02.723979165+01:00][ERROR][3083447 indexer-0][server::pipeline::walk][Some("tabnine/server/src/pipeline/walk.rs")][Some(338)] error unwatching "/home/gogoprog/code/aoc/2020": No watch was found.

Seems to indicate that something about this project's structure that "confuses" TabNine. Is there anything you can think of? Maybe symlinks, or maybe something else that's a little different about this project directory structure?

Another thing we can try is to increase the log verbosity.
You can change the plugin code again, to add --log-level TRACE to TabNine's arguments.

@gogoprog
Copy link

No I can't find anything special in my repo, here it is : https://github.com/gogoprog/advent-of-code
It is quite small and I've been using it before when it was fine.

It is really the TabNine version that has changed not the repo...

I have the trace log but it is 50MB heavy

@amircodota
Copy link
Collaborator

@gogoprog trying to reproduce.
I cloned the repo, compiled everything (some dirs did not compile), but it seems to work fine. TabNine memory at around 1.5GB.

If the trace log is too big, maybe you can send the last 20 seconds or something like that?

@gogoprog
Copy link

@amircodota
Here is the full log, I forgot I could compress.
So a full session until it did not work anymore.
t9fail.tar.gz

@amircodota
Copy link
Collaborator

@gogoprog

Went over the logs.

you were running pid 3618701.
Memory seems stable.

Then the process just disappeared without any error in the log.

Is it possible something on your system is killing it?

One thing we can try is to disable deep local suggestions (you are using both local and cloud right) and see if it alleviates this.

@gogoprog
Copy link

No I have nothing new beside TabNine itself.
It is a pity, how can I go back to a previous version?

I just disabled local suggestions and the problem still occurs.

@gogoprog
Copy link

This is my log for a crash after a very short session (a few seconds after :YcmRestartServer)
t9.log

@gogoprog
Copy link

I also see this even though it is not true (after :YcmRestartServer)

2020-12-22_09:59:49

I don't know if it is related to the initial issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants