protected async Task ApplicationInsights_SucceedsTest() { string functionName = "Scenarios"; TestHelpers.ClearFunctionLogs(functionName); string functionTrace = $"Function trace: {Guid.NewGuid().ToString()}"; ScenarioInput input = new ScenarioInput { Scenario = "appInsights", Container = "scenarios-output", Value = functionTrace }; Dictionary <string, object> arguments = new Dictionary <string, object> { { "input", JsonConvert.SerializeObject(input) } }; await Fixture.Host.CallAsync(functionName, arguments); // make sure file logs have the info IList <string> logs = null; await TestHelpers.Await(() => { logs = TestHelpers.GetFunctionLogsAsync(functionName, throwOnNoLogs: false).Result; return(logs.Count > 0); }); // No need for assert; this will throw if there's not one and only one logs.Single(p => p.EndsWith(functionTrace)); // Validate the traces. Order by message string as the requests may come in // slightly out-of-order or on different threads TelemetryPayload[] telemetries = _fixture.TelemetryItems .Where(t => t.Data.BaseType == "MessageData") .Where(t => !t.Data.BaseData.Message.Contains("Loaded custom extension")) .OrderBy(t => t.Data.BaseData.Message) .ToArray(); ValidateTrace(telemetries[0], "Found the following functions:\r\n", LogCategories.Startup); ValidateTrace(telemetries[1], "Function completed (Success, Id=", LogCategories.Executor); ValidateTrace(telemetries[2], "Function started (Id=", LogCategories.Executor); ValidateTrace(telemetries[3], functionTrace, LogCategories.Function); ValidateTrace(telemetries[4], "Generating 1 job function(s)", LogCategories.Startup); ValidateTrace(telemetries[5], "Host configuration file read:", LogCategories.Startup); ValidateTrace(telemetries[6], "Host lock lease acquired by instance ID", ScriptConstants.LogCategoryHostGeneral); ValidateTrace(telemetries[7], "Job host started", LogCategories.Startup); ValidateTrace(telemetries[8], "Reading host configuration file", LogCategories.Startup); // Finally, validate the request TelemetryPayload request = _fixture.TelemetryItems .Where(t => t.Data.BaseType == "RequestData") .Single(); ValidateRequest(request); }
private bool IsIndexingError(TelemetryPayload t) { if (t.Data.BaseType == "ExceptionData") { return(true); } var message = t.Data.BaseData.Message; if (message != null && message.StartsWith("Microsoft.Azure.WebJobs.Host: Error indexing method ")) { return(true); } return(false); }
private static void ValidateRequest(TelemetryPayload telemetryItem) { Assert.Equal("RequestData", telemetryItem.Data.BaseType); Assert.NotNull(telemetryItem.Data.BaseData.Id); Assert.Equal("Scenarios", telemetryItem.Data.BaseData.Name); Assert.NotNull(telemetryItem.Data.BaseData.Duration); Assert.True(telemetryItem.Data.BaseData.Success); AssertHasKey(telemetryItem.Data.BaseData.Properties, "param__blob"); AssertHasKey(telemetryItem.Data.BaseData.Properties, "param__input"); AssertHasKey(telemetryItem.Data.BaseData.Properties, "param___context"); AssertHasKey(telemetryItem.Data.BaseData.Properties, "FullName", "Functions.Scenarios"); AssertHasKey(telemetryItem.Data.BaseData.Properties, "TriggerReason", "This function was programmatically called via the host APIs."); ValidateSdkVersion(telemetryItem); }
private void ProcessRequest(HttpListenerContext context) { var request = context.Request; var response = context.Response; try { string result = null; if (request.HasEntityBody) { using (var requestInputStream = request.InputStream) { var encoding = request.ContentEncoding; using (var reader = new StreamReader(requestInputStream, encoding)) { result = reader.ReadToEnd(); } } } if (!string.IsNullOrWhiteSpace(request.Headers["Content-Encoding"]) && string.Equals("gzip", request.Headers["Content-Encoding"], StringComparison.InvariantCultureIgnoreCase)) { result = Decompress(result); } var newLines = new[] { "\r\n", "\n" }; string[] lines = result.Split(newLines, StringSplitOptions.RemoveEmptyEntries); TelemetryPayload telemetry = JsonConvert.DeserializeObject <TelemetryPayload>(result); TelemetryItems.Add(telemetry); } finally { response.Close(); } }
private static void ValidateTrace(TelemetryPayload telemetryItem, string expectedMessageStartsWith, string expectedCategory) { Assert.Equal("MessageData", telemetryItem.Data.BaseType); Assert.StartsWith(expectedMessageStartsWith, telemetryItem.Data.BaseData.Message); Assert.Equal("Information", telemetryItem.Data.BaseData.SeverityLevel); Assert.Equal(expectedCategory, telemetryItem.Data.BaseData.Properties["Category"]); if (expectedCategory == LogCategories.Function || expectedCategory == LogCategories.Executor) { // These should have associated operation information Assert.Equal("Scenarios", telemetryItem.Tags["ai.operation.name"]); Assert.NotNull(telemetryItem.Tags["ai.operation.id"]); } else { Assert.DoesNotContain("ai.operation.name", telemetryItem.Tags.Keys); Assert.DoesNotContain("ai.operation.id", telemetryItem.Tags.Keys); } ValidateSdkVersion(telemetryItem); }
private static void ValidateSdkVersion(TelemetryPayload telemetryItem) { Assert.StartsWith("azurefunctions: ", telemetryItem.Tags["ai.internal.sdkVersion"]); }
protected async Task ApplicationInsights_SucceedsTest() { string functionName = "Scenarios"; TestHelpers.ClearFunctionLogs(functionName); string guid = Guid.NewGuid().ToString(); ScenarioInput input = new ScenarioInput { Scenario = "appInsights", Container = "scenarios-output", Value = guid }; Dictionary <string, object> arguments = new Dictionary <string, object> { { "input", JsonConvert.SerializeObject(input) } }; await Fixture.Host.CallAsync(functionName, arguments); // make sure file logs have the info IList <string> logs = null; await TestHelpers.Await(() => { logs = TestHelpers.GetFunctionLogsAsync(functionName, throwOnNoLogs: false).Result; return(logs.Count > 0); }); // No need for assert; this will throw if there's not one and only one logs.Single(p => p.EndsWith(guid)); Assert.Equal(10, _fixture.TelemetryItems.Count); // Pull out the function log and verify; it's timestamp may make the following ordering // tough to verify. TelemetryPayload telemetryItem = _fixture.TelemetryItems.Single(t => t.Data.BaseData.Message == guid); ValidateTrace(telemetryItem, guid, LogCategories.Function); _fixture.TelemetryItems.Remove(telemetryItem); // The Host lock message is on another thread and may fire out of order. // https://github.com/Azure/azure-webjobs-sdk-script/issues/1674 telemetryItem = _fixture.TelemetryItems.Single(t => t.Data.BaseData.Message?.StartsWith("Host lock lease acquired by instance ID") ?? false); ValidateTrace(telemetryItem, "Host lock lease acquired by instance ID", ScriptConstants.LogCategoryHostGeneral); _fixture.TelemetryItems.Remove(telemetryItem); // Enqueue by time as the requests may come in slightly out-of-order Queue <TelemetryPayload> telemetryQueue = new Queue <TelemetryPayload>(); _fixture.TelemetryItems.OrderBy(t => t.Time).ToList().ForEach(t => telemetryQueue.Enqueue(t)); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Reading host configuration file", LogCategories.Startup); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Host configuration file read:", LogCategories.Startup); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Generating 26 job function(s)", LogCategories.Startup); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Found the following functions:\r\n", LogCategories.Startup); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Job host started", LogCategories.Startup); // Even though the RequestTelemetry comes last, the timestamp is at the beginning of the invocation telemetryItem = telemetryQueue.Dequeue(); ValidateRequest(telemetryItem); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Function started (Id=", LogCategories.Executor); telemetryItem = telemetryQueue.Dequeue(); ValidateTrace(telemetryItem, "Function completed (Success, Id=", LogCategories.Executor); }