URL Encoded Webhook - Python3 Encoding Failure

SUMMARY

Provide a quick summary of your bug report.

STACKSTORM VERSION

Paste the output of st2 --version:

st2 3.1.0, on Python 3.6.8

OS, environment, install method

Post what OS you are running this on, along with any other relevant information/

• e.g. Docker, Vagrant, Kubernetes, etc. Describe how you installed ST2
• e.g. one-line install, custom install, etc -->

Ubuntu 18.04.3 LTS - Manual install

Steps to reproduce the problem

When running the system with Python3, configuring a webhook as a trigger to receive data from a remote source. Configure the remote source to send text data that is URL encoded in the body of the message, as shown in sample curl output below:

curl --location --request POST 'https://127.0.0.1/api/v1/webhooks/test_hook'
--header 'St2-Api-Key: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
--header 'Content-Type: application/x-www-form-urlencoded'
--data-raw 'MyVariableOne=ValueOne&MyVariableTwo=ValueTwo'

Expected Results

What did you expect to happen when running the steps above?

The system should properly process the URL encoded body data and should return it a proper JSON

{
"MyVariableOne": [
"ValueOne"
],
"MyVariableTwo": [
"ValueTwo\n"
]
}

Actual Results

What happened? What output did you get?

The process fails with the following debug output:

[2020-01-27 11:49:57 +0000] [10770] [DEBUG] POST /v1/webhooks/valero_cpe
2020-01-27 11:49:57,579 140064340756784 DEBUG (unknown file) [-] Match path: /v1/webhooks/valero_cpe
2020-01-27 11:49:57,580 140064340756784 INFO (unknown file) [-] 684b74a5-5ea6-4602-9006-2a9a0033710c - POST /v1/webhooks/valero_cpe with query={} (method='POST',path='/v1/webhooks/valero_cpe',remote_addr='127.0.0.1',query={},request_id='684b74a5-5ea6-4602-9006-2a9a0033710c')
2020-01-27 11:49:57,580 140064340756784 DEBUG (unknown file) [-] Received call with WebOb: POST /v1/webhooks/valero_cpe HTTP/1.0
Accept: */*
Accept-Encoding: gzip, deflate, br
Cache-Control: no-cache
Content-Length: 46
Content-Type: application/x-www-form-urlencoded
Host: 81296fd8.ngrok.io,81296fd8.ngrok.io
Postman-Token: 00a125ee-11b4-46fe-9500-75f5d9a811d8
St2-Api-Key: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
User-Agent: PostmanRuntime/7.22.0
X-Forwarded-For: 68.187.78.177, 127.0.0.1
X-Forwarded-Proto: https
X-Real-Ip: 127.0.0.1
X-Request-Id: 684b74a5-5ea6-4602-9006-2a9a0033710c

MyVariableOne=ValueOne&MyVariableTwo=ValueTwo

2020-01-27 11:49:57,580 140064340756784 DEBUG (unknown file) [-] Match path: /v1/webhooks/valero_cpe
2020-01-27 11:49:57,581 140064340756784 DEBUG (unknown file) [-] Parsed endpoint: {'operationId': 'st2api.controllers.v1.webhooks:webhooks_controller.post', 'x-requirements': {'hook': '.*'}, 'description': 'Trigger a webhook.\n', 'parameters': [{'name': 'hook', 'in': 'path', 'description': 'Webhook path', 'type': 'string', 'required': True}, {'name': 'webhook_body_api', 'in': 'body', 'description': 'Webhook payload', 'schema': {'$ref': '#/definitions/WebhookBody'}}], 'x-parameters': [{'name': 'headers', 'in': 'request', 'description': 'List of headers attached to the request.'}, {'name': 'user', 'in': 'context', 'x-as': 'requester_user', 'description': 'User performing the operation.'}], 'responses': {'202': {'description': 'Single action being created', 'schema': {'$ref': '#/definitions/WebhookBody'}, 'examples': {'application/json': {'ref': 'core.local'}}}, 'default': {'description': 'Unexpected error', 'schema': {'$ref': '#/definitions/Error'}}}}
2020-01-27 11:49:57,581 140064340756784 DEBUG (unknown file) [-] Parsed path_vars: {'hook': 'valero_cpe'}
2020-01-27 11:49:57,583 140064340756784 AUDIT (unknown file) [-] API key with id "5ddbbb999e14ef34dced4bfc" is validated.
2020-01-27 11:49:57,587 140064340756784 DEBUG (unknown file) [-] Dispatching trigger {'uid': 'trigger:core:8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d:f7c2bb36b9bae14671835604c4167e1c', 'ref': 'core.8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'name': '8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'pack': 'core', 'type': 'core.st2.webhook', 'parameters': {'url': '/valero_cpe'}, 'id': '5df13f759e14ef0c5f1bcc3a'} with payload {'headers': {'Host': '81296fd8.ngrok.io,81296fd8.ngrok.io', 'X-Real-Ip': '127.0.0.1', 'X-Forwarded-For': '68.187.78.177, 127.0.0.1', 'Content-Length': '46', 'St2-Api-Key': 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx', 'Content-Type': 'application/x-www-form-urlencoded', 'User-Agent': 'PostmanRuntime/7.22.0', 'Accept': '*/*', 'Cache-Control': 'no-cache', 'Postman-Token': '00a125ee-11b4-46fe-9500-75f5d9a811d8', 'Accept-Encoding': 'gzip, deflate, br', 'X-Forwarded-Proto': 'https', 'X-Request-Id': '684b74a5-5ea6-4602-9006-2a9a0033710c'}, 'body': {b'MyVariableOne': [b'ValueOne'], b'MyVariableTwo': [b'ValueTwo\n']}}.
2020-01-27 11:49:57,590 140064340756784 DEBUG (unknown file) [-] Dispatching trigger (trigger={'uid': 'trigger:core:8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d:f7c2bb36b9bae14671835604c4167e1c', 'ref': 'core.8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'name': '8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'pack': 'core', 'type': 'core.st2.webhook', 'parameters': {'url': '/valero_cpe'}, 'id': '5df13f759e14ef0c5f1bcc3a'},payload={'trigger': {'uid': 'trigger:core:8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d:f7c2bb36b9bae14671835604c4167e1c', 'ref': 'core.8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'name': '8e1eb20c-33f6-4e4e-b0e9-dc166b37be7d', 'pack': 'core', 'type': 'core.st2.webhook', 'parameters': {'url': '/valero_cpe'}, 'id': '5df13f759e14ef0c5f1bcc3a'}, 'payload': {'headers': {'Host': '81296fd8.ngrok.io,81296fd8.ngrok.io', 'X-Real-Ip': '127.0.0.1', 'X-Forwarded-For': '68.187.78.177, 127.0.0.1', 'Content-Length': '46', 'St2-Api-Key': 'MzE0NDQ2MzI1YjhiZDFjNmRjZjE5NmUzODEyYTViYmZjNzY3YjYyNzVlNGMxMGQ3ODQ3NzI0YzE0YjNjNjVjNA', 'Content-Type': 'application/x-www-form-urlencoded', 'User-Agent': 'PostmanRuntime/7.22.0', 'Accept': '*/*', 'Cache-Control': 'no-cache', 'Postman-Token': '00a125ee-11b4-46fe-9500-75f5d9a811d8', 'Accept-Encoding': 'gzip, deflate, br', 'X-Forwarded-Proto': 'https', 'X-Request-Id': '684b74a5-5ea6-4602-9006-2a9a0033710c'}, 'body': {b'MyVariableOne': [b'ValueOne'], b'MyVariableTwo': [b'ValueTwo\n']}}, 'trace_context': <st2common.models.api.trace.TraceContext object at 0x7f634564e518>})
2020-01-27 11:49:57,591 140064340756784 DEBUG channel [-] using channel_id: 1
2020-01-27 11:49:57,596 140064340756784 DEBUG channel [-] Channel open
2020-01-27 11:49:57,600 140064340756784 DEBUG channel [-] Closed channel #1
2020-01-27 11:49:57,601 140064340756784 ERROR (unknown file) [-] Failed to call controller function "post" for operation "st2api.controllers.v1.webhooks:webhooks_controller.post": key b'MyVariableOne' is not a string
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 515, in __call__
    resp = func(**kw)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2api/controllers/v1/webhooks.py", line 172, in post
    return Response(json=body, status=http_client.ACCEPTED)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 150, in __init__
    body = json_encode(json_body).encode('UTF-8')
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/util/jsonify.py", line 45, in json_encode
    return json.dumps(obj, cls=GenericJSON, indent=indent)
  File "/usr/lib/python3.6/json/__init__.py", line 238, in dumps
    **kw).encode(obj)
  File "/usr/lib/python3.6/json/encoder.py", line 201, in encode
    chunks = list(chunks)
  File "/usr/lib/python3.6/json/encoder.py", line 430, in _iterencode
    yield from _iterencode_dict(o, _current_indent_level)
  File "/usr/lib/python3.6/json/encoder.py", line 376, in _iterencode_dict
    raise TypeError("key " + repr(key) + " is not a string")
TypeError: key b'MyVariableOne' is not a string
2020-01-27 11:49:57,601 140064340756784 ERROR (unknown file) [-] API call failed: key b'MyVariableOne' is not a string
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/middleware/error_handling.py", line 48, in __call__
    return self.app(environ, start_response)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/middleware/streaming.py", line 47, in __call__
    return self.app(environ, start_response)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 594, in as_wsgi
    resp = self(req)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 519, in __call__
    raise e
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 515, in __call__
    resp = func(**kw)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2api/controllers/v1/webhooks.py", line 172, in post
    return Response(json=body, status=http_client.ACCEPTED)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 150, in __init__
    body = json_encode(json_body).encode('UTF-8')
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/util/jsonify.py", line 45, in json_encode
    return json.dumps(obj, cls=GenericJSON, indent=indent)
  File "/usr/lib/python3.6/json/__init__.py", line 238, in dumps
    **kw).encode(obj)
  File "/usr/lib/python3.6/json/encoder.py", line 201, in encode
    chunks = list(chunks)
  File "/usr/lib/python3.6/json/encoder.py", line 430, in _iterencode
    yield from _iterencode_dict(o, _current_indent_level)
  File "/usr/lib/python3.6/json/encoder.py", line 376, in _iterencode_dict
    raise TypeError("key " + repr(key) + " is not a string")
TypeError: key b'MyVariableOne' is not a string (_exception_class='TypeError',_exception_message="key b'MyVariableOne' is not a string",_exception_data={})
2020-01-27 11:49:57,606 140064340756784 DEBUG (unknown file) [-] Match path: /v1/webhooks/valero_cpe
2020-01-27 11:49:57,607 140064340756784 INFO (unknown file) [-] 684b74a5-5ea6-4602-9006-2a9a0033710c - 500 46 27.193ms (method='POST',path='/v1/webhooks/valero_cpe',remote_addr='127.0.0.1',status=500,runtime=27.193,content_length=46,request_id='684b74a5-5ea6-4602-9006-2a9a0033710c')
2020-01-27 11:49:57,608 140064340756784 DEBUG (unknown file) [-] 684b74a5-5ea6-4602-9006-2a9a0033710c - 500 46 27.193ms
b'{\n    "faultstring": "Internal Server Error"\n}' (method='POST',path='/v1/webhooks/valero_cpe',remote_addr='127.0.0.1',status=500,runtime=27.193,content_length=46,request_id='684b74a5-5ea6-4602-9006-2a9a0033710c',result='b\'{\\n    "faultstring": "Internal Server Error"\\n}\'')
[2020-01-27 11:49:57 +0000] [10770] [DEBUG] Closing connection.

I believe I have isolated the issue and it is due to the encoding for the body data that is returned by the WSGI server. In Python2, the body data was returned as a string so line 404 (below) in the router.py file worked properly to process the URL encoded body data.

data = urlparse.parse_qs(req.body)

In Python3, the WSGI server encoded the body data as a byte string and it needed to be decoded as a string before being processed further. Changing line 404 to the following, corrected the error and processed the web hook data properly:

data = urlparse.parse_qs(req.body.decode('utf-8'))

Making sure to follow these steps will guarantee the quickest resolution possible.

Thanks!

Start in st2common/router.py around line 404 and inspect how the webhook request body is passed to parse_qs; webhooks.py line 172 shows where the parsed body is returned. Reproduce the application/x-www-form-urlencoded POST against the webhook endpoint and verify that the response is valid JSON rather than raising the reported bytes-key TypeError.