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

Intent Parser returning intermittent HTTP 500 Error #202

Closed
mwes opened this issue Jun 19, 2020 · 17 comments
Closed

Intent Parser returning intermittent HTTP 500 Error #202

mwes opened this issue Jun 19, 2020 · 17 comments
Assignees
Labels
bug Something isn't working
Milestone

Comments

@mwes
Copy link
Contributor

mwes commented Jun 19, 2020

In GitLab by @MWeston on May 26, 2020, 17:25

@dbryce noticed some issues parsing an experiment request:

http://intentparser.sd2e.org/document_request?1fFcxyJyheMrzSsVoSsO6v7qHJKFf_0heIFtqEur02cg

Trying to reproduce, I built out a minimal example:

import requests
import simplejson as json
from simplejson.errors import JSONDecodeError

for i in range(10):
    try:
        intent_request = "http://intentparser.sd2e.org/document_request?1fFcxyJyheMrzSsVoSsO6v7qHJKFf_0heIFtqEur02cg"
        r = requests.get(intent_request)
        print(r.json())
    except JSONDecodeError as jde:
        print(r)
        print(jde)

Running this gives inconsistent results. Sometimes we'll get the JSON returned, and sometimes we'll get an HTTP 500.

Running more than one instance of the above seems to increase the likelihood of the error, but even then it's not consistent/guaranteed.

@tramyn can you look into this? I'm not sure what's going on, but it's non-deterministic. Maybe a possible state or race condition issue related to load?

@mwes mwes added the bug Something isn't working label Jun 19, 2020
@mwes mwes added this to the 2.7 milestone Jun 19, 2020
@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on May 26, 2020, 17:34

@MWeston Will look into this now.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @MWeston on May 26, 2020, 17:36

I was able to pull the following traces from the logs. It looks like the container eventually crashes at the end.

[INFO ] 2020-05-26 21:31:20,990 intent_parser_server.py line:174 Traceback (most recent call last):
File "/usr/src/intent_parser/server/intent_parser_server.py", line 166, in handle_client_connection
self.handle_GET(httpMessage, socket_manager)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 199, in handle_GET
response = self.process_document_request(httpMessage)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 226, in process_document_request
intent_parser.process()
File "/usr/src/intent_parser/intent_parser.py", line 46, in process
self._generate_request()
File "/usr/src/intent_parser/intent_parser.py", line 329, in _generate_request
parameter_table = ParameterTable(self.sbol_dictionary.get_strateos_mappings())
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 165, in get_strateos_mappings
attribute_tab = self.get_tab_sheet('Attribute')
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 179, in get_tab_sheet
sheet_data = self.fetch_spreadsheet_data()
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 92, in fetch_spreadsheet_data
tab_data[tab] = self.google_accessor.get_row_data(tab=tab)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 355, in get_row_data
tab_data = self._get_tab_data(value_range)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 275, in _get_tab_data
return self._execute_request(get)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 260, in _execute_request
return request.execute()
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/_helpers.py", line 134, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 901, in execute
headers=self.headers,
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 204, in _retry_request
raise exception
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 177, in _retry_request
resp, content = http.request(uri, method, *args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/google_auth_httplib2.py", line 198, in request
uri, method, body=body, headers=request_headers, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1991, in request
cachekey,
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1651, in _request
conn, request_uri, method, body, headers
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1589, in _conn_request
response = conn.getresponse()
File "/usr/lib/python3.6/http/client.py", line 1356, in getresponse
response.begin()
File "/usr/lib/python3.6/http/client.py", line 307, in begin
version, status, reason = self._read_status()
File "/usr/lib/python3.6/http/client.py", line 268, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "/usr/lib/python3.6/socket.py", line 586, in readinto
return self._sock.recv_into(b)
File "/usr/lib/python3.6/ssl.py", line 1012, in recv_into
return self.read(nbytes, buffer)
File "/usr/lib/python3.6/ssl.py", line 874, in read
return self._sslobj.read(len, buffer)
File "/usr/lib/python3.6/ssl.py", line 631, in read
v = self._sslobj.read(len, buffer)
ssl.SSLError: [SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption failed or bad record mac (_ssl.c:2309)

[INFO ] 2020-05-26 21:31:20,991 intent_parser_server.py line:174 Traceback (most recent call last):
File "/usr/src/intent_parser/server/intent_parser_server.py", line 166, in handle_client_connection
self.handle_GET(httpMessage, socket_manager)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 199, in handle_GET
response = self.process_document_request(httpMessage)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 226, in process_document_request
intent_parser.process()
File "/usr/src/intent_parser/intent_parser.py", line 46, in process
self._generate_request()
File "/usr/src/intent_parser/intent_parser.py", line 329, in _generate_request
parameter_table = ParameterTable(self.sbol_dictionary.get_strateos_mappings())
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 165, in get_strateos_mappings
attribute_tab = self.get_tab_sheet('Attribute')
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 179, in get_tab_sheet
sheet_data = self.fetch_spreadsheet_data()
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 92, in fetch_spreadsheet_data
tab_data[tab] = self.google_accessor.get_row_data(tab=tab)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 355, in get_row_data
tab_data = self._get_tab_data(value_range)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 275, in _get_tab_data
return self._execute_request(get)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 260, in _execute_request
return request.execute()
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/_helpers.py", line 134, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 901, in execut
headers=self.headers,
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 177, in _retry_request
resp, content = http.request(uri, method, *args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/google_auth_httplib2.py", line 198, in request
uri, method, body=body, headers=request_headers, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1991, in request
cachekey,
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1651, in _request
conn, request_uri, method, body, headers
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1618, in _conn_request
content = response.read()
File "/usr/lib/python3.6/http/client.py", line 466, in read
return self._readall_chunked()
File "/usr/lib/python3.6/http/client.py", line 576, in _readall_chunked
value.append(self._safe_read(chunk_left))
File "/usr/lib/python3.6/http/client.py", line 622, in _safe_read
chunk = self.fp.read(min(amt, MAXAMOUNT))
File "/usr/lib/python3.6/socket.py", line 586, in readinto
return self._sock.recv_into(b)
File "/usr/lib/python3.6/ssl.py", line 1012, in recv_into
return self.read(nbytes, buffer)
File "/usr/lib/python3.6/ssl.py", line 874, in read
return self._sslobj.read(len, buffer)
File "/usr/lib/python3.6/ssl.py", line 631, in read
v = self._sslobj.read(len, buffer)
OSError: [Errno 0] Error

File "/usr/src/intent_parser/server/intent_parser_server.py", line 166, in handle_client_connection
self.handle_GET(httpMessage, socket_manager)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 199, in handle_GET
response = self.process_document_request(httpMessage)
File "/usr/src/intent_parser/server/intent_parser_server.py", line 226, in process_document_request
intent_parser.process()
File "/usr/src/intent_parser/intent_parser.py", line 46, in process
self._generate_request()
File "/usr/src/intent_parser/intent_parser.py", line 329, in _generate_request
parameter_table = ParameterTable(self.sbol_dictionary.get_strateos_mappings())
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 165, in get_strateos_mappings
attribute_tab = self.get_tab_sheet('Attribute')
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 179, in get_tab_sheet
sheet_data = self.fetch_spreadsheet_data()
File "/usr/src/intent_parser/accessor/sbol_dictionary_accessor.py", line 92, in fetch_spreadsheet_data
tab_data[tab] = self.google_accessor.get_row_data(tab=tab)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 355, in get_row_data
tab_data = self._get_tab_data(value_range)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 275, in _get_tab_data
return self._execute_request(get)
File "/usr/src/intent_parser/accessor/google_accessor.py", line 260, in _execute_request
return request.execute()
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/_helpers.py", line 134, in positional_wrapper
return wrapped(*args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 901, in execute
headers=self.headers,
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 204, in _retry_request
raise exception
File "/usr/local/lib/python3.6/dist-packages/googleapiclient/http.py", line 177, in _retry_request
resp, content = http.request(uri, method, *args, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/google_auth_httplib2.py", line 198, in request
uri, method, body=body, headers=request_headers, **kwargs)
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1991, in request
cachekey,
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1651, in _request
conn, request_uri, method, body, headers
File "/usr/local/lib/python3.6/dist-packages/httplib2/init.py", line 1589, in _conn_request
response = conn.getresponse()
File "/usr/lib/python3.6/http/client.py", line 1356, in getresponse
response.begin()
File "/usr/lib/python3.6/http/client.py", line 307, in begin
version, status, reason = self._read_status()
File "/usr/lib/python3.6/http/client.py", line 268, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "/usr/lib/python3.6/socket.py", line 586, in readinto
return self._sock.recv_into(b)
File "/usr/lib/python3.6/ssl.py", line 1012, in recv_into
return self.read(nbytes, buffer)
File "/usr/lib/python3.6/ssl.py", line 874, in read
return self._sslobj.read(len, buffer)
File "/usr/lib/python3.6/ssl.py", line 631, in read
v = self._sslobj.read(len, buffer)
ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:2309)
Segmentation fault (core dumped)

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on May 26, 2020, 18:43

@MWeston, I agree, this looks like a threading issue.
I will try addressing this in milestone 2.6. In the meantime, rerunning the requests should work.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @MWeston on May 28, 2020, 11:42

mentioned in merge request cp-request!438

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on May 28, 2020, 14:44

mentioned in merge request !115

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on May 28, 2020, 14:44

created merge request !115 to address this issue

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on Jun 10, 2020, 13:06

@MWeston Pushing issue to 2.8 milestone in order to address others that are higher in priorities.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @MWeston on Jun 10, 2020, 13:17

@tramyn this is a reliability issue that we currently have to work around - I request we fix this vs. working on new features next after 2.6 is released.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on Jun 10, 2020, 14:57

@MWeston, Can you provide me reasons on why this is classified as a high priority issue? Right now, I see this issue as a medium to low priority. I am hesitant to address this issue in 2.6 because a lot of code changes were made to support parsing control tables and linking URIs correctly. I want to minimize the type of issues that could occur with this new release so that they are all related to parsing tables. I understand that there is a workaround solution and that's why I think it is safe to push this issue to a later milestone release.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @MWeston on Jun 10, 2020, 16:15

@tramyn sure. Your change pushed this issue back to 2.8 - this is two releases away (we're currently at 2.6, 2.7 is next). I am requesting this be looked at in 2.7 next before we do any new feature requests. Alternatively something like a minor fix release of "2.6.1".

This is a small change, but it's important. Currently, any call to the intent-parser can fail because we're calling the Google API Python Client from a multi-threaded environment. As documented, this is not supported by the underlying use of the httplib2 library and can non-deterministically fail.

Any client currently using the intent parser (of which we are just one example) has to defensively code around this non-determinism. Even then, there's no guarantee we'll get correct behavior. The choices of the clients are:

  • Repeatedly make the call to IP, check for the non-deterministic error, stopping after a certain number of attempts and giving up. This is a failure condition that stops the automation chain of which the intent parser is a part. A human has to now step in and fix this.

  • Repeatedly make the call to IP, check for the non-deterministic error, not stopping regardless of the number of attempts. This can block indefinitely, and the caller is now stuck. A human has to now step in and fix this.

We could say: "Yes, if we make enough calls to the IP, the probability of this happening approaches 0" but this is not desirable from the perspective of:

  • Overall correct behavior of the software
  • The behavior clients have to perform to work around this

This change should have no effect on any of the actual parsing output. As documented above, the suggested solutions are to 1) build an accessor http service for the google api accessor used by each thread or 2) re-use a single http instance in the accessor initialization.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on Jun 10, 2020, 16:19

@MWeston Okay, these are valid reasons. I will try to address this in 2.6.1 if it is easy enough to resolve. Otherwise, I will need to bump this to 2.7.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @tramyn on Jun 18, 2020, 01:14

@MWeston the above solution is producing a google credential issue that intent parser will need to address. This credential issue occurs when fetching information from the SD2 Dictionary Maintainer. I'm not positive if the above solution will resolve this issue but I'll know more after I spend some time isolating each google APIs to run with its own credential file.

@mwes
Copy link
Contributor Author

mwes commented Jun 19, 2020

In GitLab by @MWeston on Jun 18, 2020, 08:17

@tramyn interesting - what is the error? The specific change has to do when building the service - passing in either a new http2 library for each service, or re-using one. You shouldn't need to run with separate credentials here for each service call.

@tramyn
Copy link
Collaborator

tramyn commented Jul 13, 2020

@mwes I looked into this issue and it turns out that IP was maxing out it's given quota for fetching information from the SBOL Spreadsheet. To resolve this, I had to filter through IP to ensure that functions accessing the spreadsheet should use IP's cached version of the spreadsheet and not directly calling the API. As it turns out, one function had this issue and to confirm it further, this function is what we see in the error report (mapping common names to Transcriptic UID). This function has been updated.

Now, one task remain. When IP has reached its quota limit for caching information from the spreadsheet, IP will need to safely catch this HTTP 500 error and bypass caching the spreadsheet until the next scheduled call.

@mwes
Copy link
Contributor Author

mwes commented Jul 13, 2020

Great, thanks @tramyn

tramyn added a commit that referenced this issue Jul 25, 2020
@tramyn
Copy link
Collaborator

tramyn commented Jul 25, 2020

This should be fixed in 746ae7d.

@tramyn tramyn closed this as completed Jul 25, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants