Skip to content

Commit

Permalink
Make init durations more accurate
Browse files Browse the repository at this point in the history
  • Loading branch information
@mhart
mhart committed Nov 18, 2019
1 parent 9c9585e commit ce1203b
Show file tree
Hide file tree
Showing 10 changed files with 275 additions and 100 deletions.
47 changes: 31 additions & 16 deletions dotnetcore2.0/run/MockBootstraps/MockRuntime.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,10 @@ internal class MockRuntime : ILambdaRuntime

private bool logTail;

private bool initTimeSent;

private DateTimeOffset receivedInvokeAt = DateTimeOffset.MinValue;

private string logs;

private Exception invokeError;
Expand All @@ -38,9 +42,11 @@ internal class MockRuntime : ILambdaRuntime

private static readonly HttpClient client = new HttpClient();

private readonly MockXRayProfiler xRayProfiler = new MockXRayProfiler();

public IEnvironment Environment { get; } = new SystemEnvironment();

public IXRayProfiler XRayProfiler { get; } = new MockXRayProfiler();
public IXRayProfiler XRayProfiler { get { return xRayProfiler; } }

public InitData InitData
{
Expand Down Expand Up @@ -94,17 +100,20 @@ public void Init()

unsafe InvokeData ILambdaRuntime.ReceiveInvoke(IDictionary initialEnvironmentVariables, RuntimeReceiveInvokeBuffers buffers)
{
var result = client.GetAsync("http://127.0.0.1:9001/2018-06-01/runtime/invocation/next").Result;
if (result.StatusCode != HttpStatusCode.OK)
if (!invoked)
{
throw new Exception("Got a bad response from the bootstrap");
receivedInvokeAt = DateTimeOffset.Now;
invoked = true;
}

if (invoked)
else
{
logs = "";
}
invoked = true;
var result = client.GetAsync("http://127.0.0.1:9001/2018-06-01/runtime/invocation/next").Result;
if (result.StatusCode != HttpStatusCode.OK)
{
throw new Exception("Got a bad response from the bootstrap");
}

var requestId = result.Headers.GetValues("Lambda-Runtime-Aws-Request-Id").First();
var deadlineMs = result.Headers.GetValues("Lambda-Runtime-Deadline-Ms").First();
Expand Down Expand Up @@ -162,6 +171,12 @@ public unsafe void ReportDone(string invokeId, string errorType, bool waitForExi
{
requestMessage.Headers.Add("Docker-Lambda-Log-Result", Convert.ToBase64String(LogsTail4k()));
}
if (!initTimeSent)
{
requestMessage.Headers.Add("Docker-Lambda-Invoke-Wait", receivedInvokeAt.ToUnixTimeMilliseconds().ToString());
requestMessage.Headers.Add("Docker-Lambda-Init-End", xRayProfiler.InitEnd.ToUnixTimeMilliseconds().ToString());
initTimeSent = true;
}
requestMessage.Content = new StringContent(output);
task = client.SendAsync(requestMessage);
try
Expand Down Expand Up @@ -246,16 +261,13 @@ private static void AppendStackTraceToStringBuilder(StringBuilder builder, Excep
{
if (!string.IsNullOrWhiteSpace(ex.StackTrace))
{
string[] array = (from s in ex.StackTrace.Split(new string[]
{
System.Environment.NewLine
}, StringSplitOptions.None)
select s.Trim() into s
where !string.IsNullOrWhiteSpace(s)
select STACK_TRACE_INDENT + s).ToArray();
foreach (string value in array)
foreach (var line in ex.StackTrace
.Split(new string[] { System.Environment.NewLine }, StringSplitOptions.None)
.Select(s => s.Trim())
.Where(s => !string.IsNullOrWhiteSpace(s))
.Select(s => STACK_TRACE_INDENT + s))
{
builder.AppendLine(value);
builder.AppendLine(line);
}
}
if (ex.InnerException != null)
Expand Down Expand Up @@ -313,12 +325,15 @@ internal static Lazy<CognitoClientContextInternal> GetCognitoClientContextIntern

internal class MockXRayProfiler : IXRayProfiler
{
public DateTimeOffset InitEnd { get; private set; }

public void ReportUserInitStart()
{
}

public void ReportUserInitEnd()
{
InitEnd = DateTimeOffset.Now;
}

public void ReportUserInvokeStart()
Expand Down
47 changes: 31 additions & 16 deletions dotnetcore2.1/run/MockBootstraps/MockRuntime.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,10 @@ internal class MockRuntime : ILambdaRuntime

private bool logTail;

private bool initTimeSent;

private DateTimeOffset receivedInvokeAt = DateTimeOffset.MinValue;

private string logs;

private Exception invokeError;
Expand All @@ -38,9 +42,11 @@ internal class MockRuntime : ILambdaRuntime

private static readonly HttpClient client = new HttpClient();

private readonly MockXRayProfiler xRayProfiler = new MockXRayProfiler();

public IEnvironment Environment { get; } = new SystemEnvironment();

public IXRayProfiler XRayProfiler { get; } = new MockXRayProfiler();
public IXRayProfiler XRayProfiler { get { return xRayProfiler; } }

public InitData InitData
{
Expand Down Expand Up @@ -94,17 +100,20 @@ public void Init()

unsafe InvokeData ILambdaRuntime.ReceiveInvoke(IDictionary initialEnvironmentVariables, RuntimeReceiveInvokeBuffers buffers)
{
var result = client.GetAsync("http://127.0.0.1:9001/2018-06-01/runtime/invocation/next").Result;
if (result.StatusCode != HttpStatusCode.OK)
if (!invoked)
{
throw new Exception("Got a bad response from the bootstrap");
receivedInvokeAt = DateTimeOffset.Now;
invoked = true;
}

if (invoked)
else
{
logs = "";
}
invoked = true;
var result = client.GetAsync("http://127.0.0.1:9001/2018-06-01/runtime/invocation/next").Result;
if (result.StatusCode != HttpStatusCode.OK)
{
throw new Exception("Got a bad response from the bootstrap");
}

var requestId = result.Headers.GetValues("Lambda-Runtime-Aws-Request-Id").First();
var deadlineMs = result.Headers.GetValues("Lambda-Runtime-Deadline-Ms").First();
Expand Down Expand Up @@ -162,6 +171,12 @@ public unsafe void ReportDone(string invokeId, string errorType, bool waitForExi
{
requestMessage.Headers.Add("Docker-Lambda-Log-Result", Convert.ToBase64String(LogsTail4k()));
}
if (!initTimeSent)
{
requestMessage.Headers.Add("Docker-Lambda-Invoke-Wait", receivedInvokeAt.ToUnixTimeMilliseconds().ToString());
requestMessage.Headers.Add("Docker-Lambda-Init-End", xRayProfiler.InitEnd.ToUnixTimeMilliseconds().ToString());
initTimeSent = true;
}
requestMessage.Content = new StringContent(output);
task = client.SendAsync(requestMessage);
try
Expand Down Expand Up @@ -246,16 +261,13 @@ private static void AppendStackTraceToStringBuilder(StringBuilder builder, Excep
{
if (!string.IsNullOrWhiteSpace(ex.StackTrace))
{
string[] array = (from s in ex.StackTrace.Split(new string[]
{
System.Environment.NewLine
}, StringSplitOptions.None)
select s.Trim() into s
where !string.IsNullOrWhiteSpace(s)
select STACK_TRACE_INDENT + s).ToArray();
foreach (string value in array)
foreach (var line in ex.StackTrace
.Split(new string[] { System.Environment.NewLine }, StringSplitOptions.None)
.Select(s => s.Trim())
.Where(s => !string.IsNullOrWhiteSpace(s))
.Select(s => STACK_TRACE_INDENT + s))
{
builder.AppendLine(value);
builder.AppendLine(line);
}
}
if (ex.InnerException != null)
Expand Down Expand Up @@ -313,12 +325,15 @@ internal static Lazy<CognitoClientContextInternal> GetCognitoClientContextIntern

internal class MockXRayProfiler : IXRayProfiler
{
public DateTimeOffset InitEnd { get; private set; }

public void ReportUserInitStart()
{
}

public void ReportUserInitEnd()
{
InitEnd = DateTimeOffset.Now;
}

public void ReportUserInvokeStart()
Expand Down
22 changes: 21 additions & 1 deletion go1.x/run/aws-lambda-mock.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -211,7 +211,18 @@ func main() {
time.Sleep(5 * time.Millisecond)
}

var initEndSent bool
var invoked bool
var receivedInvokeAt time.Time

for {
if !invoked {
receivedInvokeAt = time.Now()
invoked = true
} else {
logsBuf.Reset()
}

resp, err := http.Get(apiBase + "/runtime/invocation/next")
if err != nil {
if uerr, ok := err.(*url.Error); ok {
Expand Down Expand Up @@ -262,7 +273,10 @@ func main() {

logTail := resp.Header.Get("Docker-Lambda-Log-Type") == "Tail"

logsBuf.Reset()
var initEnd time.Time
if !initEndSent {
initEnd = time.Now()
}

var reply *messages.InvokeResponse
err = client.Call("Function.Invoke", invokeRequest, &reply)
Expand Down Expand Up @@ -303,6 +317,12 @@ func main() {
}
}

if !initEndSent {
req.Header.Add("Docker-Lambda-Invoke-Wait", strconv.FormatInt(receivedInvokeAt.UnixNano()/int64(time.Millisecond), 10))
req.Header.Add("Docker-Lambda-Init-End", strconv.FormatInt(initEnd.UnixNano()/int64(time.Millisecond), 10))
initEndSent = true
}

resp, err = http.DefaultClient.Do(req)
if err != nil {
log.Fatal(err)
Expand Down
18 changes: 16 additions & 2 deletions java8/run/lambda-runtime-mock/src/main/java/lambdainternal/LambdaRuntime.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,9 @@ public class LambdaRuntime {
private static long deadlineMs;
private static boolean invoked = false;
private static boolean errored = false;
private static boolean initEndSent = false;
private static long initEnd;
private static long receivedInvokeAt;

public static final int MEMORY_LIMIT;
public static final String LOG_GROUP_NAME;
Expand Down Expand Up @@ -126,7 +129,12 @@ public static WaitForStartResult waitForStart() {
}

public static InvokeRequest waitForInvoke() {
invoked = true;
if (!invoked) {
receivedInvokeAt = System.currentTimeMillis();
invoked = true;
} else {
LOGS.reset();
}
try {
HttpURLConnection conn = (HttpURLConnection) new URL(API_BASE + "/runtime/invocation/next")
.openConnection();
Expand All @@ -151,7 +159,6 @@ public static InvokeRequest waitForInvoke() {
}

needsDebugLogs = "Tail".equals(conn.getHeaderField("Docker-Lambda-Log-Type"));
LOGS.reset();

String responseBody = "";
try (Scanner scanner = new Scanner(conn.getInputStream())) {
Expand Down Expand Up @@ -192,6 +199,12 @@ public static void reportDone(final String invokeid, final byte[] result, final
}
conn.setRequestProperty("Docker-Lambda-Log-Result", Base64.getEncoder().encodeToString(logs));
}

if (!initEndSent) {
conn.setRequestProperty("Docker-Lambda-Invoke-Wait", Long.toString(receivedInvokeAt));
conn.setRequestProperty("Docker-Lambda-Init-End", Long.toString(initEnd));
initEndSent = true;
}

byte[] resultCopy = result == null ? new byte[0]
: new String(result, 0, resultLength).getBytes(StandardCharsets.UTF_8);
Expand Down Expand Up @@ -235,6 +248,7 @@ public static void reportUserInitStart() {
}

public static void reportUserInitEnd() {
initEnd = System.currentTimeMillis();
}

public static void reportUserInvokeStart() {
Expand Down
26 changes: 20 additions & 6 deletions nodejs4.3/run/awslambda-mock.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,9 @@ OPTIONS.invokeid = OPTIONS.invokeId

var invoked = false
var errored = false
var initEndSent = false
var receivedInvokeAt
var initEnd
var pingPromise
var reportDonePromise

Expand All @@ -93,6 +96,12 @@ module.exports = {
},
waitForInvoke: function (cb) {
Promise.all([pingPromise, reportDonePromise]).then(() => {
if (!invoked) {
receivedInvokeAt = Date.now()
invoked = true
} else {
LOGS = ''
}
http.get({
hostname: '127.0.0.1',
port: 9001,
Expand All @@ -102,10 +111,6 @@ module.exports = {
console.error(`Mock server invocation/next returned a ${res.statusCode} response`)
return process.exit(1)
}
if (invoked) {
LOGS = ''
}
invoked = true
OPTIONS.invokeId = OPTIONS.initInvokeId = OPTIONS.invokeid = res.headers['lambda-runtime-aws-request-id']
OPTIONS.invokedFunctionArn = res.headers['lambda-runtime-invoked-function-arn']
OPTIONS['x-amzn-trace-id'] = res.headers['lambda-runtime-trace-id']
Expand Down Expand Up @@ -140,12 +145,21 @@ module.exports = {
if (!invoked) return
if (errType) errored = true
reportDonePromise = new Promise(resolve => {
var headers = {}
if (LOG_TAIL) {
headers['Docker-Lambda-Log-Result'] = newBuffer(LOGS).slice(-4096).toString('base64')
}
if (!initEndSent) {
headers['Docker-Lambda-Invoke-Wait'] = receivedInvokeAt
headers['Docker-Lambda-Init-End'] = initEnd
initEndSent = true
}
http.request({
method: 'POST',
hostname: '127.0.0.1',
port: 9001,
path: '/2018-06-01/runtime/invocation/' + invokeId + (errType == null ? '/response' : '/error'),
headers: LOG_TAIL ? { 'Docker-Lambda-Log-Result': newBuffer(LOGS).slice(-4096).toString('base64') } : {},
headers,
}, res => {
if (res.statusCode !== 202) {
console.error(err || 'Got status code: ' + res.statusCode)
Expand All @@ -164,7 +178,7 @@ module.exports = {
if (errStack) systemErr(errStack)
},
reportUserInitStart: function () { },
reportUserInitEnd: function () { },
reportUserInitEnd: function () { initEnd = Date.now() },
reportUserInvokeStart: function () { },
reportUserInvokeEnd: function () { },
reportException: function () { },
Expand Down
Loading

0 comments on commit ce1203b

Please sign in to comment.