search

python-hyper / hyper

HTTP/2 for Python.
http://hyper.rtfd.org/en/latest/
MIT License
1.05k stars 192 forks source link

HTTP20Connection request and OpenSSL version #227

Closed lithiumlab closed 8 years ago

lithiumlab commented 8 years ago

Any information on how to create a multipart body? On the code comments of hyper body is about a file-like object or bytestring

        v2_url = 'service.example.api.com'
        conn = HTTP20Connection(v2_url)
        conn.request('POST', '/endpoint', headers=headers, body='NOTHING_HERE_YET')
        resp = conn.get_response()
        return resp.read()

Im getting this error exception when accessing a external api that expects a multipart body.

{"code":"INVALID_REQUEST_EXCEPTION","description":"No multipart body found in the payload."}

Any help, links to samples or hint would be appreciated.

Lukasa commented 8 years ago

@lithiumlab Hyper is much lower-level than many of the libraries you'll be used to using, and does not provide a hook for producing a multipart body. For that reason, you may want to try using the transport adapter for requests provided in this module, which should give you requests' tools for building the multipart body.

lithiumlab commented 8 years ago

Great. Thanks for the quick reply!

lithiumlab commented 8 years ago

@Lukasa

Is it possible to get_pushes() using this adapter?

s = requests.Session()
s.mount('https://myapiservice.com', HTTP20Adapter( enable_push=True ) )
r = s.post('https://myapiservice.com/events')

As r now seems a Response object from requests can't call get_pushes() on it.

I need to keep track of a downstream from an external API to handle multipart messages to generate events that trigger actions in the the front-end. Im using Flask to handle routes and requests to get the api external data. I get the initial data but i know need to keep track of the downstream.

Is it possible still using the Adapter?

Lukasa commented 8 years ago

Requests itself cannot call getpushes, but you can get access to the response object from response.raw. You can use that then to chain through, and you should be able to grab the underlying connection from in there.

lithiumlab commented 8 years ago

Thanks for the info.

Getting it to production (AWS Elastic Beanstalk) raises and error in the r = post.() call:

        try:
           r = s.post(url, data=multipart_encoded_data, headers=headers)
        except Exception as e:
            print('ERROR: '+ str(e) )
            raise
[Errno 104] Connection reset by peer

This is the aws environment info:

  Platform: 64bit Amazon Linux 2016.03 v2.1.0 running Python 2.7

Looking for hints on what can be the problem took me here: https://lukasa.co.uk/2013/01/Choosing_SSL_Version_In_Requests/ which suggest me it can be about correct SSL version maybe? I couldn't find much about AWS EB http2 support. Also im not exactly sure what python version is running in EB. My local environment is 2.7.11

Im using Flask and SSLify for routes, and hyper and requests for the external http/2 calls, https looks ok but im relatively new to protocols, http/2

Do you have any suggestion that helps me about whats happening? Thanks in advance and very grateful for the help already given.

    # local 
context = ('../outsidetheapp/cert.crt', '../outsidetheapp/key.key')
application.run(host='localhost', port=12344, ssl_context=context, threaded=True, debug=True)

    # aws eb 
    application.debug=True
application.run()

proper certs for domain are in place and attached to the eb environment. everything works normally except for the http2 call.

Lukasa commented 8 years ago

It's a bit tricky to tell. It could be related to OpenSSL functionality though, for sure. Can you provide me ssl.OPENSSL_VERSION from your production install?

lithiumlab commented 8 years ago

Sure... 

OpenSSL 1.0.1k-fips 8 Jan 2015
Lukasa commented 8 years ago

So the biggest problem there is that you might be missing ALPN, which could be causing the connection to be closed. It could also be related to missing cipher suites. Do you have the ability to run packet capture on your machines?

Lukasa commented 8 years ago

Either Wireshark or tcpdump, I mean.

Lukasa commented 8 years ago

Hrm, no, those look fine. What I'm interested in is what's going on with the TLS handshake itself.

lithiumlab commented 8 years ago

Ok. i have installed tcpdump on the aws eb machine through ssh. What will be the command?

Lukasa commented 8 years ago

tcpdump -s 1514 -w capture.pcap port 443 should do for now. That'll save to a file called capture.pcap, which you can mail to me.

lithiumlab commented 8 years ago

capture file sent

lithiumlab commented 8 years ago

Noticed getting two different errors when making some calls consecutively:

[Errno 104] Connection reset by peer
[Errno 32] Broken pipe

And this when no multipart data is sent:

 need more than 1 value to unpack

Last one probably just related to not sending data at all.

Lukasa commented 8 years ago

Broken Pipe and Connection Reset By Peer are very related exceptions, so we don't need to worry about them right now: they're likely both caused by the same thing.

So the reset connection seems to be about the format of your data, I think. The TLS handshake is completing successfully, and application data is being transmitted, but the connection then gets torn down. I'm missing some data here (you're able to use jumbo frames on this machine so the capture size wasn't large enough), but it appears to be a tear-down happening at the application layer.

In this instance, I recommend turning on debug logging and printing the output of the logs here (please scrub any headers or body that contains credentials by replacing those credentials with XXXXXX). That should let us see what's going on.

Lukasa commented 8 years ago

Sorry, when I said turn logging on I meant on the client side. =) I want to see the logs that hyper is emitting.

lithiumlab commented 8 years ago

Ok, here a call from the server to http2bin.org:

[Thu Apr 28 15:26:50.661477 2016] [:error] [pid 2962] --# POST ATTEMPT #--
[Thu Apr 28 15:26:50.695246 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.695346 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.695414 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.695517 2016] [:error] [pid 2962] HTTPHeaderMap([('server', 'h2o/1.7.0'), ('date', 'Thu, 28 Apr 2016 15:26:50 GMT'), ('content-type', 'text/html'), ('access-control-allow-origin', '*'), ('access-control-allow-credentials', 'true'), ('x-clacks-overhead', 'GNU Terry Pratchett'), ('content-length', '233')])
[Thu Apr 28 15:26:50.695617 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.695724 2016] [:error] [pid 2962] <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">
[Thu Apr 28 15:26:50.695803 2016] [:error] [pid 2962] <title>404 Not Found</title>
[Thu Apr 28 15:26:50.695866 2016] [:error] [pid 2962] <h1>Not Found</h1>
[Thu Apr 28 15:26:50.695939 2016] [:error] [pid 2962] <p>The requested URL was not found on the server.  If you entered the URL manually please check your spelling and try again.</p>
[Thu Apr 28 15:26:50.696010 2016] [:error] [pid 2962] 
[Thu Apr 28 15:26:50.696064 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.696114 2016] [:error] [pid 2962] ====================
[Thu Apr 28 15:26:50.696163 2016] [:error] [pid 2962] ====================

and here's a call to Alexa Voice Service (AVS) where i get the error:

[Thu Apr 28 15:30:54.591016 2016] [:error] [pid 3067] --# POST ATTEMPT #--
[Thu Apr 28 15:30:54.593137 2016] [:error] [pid 3067] [Errno 111] Connection refused
[Thu Apr 28 15:30:54.593284 2016] [:error] [pid 3067] [remote 172.31.63.223:52518] mod_wsgi (pid=3067): Exception occurred processing WSGI script '/path/to/my/app/application.py'.
[Thu Apr 28 15:30:54.593403 2016] [:error] [pid 3067] [remote 172.31.63.223:52518] Traceback (most recent call last):
[Thu Apr 28 15:30:54.593494 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1836, in __call__
[Thu Apr 28 15:30:54.593595 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     return self.wsgi_app(environ, start_response)
[Thu Apr 28 15:30:54.593695 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1820, in wsgi_app
[Thu Apr 28 15:30:54.593784 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     response = self.make_response(self.handle_exception(e))
[Thu Apr 28 15:30:54.593864 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1403, in handle_exception
[Thu Apr 28 15:30:54.593959 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     reraise(exc_type, exc_value, tb)
[Thu Apr 28 15:30:54.594045 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
[Thu Apr 28 15:30:54.594119 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     response = self.full_dispatch_request()
[Thu Apr 28 15:30:54.594185 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
[Thu Apr 28 15:30:54.594251 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     rv = self.handle_user_exception(e)
[Thu Apr 28 15:30:54.594321 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
[Thu Apr 28 15:30:54.594384 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     reraise(exc_type, exc_value, tb)
[Thu Apr 28 15:30:54.594439 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
[Thu Apr 28 15:30:54.594516 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     rv = self.dispatch_request()
[Thu Apr 28 15:30:54.594575 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
[Thu Apr 28 15:30:54.594640 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     return self.view_functions[rule.endpoint](**req.view_args)
[Thu Apr 28 15:30:54.594698 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/my/app/application.py", line 270, in audio
[Thu Apr 28 15:30:54.594765 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     conn.request('POST', 'https://avs-alexa-na.amazon.com/v20160207/events', headers=headers, body=u'SOMETHING')
[Thu Apr 28 15:30:54.594829 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/hyper/common/connection.py", line 98, in request
[Thu Apr 28 15:30:54.594908 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     method=method, url=url, body=body, headers=headers
[Thu Apr 28 15:30:54.594964 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/hyper/http11/connection.py", line 164, in request
[Thu Apr 28 15:30:54.595027 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     self.connect()
[Thu Apr 28 15:30:54.595081 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/path/to/virtual_environment/venv/lib/python2.7/site-packages/hyper/http11/connection.py", line 123, in connect
[Thu Apr 28 15:30:54.595143 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     sock = socket.create_connection((host, port), 5)
[Thu Apr 28 15:30:54.595214 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]   File "/usr/lib64/python2.7/socket.py", line 575, in create_connection
[Thu Apr 28 15:30:54.595279 2016] [:error] [pid 3067] [remote 172.31.63.223:52518]     raise err
[Thu Apr 28 15:30:54.595343 2016] [:error] [pid 3067] [remote 172.31.63.223:52518] error: [Errno 111] Connection refused
Lukasa commented 8 years ago

Hrm can you change this so that it logs out DEBUG level and higher?

lithiumlab commented 8 years ago

Can you please advise how to? I previuosly upped http module LogLevel trace6 in apache And flask debug is turned on with

application.debug=True
Lukasa commented 8 years ago

@lithiumlab Ah, sorry, it's a flask problem. In a top level file in your Flask app, please add these lines:

import logging
logging.basicConfig(level=logging.DEBUG)

That'll generate a lot of logs, but that should be fine.

lithiumlab commented 8 years ago

apart from the mod_http logs that are now included, not much else is coming out...

 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Accept-Encoding: gzip, deflate, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Accept-Language: es-419,es;q=0.8,en-US;q=0.6,en;q=0.4, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Content-Type: multipart/form-data; boundary=----WebKitFormBoundaryCYU2KDoQYW6qjcAi, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Cookie: pll_language=en; _gat_UA-15467192-76=1; session=XXXXXXXXXXXXXX; _ga=GA1.2.1332843141.1460737349, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Origin: https://myappdomain.com, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Referer: https://myappdomain.com/, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.86 Safari/537.36, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   X-Forwarded-For: 190.166.20.42, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   X-Forwarded-Port: 443, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   X-Forwarded-Proto: https, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Content-Length: 270658, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_request.c(398): [client XXX.XX.XX.XXX:15249]   Connection: keep-alive, referer: https://myappdomain.com/
 [http:trace4] [pid 3610] http_request.c(394): [client ::1:47104] Headers received from client:
 [http:trace4] [pid 3610] http_request.c(398): [client ::1:47104]   User-Agent: Apache/2.4.18 (Amazon) mod_wsgi/3.5 Python/2.7.10 (internal dummy connection)
 [http:trace3] [pid 3610] http_filters.c(1006): [client ::1:47104] Response sent with status 200, headers:
 [http:trace5] [pid 3610] http_filters.c(1013): [client ::1:47104]   Date: Thu, 28 Apr 2016 15:48:53 GMT
 [http:trace5] [pid 3610] http_filters.c(1016): [client ::1:47104]   Server: Apache/2.4.18 (Amazon) mod_wsgi/3.5 Python/2.7.10
 [http:trace4] [pid 3610] http_filters.c(835): [client ::1:47104]   Content-Length: 0
 [http:trace4] [pid 3610] http_filters.c(835): [client ::1:47104]   Connection: close
 [:error] [pid 3568] --# POST ATTEMPT #--
 [:error] [pid 3568] [Errno 111] Connection refused
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461] mod_wsgi (pid=3568): Exception occurred processing WSGI script '/opt/python/current/app/application.py'.
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461] Traceback (most recent call last):
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1836, in __call__
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     return self.wsgi_app(environ, start_response)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1820, in wsgi_app
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     response = self.make_response(self.handle_exception(e))
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1403, in handle_exception
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     reraise(exc_type, exc_value, tb)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     response = self.full_dispatch_request()
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     rv = self.handle_user_exception(e)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     reraise(exc_type, exc_value, tb)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     rv = self.dispatch_request()
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     return self.view_functions[rule.endpoint](**req.view_args)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/current/app/application.py", line 270, in audio
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     h2request = conn.request('POST', 'https://avs-alexa-na.amazon.com/v20160207/events', headers=headers, body=u'SOMETHING')
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/hyper/common/connection.py", line 98, in request
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     method=method, url=url, body=body, headers=headers
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/hyper/http11/connection.py", line 164, in request
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     self.connect()
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/opt/python/run/venv/lib/python2.7/site-packages/hyper/http11/connection.py", line 123, in connect
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     sock = socket.create_connection((host, port), 5)
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]   File "/usr/lib64/python2.7/socket.py", line 575, in create_connection
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461]     raise err
 [:error] [pid 3568] [remote XXX.XX.XX.XXX:30461] error: [Errno 111] Connection refused
 [http:trace3] [pid 3611] http_filters.c(1006): [client XXX.XX.XX.XXX:15249] Response sent with status 500, headers:, referer: https://myappdomain.com/
 [http:trace5] [pid 3611] http_filters.c(1013): [client XXX.XX.XX.XXX:15249]   Date: Thu, 28 Apr 2016 15:48:51 GMT, referer: https://myappdomain.com/
 [http:trace5] [pid 3611] http_filters.c(1016): [client XXX.XX.XX.XXX:15249]   Server: Apache/2.4.18 (Amazon) mod_wsgi/3.5 Python/2.7.10, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_filters.c(835): [client XXX.XX.XX.XXX:15249]   Content-Length: 527, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_filters.c(835): [client XXX.XX.XX.XXX:15249]   Connection: close, referer: https://myappdomain.com/
 [http:trace4] [pid 3611] http_filters.c(835): [client XXX.XX.XX.XXX:15249]   Content-Type: text/html; charset=iso-8859-1, referer: https://myappdomain.com/
 [http:trace4] [pid 3608] http_request.c(394): [client ::1:47108] Headers received from client:
 [http:trace4] [pid 3608] http_request.c(398): [client ::1:47108]   User-Agent: Apache/2.4.18 (Amazon) mod_wsgi/3.5 Python/2.7.10 (internal dummy connection)
 [http:trace3] [pid 3608] http_filters.c(1006): [client ::1:47108] Response sent with status 200, headers:
 [http:trace5] [pid 3608] http_filters.c(1013): [client ::1:47108]   Date: Thu, 28 Apr 2016 15:48:54 GMT
 [http:trace5] [pid 3608] http_filters.c(1016): [client ::1:47108]   Server: Apache/2.4.18 (Amazon) mod_wsgi/3.5 Python/2.7.10
 [http:trace4] [pid 3608] http_filters.c(835): [client ::1:47108]   Content-Length: 0
 [http:trace4] [pid 3608] http_filters.c(835): [client ::1:47108]   Connection: close
Lukasa commented 8 years ago

Hrm, you may need to log to a file instead. Try adding filename='mylogfile.log' to the basicConfig call.

lithiumlab commented 8 years ago

doing that triggers a permission denied error im trying to solve. chmod and httpd service restart didnt do the job.

Lukasa commented 8 years ago

@lithiumlab Probably you don't have permission to write to your web server's working directory. Try hardcoding a path to somewhere you know your web server's user can write data (the same place it writes log files, for example).

lithiumlab commented 8 years ago

ok. logs are in the file now. thanks for the hint. but tailing it i see the same errors. tailing the log file errors comes in. but nothing different from what i have posted.

logging.basicConfig(level=logging.DEBUG, filename='/location/to/logs/flask_log')
lithiumlab commented 8 years ago 
ERROR:_mod_wsgi_c43d580a63001a918a0ca7939113f619:Exception on /audio [POST]
Traceback (most recent call last):
  File "/path/to/the/app/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/path/to/the/app/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/path/to/the/app/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/path/to/the/app/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/path/to/the/app/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/python/current/app/application.py", line 278, in audio
    h2request = conn.request('POST', 'https://avs-alexa-na.amazon.com/v20160207/events', headers=headers, body=u'SOMETHING')
  File "/path/to/the/app/python2.7/site-packages/hyper/common/connection.py", line 98, in request
    method=method, url=url, body=body, headers=headers
  File "/path/to/the/app/python2.7/site-packages/hyper/http11/connection.py", line 164, in request
    self.connect()
  File "/path/to/the/app/python2.7/site-packages/hyper/http11/connection.py", line 123, in connect
    sock = socket.create_connection((host, port), 5)
  File "/usr/lib64/python2.7/socket.py", line 575, in create_connection
    raise err
error: [Errno 111] Connection refused
Lukasa commented 8 years ago

Well, that exception suggests that wherever you're trying to connect to is not actually running. That is, nothing is listening ont hat part. Are you sure that URL is right?

lithiumlab commented 8 years ago

ERRORS HERE:

 --# POST ATTEMPT VIA HTTP20Adapter for requests #--
 DEBUG:hyper.http11.connection:Selected protocol: None
 [Errno 32] Broken pipe
 ERROR:_mod_wsgi_c43d580a63001a918a0ca7939113f619:Exception on /audio [POST]
 Traceback (most recent call last):
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
     response = self.full_dispatch_request()
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
     rv = self.handle_user_exception(e)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
     reraise(exc_type, exc_value, tb)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
     rv = self.dispatch_request()
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
     return self.view_functions[rule.endpoint](**req.view_args)
   File "/opt/python/current/app/application.py", line 248, in audio
     r = s.post(url, data=multipart_data, headers=headers)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/requests/sessions.py", line 511, in post
     return self.request('POST', url, data=data, json=json, **kwargs)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/requests/sessions.py", line 468, in request
     resp = self.send(prep, **send_kwargs)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/requests/sessions.py", line 576, in send
     r = adapter.send(request, **kwargs)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/hyper/contrib.py", line 66, in send
     request.headers
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/hyper/common/connection.py", line 98, in request
     method=method, url=url, body=body, headers=headers
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/hyper/http11/connection.py", line 182, in request
     self._send_body(body, body_type)
   File "/path/to/python/virtualenvironment/lib/python2.7/site-packages/hyper/http11/connection.py", line 286, in _send_body
     self._sock.send(block)
   File "/usr/lib64/python2.7/ssl.py", line 687, in send
     v = self._sslobj.write(data)
 error: [Errno 32] Broken pipe
lithiumlab commented 8 years ago

Notice

DEBUG:hyper.http11.connection:Selected protocol: None

in the call from the instance machine in aws

Lukasa commented 8 years ago

Are those the logs from right before the exception? Those logs don't seem to contain a problem...

lithiumlab commented 8 years ago

Look closely the first part. I just added below a call from my local machine working good for comparison. Errors are in the first part.

lithiumlab commented 8 years ago

Im getting the same error using an nginx plus linux ami in aws. This time a bit more output in the logs from uwsgi:

--# POST ATTEMPT VIA HTTP20Adapter for requests #--
Sun May  8 17:51:52 2016 - SIGPIPE: writing to a closed pipe/socket/fd (probably the client disconnected) on request /audio (ip 172.31.50.2) !!!
[Errno 32] Broken pipe
ERROR:application:Exception on /audio [POST]
Traceback (most recent call last):
  File "/opt/python/env/py/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/opt/python/env/py/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/python/env/py/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "./application.py", line 262, in audio

  File "/opt/python/env/py/local/lib/python2.7/site-packages/requests/sessions.py", line 511, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/requests/sessions.py", line 468, in request
    resp = self.send(prep, **send_kwargs)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/requests/sessions.py", line 576, in send
    r = adapter.send(request, **kwargs)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/hyper/contrib.py", line 66, in send
    request.headers
  File "/opt/python/env/py/local/lib/python2.7/site-packages/hyper/common/connection.py", line 98, in request
    method=method, url=url, body=body, headers=headers
  File "/opt/python/env/py/local/lib/python2.7/site-packages/hyper/http11/connection.py", line 182, in request
    self._send_body(body, body_type)
  File "/opt/python/env/py/local/lib/python2.7/site-packages/hyper/http11/connection.py", line 286, in _send_body
    self._sock.send(block)
  File "/usr/lib64/python2.7/ssl.py", line 687, in send
    v = self._sslobj.write(data)
error: [Errno 32] Broken pipe
[pid: 2042|app: 0|req: 97/196] 172.31.50.2 () {56 vars in 1453 bytes} [Sun May  8 17:51:52 2016] POST /audio => generated 291 bytes in 97 msecs (HTTP/2.0 500) 2 headers in 84 bytes (1 switches on core 0)

Everything else in the app works as expected, flask routing, static files etc. The server is using uwsgi to get python files served to nginx

Lukasa commented 8 years ago

Hrm, in all of these cases it looks like the remote peer is immediately responding negatively and tearing the connection down. Can you try catching the exception and then calling get_response immediately afterward, then check what that response contains?

lithiumlab commented 8 years ago

I've solved the issue upgrading to latest openssl available in the machine os, in this case had to update Debian to latest 'stretch' version to upgrade to openssl 1.0.2g.

I have tried previously to update only openssl but it seems it doesn't play well with the underlying OS or not configured correctly even thou version is displaying well in python and command line. I've spent more time than i'm willing to confess trying to make this work. But its finally there.

A simple apt-get update openssl, or apk update for linux alpine, or pip install pyopenssl, will not work in all cases, AWS for example because repositories doesn't have recent packages yet available. Getting openssl update from project source will not necessary work. I recommend to research a bit first what version comes included in the latest version of the desired OS so you have an os that plays nice with a recent version of OpenSSL. And that's it.

Just leaving this here in case more people find this block on their path to play with hyper, http/2 and other modern tools. Amazing library. Finally getting creative with it. Back to code.

TL;DR: Better to update your OS with a recent OpenSSL version already included than upgrading only OpenSSL.

Lukasa commented 8 years ago

<3 Thanks @lithiumlab for coming back to mention that!

michael-pryor commented 8 years ago

I too experienced this, the culprit being using a version of Python built against an old OpenSSL.

The hyper website says the requirement is any version of OpenSSL greater than 1.0.1, but this I don't think is true. I was running "OpenSSL 1.0.1e-fips 11 Feb 2013" and upgraded to "OpenSSL 1.0.2i 22 Sep 2016" to solve the issue.

Note that it is not enough to only upgrade the OS, you also need to rebuild Python against that version of OpenSSL aswell.

Also note that the first indicator of an issue is the log line: hyper.http11.connection DEBUG Selected protocol: None

If it was working, it would read: hyper.http11.connection DEBUG Selected protocol: h2

I wonder if the protocol is defaulting back to HTTP 1.1 (instead of 2.0) and that's why the server is terminating the connection.

Lukasa commented 8 years ago

There are multiple possible ways this can fail, but it depends on what you need. NPN was added in 1.0.1, but ALPN was not added until 1.0.2. If you need ALPN, then yes, 1.0.2 is the lowest that will work.

citizenrich commented 8 years ago

Thanks, @Lukasa and @watfordxp and @lithiumlab. This is very, very helpful.