SNOW-19748: added better error message in case of 403, 502 and 504. Corrected timeout calculations.

Author: smtakeda

errors.py

@@ -162,47 +162,76 @@ class NotSupportedError(DatabaseError):
 class InternalServerError(Error):
     u"""Exception for 500 HTTP code for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 500: InternalServerError')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self,
+            msg=kwargs.get('msg') or u'HTTP 500: Internal Server Error',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class ServiceUnavailableError(Error):
     u"""Exception for 503 HTTP code for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 503: ServiceUnavailable')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 503: Service Unavailable',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class GatewayTimeoutError(Error):
     u"""Exception for 504 HTTP error for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 504: GatewayTimeout')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 504: Gateway Timeout',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class ForbiddenError(Error):
     """Exception for 403 HTTP error for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 403: Forbidden')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 403: Forbidden',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class RequestTimeoutError(Error):
     u"""Exception for 408 HTTP error for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 408: RequestTimeout')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 408: Request Timeout',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class BadRequest(Error):
     u"""Exception for 400 HTTP error for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 400: BadRequest')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 400: Bad Request',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))
 
 
 class BadGatewayError(Error):
     u"""Exception for 502 HTTP error for retry"""
 
-    def __init__(self, **_):
-        Error.__init__(self, msg=u'HTTP 502: BadGateway')
+    def __init__(self, **kwargs):
+        Error.__init__(
+            self, msg=kwargs.get('msg') or u'HTTP 502: Bad Gateway',
+            errno=kwargs.get('errno'),
+            sqlstate=kwargs.get('sqlstate'),
+            sfqid=kwargs.get('sfqid'))

network.py

@@ -6,7 +6,6 @@
 import copy
 import gzip
 import json
-import logging
 import platform
 import sys
 import time
@@ -276,9 +275,43 @@ def authenticate(self, account, user, password, master_token=None,
             "body['data']: %s",
             {k: v for (k, v) in body[u'data'].items() if k != u'PASSWORD'})
 
-        ret = self._post_request(
-            url, headers, json.dumps(body),
-            timeout=self._connection._login_timeout)
+        try:
+            ret = self._post_request(
+                url, headers, json.dumps(body),
+                timeout=self._connection._login_timeout)
+        except ForbiddenError as err:
+            # HTTP 403
+            raise err.__class__(
+                msg=(u"Failed to connect to DB. "
+                     u"Verify the account name is correct: {host}:{port}, "
+                     u"proxies={proxy_host}:{proxy_port}, "
+                     u"proxy_user={proxy_user}. {message}").format(
+                    host=self._host,
+                    port=self._port,
+                    proxy_host=self._proxy_host,
+                    proxy_port=self._proxy_port,
+                    proxy_user=self._proxy_user,
+                    message=TO_UNICODE(err)
+                ),
+                errno=ER_FAILED_TO_CONNECT_TO_DB,
+                sqlstate=SQLSTATE_CONNECTION_WAS_NOT_ESTABLISHED)
+        except (ServiceUnavailableError, BadGatewayError) as err:
+            # HTTP 502/504
+            raise err.__class__(
+                msg=(u"Failed to connect to DB. "
+                     u"Service is unavailable: {host}:{port}, "
+                     u"proxies={proxy_host}:{proxy_port}, "
+                     u"proxy_user={proxy_user}. {message}").format(
+                    host=self._host,
+                    port=self._port,
+                    proxy_host=self._proxy_host,
+                    proxy_port=self._proxy_port,
+                    proxy_user=self._proxy_user,
+                    message=TO_UNICODE(err)
+                ),
+                errno=ER_FAILED_TO_CONNECT_TO_DB,
+                sqlstate=SQLSTATE_CONNECTION_WAS_NOT_ESTABLISHED)
+
         # this means we are waiting for MFA authentication
         if ret[u'data'].get(u'nextAction') and ret[u'data'][
             u'nextAction'] == u'EXT_AUTHN_DUO_ALL':
@@ -699,8 +732,7 @@ def request_thread(result_queue):
                     ProtocolError,
                     OpenSSL.SSL.SysCallError, ValueError) as err:
                 logger.exception('who is hitting error?')
-                if logger.getEffectiveLevel() <= logging.DEBUG:
-                    logger.debug(err)
+                logger.debug(err)
                 if not isinstance(err, OpenSSL.SSL.SysCallError) or \
                                 err.args[0] in (
                                 errno.ECONNRESET,
@@ -714,12 +746,14 @@ def request_thread(result_queue):
             except ConnectionError as err:
                 logger.exception(u'ConnectionError: %s', err)
                 result_queue.put((OperationalError(
+                    # no full_url is required in the message
+                    # as err includes all information
                     msg=u'Failed to connect: {0}'.format(err),
                     errno=ER_FAILED_TO_SERVER,
                     sqlstate=SQLSTATE_CONNECTION_WAS_NOT_ESTABLISHED
                 ), False))
             except ValueError as err:
-                logger.exception(u'Return value is not JSON: %s', err)
+                logger.exception(u'Return value is NOT JSON: %s', err)
                 result_queue.put((InterfaceError(
                     msg=u"Failed to decode JSON output",
                     errno=ER_FAILED_TO_REQUEST,
@@ -752,10 +786,19 @@ def request_thread(result_queue):
                              request_thread_timeout,
                              request_timeout,
                              retry_cnt + 1)
+                start_request_thread = time.time()
                 th.join(timeout=request_thread_timeout)
                 logger.debug('request thread joined')
+                if request_timeout is not None:
+                    request_timeout -= min(
+                        int(time.time() - start_request_thread),
+                        request_timeout)
+                start_get_queue = time.time()
                 return_object, retryable = request_result_queue.get(
-                    timeout=int(request_thread_timeout / 2))
+                    timeout=int(request_thread_timeout / 4))
+                if request_timeout is not None:
+                    request_timeout -= min(
+                        int(time.time() - start_get_queue), request_timeout)
                 logger.debug('request thread returned object')
                 if retryable:
                     raise RequestRetry()
@@ -797,7 +840,41 @@ def request_thread(result_queue):
             time.sleep(sleeping_time)
             retry_cnt += 1
 
-        if isinstance(return_object, Error):
+        if return_object is None:
+            if data:
+                try:
+                    decoded_data = json.loads(data)
+                    if decoded_data.get(
+                            'data') and decoded_data['data'].get('PASSWORD'):
+                        # masking the password
+                        decoded_data['data']['PASSWORD'] = '********'
+                        data = json.dumps(decoded_data)
+                except:
+                    logger.info("data is not JSON")
+            logger.error(
+                u'Failed to get the response. Hanging? '
+                u'method: {method}, url: {url}, headers:{headers}, '
+                u'data: {data}, proxies: {proxies}'.format(
+                    method=method,
+                    url=full_url,
+                    headers=headers,
+                    data=data,
+                    proxies=proxies
+                )
+            )
+            Error.errorhandler_wrapper(
+                conn, None, OperationalError,
+                {
+                    u'msg': u'Failed to get the response. Hanging? '
+                            u'method: {method}, url: {url}, '
+                            u'proxies: {proxies}'.format(
+                        method=method,
+                        url=full_url,
+                        proxies=proxies
+                    ),
+                    u'errno': ER_FAILED_TO_REQUEST,
+                })
+        elif isinstance(return_object, Error):
             Error.errorhandler_wrapper(conn, None, return_object)
         elif isinstance(return_object, Exception):
             Error.errorhandler_wrapper(
@@ -844,7 +921,7 @@ def authenticate_by_saml(self, authenticator, account, user, password):
             Error.errorhandler_wrapper(
                 self._connection, None, DatabaseError,
                 {
-                    u'msg': (u"failed to connect to DB: {host}:{port}, "
+                    u'msg': (u"Failed to connect to DB: {host}:{port}, "
                              u"proxies={proxy_host}:{proxy_port}, "
                              u"proxy_user={proxy_user}, "
                              u"{message}").format(

test/test_connection.py

@@ -9,8 +9,8 @@
 import snowflake.connector
 from snowflake.connector import (
     DatabaseError,
-    ProgrammingError)
-from snowflake.connector.errors import ForbiddenError
+    ProgrammingError, InterfaceError, OperationalError)
+from snowflake.connector.errors import (ForbiddenError)
 
 
 def test_basic(conn_testaccount):
@@ -238,3 +238,45 @@ def test_invalid_account_timeout():
             password='test',
             login_timeout=5
         )
+
+
+@pytest.mark.timeout(15)
+def test_invalid_host():
+    with pytest.raises(InterfaceError):
+        snowflake.connector.connect(
+            account='bogus',
+            user='test',
+            password='test',
+            host='bogus.com',
+            login_timeout=5
+        )
+
+
+@pytest.mark.timeout(15)
+def test_invalid_port(db_parameters):
+    with pytest.raises(OperationalError):
+        snowflake.connector.connect(
+            protocol='http',
+            account='testaccount',
+            user=db_parameters['user'],
+            password=db_parameters['password'],
+            host=db_parameters['host'],
+            port=12345,
+            login_timeout=5,
+        )
+
+
+@pytest.mark.timeout(15)
+def test_invalid_proxy(db_parameters):
+    with pytest.raises(OperationalError):
+        snowflake.connector.connect(
+            protocol='http',
+            account='testaccount',
+            user=db_parameters['user'],
+            password=db_parameters['password'],
+            host=db_parameters['host'],
+            port=db_parameters['port'],
+            login_timeout=5,
+            proxy_host='localhost',
+            proxy_port='3333'
+        )