Skip to content

Commit

Permalink
adding fix for box app request timeout (#1040) (#1057)
Browse files Browse the repository at this point in the history 
* adding fix for #1040

* addressing pr feedback
  • Loading branch information
@ryandeivert
ryandeivert authored Nov 26, 2019
1 parent 4b034c9 commit 2746509
Show file tree
Hide file tree
Showing 2 changed files with 58 additions and 38 deletions.
20 changes: 14 additions & 6 deletions streamalert/apps/_apps/box.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@
from boxsdk import Client, JWTAuth
from boxsdk.exception import BoxException
from boxsdk.object.events import EnterpriseEventsStreamType
from requests.exceptions import ConnectionError as requestsConnectionError
import requests

from . import AppIntegration, StreamAlertApp, get_logger, safe_timeout

Expand All @@ -30,6 +30,7 @@
class BoxApp(AppIntegration):
"""BoxApp integration"""
_MAX_CHUNK_SIZE = 500
_MAX_RETRY_COUNT = 3

def __init__(self, event, context):
super(BoxApp, self).__init__(event, context)
Expand Down Expand Up @@ -117,34 +118,41 @@ def _make_request(self):

LOGGER.debug('[%s] Requesting events', self)

def _perform_request(allow_retry=True):
def _perform_request(timeout, allow_retry=True, retry_count=0):
try:
# Get the events using a make_request call with the box api. This is to
# support custom parameters such as 'created_after' and 'created_before'
box_response = self._client.make_request(
'GET',
self._client.get_url('events'),
params=params,
timeout=self._DEFAULT_REQUEST_TIMEOUT
timeout=timeout
)
except BoxException:
LOGGER.exception('[%s] Failed to get events', self)
return False, {} # Return a tuple to conform to return value of safe_timeout
except requestsConnectionError:
except requests.exceptions.Timeout:
# Retry requests that timed out a few more times, with increased timeout
timeout *= 2
LOGGER.debug('Attempting new request with timeout: %0.2f seconds', timeout)
if retry_count == self._MAX_RETRY_COUNT:
raise # eventually give up and raise this
return _perform_request(timeout, allow_retry, retry_count + 1)
except requests.exceptions.ConnectionError:
# In testing, the requests connection seemed to get reset for no
# obvious reason, and a simple retry once works fine so catch it
# and retry once, but after that return False
LOGGER.exception('Bad response received from host, will retry once')
if allow_retry:
return _perform_request(allow_retry=False)
return _perform_request(timeout, allow_retry=False)

return False, {} # Return a tuple to conform to return value of safe_timeout

# Return a successful status and the JSON from the box response
# Return a tuple to conform to return value of safe_timeout
return True, box_response.json()

return _perform_request()
return _perform_request(self._DEFAULT_REQUEST_TIMEOUT)

def _gather_logs(self):
"""Gather the Box Admin Events
Expand Down
76 changes: 44 additions & 32 deletions tests/unit/streamalert/apps/test_apps/test_box.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,10 +17,10 @@
import os

from boxsdk.exception import BoxException
from mock import Mock, mock_open, patch
from mock import call, Mock, mock_open, patch
from moto import mock_ssm
from nose.tools import assert_equal, assert_false, assert_count_equal, assert_true
from requests.exceptions import ConnectionError as reConnectionError, Timeout
import requests

from streamalert.apps._apps.box import BoxApp

Expand Down Expand Up @@ -52,8 +52,7 @@ def test_required_auth_info(self):
"""BoxApp - Required Auth Info"""
assert_count_equal(list(self._app.required_auth_info().keys()), {'keyfile'})

@patch('streamalert.apps._apps.box.JWTAuth.from_settings_dictionary',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.JWTAuth.from_settings_dictionary', Mock())
def test_keyfile_validator(self):
"""BoxApp - Keyfile Validation, Success"""
validation_function = self._app.required_auth_info()['keyfile']['format']
Expand Down Expand Up @@ -82,8 +81,7 @@ def test_keyfile_validator_bad_json(self, cred_mock):
assert_false(validation_function('fakepath'))
cred_mock.assert_not_called()

@patch('streamalert.apps._apps.box.JWTAuth.from_settings_dictionary',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.JWTAuth.from_settings_dictionary', Mock())
def test_load_credentials(self):
"""BoxApp - Load Auth, Success"""
assert_true(self._app._load_auth('fakedata'))
Expand All @@ -94,8 +92,6 @@ def test_load_credentials_bad(self, cred_mock):
cred_mock.side_effect = ValueError('Bad things happened')
assert_false(self._app._load_auth('fakedata'))

@patch('streamalert.apps._apps.box.Client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._load_auth')
def test_create_client(self, auth_mock):
"""BoxApp - Create Client, Success"""
Expand All @@ -109,27 +105,20 @@ def test_create_client_exists(self, log_mock):
assert_true(self._app._create_client())
log_mock.assert_called_with('[%s] Client already instantiated', self._app)

@patch('streamalert.apps._apps.box.BoxApp._load_auth',
Mock(return_value=False))
@patch('streamalert.apps._apps.box.BoxApp._load_auth', Mock(return_value=False))
def test_create_client_fail_auth(self):
"""BoxApp - Create Client, Auth Failure"""
assert_false(self._app._create_client())

def test_gather_logs(self):
"""BoxApp - Gather Logs, Success"""
with patch.object(self._app, '_client') as client_mock:
payload = {
'chunk_size': 10,
'next_stream_position': '1152922976252290886',
'entries': self._get_sample_logs(10)
}
client_mock.make_request.return_value.json.return_value = payload
client_mock.make_request.return_value.json.return_value = self._get_sample_payload(10)

assert_equal(len(self._app._gather_logs()), 10)
assert_equal(self._app._last_timestamp, '2017-10-27T12:31:22-07:00')

@patch('streamalert.apps._apps.box.BoxApp._create_client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.exception')
def test_gather_logs_box_error(self, log_mock):
"""BoxApp - Gather Logs, BoxException"""
Expand All @@ -138,38 +127,55 @@ def test_gather_logs_box_error(self, log_mock):
assert_false(self._app._gather_logs())
log_mock.assert_called_with('[%s] Failed to get events', self._app)

@patch('streamalert.apps._apps.box.BoxApp._create_client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.exception')
def test_gather_logs_requests_error(self, log_mock):
"""BoxApp - Gather Logs, requests.ConnectionError"""
with patch.object(self._app, '_client') as client_mock:
self._app._next_stream_position = 10241040195019
client_mock.make_request.side_effect = reConnectionError(response='bad error')
client_mock.make_request.side_effect = requests.exceptions.ConnectionError(
response='bad error'
)
assert_false(self._app._gather_logs())
log_mock.assert_called_with('Bad response received from host, will retry once')

@patch('streamalert.apps._apps.box.BoxApp._create_client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.exception')
def test_gather_logs_requests_timeout(self, log_mock):
"""BoxApp - Gather Logs, Timeout"""
def test_gather_logs_requests_timeout_retry_fail(self, log_mock):
"""BoxApp - Gather Logs, Timeout Retry and Fail"""
with patch.object(self._app, '_client') as client_mock:
client_mock.make_request.side_effect = Timeout(response='request timed out')
client_mock.make_request.side_effect = requests.exceptions.Timeout(
response='request timed out'
)
assert_false(self._app._gather_logs())
log_mock.assert_called_with('[%s] Request timed out', '_make_request')

@patch('streamalert.apps._apps.box.BoxApp._load_auth',
Mock(return_value=False))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.debug')
def test_gather_logs_requests_timeout_retry_success(self, log_mock):
"""BoxApp - Gather Logs, Timeout Retry and Succeed"""
with patch.object(self._app, '_client') as client_mock:
# client_mock.make_request.return_value.json.return_value = None
client_mock.make_request.side_effect = [
requests.exceptions.Timeout(response='request timed out once'),
requests.exceptions.Timeout(response='request timed out twice'),
Mock(json=Mock(return_value=self._get_sample_payload(1))),
]
assert_equal(bool(self._app._gather_logs()), True)
log_mock.assert_has_calls([
call('Attempting new request with timeout: %0.2f seconds', 6.10),
call('Attempting new request with timeout: %0.2f seconds', 12.20),
])

@patch('streamalert.apps._apps.box.BoxApp._load_auth', Mock(return_value=False))
def test_gather_logs_no_client(self):
"""BoxApp - Gather Logs, No Client"""
with patch.object(self._app, '_client') as client_mock:
self._app._client = False
assert_false(self._app._gather_logs())
client_mock.make_request.assert_not_called()

@patch('streamalert.apps._apps.box.BoxApp._create_client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.error')
def test_gather_logs_no_results(self, log_mock):
"""BoxApp - Gather Logs, No Results From API"""
Expand All @@ -178,8 +184,7 @@ def test_gather_logs_no_results(self, log_mock):
assert_false(self._app._gather_logs())
log_mock.assert_called_with('[%s] No results received in request', self._app)

@patch('streamalert.apps._apps.box.BoxApp._create_client',
Mock(return_value=True))
@patch('streamalert.apps._apps.box.BoxApp._create_client', Mock())
@patch('logging.Logger.info')
def test_gather_logs_empty_items(self, log_mock):
"""BoxApp - Gather Logs, Empty Entries List"""
Expand All @@ -193,6 +198,13 @@ def test_gather_logs_empty_items(self, log_mock):
assert_false(self._app._gather_logs())
log_mock.assert_called_with('[%s] No events found in result', self._app)

def _get_sample_payload(self, count):
return {
'chunk_size': 10,
'next_stream_position': '1152922976252290886',
'entries': self._get_sample_logs(count)
}

@staticmethod
def _get_sample_logs(count):
"""Helper function for returning sample Box admin event logs"""
Expand Down

0 comments on commit 2746509

Please sign in to comment.