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.

Sign up for GitHub

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

Jump to bottom

Timed out requests lead to single driver instance running #303

Open
vmarkovtsev opened this issue Jul 27, 2019 · 1 comment
Open

Timed out requests lead to single driver instance running #303

vmarkovtsev opened this issue Jul 27, 2019 · 1 comment
Labels
bug

Comments

@vmarkovtsev
Copy link
Contributor

vmarkovtsev commented Jul 27, 2019 •
edited
Loading

I am running massively-parallel UAST extraction from PGA. I am using 64 goroutines to parse.
I noticed that some of my machines got stuck in a few days and I investigated why.

Date: July 27 9am.

Machine 1

No other bblfsh processes except:

28003 root      20   0 4101516 2.625g   2112 R 100.0  8.4   2408:51 python3

docker logs bblfshd | tail:

time="2019-07-26T08:03:57Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmxnqygsjjap8nbkx94p15 language=javascript
time="2019-07-26T08:03:57Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxnqygsjjap8nbkx94p15 language=javascript
time="2019-07-26T08:03:57Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgpmxnzmpvft3wzxqkze6cez language=bash
time="2019-07-26T08:03:57Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxnzmpvft3wzxqkze6cez language=bash
time="2019-07-26T08:03:58Z" level=error msg="request processed content 4496 bytes error: unknown source file encoding (expected UTF-8)" elapsed=17.042µs filename="455209bd3a8583b7c84c7fd047986b929920b2a4/0169ed0c-9a25-9e94-bf54-32f10d29da58/luaObject.h"
time="2019-07-26T08:03:58Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgpmxppz74wnarmh4rdy6cdc language=cpp
time="2019-07-26T08:03:58Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxppz74wnarmh4rdy6cdc language=cpp
time="2019-07-26T08:03:58Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmxnqygsjjap8nbkx94p15)"
time="2019-07-26T08:03:58Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgpmxnzmpvft3wzxqkze6cez)"
time="2019-07-26T08:03:58Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmxq6t16g30tw55dxp3gsa language=javascript
time="2019-07-26T08:03:58Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxq6t16g30tw55dxp3gsa language=javascript
time="2019-07-26T08:03:59Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgpmxppz74wnarmh4rdy6cdc)"
time="2019-07-26T08:03:59Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmxq6t16g30tw55dxp3gsa)"
time="2019-07-26T08:04:00Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgpmxr9fxvk8a3exc59m6gae language=cpp
time="2019-07-26T08:04:00Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxr9fxvk8a3exc59m6gae language=cpp
time="2019-07-26T08:04:01Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgpmxr9fxvk8a3exc59m6gae)"
time="2019-07-26T08:04:02Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgpmxt7z0hfwztps4w6mz44m language=cpp
time="2019-07-26T08:04:02Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxt7z0hfwztps4w6mz44m language=cpp
time="2019-07-26T08:04:02Z" level=error msg="request processed content 23791 bytes error: rpc error: code = FailedPrecondition desc = received 14 errors:
	check: key "Prop_Declarator": key "Prop_Parameters": elem 3 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 3 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 3 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 3 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 2 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
	check: key "Prop_Declarator": key "Prop_Parameters": elem 1 (nodes.Object): unused field(s) on node CPPASTDeclarator: Prop_NestedDeclarator
" elapsed=4.491688605s filename="455209bd3a8583b7c84c7fd047986b929920b2a4/0169ed0c-9a25-9e94-bf54-32f10d29da58/luaClass.h" language=cpp
time="2019-07-26T08:04:02Z" level=error msg="request processed content 2919 bytes error: rpc error: code = FailedPrecondition desc = received 2 errors:
	check: unused field(s) on node CPPASTCompoundStatement: Prop_ImplicitDestructorNames
	check: unused field(s) on node CPPASTCompoundStatement: [Prop_ImplicitDestructorNames Prop_Statements]
" elapsed=4.59262799s filename="455209bd3a8583b7c84c7fd047986b929920b2a4/0169ed0c-9a25-9e94-bf54-32f10d29da58/test/test_class/test.cpp" language=cpp
time="2019-07-26T08:04:03Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgpmxt7z0hfwztps4w6mz44m)"
time="2019-07-26T08:04:03Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgpmxvpv4tjsf1v3g9d433e1 language=cpp
time="2019-07-26T08:04:03Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxvpv4tjsf1v3g9d433e1 language=cpp
time="2019-07-26T08:04:04Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgpmxvpv4tjsf1v3g9d433e1)"
time="2019-07-26T08:04:06Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmxyh62zj5133snydtjdkz language=javascript
time="2019-07-26T08:04:06Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmxyh62zj5133snydtjdkz language=javascript
time="2019-07-26T08:04:07Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmxyh62zj5133snydtjdkz)"
time="2019-07-26T08:04:08Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmy0029etta4pc65yfy30x language=javascript
time="2019-07-26T08:04:08Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmy0029etta4pc65yfy30x language=javascript
time="2019-07-26T08:04:09Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmy0029etta4pc65yfy30x)"
time="2019-07-26T08:04:10Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmy1yj9xxxjv7sxy8jtmwp language=javascript
time="2019-07-26T08:04:10Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmy1yj9xxxjv7sxy8jtmwp language=javascript
time="2019-07-26T08:04:11Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmy1yj9xxxjv7sxy8jtmwp)"
time="2019-07-26T08:04:11Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmy3degn45rqb00wrb9s24 language=javascript
time="2019-07-26T08:04:11Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmy3degn45rqb00wrb9s24 language=javascript
time="2019-07-26T08:04:12Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmy3degn45rqb00wrb9s24)"
time="2019-07-26T08:04:13Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmy5by70z4e5r0hd68s5jk language=javascript
time="2019-07-26T08:04:13Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmy5by70z4e5r0hd68s5jk language=javascript
time="2019-07-26T08:04:14Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmy5by70z4e5r0hd68s5jk)"
time="2019-07-26T08:04:19Z" level=info msg="php-driver version: v2.8.0 (build: 2019-04-17T16:56:09Z)" id=01dgpmyawj3jj2987mdpby9pej language=php
time="2019-07-26T08:04:19Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyawj3jj2987mdpby9pej language=php
time="2019-07-26T08:04:19Z" level=error msg="request processed content 17392 bytes error: rpc error: code = FailedPrecondition desc = received 2 errors:
	check: unused field(s) on node Scalar_String: comments
	check: unused field(s) on node Scalar_String: [attributes comments]
" elapsed=293.479278ms filename="45536d342290929c95c4c45f3acd4cb1acfac8fd/0169ed11-b336-02e0-f336-d461187163a6/class-wc-wechatpay.php" language=php
time="2019-07-26T08:04:19Z" level=error msg="request processed content 65786 bytes error: rpc error: code = FailedPrecondition desc = check: unused field(s) on node Expr_Include: comments" elapsed=1.009349988s filename="45536d342290929c95c4c45f3acd4cb1acfac8fd/0169ed11-b336-02e0-f336-d461187163a6/lib/WxPay.Data.php" language=php
time="2019-07-26T08:04:20Z" level=info msg="new driver instance started bblfsh/php-driver:latest (01dgpmyawj3jj2987mdpby9pej)"
time="2019-07-26T08:04:21Z" level=info msg="php-driver version: v2.8.0 (build: 2019-04-17T16:56:09Z)" id=01dgpmycv2nvg41g2246avmcxh language=php
time="2019-07-26T08:04:21Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmycv2nvg41g2246avmcxh language=php
time="2019-07-26T08:04:22Z" level=info msg="new driver instance started bblfsh/php-driver:latest (01dgpmycv2nvg41g2246avmcxh)"
time="2019-07-26T08:04:22Z" level=error msg="request processed content 1559 bytes error: rpc error: code = FailedPrecondition desc = check: unused field(s) on node Expr_Include: comments" elapsed=3.182377915s filename="45536d342290929c95c4c45f3acd4cb1acfac8fd/0169ed11-b336-02e0-f336-d461187163a6/lib/phpqrcode/qrlib.php" language=php
time="2019-07-26T08:04:22Z" level=info msg="php-driver version: v2.8.0 (build: 2019-04-17T16:56:09Z)" id=01dgpmye9yxgqwdcanbzny4da1 language=php
time="2019-07-26T08:04:22Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmye9yxgqwdcanbzny4da1 language=php
time="2019-07-26T08:04:23Z" level=info msg="new driver instance started bblfsh/php-driver:latest (01dgpmye9yxgqwdcanbzny4da1)"
time="2019-07-26T08:04:24Z" level=info msg="php-driver version: v2.8.0 (build: 2019-04-17T16:56:09Z)" id=01dgpmyg8ew9hvrqhkda88eng0 language=php
time="2019-07-26T08:04:24Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyg8ew9hvrqhkda88eng0 language=php
time="2019-07-26T08:04:25Z" level=info msg="new driver instance started bblfsh/php-driver:latest (01dgpmyg8ew9hvrqhkda88eng0)"
time="2019-07-26T08:04:27Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmyjht2sxn0fsheqeqymda language=javascript
time="2019-07-26T08:04:27Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyjht2sxn0fsheqeqymda language=javascript
time="2019-07-26T08:04:28Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmyjht2sxn0fsheqeqymda)"
time="2019-07-26T08:04:29Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmymgamkm830s1rwpvc8eg language=javascript
time="2019-07-26T08:04:29Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmymgamkm830s1rwpvc8eg language=javascript
time="2019-07-26T08:04:30Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmymgamkm830s1rwpvc8eg)"
time="2019-07-26T08:04:30Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgpmynz6361epcr4xtd8ymea language=javascript
time="2019-07-26T08:04:30Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmynz6361epcr4xtd8ymea language=javascript
time="2019-07-26T08:04:31Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgpmynz6361epcr4xtd8ymea)"
time="2019-07-26T08:04:35Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgpmyv5yn3z0750ysetxc2w5 language=python
time="2019-07-26T08:04:35Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyv5yn3z0750ysetxc2w5 language=python
time="2019-07-26T08:04:36Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgpmyv5yn3z0750ysetxc2w5)"
time="2019-07-26T08:04:37Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgpmyx4ey7f036faeg8684yc language=python
time="2019-07-26T08:04:37Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyx4ey7f036faeg8684yc language=python
time="2019-07-26T08:04:38Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgpmyx4ey7f036faeg8684yc)"
time="2019-07-26T08:04:39Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgpmyyka13nfpst9fhc47tka language=python
time="2019-07-26T08:04:39Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmyyka13nfpst9fhc47tka language=python
time="2019-07-26T08:04:40Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgpmyyka13nfpst9fhc47tka)"
time="2019-07-26T08:04:41Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgpmz0htahhj49q2v8m9mz58 language=python
time="2019-07-26T08:04:41Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmz0htahhj49q2v8m9mz58 language=python
time="2019-07-26T08:04:42Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgpmz0htahhj49q2v8m9mz58)"
time="2019-07-26T08:04:42Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgpmz20pry2hq13k59zycv21 language=python
time="2019-07-26T08:04:42Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgpmz20pry2hq13k59zycv21 language=python
time="2019-07-26T08:04:43Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgpmz20pry2hq13k59zycv21)"
time="2019-07-26T09:04:35Z" level=error msg="request processed content 4722 bytes error: rpc error: code = Canceled desc = context canceled" elapsed=1h0m0.000539369s filename="45538c91acd1c5fa1f1e84246faf9ff58f31679f/0169ed02-f85d-f946-0448-fdbf6ec30038/dataset.py" language=python

Machine 2

No other bblfsh processes except:

18268 root      20   0 9992740 2.073g  12880 S 100.0  6.6   2240:47 java

docker logs bblfshd | tail:

time="2019-07-27T01:01:48Z" level=error msg="request processed content 2488 bytes error: rpc error: code = Internal desc = (was java.lang.NullPointerException) (through reference chain: bblfsh.bash.Response["ast"])" elapsed=3.106685476s filename="590962fb400c30b767062dbcbe4676e8dfe38e20/0169ecf5-e8e1-9f11-cebb-6723e3e5aefa/vendor/semver_bash/semver.sh" language=shell
time="2019-07-27T01:01:49Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrf5d27w1vsjhx0pmn6jrr8)"
time="2019-07-27T01:01:49Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrf5eh3gh3f2cen5z9dh4fw language=bash
time="2019-07-27T01:01:49Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrf5eh3gh3f2cen5z9dh4fw language=bash
time="2019-07-27T01:01:50Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrf5eh3gh3f2cen5z9dh4fw)"
time="2019-07-27T01:01:51Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrf5gfktw5yntkhem66g03q language=bash
time="2019-07-27T01:01:51Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrf5gfktw5yntkhem66g03q language=bash
time="2019-07-27T01:01:52Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrf5gfktw5yntkhem66g03q)"
time="2019-07-27T02:01:45Z" level=error msg="request processed content 1022 bytes error: rpc error: code = DeadlineExceeded desc = context deadline exceeded" elapsed=1h0m0.000415156s filename="590962fb400c30b767062dbcbe4676e8dfe38e20/0169ecf5-e8e1-9f11-cebb-6723e3e5aefa/ci/await-app-health.sh" language=shell
time="2019-07-27T03:01:46Z" level=error msg="request processed content 748 bytes error: rpc error: code = Canceled desc = context canceled" elapsed=1h0m0.000399961s filename="5909d6bca4b3ade544196206c58934c3a7fb1a09/0169ecd3-705f-dc9b-1e15-6dc12e0e43b0/get_texmf_dir.sh" language=shell
time="2019-07-27T03:01:46Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrp13689a1v5g7gtpq4erze language=javascript
time="2019-07-27T03:01:46Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrp13689a1v5g7gtpq4erze language=javascript
time="2019-07-27T03:01:47Z" level=error msg="request processed content 7291 bytes error: rpc error: code = Internal desc = Traceback (most recent call last):
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/requestprocessor.py", line 155, in process_request
    ast = AstImprover(code, orig_ast).parse()
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 39, in parse
    res = self.visit(self._astdict, root=True)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 66, in visit
    visit_result = meth(node)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 264, in visit_other
    node[field] = meth(child)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 271, in visit_other_field
    return [self.visit(x) for x in node]
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 271, in 
    return [self.visit(x) for x in node]
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 66, in visit
    visit_result = meth(node)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 264, in visit_other
    node[field] = meth(child)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 271, in visit_other_field
    return [self.visit(x) for x in node]
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 271, in 
    return [self.visit(x) for x in node]
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 66, in visit
    visit_result = meth(node)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 264, in visit_other
    node[field] = meth(child)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 269, in visit_other_field
    return self.visit(node)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 66, in visit
    visit_result = meth(node)
  File "/opt/driver/bin/.local/lib/python3.6/site-packages/python_driver/astimprove.py", line 242, in visit_arguments
    vararg["ast_type"] = "vararg"
TypeError: 'str' object does not support item assignment
" elapsed=499.001118ms filename="590a40732ec7bfcb177e655fb960f51529c58d70/0169ed05-1843-7392-9b29-42fbf6f7fec8/nofussbm/api.py" language=python
time="2019-07-27T03:01:47Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrp13azk35fgsxsz372tp2n language=bash
time="2019-07-27T03:01:47Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrp13azk35fgsxsz372tp2n language=bash
time="2019-07-27T03:01:47Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgrp13b9tb2xhydq339r9wqp language=python
time="2019-07-27T03:01:47Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrp13b9tb2xhydq339r9wqp language=python
time="2019-07-27T03:01:47Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrp13689a1v5g7gtpq4erze)"
time="2019-07-27T03:01:48Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgrp13b9tb2xhydq339r9wqp)"
time="2019-07-27T03:01:48Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrp13azk35fgsxsz372tp2n)"
com.fasterxml.jackson.databind.JsonMappingException: (was java.lang.NullPointerException) (through reference chain: bblfsh.bash.Response["ast"])
	at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:388)
	at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:348)
	at com.fasterxml.jackson.databind.ser.std.StdSerializer.wrapAndThrow(StdSerializer.java:343)
	at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:698)
	at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:155)
	at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:292)
	at com.fasterxml.jackson.databind.ObjectMapper._configAndWriteValue(ObjectMapper.java:3681)
	at com.fasterxml.jackson.databind.ObjectMapper.writeValue(ObjectMapper.java:3014)
	at bblfsh.bash.ResponseWriter.write(ResponseWriter.java:23)
	at bblfsh.bash.Driver.processOne(Driver.java:36)
	at bblfsh.bash.Driver.run(Driver.java:20)
	at bblfsh.bash.Main.main(Main.java:14)
Caused by: java.lang.NullPointerException
	at com.intellij.psi.impl.source.tree.FileElement.getManager(FileElement.java:74)
	at com.intellij.psi.impl.source.tree.TreeElement.getManager(TreeElement.java:81)
	at com.intellij.psi.impl.source.tree.CompositePsiElement.getProject(CompositePsiElement.java:299)
	at com.ansorgit.plugins.bash.lang.parser.eval.BashEvalElementType.doParseContents(BashEvalElementType.java:39)
	at com.intellij.psi.tree.ILazyParseableElementType.parseContents(ILazyParseableElementType.java:80)
	at com.intellij.psi.impl.source.tree.LazyParseableElement.ensureParsed(LazyParseableElement.java:192)
	at com.intellij.psi.impl.source.tree.LazyParseableElement.getFirstChildNode(LazyParseableElement.java:240)
	at com.intellij.psi.impl.source.tree.CompositeElement.countChildren(CompositeElement.java:498)
	at com.intellij.psi.impl.source.tree.CompositeElement.getChildren(CompositeElement.java:443)
	at bblfsh.bash.ASTNodeSerializer.serializeWithChild(ASTNodeSerializer.java:130)
	at bblfsh.bash.ASTNodeSerializer.serializeChildren(ASTNodeSerializer.java:169)
	at bblfsh.bash.ASTNodeSerializer.serializeWithChild(ASTNodeSerializer.java:130)
	at bblfsh.bash.ASTNodeSerializer.serializeChildren(ASTNodeSerializer.java:169)
	at bblfsh.bash.ASTNodeSerializer.serializeWithChild(ASTNodeSerializer.java:130)
	at bblfsh.bash.ASTNodeSerializer.serialize(ASTNodeSerializer.java:106)
	at bblfsh.bash.ASTNodeSerializer.serialize(ASTNodeSerializer.java:21)
	at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:704)
	at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:690)
	... 8 more

time="2019-07-27T03:01:48Z" level=error msg="request processed content 263 bytes error: rpc error: code = Internal desc = (was java.lang.NullPointerException) (through reference chain: bblfsh.bash.Response["ast"])" elapsed=1.933376713s filename="590a40732ec7bfcb177e655fb960f51529c58d70/0169ed05-1843-7392-9b29-42fbf6f7fec8/wrapper.sh" language=shell

time="2019-07-27T03:01:49Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrp159f3e6mcy8sz0trbd77 language=bash

time="2019-07-27T03:01:49Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrp159f3e6mcy8sz0trbd77 language=bash

time="2019-07-27T03:01:50Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrp159f3e6mcy8sz0trbd77)"

time="2019-07-27T04:01:46Z" level=error msg="request processed content 783 bytes error: rpc error: code = DeadlineExceeded desc = context deadline exceeded" elapsed=1h0m0.000529622s filename="590a40732ec7bfcb177e655fb960f51529c58d70/0169ed05-1843-7392-9b29-42fbf6f7fec8/scripts/cli_client" language=shell

time="2019-07-27T04:01:48Z" level=info msg="go-driver version: v2.7.0 (build: 2019-05-28T14:48:13Z)" id=01dgrsf02cc0cmq6e4v1tpm19x language=go

time="2019-07-27T04:01:48Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrsf02cc0cmq6e4v1tpm19x language=go

time="2019-07-27T04:01:49Z" level=info msg="new driver instance started bblfsh/go-driver:latest (01dgrsf02cc0cmq6e4v1tpm19x)"

time="2019-07-27T04:01:50Z" level=info msg="java-driver version: v2.7.2 (build: 2019-05-28T15:02:12Z)" id=01dgrsf1v8w083gn1qz3f6mdjs language=java

time="2019-07-27T04:01:50Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrsf1v8w083gn1qz3f6mdjs language=java

time="2019-07-27T04:01:51Z" level=info msg="new driver instance started bblfsh/java-driver:latest (01dgrsf1v8w083gn1qz3f6mdjs)"

time="2019-07-27T05:01:49Z" level=error msg="request processed content 4971 bytes error: rpc error: code = DeadlineExceeded desc = context deadline exceeded" elapsed=1h0m0.000304326s filename="590ad5fb85c7862d1cbb4d066afa5911e53962a6/0169ed00-151f-c848-a05b-fe1dfa0eb9f8/gradlew" language=shell

time="2019-07-27T05:01:50Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwwxvmc8rb4bkxwnxvjxtr language=javascript

time="2019-07-27T05:01:50Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwwxvmc8rb4bkxwnxvjxtr language=javascript

time="2019-07-27T05:01:51Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwwxvmc8rb4bkxwnxvjxtr)"

time="2019-07-27T05:01:51Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgrwwyzxfk0ex7k7p85agqmj language=python

time="2019-07-27T05:01:51Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwwyzxfk0ex7k7p85agqmj language=python

time="2019-07-27T05:01:52Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgrwwyzxfk0ex7k7p85agqmj)"

time="2019-07-27T05:01:52Z" level=info msg="ruby-driver version: v2.9.4 (build: 2019-05-28T14:59:54Z)" id=01dgrwx092kggq23adzw5gemdk language=ruby

time="2019-07-27T05:01:52Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx092kggq23adzw5gemdk language=ruby

warning: parser/current is loading parser/ruby24, which recognizes

warning: 2.4.6-compliant syntax, but you are running 2.4.5.

warning: please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.

time="2019-07-27T05:01:53Z" level=info msg="new driver instance started bblfsh/ruby-driver:latest (01dgrwx092kggq23adzw5gemdk)"

time="2019-07-27T05:01:54Z" level=info msg="ruby-driver version: v2.9.4 (build: 2019-05-28T14:59:54Z)" id=01dgrwx27j2gx0n1spxdz9sgyk language=ruby

time="2019-07-27T05:01:54Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx27j2gx0n1spxdz9sgyk language=ruby

warning: parser/current is loading parser/ruby24, which recognizes

warning: 2.4.6-compliant syntax, but you are running 2.4.5.

warning: please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.

time="2019-07-27T05:01:55Z" level=info msg="new driver instance started bblfsh/ruby-driver:latest (01dgrwx27j2gx0n1spxdz9sgyk)"

time="2019-07-27T05:01:56Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgrwx3ape9vjrka5h8zbqyvv language=cpp

time="2019-07-27T05:01:56Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx3ape9vjrka5h8zbqyvv language=cpp

time="2019-07-27T05:01:56Z" level=error msg="request processed content 7648 bytes error: rpc error: code = FailedPrecondition desc = received 5 errors:

check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType

check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType

check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType

check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType

check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType

" elapsed=577.299089ms filename="590d0c665429ca9403f602961910a752c2c22237/0169ecff-3123-c9ea-323f-aaeded8db95a/include/flags/flags.hpp" language=cpp

time="2019-07-27T05:01:56Z" level=info msg="ruby-driver version: v2.9.4 (build: 2019-05-28T14:59:54Z)" id=01dgrwx3pe0g11yf81em671npf language=ruby

time="2019-07-27T05:01:56Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx3pe0g11yf81em671npf language=ruby

warning: parser/current is loading parser/ruby24, which recognizes

warning: 2.4.6-compliant syntax, but you are running 2.4.5.

warning: please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.

time="2019-07-27T05:01:56Z" level=error msg="request processed content 9438 bytes error: rpc error: code = FailedPrecondition desc = check: key "Prop_Declarator": unused field(s) on node CPPASTFunctionDeclarator: Prop_TrailingReturnType" elapsed=1.135503187s filename="590d0c665429ca9403f602961910a752c2c22237/0169ecff-3123-c9ea-323f-aaeded8db95a/test/main-test.cpp" language=cpp

time="2019-07-27T05:01:57Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgrwx3ape9vjrka5h8zbqyvv)"

time="2019-07-27T05:01:57Z" level=info msg="new driver instance started bblfsh/ruby-driver:latest (01dgrwx3pe0g11yf81em671npf)"

time="2019-07-27T05:01:58Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgrwx596c7py52eejgf4q2je language=cpp

time="2019-07-27T05:01:58Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx596c7py52eejgf4q2je language=cpp

time="2019-07-27T05:01:58Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwx5nmcx2b92tg47z5esfm language=javascript

time="2019-07-27T05:01:58Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx5nmcx2b92tg47z5esfm language=javascript

time="2019-07-27T05:01:59Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgrwx596c7py52eejgf4q2je)"

time="2019-07-27T05:01:59Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwx5nmcx2b92tg47z5esfm)"

time="2019-07-27T05:01:59Z" level=info msg="cpp-driver version: v1.4.0 (build: 2019-05-28T14:27:00Z)" id=01dgrwx6r20zs3twzp0cmjckc0 language=cpp

time="2019-07-27T05:01:59Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx6r20zs3twzp0cmjckc0 language=cpp

time="2019-07-27T05:02:00Z" level=info msg="new driver instance started bblfsh/cpp-driver:latest (01dgrwx6r20zs3twzp0cmjckc0)"

time="2019-07-27T05:02:02Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrwx9qbdddb22strgmmxhkn language=bash

time="2019-07-27T05:02:02Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwx9qbdddb22strgmmxhkn language=bash

time="2019-07-27T05:02:03Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwxaj3crtsh40kk3md1271 language=javascript

time="2019-07-27T05:02:03Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxaj3crtsh40kk3md1271 language=javascript

time="2019-07-27T05:02:03Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrwx9qbdddb22strgmmxhkn)"

time="2019-07-27T05:02:04Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwxaj3crtsh40kk3md1271)"

time="2019-07-27T05:02:04Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrwxbnv2cq24sfa62ph5e8r language=bash

time="2019-07-27T05:02:04Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxbnv2cq24sfa62ph5e8r language=bash

time="2019-07-27T05:02:04Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwxc0rbyk7xrgvap5h4vm4 language=javascript

time="2019-07-27T05:02:04Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxc0rbyk7xrgvap5h4vm4 language=javascript

time="2019-07-27T05:02:05Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrwxbnv2cq24sfa62ph5e8r)"

time="2019-07-27T05:02:05Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwxc0rbyk7xrgvap5h4vm4)"

time="2019-07-27T05:02:07Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwxdz8vg2r8m40jsn9st65 language=javascript

time="2019-07-27T05:02:07Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxdz8vg2r8m40jsn9st65 language=javascript

time="2019-07-27T05:02:07Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgrwxe3znerq3avsbta56ab5 language=bash

time="2019-07-27T05:02:07Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxe3znerq3avsbta56ab5 language=bash

time="2019-07-27T05:02:08Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwxdz8vg2r8m40jsn9st65)"

time="2019-07-27T05:02:08Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgrwxe3znerq3avsbta56ab5)"

time="2019-07-27T05:02:08Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwxfe4vx1h7jdz82gwffpa language=javascript

time="2019-07-27T05:02:08Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxfe4vx1h7jdz82gwffpa language=javascript

time="2019-07-27T05:02:09Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwxfe4vx1h7jdz82gwffpa)"

time="2019-07-27T05:02:10Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgrwxhcm47xaq8mzd2eghf1q language=javascript

time="2019-07-27T05:02:10Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgrwxhcm47xaq8mzd2eghf1q language=javascript

time="2019-07-27T05:02:11Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgrwxhcm47xaq8mzd2eghf1q)"

time="2019-07-27T05:02:14Z" level=error msg="error removing stopped driver: container is not destroyed" image="bblfsh/bash-driver:latest" language=bash

time="2019-07-27T06:02:02Z" level=error msg="request processed content 2743 bytes error: rpc error: code = Canceled desc = context canceled" elapsed=1h0m0.000301283s filename="590d2df969bb8850199eb804aacd5e828cb6f5bb/0169ed00-3b90-032b-50a3-671783dbf787/Jenkins_Script/CI_Script.sh" language=shell

time="2019-07-27T06:02:03Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgs0b65wp87py1mrf9xqbtq6 language=javascript

time="2019-07-27T06:02:03Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs0b65wp87py1mrf9xqbtq6 language=javascript

time="2019-07-27T06:02:04Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgs0b65wp87py1mrf9xqbtq6)"

time="2019-07-27T06:02:05Z" level=info msg="javascript-driver version: v2.9.0 (build: 2019-05-28T14:40:18Z)" id=01dgs0b84c523gtxat7gmw1ya8 language=javascript

time="2019-07-27T06:02:05Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs0b84c523gtxat7gmw1ya8 language=javascript

time="2019-07-27T06:02:06Z" level=info msg="new driver instance started bblfsh/javascript-driver:latest (01dgs0b84c523gtxat7gmw1ya8)"

time="2019-07-27T07:02:04Z" level=error msg="request processed content 725 bytes error: rpc error: code = Canceled desc = context canceled" elapsed=1h0m0.000150923s filename="590d8dbac214b90707000292ab21a8d2ceb12635/0169ecdf-9a86-f3f7-4e37-0c3b93af1820/sql/mysqld.sh" language=shell

time="2019-07-27T07:02:05Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgs3s3x3zwbzj3svmmrhpxwz language=bash

time="2019-07-27T07:02:05Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s3x3zwbzj3svmmrhpxwz language=bash

time="2019-07-27T07:02:05Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgs3s3xd19knc156wxtxvyrg language=python

time="2019-07-27T07:02:05Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s3xd19knc156wxtxvyrg language=python

time="2019-07-27T07:02:06Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgs3s3x3zwbzj3svmmrhpxwz)"

time="2019-07-27T07:02:06Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgs3s3xd19knc156wxtxvyrg)"

time="2019-07-27T07:02:07Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgs3s5vxnfzcds5qwdmdbrnt language=python

time="2019-07-27T07:02:07Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s5vxnfzcds5qwdmdbrnt language=python

time="2019-07-27T07:02:07Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgs3s5vk92rnszn77bp6d2bh language=bash

time="2019-07-27T07:02:07Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s5vk92rnszn77bp6d2bh language=bash

time="2019-07-27T07:02:08Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgs3s5vxnfzcds5qwdmdbrnt)"

time="2019-07-27T07:02:08Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgs3s5vk92rnszn77bp6d2bh)"

time="2019-07-27T07:02:09Z" level=info msg="bash-driver version: v2.7.0 (build: 2019-05-28T15:06:29Z)" id=01dgs3s7afrfvcj4gdm9vcy93a language=bash

time="2019-07-27T07:02:09Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgs3s7as3crsdxksg4dd5yxk language=python

time="2019-07-27T07:02:09Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s7afrfvcj4gdm9vcy93a language=bash

time="2019-07-27T07:02:09Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s7as3crsdxksg4dd5yxk language=python

time="2019-07-27T07:02:10Z" level=info msg="new driver instance started bblfsh/bash-driver:latest (01dgs3s7afrfvcj4gdm9vcy93a)"

time="2019-07-27T07:02:10Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgs3s7as3crsdxksg4dd5yxk)"

time="2019-07-27T07:02:11Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgs3s999tmhr1xccasnwtnn4 language=python

time="2019-07-27T07:02:11Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3s999tmhr1xccasnwtnn4 language=python

time="2019-07-27T07:02:12Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgs3s999tmhr1xccasnwtnn4)"

time="2019-07-27T07:02:12Z" level=info msg="python-driver version: v2.10.0 (build: 2019-05-28T14:59:42Z)" id=01dgs3sar58e70hmceb7vas68f language=python

time="2019-07-27T07:02:12Z" level=info msg="server listening in /tmp/rpc.sock (unix)" id=01dgs3sar58e70hmceb7vas68f language=python

time="2019-07-27T07:02:13Z" level=info msg="new driver instance started bblfsh/python-driver:latest (01dgs3sar58e70hmceb7vas68f)"

Reproduce

For example, let's take 45538c91acd1c5fa1f1e84246faf9ff58f31679f/0169ed02-f85d-f946-0448-fdbf6ec30038/dataset.py. The siva file name is 45538c91acd1c5fa1f1e84246faf9ff58f31679f.siva, the head is 0169ed02-f85d-f946-0448-fdbf6ec30038 and the file name is dataset.py.
My extractor is https://github.com/src-d/datasets/tree/master/PublicGitArchive/pga2uast

# /45/ is the first two chars
wget pga.sourced.tech/siva/v2/45/45538c91acd1c5fa1f1e84246faf9ff58f31679f.siva
pga2uast -lbash,cpp,csharp,go,java,javascript,php,python,ruby -m -o . .

Versions

bblfsh/bblfshd      latest              9166f2f6548a        8 weeks ago         197MB
Build information
  commit: v2.14.0
  date: 2019-05-28T16:00:37+0000
+------------+------------------------------------------+---------+--------+----------+----+--------+
|  LANGUAGE  |                  IMAGE                   | VERSION | STATUS | CREATED  | GO | NATIVE |
+------------+------------------------------------------+---------+--------+----------+----+--------+
| python     | docker://bblfsh/python-driver:latest     | v2.10.0 | beta   | 8 weeks  |    |        |
| cpp        | docker://bblfsh/cpp-driver:latest        | v1.4.0  | beta   | 8 weeks  |    |        |
| java       | docker://bblfsh/java-driver:latest       | v2.7.2  | beta   | 8 weeks  |    |        |
| javascript | docker://bblfsh/javascript-driver:latest | v2.9.0  | beta   | 8 weeks  |    |        |
| bash       | docker://bblfsh/bash-driver:latest       | v2.7.0  | beta   | 8 weeks  |    |        |
| ruby       | docker://bblfsh/ruby-driver:latest       | v2.9.4  | beta   | 8 weeks  |    |        |
| go         | docker://bblfsh/go-driver:latest         | v2.7.0  | beta   | 8 weeks  |    |        |
| csharp     | docker://bblfsh/csharp-driver:latest     | v1.6.0  | beta   | 8 weeks  |    |        |
| php        | docker://bblfsh/php-driver:latest        | v2.8.0  | beta   | 3 months |    |        |
+------------+------------------------------------------+---------+--------+----------+----+--------+

Speculation

When I kill my extractor process, those bblfsh processes continue to hang with 100% CPU.
When I restart bblfshd and reinitialize it, everything returns back to normal.

My hypothesis is that some drivers timeout or crash, and bblfshd continues to run only one instance of the driver. So my "hang" is just a single-threaded extraction, according to the logs.
@vmarkovtsev vmarkovtsev changed the title Timed out requests do not really end Timed out requests lead to single driver instance running Jul 27, 2019
@dennwc dennwc added the bug label Jul 27, 2019
@dennwc
Copy link
Member

dennwc commented Jul 27, 2019

Thanks for a very detailed report!

This is a known issue - the request cancellation can only be propagated to the Go part of the driver, but the native part will continue parsing anyway.

Can be fixed by killing the native driver when the request is canceled. It will slow down the next request because we'll need to restart the native driver, but it's definitely better than hanging forever.

We will also examine the files you mentioned - those may trigger some infinite recursion in the driver which causes the parsing to stuck.

@vmarkovtsev vmarkovtsev mentioned this issue Jul 31, 2019
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dennwc @vmarkovtsev