Skip to content

Commit 796bf65

Browse files
authored
Add new columns: ScriptHostInstanceId, FunctionInvocationId. Populate ActivityId for Http requests (#2467)
* Add columns - FunctionInvocationId, ScriptHostInstanceId. Populate ActivityId * Move setting requestId to SystemTraceHandler
1 parent 5e4e4a1 commit 796bf65

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

44 files changed

+599
-453
lines changed

src/WebJobs.Script.WebHost/Controllers/AdminController.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,7 @@ public AdminController(WebScriptHostManager scriptHostManager, WebHostSettings w
3838
{
3939
_scriptHostManager = scriptHostManager;
4040
_webHostSettings = webHostSettings;
41-
_traceWriter = traceWriter.WithSource($"{ScriptConstants.TraceSourceHostAdmin}.Api");
41+
_traceWriter = traceWriter.WithDefaults($"{ScriptConstants.TraceSourceHostAdmin}.Api");
4242
_logger = loggerFactory?.CreateLogger(ScriptConstants.LogCategoryAdminController);
4343
}
4444

src/WebJobs.Script.WebHost/Controllers/KeysController.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ public KeysController(WebScriptHostManager scriptHostManager, ISecretManager sec
3232
{
3333
_scriptHostManager = scriptHostManager;
3434
_secretManager = secretManager;
35-
_traceWriter = traceWriter.WithSource($"{ScriptConstants.TraceSourceSecretManagement}.Api");
35+
_traceWriter = traceWriter.WithDefaults($"{ScriptConstants.TraceSourceSecretManagement}.Api");
3636
_logger = loggerFactory?.CreateLogger(ScriptConstants.LogCategoryKeysController);
3737
}
3838

src/WebJobs.Script.WebHost/Controllers/SwaggerController.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@ public SwaggerController(ISwaggerDocumentManager swaggerDocumentManager, WebScri
2525
{
2626
_swaggerDocumentManager = swaggerDocumentManager;
2727
_scriptHostManager = scriptHostManager;
28-
_traceWriter = traceWriter.WithSource($"{ScriptConstants.TraceSourceSwagger}.Api");
28+
_traceWriter = traceWriter.WithDefaults($"{ScriptConstants.TraceSourceSwagger}.Api");
2929
_logger = loggerFactory?.CreateLogger(ScriptConstants.LogCategorySwaggerController);
3030
}
3131

src/WebJobs.Script.WebHost/Diagnostics/EventGenerator.cs

Lines changed: 7 additions & 314 deletions
Large diffs are not rendered by default.
Lines changed: 245 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,245 @@
1+
using System;
2+
using System.Diagnostics;
3+
using System.Diagnostics.CodeAnalysis;
4+
using System.Diagnostics.Tracing;
5+
using System.Reflection;
6+
7+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
8+
{
9+
public abstract unsafe class ExtendedEventSource : EventSource
10+
{
11+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly", Scope = "For this type", Target = "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics")]
12+
[NonEvent]
13+
[Obsolete("Do not use params object[] overload, create a explicit WriteEvent in ExtendedEventSource.", true)]
14+
protected new void WriteEvent(int eventNum, params object[] args)
15+
{
16+
base.WriteEvent(eventNum, args);
17+
}
18+
19+
// LogFunctionExecutionAggregateEvent
20+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
21+
[NonEvent]
22+
protected void WriteEvent(int eventNumber, string a, string b, ulong c, ulong d, ulong e, ulong f)
23+
{
24+
const int count = 6;
25+
fixed (char* aPtr = a, bPtr = b)
26+
{
27+
EventData* data = stackalloc EventData[count];
28+
data[0].DataPointer = (IntPtr)aPtr;
29+
data[0].Size = (a.Length + 1) * sizeof(char);
30+
data[1].DataPointer = (IntPtr)bPtr;
31+
data[1].Size = (b.Length + 1) * sizeof(char);
32+
data[2].DataPointer = (IntPtr)(&c);
33+
data[2].Size = sizeof(ulong);
34+
data[3].DataPointer = (IntPtr)(&d);
35+
data[3].Size = sizeof(ulong);
36+
data[4].DataPointer = (IntPtr)(&e);
37+
data[4].Size = sizeof(ulong);
38+
data[5].DataPointer = (IntPtr)(&f);
39+
data[5].Size = sizeof(ulong);
40+
41+
WriteEventCore(eventNumber, count, data);
42+
}
43+
}
44+
45+
46+
// LogFunctionDetailsEvent
47+
[NonEvent]
48+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
49+
protected void WriteEvent(int eventNum, string a, string b, string c, string d, string e, bool f)
50+
{
51+
const int count = 6;
52+
fixed (char* aPtr = a,
53+
bPtr = b,
54+
cPtr = c,
55+
dPtr = d,
56+
ePtr = e)
57+
{
58+
EventData* data = stackalloc EventData[count];
59+
data[0].DataPointer = (IntPtr)aPtr;
60+
data[0].Size = (a.Length + 1) * sizeof(char);
61+
data[1].DataPointer = (IntPtr)bPtr;
62+
data[1].Size = (b.Length + 1) * sizeof(char);
63+
data[2].DataPointer = (IntPtr)cPtr;
64+
data[2].Size = (c.Length + 1) * sizeof(char);
65+
data[3].DataPointer = (IntPtr)dPtr;
66+
data[3].Size = (d.Length + 1) * sizeof(char);
67+
data[4].DataPointer = (IntPtr)ePtr;
68+
data[4].Size = (e.Length + 1) * sizeof(char);
69+
data[5].DataPointer = (IntPtr)(&f);
70+
data[5].Size = 4; // boolean variables have size 4
71+
72+
WriteEventCore(eventNum, count, data);
73+
}
74+
}
75+
76+
// LogFunctionExecutionEvent
77+
[NonEvent]
78+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
79+
protected void WriteEvent(int eventNum, string a, string b, int c, string d, string e, string f, ulong g, bool h)
80+
{
81+
const int count = 8;
82+
fixed (char* aPtr = a,
83+
bPtr = b,
84+
dPtr = d,
85+
ePtr = e,
86+
fPtr = f)
87+
{
88+
EventData* data = stackalloc EventData[count];
89+
data[0].DataPointer = (IntPtr)aPtr;
90+
data[0].Size = (a.Length + 1) * sizeof(char);
91+
data[1].DataPointer = (IntPtr)bPtr;
92+
data[1].Size = (b.Length + 1) * sizeof(char);
93+
data[2].DataPointer = (IntPtr)(&c);
94+
data[2].Size = sizeof(int);
95+
data[3].DataPointer = (IntPtr)dPtr;
96+
data[3].Size = (d.Length + 1) * sizeof(char);
97+
data[4].DataPointer = (IntPtr)ePtr;
98+
data[4].Size = (e.Length + 1) * sizeof(char);
99+
data[5].DataPointer = (IntPtr)fPtr;
100+
data[5].Size = (f.Length + 1) * sizeof(char);
101+
data[6].DataPointer = (IntPtr)(&g);
102+
data[6].Size = sizeof(ulong);
103+
data[7].DataPointer = (IntPtr)(&h);
104+
data[7].Size = 4; // boolean variables have size 4
105+
106+
WriteEventCore(eventNum, count, data);
107+
}
108+
}
109+
110+
// RaiseFunctionsEventVerbose/Info/Warning
111+
[NonEvent]
112+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
113+
protected void WriteEvent(int eventNum, string a, string b, string c, string d, string e, string f, string g, string h, string i, string j, string k)
114+
{
115+
int count = MethodBase.GetCurrentMethod().GetParameters().Length;
116+
fixed (char* aPtr = a,
117+
bPtr = b,
118+
cPtr = c,
119+
dPtr = d,
120+
ePtr = e,
121+
fPtr = f,
122+
gPtr = g,
123+
hPtr = h,
124+
iPtr = i,
125+
jPtr = j,
126+
kPtr = k)
127+
{
128+
EventData* data = stackalloc EventData[count];
129+
data[0].DataPointer = (IntPtr)aPtr;
130+
data[0].Size = (a.Length + 1) * sizeof(char);
131+
data[1].DataPointer = (IntPtr)bPtr;
132+
data[1].Size = (b.Length + 1) * sizeof(char);
133+
data[2].DataPointer = (IntPtr)cPtr;
134+
data[2].Size = (c.Length + 1) * sizeof(char);
135+
data[3].DataPointer = (IntPtr)dPtr;
136+
data[3].Size = (d.Length + 1) * sizeof(char);
137+
data[4].DataPointer = (IntPtr)ePtr;
138+
data[4].Size = (e.Length + 1) * sizeof(char);
139+
data[5].DataPointer = (IntPtr)fPtr;
140+
data[5].Size = (f.Length + 1) * sizeof(char);
141+
data[6].DataPointer = (IntPtr)gPtr;
142+
data[6].Size = (g.Length + 1) * sizeof(char);
143+
data[7].DataPointer = (IntPtr)hPtr;
144+
data[7].Size = (h.Length + 1) * sizeof(char);
145+
data[8].DataPointer = (IntPtr)iPtr;
146+
data[8].Size = (i.Length + 1) * sizeof(char);
147+
data[9].DataPointer = (IntPtr)jPtr;
148+
data[9].Size = (j.Length + 1) * sizeof(char);
149+
data[10].DataPointer = (IntPtr)kPtr;
150+
data[10].Size = (k.Length + 1) * sizeof(char);
151+
WriteEventCore(eventNum, count, data);
152+
}
153+
}
154+
155+
// RaiseFunctionsEventError
156+
[NonEvent]
157+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
158+
protected void WriteEvent(int eventNum, string a, string b, string c, string d, string e, string f, string g, string h, string i, string j, string k, string l, string m)
159+
{
160+
int count = MethodBase.GetCurrentMethod().GetParameters().Length;
161+
fixed (char* aPtr = a,
162+
bPtr = b,
163+
cPtr = c,
164+
dPtr = d,
165+
ePtr = e,
166+
fPtr = f,
167+
gPtr = g,
168+
hPtr = h,
169+
iPtr = i,
170+
jPtr = j,
171+
kPtr = k,
172+
lPtr = l,
173+
mPtr = m)
174+
{
175+
EventData* data = stackalloc EventData[count];
176+
data[0].DataPointer = (IntPtr)aPtr;
177+
data[0].Size = (a.Length + 1) * sizeof(char);
178+
data[1].DataPointer = (IntPtr)bPtr;
179+
data[1].Size = (b.Length + 1) * sizeof(char);
180+
data[2].DataPointer = (IntPtr)cPtr;
181+
data[2].Size = (c.Length + 1) * sizeof(char);
182+
data[3].DataPointer = (IntPtr)dPtr;
183+
data[3].Size = (d.Length + 1) * sizeof(char);
184+
data[4].DataPointer = (IntPtr)ePtr;
185+
data[4].Size = (e.Length + 1) * sizeof(char);
186+
data[5].DataPointer = (IntPtr)fPtr;
187+
data[5].Size = (f.Length + 1) * sizeof(char);
188+
data[6].DataPointer = (IntPtr)gPtr;
189+
data[6].Size = (g.Length + 1) * sizeof(char);
190+
data[7].DataPointer = (IntPtr)hPtr;
191+
data[7].Size = (h.Length + 1) * sizeof(char);
192+
data[8].DataPointer = (IntPtr)iPtr;
193+
data[8].Size = (i.Length + 1) * sizeof(char);
194+
data[9].DataPointer = (IntPtr)jPtr;
195+
data[9].Size = (j.Length + 1) * sizeof(char);
196+
data[10].DataPointer = (IntPtr)kPtr;
197+
data[10].Size = (k.Length + 1) * sizeof(char);
198+
data[11].DataPointer = (IntPtr)lPtr;
199+
data[11].Size = (l.Length + 1) * sizeof(char);
200+
data[12].DataPointer = (IntPtr)mPtr;
201+
data[12].Size = (m.Length + 1) * sizeof(char);
202+
WriteEventCore(eventNum, count, data);
203+
}
204+
}
205+
206+
// LogFunctionMetricEvent
207+
[NonEvent]
208+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentifiersShouldBeSpelledCorrectly")]
209+
protected void WriteEvent(int eventNum, string a, string b, string c, string d, long e, long f, long g, long h, string i, string j)
210+
{
211+
int count = MethodBase.GetCurrentMethod().GetParameters().Length;
212+
fixed (char* aPtr = a,
213+
bPtr = b,
214+
cPtr = c,
215+
dPtr = d,
216+
iPtr = i,
217+
jPtr = j)
218+
{
219+
EventData* data = stackalloc EventData[count];
220+
data[0].DataPointer = (IntPtr)aPtr;
221+
data[0].Size = (a.Length + 1) * sizeof(char);
222+
data[1].DataPointer = (IntPtr)bPtr;
223+
data[1].Size = (b.Length + 1) * sizeof(char);
224+
data[2].DataPointer = (IntPtr)cPtr;
225+
data[2].Size = (c.Length + 1) * sizeof(char);
226+
data[3].DataPointer = (IntPtr)dPtr;
227+
data[3].Size = (d.Length + 1) * sizeof(char);
228+
data[4].DataPointer = (IntPtr)(&e);
229+
data[4].Size = sizeof(long);
230+
data[5].DataPointer = (IntPtr)(&f);
231+
data[5].Size = sizeof(long);
232+
data[6].DataPointer = (IntPtr)(&g);
233+
data[6].Size = sizeof(long);
234+
data[7].DataPointer = (IntPtr)(&h);
235+
data[7].Size = sizeof(long);
236+
data[8].DataPointer = (IntPtr)iPtr;
237+
data[8].Size = (i.Length + 1) * sizeof(char);
238+
data[9].DataPointer = (IntPtr)jPtr;
239+
data[9].Size = (j.Length + 1) * sizeof(char);
240+
241+
WriteEventCore(eventNum, count, data);
242+
}
243+
}
244+
}
245+
}

src/WebJobs.Script.WebHost/Diagnostics/FunctionInstanceLogger.cs

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@ internal class FunctionInstanceLogger : IAsyncCollector<FunctionInstanceLogEntry
2727
public FunctionInstanceLogger(
2828
Func<string, FunctionDescriptor> funcLookup,
2929
IMetricsLogger metrics,
30-
string hostName,
30+
string hostId,
3131
string accountConnectionString, // May be null
3232
TraceWriter trace) : this(funcLookup, metrics)
3333
{
@@ -43,7 +43,7 @@ public FunctionInstanceLogger(
4343
var tableProvider = LogFactory.NewLogTableProvider(client);
4444

4545
string containerName = Environment.MachineName;
46-
this._writer = LogFactory.NewWriter(hostName, containerName, tableProvider, (e) => OnException(e, trace));
46+
_writer = LogFactory.NewWriter(hostId, containerName, tableProvider, (e) => OnException(e, trace));
4747
}
4848
}
4949

@@ -79,6 +79,7 @@ internal FunctionInstanceLogger(
7979
// This exception will cause the function to not get executed.
8080
throw new InvalidOperationException($"Missing function.json for '{shortName}'.");
8181
}
82+
8283
state = new FunctionInstanceMonitor(descr.Metadata, _metrics, item.FunctionInstanceId, descr.Invoker.FunctionLogger);
8384

8485
item.Properties[Key] = state;
Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
using System.Diagnostics.CodeAnalysis;
2+
using System.Diagnostics.Tracing;
3+
4+
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
5+
{
6+
[EventSource(Guid = "08D0D743-5C24-43F9-9723-98277CEA5F9B")]
7+
public sealed class FunctionsEventSource : ExtendedEventSource
8+
{
9+
internal static readonly FunctionsEventSource Instance = new FunctionsEventSource();
10+
11+
[SuppressMessage("Microsoft.Naming", "CA1709:IdentifiersShouldBeCasedCorrectly", MessageId = "Ms")]
12+
[SuppressMessage("Microsoft.Naming", "CA1704:IdentfiersShouldBeSpelledCorrectly", MessageId = "Ms")]
13+
[Event(57907, Level = EventLevel.Informational, Channel = EventChannel.Operational, Keywords = FunctionsKeywords.DefaultMetricsKeyword)]
14+
public void LogFunctionExecutionAggregateEvent(string siteName, string functionName, ulong executionTimeInMs, ulong functionStartedCount, ulong functionCompletedCount, ulong functionFailedCount)
15+
{
16+
if (IsEnabled())
17+
{
18+
WriteEvent(57907, siteName, functionName, executionTimeInMs, functionStartedCount, functionCompletedCount, functionFailedCount);
19+
}
20+
}
21+
22+
[Event(57908, Level = EventLevel.Informational, Channel = EventChannel.Operational, Keywords = FunctionsKeywords.DefaultMetricsKeyword)]
23+
[SuppressMessage("Microsoft.Naming", "CA1709:IdentifiersShouldBeCasedCorrectly")]
24+
public void LogFunctionDetailsEvent(string siteName, string functionName, string inputBindings, string outputBindings, string scriptType, bool isDisabled)
25+
{
26+
if (IsEnabled())
27+
{
28+
WriteEvent(57908, siteName, functionName, inputBindings, outputBindings, scriptType, isDisabled);
29+
}
30+
}
31+
32+
[Event(57909, Level = EventLevel.Informational, Channel = EventChannel.Operational, Keywords = FunctionsKeywords.DefaultMetricsKeyword)]
33+
[SuppressMessage("Microsoft.Naming", "CA1709:IdentifiersShouldBeCasedCorrectly")]
34+
public void LogFunctionExecutionEvent(string executionId, string siteName, int concurrency, string functionName, string invocationId, string executionStage, ulong executionTimeSpan, bool success)
35+
{
36+
if (IsEnabled())
37+
{
38+
WriteEvent(57909, executionId, siteName, concurrency, functionName, invocationId, executionStage, executionTimeSpan, success);
39+
}
40+
}
41+
42+
internal class FunctionsKeywords
43+
{
44+
public const EventKeywords DefaultMetricsKeyword = unchecked((EventKeywords)0x8000000000000000);
45+
}
46+
}
47+
}

0 commit comments

Comments
 (0)