version 4.7.0 leads to SSLError in AWS Lambda Python 3.6

[neotheicebird]

When I deploy lambda functions with the new release, the functions fail with the following error. This doesn't happen with the previous release.

HTTPSConnectionPool(host='api.mixpanel.com', port=443): Max retries exceeded with url: /track (Caused by SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)): MixpanelException
Traceback (most recent call last):
  File "/var/task/common.py", line 346, in wrapper
    return handler(event, context)
  File "/var/task/common.py", line 69, in wrapper
    return handler(event, context)
  File "/var/task/common.py", line 223, in wrapper
    return handler(event, context)
  File "/var/task/handler.py", line 110, in add_distributor_retailer
    logger.log_uncaught_exception()
  File "/var/task/handler.py", line 83, in add_distributor_retailer
    mp.track(context.user_id, 'Added Distributor Retailer')
  File "/var/task/mixpanel/__init__.py", line 100, in track
    self._consumer.send('events', json_dumps(event, cls=self._serializer))
  File "/var/task/mixpanel/__init__.py", line 539, in send
    self._write_request(self._endpoints[endpoint], json_message, api_key)
  File "/var/task/mixpanel/__init__.py", line 560, in _write_request
    six.raise_from(MixpanelException(e), e)
  File "<string>", line 3, in raise_from
mixpanel.MixpanelException: HTTPSConnectionPool(host='api.mixpanel.com', port=443): Max retries exceeded with url: /track (Caused by SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),))

Example code used in functions:

mp = Mixpanel("MIXPANEL_TOKEN")
mp.track("unique_id", "event_name")

[seizethedave]

@neotheicebird Thanks for the report. Just trying to reproduce the problem in Lambda- by creating a Python 3.6 function with the mixpanel==4.7.0 package+dependencies deployed via zip file, I don't get the same problem.

Can you add this to your script and post the output?

import subprocess
print(subprocess.check_output(["curl", "-vvv", "https://api.mixpanel.com/track"], stderr=subprocess.STDOUT).decode())

[neotheicebird]

Hi @seizethedave , sorry for the delayed response. Here is a part of the logs in my serverless function, from executing the above command to hitting the error:

% Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Dload  Upload   Total   Spent    Left  Speed
0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 35.190.25.25...
* TCP_NODELAY set
* Connected to api.mixpanel.com (35.190.25.25) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /etc/pki/tls/certs/ca-bundle.crt
CApath: none
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [96 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [3717 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [333 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [70 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Change cipher spec (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=*.mixpanel.com
*  start date: Apr 20 00:00:00 2020 GMT
*  expire date: Apr 21 12:00:00 2022 GMT
*  subjectAltName: host "api.mixpanel.com" matched cert's "*.mixpanel.com"
*  issuer: C=US; O=DigiCert Inc; OU=www.digicert.com; CN=GeoTrust RSA CA 2018
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
} [5 bytes data]
* Using Stream ID: 1 (easy handle 0x9fbd10)
} [5 bytes data]
> GET /track HTTP/2
> Host: api.mixpanel.com
> User-Agent: curl/7.61.1
> Accept: */*
> 
{ [5 bytes data]
* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
} [5 bytes data]
< HTTP/2 200 
< access-control-allow-credentials: true
< access-control-allow-headers: X-Requested-With
< access-control-allow-methods: GET, POST, OPTIONS
< access-control-allow-origin: *
< access-control-expose-headers: X-MP-CE-Backoff
< access-control-max-age: 1728000
< cache-control: no-cache, no-store
< content-type: application/json
< date: Tue, 15 Sep 2020 12:22:02 GMT
< content-length: 1
< x-envoy-upstream-service-time: 0
< server: envoy
< via: 1.1 google
< alt-svc: clear
< 
{ [5 bytes data]
100     1  100     1    0     0     21      0 --:--:-- --:--:-- --:--:--    21
* Connection #0 to host api.mixpanel.com left intact
0
[WARNING]	2020-09-15T12:22:03.5Z	62f700ea-9675-4511-8ab7-0c920e6bb1a3	Retrying (Retry(total=3, connect=None, read=None, redirect=None, status=None)) after connection broken by 'SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)': /track
[WARNING]	2020-09-15T12:22:03.511Z	62f700ea-9675-4511-8ab7-0c920e6bb1a3	Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)': /track
[WARNING]	2020-09-15T12:22:04.518Z	62f700ea-9675-4511-8ab7-0c920e6bb1a3	Retrying (Retry(total=1, connect=None, read=None, redirect=None, status=None)) after connection broken by 'SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)': /track
[WARNING]	2020-09-15T12:22:06.526Z	62f700ea-9675-4511-8ab7-0c920e6bb1a3	Retrying (Retry(total=0, connect=None, read=None, redirect=None, status=None)) after connection broken by 'SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)': /track
HTTPSConnectionPool(host='api.mixpanel.com', port=443): Max retries exceeded with url: /track (Caused by SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),)): MixpanelException
Traceback (most recent call last):
  File "/var/task/common.py", line 346, in wrapper
    return handler(event, context)
  File "/var/task/common.py", line 69, in wrapper
    return handler(event, context)
  File "/var/task/common.py", line 176, in wrapper
    return handler(event, context)
  File "/var/task/common.py", line 81, in wrapper
    return handler(event, context)
  File "/var/task/handler.py", line 56, in get_every_supplier_distributor
    mp.track(context.user_id, 'Get Supplier Distributors')
  File "/var/task/mixpanel/__init__.py", line 100, in track
    self._consumer.send('events', json_dumps(event, cls=self._serializer))
  File "/var/task/mixpanel/__init__.py", line 539, in send
    self._write_request(self._endpoints[endpoint], json_message, api_key)
  File "/var/task/mixpanel/__init__.py", line 560, in _write_request
    six.raise_from(MixpanelException(e), e)
  File "<string>", line 3, in raise_from
mixpanel.MixpanelException: HTTPSConnectionPool(host='api.mixpanel.com', port=443): Max retries exceeded with url: /track (Caused by SSLError(SSLError("bad handshake: Error([('SSL routines', 'tls_process_server_certificate', 'certificate verify failed')],)",),))

[seizethedave]

OK. This means cURL and mixpanel-python are trying to read the local CA certs from different locations.
Can you see what import ssl; print(ssl.get_default_verify_paths()) outputs?

Thanks!

[calabash-mafia]

@seizethedave I'm receiving this error, too, on a Mac OS machine running Python 2.7 in a virtualenv. Downgrading to version 4.7.0 solved it for me. Running import ssl; print(ssl.get_default_verify_paths()) for me outputs:

DefaultVerifyPaths(cafile='/usr/local/etc/openssl/cert.pem', capath=None, openssl_cafile_env='SSL_CERT_FILE', openssl_cafile='/usr/local/etc/openssl/cert.pem', openssl_capath_env='SSL_CERT_DIR', openssl_capath='/usr/local/etc/openssl/certs')

As to the question you asked the previous poster, about with subprocess.check_output check output, here it is for me:

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 35.186.241.51...
* TCP_NODELAY set
* Connected to api.mixpanel.com (35.186.241.51) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/cert.pem
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [230 bytes data]
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [96 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [3717 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [300 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [37 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Change cipher spec (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-CHACHA20-POLY1305
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=*.mixpanel.com
*  start date: Apr 20 00:00:00 2020 GMT
*  expire date: Apr 21 12:00:00 2022 GMT
*  subjectAltName: host "api.mixpanel.com" matched cert's "*.mixpanel.com"
*  issuer: C=US; O=DigiCert Inc; OU=www.digicert.com; CN=GeoTrust RSA CA 2018
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x7f939380c400)
> GET /track HTTP/2
> Host: api.mixpanel.com
> User-Agent: curl/7.64.1
> Accept: */*
> 
* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
< HTTP/2 200 
< access-control-allow-credentials: true
< access-control-allow-headers: X-Requested-With
< access-control-allow-methods: GET, POST, OPTIONS
< access-control-allow-origin: *
< access-control-expose-headers: X-MP-CE-Backoff
< access-control-max-age: 1728000
< cache-control: no-cache, no-store
< content-type: application/json
< date: Fri, 16 Oct 2020 05:13:39 GMT
< content-length: 1
< x-envoy-upstream-service-time: 0
< server: envoy
< via: 1.1 google
< alt-svc: clear
< 
{ [1 bytes data]
100     1  100     1    0     0      2      0 --:--:-- --:--:-- --:--:--     2
* Connection #0 to host api.mixpanel.com left intact
0* Closing connection 0

Anything else I can run on my end to help you debug this?

Thanks!

[seizethedave]

I have added a verify_cert option to the Consumer type that can be used to ease these troubles. I think longer term we will need options for the local cert store location.