def test_remove_newlines_and_truncate(self):
self.assertEquals(scalyr_util.remove_newlines_and_truncate("hi", 1000), "hi")
self.assertEquals(scalyr_util.remove_newlines_and_truncate("ok then", 2), "ok")
self.assertEquals(
scalyr_util.remove_newlines_and_truncate("o\nk\n", 1000), "o k "
)
self.assertEquals(
scalyr_util.remove_newlines_and_truncate("ok\n\r there", 1000), "ok there"
)
self.assertEquals(
scalyr_util.remove_newlines_and_truncate("ok\n\r there", 6), "ok t"
)
def test_remove_newlines_and_truncate(self):
self.assertEquals(scalyr_util.remove_newlines_and_truncate('hi', 1000),
'hi')
self.assertEquals(
scalyr_util.remove_newlines_and_truncate('ok then', 2), 'ok')
self.assertEquals(
scalyr_util.remove_newlines_and_truncate('o\nk\n', 1000), 'o k ')
self.assertEquals(
scalyr_util.remove_newlines_and_truncate('ok\n\r there', 1000),
'ok there')
self.assertEquals(
scalyr_util.remove_newlines_and_truncate('ok\n\r there', 6),
'ok t')
class ScalyrClientSession(object):
"""Encapsulates the connection between the agent and the Scalyr servers.
It is a session in that we generally only have one connection open to the Scalyr servers at any given time.
The session aspect is important because we must ensure that the timestamps we include in the AddEventRequests
are monotonically increasing within a session.
"""
def __init__(self,
server,
api_key,
agent_version,
quiet=False,
request_deadline=60.0,
ca_file=None):
"""Initializes the connection.
This does not actually try to connect to the server.
@param server: The URL for the server to send requests to, such as https://agent.scalyr.com
@param api_key: The write logs key to use to authenticate all requests from this agent to scalyr.
It both authenticates the requests and identifies which account it belongs to.
@param agent_version: The agent version number, which is included in request headers sent to the server.
@param quiet: If True, will not log non-error information.
@param request_deadline: The maximum time to wait for all requests in seconds.
@param ca_file: The path to the file containing the certificates for the trusted certificate authority roots.
This is used for the SSL connections to verify the connection is to Scalyr.
@type server: str
@type api_key: str
@type agent_version: str
@type quiet: bool
@type request_deadline: float
@type ca_file: str
"""
if not quiet:
log.info('Using "%s" as address for scalyr servers' % server)
# Verify the server address looks right.
parsed_server = re.match('^(http://|https://|)([^:]*)(:\d+|)$',
server.lower())
if parsed_server is None:
raise Exception('Could not parse server address "%s"' % server)
# The full URL address
self.__full_address = server
# The host for the server.
self.__host = parsed_server.group(2)
# Whether or not the connection uses SSL. For production use, this should always be true. We only
# use non-SSL when testing against development versions of the Scalyr server.
self.__use_ssl = parsed_server.group(1) == 'https://'
# Determine the port, defaulting to the right one based on protocol if not given.
if parsed_server.group(3) != '':
self.__port = int(parsed_server.group(3)[1:])
elif self.__use_ssl:
self.__port = 443
else:
self.__port = 80
# The HTTPConnection object that has been opened to the servers, if one has been opened.
self.__connection = None
self.__api_key = api_key
self.__session_id = scalyr_util.create_unique_id()
# The time of the last success.
self.__last_success = None
# The version number of the installed agent
self.__agent_version = agent_version
# The last time the connection was closed, if any.
self.__last_connection_close = None
# We create a few headers ahead of time so that we don't have to recreate them each time we need them.
self.__standard_headers = {
'Connection': 'Keep-Alive',
'Accept': 'application/json',
'User-Agent': ScalyrClientSession.__get_user_agent(agent_version)
}
# The number of seconds to wait for a blocking operation on the connection before considering it to have
# timed out.
self.__request_deadline = request_deadline
# The total number of RPC requests sent.
self.total_requests_sent = 0
# The total number of RPC requests that failed.
self.total_requests_failed = 0
# The total number of bytes sent over the network.
self.total_request_bytes_sent = 0
# The total number of bytes received.
self.total_response_bytes_received = 0
# The total number of secs spent waiting for a responses (so average latency can be calculated by dividing
# this number by self.total_requests_sent). This includes connection establishment time.
self.total_request_latency_secs = 0
# The total number of HTTP connections successfully created.
self.total_connections_created = 0
# The path the file containing the certs for the root certificate authority to use for verifying the SSL
# connection to Scalyr. If this is None, then server certificate verification is disabled, and we are
# susceptible to man-in-the-middle attacks.
self.__ca_file = ca_file
def ping(self):
"""Ping the Scalyr server by sending a test message to add zero events.
If the returned message is 'success', then it has been verified that the agent can connect to the
configured Scalyr server and that the api key is correct.
@return: The status message returned by the server.
@rtype:
"""
return self.send(self.add_events_request())[0]
def __send_request(self,
request_path,
body=None,
body_func=None,
is_post=True):
"""Sends a request either using POST or GET to Scalyr at the specified request path. It may be either
a POST or GET.
Parses, returns response.
@param request_path: The path of the URL to post to.
@param [body]: The body string to send. May be None if body_func is specified. Ignored if not POST.
@param [body_func]: A function that will be invoked to retrieve the body to send in the post. Ignored if not
POST.
@param [is_post]: True if this request should be sent using a POST, otherwise GET.
@type request_path: str
@type body: str|None
@type body_func: func|None
@type is_post: bool
@return: A tuple containing the status message in the response (such as 'success'), the number of bytes
sent, and the full response.
@rtype: (str, int, str)
"""
current_time = time.time()
# Refuse to try to send the message if the connection has been recently closed and we have not waited
# long enough to try to re-open it. We do this to avoid excessive connection opens and SYN floods.
if self.__last_connection_close is not None and current_time - self.__last_connection_close < 30:
return 'client/connectionClosed', 0, ''
self.total_requests_sent += 1
was_success = False
bytes_received = 0
if self.__use_ssl:
if not __has_ssl__:
log.warn(
'No ssl library available so cannot verify server certificate when communicating with Scalyr. '
'This means traffic is encrypted but can be intercepted through a man-in-the-middle attack. '
'To solve this, install the Python ssl library. '
'For more details, see https://www.scalyr.com/help/scalyr-agent#ssl',
limit_once_per_x_secs=86400,
limit_key='nosslwarning',
error_code='client/nossl')
elif self.__ca_file is None:
log.warn(
'Server certificate validation has been disabled while communicating with Scalyr. '
'This means traffic is encrypted but can be intercepted through a man-in-the-middle attach. '
'Please update your configuration file to re-enable server certificate validation.',
limit_once_per_x_secs=86400,
limit_key='nocertwarning',
error_code='client/sslverifyoff')
response = ''
try:
try:
if self.__connection is None:
if self.__use_ssl:
# If we do not have the SSL library, then we cannot do server certificate validation anyway.
if __has_ssl__:
ca_file = self.__ca_file
else:
ca_file = None
self.__connection = HTTPSConnectionWithTimeoutAndVerification(
self.__host, self.__port, self.__request_deadline,
ca_file, __has_ssl__)
else:
self.__connection = HTTPConnectionWithTimeout(
self.__host, self.__port, self.__request_deadline)
self.__connection.connect()
self.total_connections_created += 1
except (socket.error, socket.herror, socket.gaierror), error:
if hasattr(error, 'errno'):
errno = error.errno
else:
errno = None
if __has_ssl__ and isinstance(error, ssl.SSLError):
log.error(
'Failed to connect to "%s" due to some SSL error. Possibly the configured certificate '
'for the root Certificate Authority could not be parsed, or we attempted to connect to '
'a server whose certificate could not be trusted (if so, maybe Scalyr\'s SSL cert has '
'changed and you should update your agent to get the new certificate). The returned '
'errno was %d and the full exception was \'%s\'. Closing connection, will re-attempt',
self.__full_address,
errno,
str(error),
error_code='client/connectionFailed')
elif errno == 61: # Connection refused
log.error(
'Failed to connect to "%s" because connection was refused. Server may be unavailable.',
self.__full_address,
error_code='client/connectionFailed')
elif errno == 8: # Unknown name
log.error(
'Failed to connect to "%s" because could not resolve address. Server host may be bad.',
self.__full_address,
error_code='client/connectionFailed')
elif errno is not None:
log.error(
'Failed to connect to "%s" due to errno=%d. Exception was %s. Closing connection, '
'will re-attempt',
self.__full_address,
errno,
str(error),
error_code='client/connectionFailed')
else:
log.error(
'Failed to connect to "%s" due to exception. Exception was %s. Closing connection, '
'will re-attempt',
self.__full_address,
str(error),
error_code='client/connectionFailed')
return 'client/connectionFailed', 0, ''
if is_post:
if body is None:
body_str = body_func()
else:
body_str = body
else:
body_str = ""
self.total_request_bytes_sent += len(body_str) + len(request_path)
# noinspection PyBroadException
try:
if is_post:
log.log(scalyr_logging.DEBUG_LEVEL_5,
'Sending POST %s with body \"%s\"', request_path,
body_str)
self.__connection.request('POST',
request_path,
body=body_str,
headers=self.__standard_headers)
else:
log.log(scalyr_logging.DEBUG_LEVEL_5, 'Sending GET %s',
request_path)
self.__connection.request('GET',
request_path,
headers=self.__standard_headers)
response = self.__connection.getresponse().read()
bytes_received = len(response)
except Exception, error:
# TODO: Do not just catch Exception. Do narrower scope.
if hasattr(error, 'errno'):
log.error(
'Failed to connect to "%s" due to errno=%d. Exception was %s. Closing connection, '
'will re-attempt',
self.__full_address,
error.errno,
str(error),
error_code='client/requestFailed')
else:
log.exception(
'Failed to send request due to exception. Closing connection, will re-attempt',
error_code='requestFailed')
return 'requestFailed', len(body_str), response
log.log(scalyr_logging.DEBUG_LEVEL_5,
'Response was received with body \"%s\"', response)
# If we got back an empty result, that often means the connection has been closed or reset.
if len(response) == 0:
log.error(
'Received empty response, server may have reset connection. Will re-attempt',
error_code='emptyResponse')
return 'emptyResponse', len(body_str), response
# Try to parse the response
# noinspection PyBroadException
try:
response_as_json = json_lib.parse(response)
except Exception:
# TODO: Do not just catch Exception. Do narrower scope. Also, log error here.
log.exception(
'Failed to parse response of \'%s\' due to exception. Closing connection, will '
're-attempt',
scalyr_util.remove_newlines_and_truncate(response, 1000),
error_code='parseResponseFailed')
return 'parseResponseFailed', len(body_str), response
self.__last_success = current_time
if 'status' in response_as_json:
status = response_as_json['status']
if status == 'success':
was_success = True
elif status == 'error/client/badParam':
log.error(
'Request to \'%s\' failed due to a bad parameter value. This may be caused by an '
'invalid write logs api key in the configuration',
self.__full_address,
error_code='error/client/badParam')
else:
log.error(
'Request to \'%s\' failed due to an error. Returned error code was \'%s\'',
self.__full_address,
status,
error_code='error/client/badParam')
return status, len(body_str), response
else:
log.error(
'No status message provided in response. Unknown error. Response was \'%s\'',
scalyr_util.remove_newlines_and_truncate(response, 1000),
error_code='unknownError')
return 'unknownError', len(body_str), response
def test_remove_newlines_and_truncate(self):
self.assertEquals(scalyr_util.remove_newlines_and_truncate('hi', 1000), 'hi')
self.assertEquals(scalyr_util.remove_newlines_and_truncate('ok then', 2), 'ok')
self.assertEquals(scalyr_util.remove_newlines_and_truncate('o\nk\n', 1000), 'o k ')
self.assertEquals(scalyr_util.remove_newlines_and_truncate('ok\n\r there', 1000), 'ok there')
self.assertEquals(scalyr_util.remove_newlines_and_truncate('ok\n\r there', 6), 'ok t')
def __report_copying_manager(output, manager_status, agent_log_file_path,
read_time):
print >> output, "Log transmission:"
print >> output, "================="
print >> output, ""
print >> output, "(these statistics cover the period from %s)" % scalyr_util.format_time(
read_time)
print >> output, ""
print >> output, "Bytes uploaded successfully: %ld" % manager_status.total_bytes_uploaded
print >> output, "Last successful communication with Scalyr: %s" % scalyr_util.format_time(
manager_status.last_success_time)
print >> output, "Last attempt: %s" % scalyr_util.format_time(
manager_status.last_attempt_time)
if manager_status.last_attempt_size is not None:
print >> output, "Last copy request size: %ld" % manager_status.last_attempt_size
if manager_status.last_response is not None:
print >> output, "Last copy response size: %ld" % len(
manager_status.last_response)
print >> output, "Last copy response status: %s" % manager_status.last_response_status
if manager_status.last_response_status != "success":
print >> output, "Last copy response: %s" % scalyr_util.remove_newlines_and_truncate(
manager_status.last_response, 1000)
if manager_status.total_errors > 0:
print >> output, "Total responses with errors: %d (see '%s' for details)" % (
manager_status.total_errors,
agent_log_file_path,
)
print >> output, ""
for matcher_status in manager_status.log_matchers:
if not matcher_status.is_glob:
if len(matcher_status.log_processors_status) == 0:
# This is an absolute file path (no wildcards) and there are not matches.
print >> output, "Path %s: no matching readable file, last checked %s" % (
matcher_status.log_path,
scalyr_util.format_time(matcher_status.last_check_time),
)
else:
# We have a match.. matcher_status.log_processors_status should really only have one
# entry, but we loop anyway.
for processor_status in matcher_status.log_processors_status:
output.write(
"Path %s: copied %ld bytes (%ld lines), %ld bytes pending, "
% (
processor_status.log_path,
processor_status.total_bytes_copied,
processor_status.total_lines_copied,
processor_status.total_bytes_pending,
))
if processor_status.total_bytes_skipped > 0:
output.write("%ld bytes skipped, " %
processor_status.total_bytes_skipped)
if processor_status.total_bytes_failed > 0:
output.write("%ld bytes failed, " %
processor_status.total_bytes_failed)
if processor_status.total_bytes_dropped_by_sampling > 0:
output.write(
"%ld bytes dropped by sampling (%ld lines), " % (
processor_status.
total_bytes_dropped_by_sampling,
processor_status.
total_lines_dropped_by_sampling,
))
if processor_status.total_redactions > 0:
output.write("%ld redactions, " %
processor_status.total_redactions)
output.write("last checked %s" % scalyr_util.format_time(
processor_status.last_scan_time))
output.write("\n")
output.flush()
need_to_add_extra_line = True
for matcher_status in manager_status.log_matchers:
if matcher_status.is_glob:
if need_to_add_extra_line:
need_to_add_extra_line = False
print >> output, ""
print >> output, "Glob: %s:: last scanned for glob matches at %s" % (
matcher_status.log_path,
scalyr_util.format_time(matcher_status.last_check_time),
)
for processor_status in matcher_status.log_processors_status:
output.write(
" %s: copied %ld bytes (%ld lines), %ld bytes pending, " %
(
processor_status.log_path,
processor_status.total_bytes_copied,
processor_status.total_lines_copied,
processor_status.total_bytes_pending,
))
if processor_status.total_bytes_skipped > 0:
output.write("%ld bytes skipped, " %
processor_status.total_bytes_skipped)
if processor_status.total_bytes_failed > 0:
output.write("%ld bytes failed, " %
processor_status.total_bytes_failed)
if processor_status.total_bytes_dropped_by_sampling > 0:
output.write(
"%ld bytes dropped by sampling (%ld lines), " % (
processor_status.total_bytes_dropped_by_sampling,
processor_status.total_lines_dropped_by_sampling,
))
if processor_status.total_redactions > 0:
output.write("%ld redactions, " %
processor_status.total_redactions)
output.write(
"last checked %s" %
scalyr_util.format_time(processor_status.last_scan_time))
output.write("\n")
output.flush()
def __report_copying_manager(output, manager_status, agent_log_file_path, read_time):
print >>output, 'Log transmission:'
print >>output, '================='
print >>output, ''
print >>output, '(these statistics cover the period from %s)' % scalyr_util.format_time(read_time)
print >>output, ''
print >>output, 'Bytes uploaded successfully: %ld' % manager_status.total_bytes_uploaded
print >>output, 'Last successful communication with Scalyr: %s' % scalyr_util.format_time(
manager_status.last_success_time)
print >>output, 'Last attempt: %s' % scalyr_util.format_time(
manager_status.last_attempt_time)
if manager_status.last_attempt_size is not None:
print >>output, 'Last copy request size: %ld' % manager_status.last_attempt_size
if manager_status.last_response is not None:
print >>output, 'Last copy response size: %ld' % len(manager_status.last_response)
print >>output, 'Last copy response status: %s' % manager_status.last_response_status
if manager_status.last_response_status != 'success':
print >>output, 'Last copy response: %s' % scalyr_util.remove_newlines_and_truncate(
manager_status.last_response, 1000)
if manager_status.total_errors > 0:
print >>output, 'Total responses with errors: %d (see \'%s\' for details)' % (
manager_status.total_errors, agent_log_file_path)
print >>output, ''
for matcher_status in manager_status.log_matchers:
if not matcher_status.is_glob:
if len(matcher_status.log_processors_status) == 0:
# This is an absolute file path (no wildcards) and there are not matches.
print >>output, 'Path %s: no matching readable file, last checked %s' % (
matcher_status.log_path, scalyr_util.format_time(matcher_status.last_check_time))
else:
# We have a match.. matcher_status.log_processors_status should really only have one
# entry, but we loop anyway.
for processor_status in matcher_status.log_processors_status:
output.write('Path %s: copied %ld bytes (%ld lines), %ld bytes pending, ' % (
processor_status.log_path, processor_status.total_bytes_copied,
processor_status.total_lines_copied, processor_status.total_bytes_pending))
if processor_status.total_bytes_skipped > 0:
output.write('%ld bytes skipped, ' % processor_status.total_bytes_skipped)
if processor_status.total_bytes_failed > 0:
output.write('%ld bytes failed, ' % processor_status.total_bytes_failed)
if processor_status.total_bytes_dropped_by_sampling > 0:
output.write('%ld bytes dropped by sampling (%ld lines), ' % (
processor_status.total_bytes_dropped_by_sampling,
processor_status.total_lines_dropped_by_sampling))
if processor_status.total_redactions > 0:
output.write('%ld redactions, ' % processor_status.total_redactions)
output.write('last checked %s' % scalyr_util.format_time(processor_status.last_scan_time))
output.write('\n')
output.flush()
need_to_add_extra_line = True
for matcher_status in manager_status.log_matchers:
if matcher_status.is_glob:
if need_to_add_extra_line:
need_to_add_extra_line = False
print >>output, ''
print >>output, 'Glob: %s:: last scanned for glob matches at %s' % (
matcher_status.log_path, scalyr_util.format_time(matcher_status.last_check_time))
for processor_status in matcher_status.log_processors_status:
output.write(' %s: copied %ld bytes (%ld lines), %ld bytes pending, ' % (
processor_status.log_path, processor_status.total_bytes_copied,
processor_status.total_lines_copied, processor_status.total_bytes_pending))
if processor_status.total_bytes_skipped > 0:
output.write('%ld bytes skipped, ' % processor_status.total_bytes_skipped)
if processor_status.total_bytes_failed > 0:
output.write('%ld bytes failed, ' % processor_status.total_bytes_failed)
if processor_status.total_bytes_dropped_by_sampling > 0:
output.write('%ld bytes dropped by sampling (%ld lines), ' % (
processor_status.total_bytes_dropped_by_sampling,
processor_status.total_lines_dropped_by_sampling))
if processor_status.total_redactions > 0:
output.write('%ld redactions, ' % processor_status.total_redactions)
output.write('last checked %s' % scalyr_util.format_time(processor_status.last_scan_time))
output.write('\n')
output.flush()
def _report_worker_session(output, worker_session, manager_status,
agent_log_file_path, indent):
# type: (TextIO, CopyingManagerWorkerSessionStatus, CopyingManagerStatus, six.text_type, int) -> None
"""
Write worker session status to the file-like object.
:param output: file-like object.
:param worker_session: worker session status object.
:param agent_log_file_path:
:param indent: Number of spaces to indent on each new line.
:param manager_status: the manager status to produce the health check.
:return:
"""
_indent_print(
"Bytes uploaded successfully: %ld" %
worker_session.total_bytes_uploaded,
file=output,
indent=indent,
)
_indent_print(
"Last successful communication with Scalyr: %s" %
scalyr_util.format_time(worker_session.last_success_time),
file=output,
indent=indent,
)
_indent_print(
"Last attempt: %s" %
scalyr_util.format_time(worker_session.last_attempt_time),
file=output,
indent=indent,
)
if worker_session.last_attempt_size is not None:
_indent_print(
"Last copy request size: %ld" %
worker_session.last_attempt_size,
file=output,
indent=indent,
)
if worker_session.last_response is not None:
_indent_print(
"Last copy response size: %ld" %
len(worker_session.last_response),
file=output,
indent=indent,
)
_indent_print(
"Last copy response status: %s" %
worker_session.last_response_status,
file=output,
indent=indent,
)
if worker_session.last_response_status != "success":
_indent_print(
"Last copy response: %s" %
scalyr_util.remove_newlines_and_truncate(
worker_session.last_response, 1000),
file=output,
indent=indent,
)
if worker_session.total_errors > 0:
_indent_print(
"Total responses with errors: %d (see '%s' for details)"
% (
worker_session.total_errors,
agent_log_file_path,
),
file=output,
indent=indent,
)
if manager_status.is_single_worker_session():
health_check_message = __get_overall_health_check(manager_status)
else:
health_check_message = worker_session.health_check_result
if health_check_message:
# if message is not empty, write it. In other case we still don't have all health check data.
_indent_print(
"Health check: %s" %
health_check_message,
file=output,
indent=indent,
)
print("", file=output)
def test_remove_newlines_and_truncate(self):
self.assertEquals(scalyr_util.remove_newlines_and_truncate("hi", 1000), "hi")
self.assertEquals(scalyr_util.remove_newlines_and_truncate("ok then", 2), "ok")
self.assertEquals(scalyr_util.remove_newlines_and_truncate("o\nk\n", 1000), "o k ")
self.assertEquals(scalyr_util.remove_newlines_and_truncate("ok\n\r there", 1000), "ok there")
self.assertEquals(scalyr_util.remove_newlines_and_truncate("ok\n\r there", 6), "ok t")
