Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: remove log & data separation from base_local_service #4563

Merged
merged 5 commits into from
Jan 13, 2023
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 1 addition & 5 deletions samcli/local/apigw/local_apigw_service.py
Original file line number Diff line number Diff line change
Expand Up @@ -362,11 +362,7 @@ def _request_handler(self, **kwargs):
except FunctionNotFound:
return ServiceErrorResponses.lambda_not_found_response()

lambda_response, lambda_logs, _ = LambdaOutputParser.get_lambda_output(stdout_stream)

if self.stderr and lambda_logs:
# Write the logs to stderr if available.
self.stderr.write(lambda_logs)
lambda_response, _ = LambdaOutputParser.get_lambda_output(stdout_stream)

try:
if route.event_type == Route.HTTP and (
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -167,13 +167,7 @@ def _invoke_request_handler(self, function_name):
LOG.debug("%s was not found to invoke.", function_name)
return LambdaErrorResponses.resource_not_found(function_name)

lambda_response, lambda_logs, is_lambda_user_error_response = LambdaOutputParser.get_lambda_output(
stdout_stream
)

if self.stderr and lambda_logs:
# Write the logs to stderr if available.
self.stderr.write(lambda_logs)
lambda_response, is_lambda_user_error_response = LambdaOutputParser.get_lambda_output(stdout_stream)

if is_lambda_user_error_response:
return self.service_response(
Expand Down
30 changes: 5 additions & 25 deletions samcli/local/services/base_local_service.py
Original file line number Diff line number Diff line change
@@ -1,7 +1,8 @@
"""Base class for all Services that interact with Local Lambda"""

import io
import json
import logging
from typing import Tuple

from flask import Response

Expand Down Expand Up @@ -81,7 +82,7 @@ def service_response(body, headers, status_code):

class LambdaOutputParser:
@staticmethod
def get_lambda_output(stdout_stream):
def get_lambda_output(stdout_stream: io.BytesIO) -> Tuple[str, bool]:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if NamedTuple or a Dataclass would provide better readability and typing. I would not block on this but just stood out to me with the update.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do agree it would be better, but I didn't want to introduce more changes to this PR, I've only added some typing into the functions that is been changed.

"""
This method will extract read the given stream and return the response from Lambda function separated out
from any log statements it might have outputted. Logs end up in the stdout stream if the Lambda function
Expand All @@ -96,39 +97,18 @@ def get_lambda_output(stdout_stream):
-------
str
String data containing response from Lambda function
str
String data containng logs statements, if any.
bool
If the response is an error/exception from the container
"""
# We only want the last line of stdout, because it's possible that
# the function may have written directly to stdout using
# System.out.println or similar, before docker-lambda output the result
stdout_data = stdout_stream.getvalue().rstrip(b"\n")

# Usually the output is just one line and contains response as JSON string, but if the Lambda function
# wrote anything directly to stdout, there will be additional lines. So just extract the last line as
# response and everything else as log output.
lambda_response = stdout_data
lambda_logs = None

last_line_position = stdout_data.rfind(b"\n")
if last_line_position >= 0:
# So there are multiple lines. Separate them out.
# Everything but the last line are logs
lambda_logs = stdout_data[:last_line_position]
# Last line is Lambda response. Make sure to strip() so we get rid of extra whitespaces & newlines around
lambda_response = stdout_data[last_line_position:].strip()

lambda_response = lambda_response.decode("utf-8")
lambda_response = stdout_stream.getvalue().decode("utf-8")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we still need the rstrip(b"\n") after the getvalue? We had it there before but not sure if it is strictly required anymore.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've confirmed this by running local integration tests (some of them confirms the output of the command). So I believe we don't need that particular line


# When the Lambda Function returns an Error/Exception, the output is added to the stdout of the container. From
# our perspective, the container returned some value, which is not always true. Since the output is the only
# information we have, we need to inspect this to understand if the container returned a some data or raised an
# error
is_lambda_user_error_response = LambdaOutputParser.is_lambda_error_response(lambda_response)

return lambda_response, lambda_logs, is_lambda_user_error_response
return lambda_response, is_lambda_user_error_response

@staticmethod
def is_lambda_error_response(lambda_response):
Expand Down
6 changes: 4 additions & 2 deletions tests/integration/local/invoke/test_integrations_cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -261,16 +261,18 @@ def test_invoke_when_function_writes_stderr(self):
"WriteToStderrFunction", template_path=self.template_path, event_path=self.event_path
)

process = Popen(command_list, stderr=PIPE)
process = Popen(command_list, stderr=PIPE, stdout=PIPE)
try:
_, stderr = process.communicate(timeout=TIMEOUT)
stdout, stderr = process.communicate(timeout=TIMEOUT)
except TimeoutExpired:
process.kill()
raise

process_stderr = stderr.strip()
process_stdout = stdout.strip()

self.assertIn("Docker Lambda is writing to stderr", process_stderr.decode("utf-8"))
self.assertIn("wrote to stderr", process_stdout.decode("utf-8"))

@pytest.mark.flaky(reruns=3)
def test_invoke_returns_expected_result_when_no_event_given(self):
Expand Down
5 changes: 1 addition & 4 deletions tests/unit/local/apigw/test_local_apigw_service.py
Original file line number Diff line number Diff line change
Expand Up @@ -258,10 +258,9 @@ def test_request_handler_returns_process_stdout_when_making_response(self, lambd
parse_output_mock.return_value = ("status_code", Headers({"headers": "headers"}), "body")
self.api_service._parse_v1_payload_format_lambda_output = parse_output_mock

lambda_logs = "logs"
lambda_response = "response"
is_customer_error = False
lambda_output_parser_mock.get_lambda_output.return_value = lambda_response, lambda_logs, is_customer_error
lambda_output_parser_mock.get_lambda_output.return_value = lambda_response, is_customer_error
service_response_mock = Mock()
service_response_mock.return_value = make_response_mock
self.api_service.service_response = service_response_mock
Expand All @@ -273,8 +272,6 @@ def test_request_handler_returns_process_stdout_when_making_response(self, lambd

# Make sure the parse method is called only on the returned response and not on the raw data from stdout
parse_output_mock.assert_called_with(lambda_response, ANY, ANY, Route.API)
# Make sure the logs are written to stderr
self.stderr.write.assert_called_with(lambda_logs)

@patch.object(LocalApigwService, "get_request_methods_endpoints")
def test_request_handler_returns_make_response(self, request_mock):
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,7 @@ def test_create_service_endpoints(self, flask_mock, error_handling_mock):
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LocalLambdaInvokeService.service_response")
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LambdaOutputParser")
def test_invoke_request_handler(self, lambda_output_parser_mock, service_response_mock):
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", None, False
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", False
service_response_mock.return_value = "request response"

request_mock = Mock()
Expand Down Expand Up @@ -98,10 +98,9 @@ def test_request_handler_returns_process_stdout_when_making_response(
request_mock.get_data.return_value = b"{}"
local_lambda_invoke_service.request = request_mock

lambda_logs = "logs"
lambda_response = "response"
is_customer_error = False
lambda_output_parser_mock.get_lambda_output.return_value = lambda_response, lambda_logs, is_customer_error
lambda_output_parser_mock.get_lambda_output.return_value = lambda_response, is_customer_error

service_response_mock.return_value = "request response"

Expand All @@ -116,9 +115,6 @@ def test_request_handler_returns_process_stdout_when_making_response(
self.assertEqual(result, "request response")
lambda_output_parser_mock.get_lambda_output.assert_called_with(ANY)

# Make sure the logs are written to stderr
stderr_mock.write.assert_called_with(lambda_logs)

@patch("samcli.local.lambda_service.local_lambda_invoke_service.LambdaErrorResponses")
def test_construct_error_handling(self, lambda_error_response_mock):
service = LocalLambdaInvokeService(lambda_runner=Mock(), port=3000, host="localhost", stderr=Mock())
Expand All @@ -138,7 +134,7 @@ def test_construct_error_handling(self, lambda_error_response_mock):
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LocalLambdaInvokeService.service_response")
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LambdaOutputParser")
def test_invoke_request_handler_with_lambda_that_errors(self, lambda_output_parser_mock, service_response_mock):
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", None, True
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", True
service_response_mock.return_value = "request response"
request_mock = Mock()
request_mock.get_data.return_value = b"{}"
Expand All @@ -159,7 +155,7 @@ def test_invoke_request_handler_with_lambda_that_errors(self, lambda_output_pars
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LocalLambdaInvokeService.service_response")
@patch("samcli.local.lambda_service.local_lambda_invoke_service.LambdaOutputParser")
def test_invoke_request_handler_with_no_data(self, lambda_output_parser_mock, service_response_mock):
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", None, False
lambda_output_parser_mock.get_lambda_output.return_value = "hello world", False
service_response_mock.return_value = "request response"

request_mock = Mock()
Expand Down
28 changes: 12 additions & 16 deletions tests/unit/local/services/test_base_local_service.py
Original file line number Diff line number Diff line change
Expand Up @@ -66,30 +66,26 @@ def test_create_returns_not_implemented(self):
class TestLambdaOutputParser(TestCase):
@parameterized.expand(
[
param("with mixed data and json response", b'data\n{"a": "b"}', 'data\n{"a": "b"}'),
param("with response as string", b"response", "response"),
param("with json response only", b'{"a": "b"}', '{"a": "b"}'),
param("with one new line and json", b'\n{"a": "b"}', '\n{"a": "b"}'),
param("with response only as string", b"this is the response line", "this is the response line"),
param("with whitespaces", b'data\n{"a": "b"} \n\n\n', 'data\n{"a": "b"} \n\n\n'),
param("with empty data", b"", ""),
param("with just new lines", b"\n\n", "\n\n"),
param(
"with both logs and response", b'this\nis\nlog\ndata\n{"a": "b"}', b"this\nis\nlog\ndata", '{"a": "b"}'
),
param("with response as string", b"logs\nresponse", b"logs", "response"),
param("with response only", b'{"a": "b"}', None, '{"a": "b"}'),
param("with one new line and response", b'\n{"a": "b"}', b"", '{"a": "b"}'),
param("with response only as string", b"this is the response line", None, "this is the response line"),
param("with whitespaces", b'log\ndata\n{"a": "b"} \n\n\n', b"log\ndata", '{"a": "b"}'),
param("with empty data", b"", None, ""),
param("with just new lines", b"\n\n", None, ""),
param(
"with no data but with whitespaces",
"with whitespaces",
b"\n \n \n",
b"\n ",
"", # Log data with whitespaces will be in the output unchanged
"\n \n \n",
),
]
)
def test_get_lambda_output_extracts_response(self, test_case_name, stdout_data, expected_logs, expected_response):
def test_get_lambda_output_extracts_response(self, test_case_name, stdout_data, expected_response):
stdout = Mock()
stdout.getvalue.return_value = stdout_data

response, logs, is_customer_error = LambdaOutputParser.get_lambda_output(stdout)
self.assertEqual(logs, expected_logs)
response, is_customer_error = LambdaOutputParser.get_lambda_output(stdout)
self.assertEqual(response, expected_response)
self.assertFalse(is_customer_error)

Expand Down