Forseti Config Validator issues
133 views
Skip to first unread message
Vincent van Daal
Jul 29, 2020, 2:54:07 PM7/29/20
to Forseti Security Discussion, Xander.K...@rackspace.com, iain.m...@rackspace.co.uk
Hi Folks,
I’m helping one of our teams with a pretty standard Forseti install with Config Validator, but running into some difficulties. I’m not an expert in Forseti, so please be gentle 😊.
If there are any bits of info that are needed to get better debugging output, just let me know and I’ll append.
--
Versions used are:
https://github.com/forseti-security/forseti-security/tree/v2.25.1
https://github.com/forseti-security/terraform-google-forseti/releases/tag/v5.2.1
We are installing into a shared vpc construct within GCP / Google Cloud. External access to the internet is via squid + nat gateway (which works fine) and this is also how we access the Google API endpoints, (also working fine).
Our http proxy variables are set as follows as we use squid + NAT gateway:
Forseti env vars are as follows:
While we are debugging, we are starting the forseti main process as:
We have disabled IPv6 and have set the forseti server to run on all ip addresses (localhost + vpc ip)
When we run the cronjob as installed, it bails out eventually (we think possibly when it is trying to do an inventory)
The output from the Forseti service also shows the error.
Routing looks ok…
Connection to localhost on the server ports looks ok…
ubuntu@forseti-server-vm-9k9ajf:~$ telnet localhost 50051
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
@@ ?
Connection closed by foreign host.
ubuntu@forseti-server-vm-9k9ajf:~$ telnet localhost 50052
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
^]
telnet>
Local firewall rules look ok (if permissive)…
I’m helping one of our teams with a pretty standard Forseti install with Config Validator, but running into some difficulties. I’m not an expert in Forseti, so please be gentle 😊.
If there are any bits of info that are needed to get better debugging output, just let me know and I’ll append.
--
Versions used are:
https://github.com/forseti-security/forseti-security/tree/v2.25.1
https://github.com/forseti-security/terraform-google-forseti/releases/tag/v5.2.1
We are installing into a shared vpc construct within GCP / Google Cloud. External access to the internet is via squid + nat gateway (which works fine) and this is also how we access the Google API endpoints, (also working fine).
Our http proxy variables are set as follows as we use squid + NAT gateway:
declare -x http_proxy="http://public-egress-proxy.gcp.company.example:3128/"
declare -x https_proxy="http://public-egress-proxy.gcp.company.example:3128/"
declare -x no_proxy="localhost"
declare -x https_proxy="http://public-egress-proxy.gcp.company.example:3128/"
declare -x no_proxy="localhost"
Forseti env vars are as follows:
ubuntu@forseti-server-vm-9k9ajf:~$ pwd
/home/ubuntu
ubuntu@forseti-server-vm-9k9ajf:~$ cat forseti_env.sh
#!/bin/bash
export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin:/usr/local/bin
export http_proxy="http://public-egress-proxy.gcp.company.example:3128/"
export https_proxy="http://public-egress-proxy.gcp.company.example:3128/"
export no_proxy="localhost"
export GRPC_TRACE=transport_security,connectivity_state,subchannel,call_error,server_channel,tcp
export GRPC_VERBOSITY=DEBUG
export GODEBUG=netdns=1
export GRPC_DNS_RESOLVER=native
export no_grpc_proxy=localhost
# Forseti environment variables
export FORSETI_HOME=/home/ubuntu/forseti-security
export FORSETI_SERVER_CONF=/home/ubuntu/forseti-security/configs/forseti_conf_server.yaml
export FORSETI_CLIENT_CONF=/home/ubuntu/forseti-security/configs/forseti_conf_client.yaml
export POLICY_LIBRARY_HOME=/home/ubuntu/policy-library
export POLICY_LIBRARY_SYNC_ENABLED=false
export POLICY_LIBRARY_SYNC_GIT_SYNC_TAG=v3.1.2
export POLICY_LIBRARY_REPOSITORY_BRANCH=master
export POLICY_LIBRARY_REPOSITORY_URL=
export CONFIG_VALIDATOR_ENDPOINT=localhost:50052
export SCANNER_BUCKET=forseti-server-9k9ajf
/home/ubuntu
ubuntu@forseti-server-vm-9k9ajf:~$ cat forseti_env.sh
#!/bin/bash
export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin:/usr/local/bin
export http_proxy="http://public-egress-proxy.gcp.company.example:3128/"
export https_proxy="http://public-egress-proxy.gcp.company.example:3128/"
export no_proxy="localhost"
export GRPC_TRACE=transport_security,connectivity_state,subchannel,call_error,server_channel,tcp
export GRPC_VERBOSITY=DEBUG
export GODEBUG=netdns=1
export GRPC_DNS_RESOLVER=native
export no_grpc_proxy=localhost
# Forseti environment variables
export FORSETI_HOME=/home/ubuntu/forseti-security
export FORSETI_SERVER_CONF=/home/ubuntu/forseti-security/configs/forseti_conf_server.yaml
export FORSETI_CLIENT_CONF=/home/ubuntu/forseti-security/configs/forseti_conf_client.yaml
export POLICY_LIBRARY_HOME=/home/ubuntu/policy-library
export POLICY_LIBRARY_SYNC_ENABLED=false
export POLICY_LIBRARY_SYNC_GIT_SYNC_TAG=v3.1.2
export POLICY_LIBRARY_REPOSITORY_BRANCH=master
export POLICY_LIBRARY_REPOSITORY_URL=
export CONFIG_VALIDATOR_ENDPOINT=localhost:50052
export SCANNER_BUCKET=forseti-server-9k9ajf
While we are debugging, we are starting the forseti main process as:
#!/bin/bash
export http_proxy="http://public-egress-proxy.gcp.example.com:3128/"
export https_proxy="http://public-egress-proxy.gcp. example.com:3128/"
export no_proxy="localhost,10.246.133.31,::,::1"
export GRPC_TRACE=transport_security,connectivity_state,subchannel,call_error,server_channel,tcp
export GRPC_VERBOSITY=DEBUG
export GODEBUG=netdns=1
export GRPC_DNS_RESOLVER=native
export POLICY_LIBRARY_HOME=/home/ubuntu/policy-library
/usr/local/bin/forseti_server --log_level debug --enable_console_log --endpoint '[::]:50051' --forseti_db mysql+pymysql://forseti_security_user:ULTRA...@127.0.0.1:3306/forset
i_security?charset=utf8 --config_file_path /home/ubuntu/forseti-security/configs/forseti_conf_server.yaml --services explain inventory model scanner notifier
export http_proxy="http://public-egress-proxy.gcp.example.com:3128/"
export https_proxy="http://public-egress-proxy.gcp. example.com:3128/"
export no_proxy="localhost,10.246.133.31,::,::1"
export GRPC_TRACE=transport_security,connectivity_state,subchannel,call_error,server_channel,tcp
export GRPC_VERBOSITY=DEBUG
export GODEBUG=netdns=1
export GRPC_DNS_RESOLVER=native
export POLICY_LIBRARY_HOME=/home/ubuntu/policy-library
/usr/local/bin/forseti_server --log_level debug --enable_console_log --endpoint '[::]:50051' --forseti_db mysql+pymysql://forseti_security_user:ULTRA...@127.0.0.1:3306/forset
i_security?charset=utf8 --config_file_path /home/ubuntu/forseti-security/configs/forseti_conf_server.yaml --services explain inventory model scanner notifier
We have disabled IPv6 and have set the forseti server to run on all ip addresses (localhost + vpc ip)
When we run the cronjob as installed, it bails out eventually (we think possibly when it is trying to do an inventory)
++ echo '{' '"serverMessage":' '"Scanner' Index ID: 1596023823959442 is 'created"' '}' '{' '"serverMessage":' '"Running' 'BigqueryScanner..."' '}' '{' '"serverMessage":' '"Running' 'BlacklistScanner..."' '}' '{' '"serverMessage":' '"Running' 'BucketsAclScanner..."' '}' '{' '"serverMessage":' '"Error' running scanner: ConfigValidatorScanner: ''\''Traceback' '(most' recent call 'last):\n' File '\"/usr/local/lib/python3.6/dist-packages/forseti_security-2.25.1-py3.6.egg/google/cloud/forseti/scanner/scanners/config_validator_util/validator_client.py\",' line 197, in 'reset\n' 'self.stub.Reset(validator_pb2.ResetRequest())\n' File '\"/usr/local/lib/python3.6/dist-packages/grpc/_channel.py\",' line 565, in '__call__\n' return '_end_unary_response_blocking(state,' call, False, 'None)\n' File '\"/usr/local/lib/python3.6/dist-packages/grpc/_channel.py\",' line 467, in '_end_unary_response_blocking\n' raise '_Rendezvous(state,' None, None, 'deadline)\ngrpc._channel._Rendezvous:' '<_Rendezvous' of RPC that terminated 'with:\n\tstatus' = 'StatusCode.UNAVAILABLE\n\tdetails' = '\"failed' to connect to all 'addresses\"\n\tdebug_error_string' = '\"{\"created\":\"@1596023825.799245398\",\"description\":\"Failed' to pick 'subchannel\",\"file\":\"src/core/ext/filters/client_channel/client_channel.cc\",\"file_line\":3528,\"referenced_errors\":[{\"created\":\"@1596023825.557379243\",\"description\":\"failed' to connect to all 'addresses\",\"file\":\"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc\",\"file_line\":399,\"grpc_status\":14}]}\"\n>\n\nDuring' handling of the above exception, another exception 'occurred:\n\nTraceback' '(most' recent call 'last):\n' File '\"/usr/local/lib/python3.6/dist-packages/forseti_security-2.25.1-py3.6.egg/google/cloud/forseti/scanner/scanner.py\",' line 119, in 'run\n' 'scanner.run()\n' File '\"/usr/local/lib/python3.6/dist-packages/forseti_security-2.25.1-py3.6.egg/google/cloud/forseti/scanner/scanners/config_validator_scanner.py\",' line 203, in 'run\n' for flattened_violations in 'self._retrieve_flattened_violations():\n' File '\"/usr/local/lib/python3.6/dist-packages/forseti_security-2.25.1-py3.6.egg/google/cloud/forseti/scanner/scanners/config_validator_scanner.py\",' line 178, in '_retrieve_flattened_violations\n' 'self.validator_client.reset()\n' File '\"/home/ubuntu/forseti-security/.eggs/retrying-1.3.3-py3.6.egg/retrying.py\",' line 49, in 'wrapped_f\n' return 'Retrying(*dargs,' '**dkw).call(f,' '*args,' '**kw)\n' File '\"/home/ubuntu/forseti-security/.eggs/retrying-1.3.3-py3.6.egg/retrying.py\",' line 212, in 'call\n' raise 'attempt.get()\n' File '\"/home/ubuntu/forseti-security/.eggs/retrying-1.3.3-py3.6.egg/retrying.py\",' line 247, in 'get\n' 'six.reraise(self.value[0],' 'self.value[1],' 'self.value[2])\n' File '\"/usr/local/lib/python3.6/dist-packages/six.py\",' line 703, in 'reraise\n' raise 'value\n' File '\"/home/ubuntu/forseti-security/.eggs/retrying-1.3.3-py3.6.egg/retrying.py\",' line 200, in 'call\n' attempt = 'Attempt(fn(*args,' '**kwargs),' attempt_number, 'False)\n' File '\"/usr/local/lib/python3.6/dist-packages/forseti_security-2.25.1-py3.6.egg/google/cloud/forseti/scanner/scanners/config_validator_util/validator_client.py\",' line 201, in 'reset\n' raise 'errors.ConfigValidatorServerUnavailableError(e)\ngoogle.cloud.forseti.scanner.scanners.config_validator_util.errors.ConfigValidatorServerUnavailableError:' '<_Rendezvous' of RPC that terminated 'with:\n\tstatus' = 'StatusCode.UNAVAILABLE\n\tdetails' = '\"failed' to connect to all 'addresses\"\n\tdebug_error_string' = '\"{\"created\":\"@1596023825.799245398\",\"description\":\"Failed' to pick 'subchannel\",\"file\":\"src/core/ext/filters/client_channel/client_channel.cc\",\"file_line\":3528,\"referenced_errors\":[{\"created\":\"@1596023825.557379243\",\"description\":\"failed' to connect to all 'addresses\",\"file\":\"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc\",\"file_line\":399,\"grpc_status\":14}]}\"\n>\n'\''"' '}' '{' '"serverMessage":' '"Running' 'CloudSqlAclScanner..."' '}' '{' '"serverMessage":' '"Running' 'FirewallPolicyScanner..."' '}' '{' '"serverMessage":' '"Running' 'GroupsScanner..."' '}' '{' '"serverMessage":' '"Running' 'GroupsSettingsScanner..."' '}' '{' '"serverMessage":' '"Running' 'IamPolicyScanner..."' '}' '{' '"serverMessage":' '"Running' 'IapScanner..."' '}' '{' '"serverMessage":' '"Running' 'KeVersionScanner..."' '}' '{' '"serverMessage":' '"Running' 'KMSScanner..."' '}' '{' '"serverMessage":' '"Running' 'LienScanner..."' '}' '{' '"serverMessage":' '"Running' 'LocationScanner..."' '}' '{' '"serverMessage":' '"Running' 'LogSinkScanner..."' '}' '{' '"serverMessage":' '"Running' 'ResourceScanner..."' '}' '{' '"serverMessage":' '"Running' 'ServiceAccountKeyScanner..."' '}' '{' '"serverMessage":' '"Scan' 'completed!"' '}'
I0729 11:18:07.641510244 13694 tcp_posix.cc:413] TCP:0x7f6018003d40 call_cb 0x7f6018005880 0x7f60292a55b0:0x7f6018005740
I0729 11:18:07.641515401 13694 tcp_posix.cc:416] READ 0x7f6018003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:18:07.641523793 13694 tcp_posix.cc:422] DATA: 5f 6c 69 6e 65 22 3a 33 35 32 38 2c 22 72 65 66 65 72 65 6e 63 65 64 5f 65 72 72 6f 72 73 22 3a 5b 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 31 34 38 37 2e 36 33 39 37 36 35 37 32 39 22 2c 22 64 65 73 63 72 69 70 74 69 6f 6e 22 3a 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2f 6c 62 5f 70 6f 6c 69 63 79 2f 70 69 63 6b 5f 66 69 72 73 74 2f 70 69 63 6b 5f 66 69 72 73 74 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 39 39 2c 22 67 72 70 63 5f 73 74 61 74 75 73 22 3a 31 34 7d 5d 7d 22 25 30 41 3e '_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"%0A>'
I0729 11:18:07.641541657 13694 tcp_posix.cc:611] TCP:0x7f6018003d40 got_read: "No Error"
I0729 11:18:07.641548989 13694 tcp_posix.cc:602] TCP:0x7f6018003d40 do_read
I0729 11:18:07.641559978 13694 tcp_posix.cc:265] TCP:0x7f6018003d40 notify_on_read
D0729 11:18:07.641571777 13694 call.cc:733] set_final_status CLI
D0729 11:18:07.641596725 13694 call.cc:734] {"created":"@1596021487.641570130","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}
Error occurred on the server side, message: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNKNOWN
details = "Exception iterating responses: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNAVAILABLE
details = "failed to connect to all addresses"
debug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>"
debug_error_string = "{"created":"@1596021487.641570130","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}"
>
I0729 11:18:07.641510244 13694 tcp_posix.cc:413] TCP:0x7f6018003d40 call_cb 0x7f6018005880 0x7f60292a55b0:0x7f6018005740
I0729 11:18:07.641515401 13694 tcp_posix.cc:416] READ 0x7f6018003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:18:07.641523793 13694 tcp_posix.cc:422] DATA: 5f 6c 69 6e 65 22 3a 33 35 32 38 2c 22 72 65 66 65 72 65 6e 63 65 64 5f 65 72 72 6f 72 73 22 3a 5b 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 31 34 38 37 2e 36 33 39 37 36 35 37 32 39 22 2c 22 64 65 73 63 72 69 70 74 69 6f 6e 22 3a 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2f 6c 62 5f 70 6f 6c 69 63 79 2f 70 69 63 6b 5f 66 69 72 73 74 2f 70 69 63 6b 5f 66 69 72 73 74 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 39 39 2c 22 67 72 70 63 5f 73 74 61 74 75 73 22 3a 31 34 7d 5d 7d 22 25 30 41 3e '_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"%0A>'
I0729 11:18:07.641541657 13694 tcp_posix.cc:611] TCP:0x7f6018003d40 got_read: "No Error"
I0729 11:18:07.641548989 13694 tcp_posix.cc:602] TCP:0x7f6018003d40 do_read
I0729 11:18:07.641559978 13694 tcp_posix.cc:265] TCP:0x7f6018003d40 notify_on_read
D0729 11:18:07.641571777 13694 call.cc:733] set_final_status CLI
D0729 11:18:07.641596725 13694 call.cc:734] {"created":"@1596021487.641570130","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}
Error occurred on the server side, message: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNKNOWN
details = "Exception iterating responses: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNAVAILABLE
details = "failed to connect to all addresses"
debug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>"
debug_error_string = "{"created":"@1596021487.641570130","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596021487.639770837","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596021487.639765729","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}"
>
The output from the Forseti service also shows the error.
{
"id": "1596022776181193",
"step": "bucket/demo_test_buctel_001",
"finalMessage": false,
"warnings": 0,
"errors": 0,
"lastWarning": "",
"lastError": ""
}
I0729 11:41:25.876017638 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876041172 14849 tcp_posix.cc:602] TCP:0x7f2750003d40 do_read
I0729 11:41:25.876054101 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876063489 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876072187 14849 tcp_posix.cc:422] DATA: 00 02 5d 01 05 00 00 00 01 40 0b 67 72 70 63 2d '..]......@.grpc-'
I0729 11:41:25.876086870 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876093673 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876103904 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876116560 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876127156 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876170678 14849 tcp_posix.cc:422] DATA: 73 74 61 74 75 73 01 32 00 0c 67 72 70 63 2d 6d 65 73 73 61 67 65 7f be 03 45 78 63 65 70 74 69 6f 6e 20 69 74 65 72 61 74 69 6e 67 20 72 65 73 70 6f 6e 73 65 73 3a 20 3c 5f 52 65 6e 64 65 7a 76 6f 75 73 20 6f 66 20 52 50 43 20 74 68 61 74 20 74 65 72 6d 69 6e 61 74 65 64 20 77 69 74 68 3a 25 30 41 25 30 39 73 74 61 74 75 73 20 3d 20 53 74 61 74 75 73 43 6f 64 65 2e 55 4e 41 56 41 49 4c 41 42 4c 45 25 30 41 25 30 39 64 65 74 61 69 6c 73 20 3d 20 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 25 30 41 25 30 39 64 65 62 75 67 5f 65 72 72 6f 72 5f 73 74 72 69 6e 67 20 3d 20 22 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 32 38 38 35 2e 38 37 33 39 35 32 32 35 37 22 2c 22 64 65 73 63 72 69 'status.2..grpc-message...Exception iterating responses: <_Rendezvous of RPC that terminated with:%0A%09status = StatusCode.UNAVAILABLE%0A%09details = "failed to connect to all addresses"%0A%09debug_error_string = "{"created":"@1596022885.873952257","descri'
I0729 11:41:25.876195467 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876205844 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876215485 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876227128 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876234627 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876246556 14849 tcp_posix.cc:422] DATA: 70 74 69 6f 6e 22 3a 22 46 61 69 6c 65 64 20 74 6f 20 70 69 63 6b 20 73 75 62 63 68 61 6e 6e 65 6c 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 35 32 38 2c 22 72 65 66 65 72 65 6e 63 65 64 5f 65 72 72 6f 72 73 22 3a 5b 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 32 38 38 35 2e 38 37 33 39 31 38 30 30 33 22 2c 22 64 65 73 63 72 69 70 74 69 6f 6e 22 3a 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 'ption":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/clien'
I0729 11:41:25.876258067 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876265198 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876271910 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876282803 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876290107 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876298609 14849 tcp_posix.cc:422] DATA: 74 5f 63 68 61 6e 6e 65 6c 2f 6c 62 5f 70 6f 6c 69 63 79 2f 70 69 63 6b 5f 66 69 72 73 74 2f 70 69 63 6b 5f 66 69 72 73 74 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 39 39 2c 22 67 72 70 63 5f 73 74 61 74 75 73 22 3a 31 34 7d 5d 7d 22 25 30 41 3e 't_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"%0A>'
I0729 11:41:25.876313709 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876320739 14849 tcp_posix.cc:602] TCP:0x7f2750003d40 do_read
I0729 11:41:25.876329682 14849 tcp_posix.cc:265] TCP:0x7f2750003d40 notify_on_read
D0729 11:41:25.876366184 14849 call.cc:733] set_final_status CLI
D0729 11:41:25.876393796 14849 call.cc:734] {"created":"@1596022885.876364027","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}
Error occurred on the server side, message: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNKNOWN
details = "Exception iterating responses: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNAVAILABLE
details = "failed to connect to all addresses"
debug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>"
debug_error_string = "{"created":"@1596022885.876364027","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}"
>
+ echo 'Finished running Forseti inventory.'
Finished running Forseti inventory.
"id": "1596022776181193",
"step": "bucket/demo_test_buctel_001",
"finalMessage": false,
"warnings": 0,
"errors": 0,
"lastWarning": "",
"lastError": ""
}
I0729 11:41:25.876017638 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876041172 14849 tcp_posix.cc:602] TCP:0x7f2750003d40 do_read
I0729 11:41:25.876054101 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876063489 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876072187 14849 tcp_posix.cc:422] DATA: 00 02 5d 01 05 00 00 00 01 40 0b 67 72 70 63 2d '..]......@.grpc-'
I0729 11:41:25.876086870 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876093673 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876103904 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876116560 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876127156 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876170678 14849 tcp_posix.cc:422] DATA: 73 74 61 74 75 73 01 32 00 0c 67 72 70 63 2d 6d 65 73 73 61 67 65 7f be 03 45 78 63 65 70 74 69 6f 6e 20 69 74 65 72 61 74 69 6e 67 20 72 65 73 70 6f 6e 73 65 73 3a 20 3c 5f 52 65 6e 64 65 7a 76 6f 75 73 20 6f 66 20 52 50 43 20 74 68 61 74 20 74 65 72 6d 69 6e 61 74 65 64 20 77 69 74 68 3a 25 30 41 25 30 39 73 74 61 74 75 73 20 3d 20 53 74 61 74 75 73 43 6f 64 65 2e 55 4e 41 56 41 49 4c 41 42 4c 45 25 30 41 25 30 39 64 65 74 61 69 6c 73 20 3d 20 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 25 30 41 25 30 39 64 65 62 75 67 5f 65 72 72 6f 72 5f 73 74 72 69 6e 67 20 3d 20 22 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 32 38 38 35 2e 38 37 33 39 35 32 32 35 37 22 2c 22 64 65 73 63 72 69 'status.2..grpc-message...Exception iterating responses: <_Rendezvous of RPC that terminated with:%0A%09status = StatusCode.UNAVAILABLE%0A%09details = "failed to connect to all addresses"%0A%09debug_error_string = "{"created":"@1596022885.873952257","descri'
I0729 11:41:25.876195467 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876205844 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876215485 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876227128 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876234627 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876246556 14849 tcp_posix.cc:422] DATA: 70 74 69 6f 6e 22 3a 22 46 61 69 6c 65 64 20 74 6f 20 70 69 63 6b 20 73 75 62 63 68 61 6e 6e 65 6c 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2f 63 6c 69 65 6e 74 5f 63 68 61 6e 6e 65 6c 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 35 32 38 2c 22 72 65 66 65 72 65 6e 63 65 64 5f 65 72 72 6f 72 73 22 3a 5b 7b 22 63 72 65 61 74 65 64 22 3a 22 40 31 35 39 36 30 32 32 38 38 35 2e 38 37 33 39 31 38 30 30 33 22 2c 22 64 65 73 63 72 69 70 74 69 6f 6e 22 3a 22 66 61 69 6c 65 64 20 74 6f 20 63 6f 6e 6e 65 63 74 20 74 6f 20 61 6c 6c 20 61 64 64 72 65 73 73 65 73 22 2c 22 66 69 6c 65 22 3a 22 73 72 63 2f 63 6f 72 65 2f 65 78 74 2f 66 69 6c 74 65 72 73 2f 63 6c 69 65 6e 'ption":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/clien'
I0729 11:41:25.876258067 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876265198 14849 tcp_posix.cc:596] TCP:0x7f2750003d40 alloc_slices
I0729 11:41:25.876271910 14849 tcp_posix.cc:577] TCP:0x7f2750003d40 read_allocation_done: "No Error"
I0729 11:41:25.876282803 14849 tcp_posix.cc:413] TCP:0x7f2750003d40 call_cb 0x7f2750005880 0x7f276070a5b0:0x7f2750005740
I0729 11:41:25.876290107 14849 tcp_posix.cc:416] READ 0x7f2750003d40 (peer=ipv4:127.0.0.1:50051) error="No Error"
D0729 11:41:25.876298609 14849 tcp_posix.cc:422] DATA: 74 5f 63 68 61 6e 6e 65 6c 2f 6c 62 5f 70 6f 6c 69 63 79 2f 70 69 63 6b 5f 66 69 72 73 74 2f 70 69 63 6b 5f 66 69 72 73 74 2e 63 63 22 2c 22 66 69 6c 65 5f 6c 69 6e 65 22 3a 33 39 39 2c 22 67 72 70 63 5f 73 74 61 74 75 73 22 3a 31 34 7d 5d 7d 22 25 30 41 3e 't_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"%0A>'
I0729 11:41:25.876313709 14849 tcp_posix.cc:611] TCP:0x7f2750003d40 got_read: "No Error"
I0729 11:41:25.876320739 14849 tcp_posix.cc:602] TCP:0x7f2750003d40 do_read
I0729 11:41:25.876329682 14849 tcp_posix.cc:265] TCP:0x7f2750003d40 notify_on_read
D0729 11:41:25.876366184 14849 call.cc:733] set_final_status CLI
D0729 11:41:25.876393796 14849 call.cc:734] {"created":"@1596022885.876364027","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}
Error occurred on the server side, message: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNKNOWN
details = "Exception iterating responses: <_Rendezvous of RPC that terminated with:
status = StatusCode.UNAVAILABLE
details = "failed to connect to all addresses"
debug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"
>"
debug_error_string = "{"created":"@1596022885.876364027","description":"Error received from peer ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception iterating responses: <_Rendezvous of RPC that terminated with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect to all addresses"\n\tdebug_error_string = "{"created":"@1596022885.873952257","description":"Failed to pick subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed to connect to all addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":399,"grpc_status":14}]}"\n>","grpc_status":2}"
>
+ echo 'Finished running Forseti inventory.'
Finished running Forseti inventory.
Routing looks ok…
ubuntu@forseti-server-vm-9k9ajf:~$ netstat -rn
Kernel IP routing table
Destination Gateway Genmask Flags MSS Window irtt Iface
0.0.0.0 10.246.133.1 0.0.0.0 UG 0 0 0 ens4
10.246.133.1 0.0.0.0 255.255.255.255 UH 0 0 0 ens4
Kernel IP routing table
Destination Gateway Genmask Flags MSS Window irtt Iface
0.0.0.0 10.246.133.1 0.0.0.0 UG 0 0 0 ens4
10.246.133.1 0.0.0.0 255.255.255.255 UH 0 0 0 ens4
Connection to localhost on the server ports looks ok…
ubuntu@forseti-server-vm-9k9ajf:~$ telnet localhost 50051
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
@@ ?
Connection closed by foreign host.
ubuntu@forseti-server-vm-9k9ajf:~$ telnet localhost 50052
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
^]
telnet>
Local firewall rules look ok (if permissive)…
ubuntu@forseti-server-vm-9k9ajf:~$ sudo iptables -L -v
Chain INPUT (policy ACCEPT 375K packets, 373M bytes)
pkts bytes target prot opt in out source destination
375K 373M sshguard all -- any any anywhere anywhere
Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination
Chain OUTPUT (policy ACCEPT 423K packets, 417M bytes)
pkts bytes target prot opt in out source destination
Chain sshguard (1 references)
pkts bytes target prot opt in out source destination
VPC-SC is running in Dry-Mode (non-enforcing)
Chain INPUT (policy ACCEPT 375K packets, 373M bytes)
pkts bytes target prot opt in out source destination
375K 373M sshguard all -- any any anywhere anywhere
Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination
Chain OUTPUT (policy ACCEPT 423K packets, 417M bytes)
pkts bytes target prot opt in out source destination
Chain sshguard (1 references)
pkts bytes target prot opt in out source destination
VPC-SC is running in Dry-Mode (non-enforcing)
So the main error in this is:
debug_error_string
=
"{"created":"@1596022885.876364027","description":"Error received from
peer
ipv4:127.0.0.1:50051","file":"src/core/lib/surface/call.cc","file_line":1052,"grpc_message":"Exception
iterating responses: <_Rendezvous of RPC that terminated
with:\n\tstatus = StatusCode.UNAVAILABLE\n\tdetails = "failed to connect
to all addresses"\n\tdebug_error_string =
"{"created":"@1596022885.873952257","description":"Failed to pick
subchannel","file":"src/core/ext/filters/client_channel/client_channel.cc","file_line":3528,"referenced_errors":[{"created":"@1596022885.873918003","description":"failed
to connect to all
addresses","file":"src/core/ext/filters/client_channel/lb_policy/pick_first
Googling led to believe it might be DNS related, but DNS seems to work fine and we can resolve addresses. The forseti repo is also able to checkout perfectly for example (proofing again that proxy/connectivity works).
Any ideas or pointers?
Reply all
Reply to author
Forward
0 new messages