Skip to content

Commit bd32c02

Browse files
nblumhardtnblumhardt
committed
Switch to UTC timestamps; added benchmark project
1 parent 85997e9 commit bd32c02

File tree

13 files changed

+171
-15
lines changed

13 files changed

+171
-15
lines changed

‎README.md

Lines changed: 13 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ A simple, compact JSON-based event format for Serilog. `CompactJsonFormatter` si
77
A simple `Hello, {User}` event.
88

99
```json
10-
{"@t":"2016-06-07T13:44:57.8532799+10:00","@mt":"Hello, {User}","User":"nblumhardt"}
10+
{"@t":"2016-06-07T03:44:57.8532799Z","@mt":"Hello, {User}","User":"nblumhardt"}
1111
```
1212

1313
### Getting started
@@ -35,7 +35,7 @@ Instead of the message template, `RenderedCompactJsonFormatter` writes the fully
3535
an _event id_ [generated from the message template](https://nblumhardt.com/2015/10/assigning-event-types-to-serilog-events/), into the event:
3636

3737
```json
38-
{"@t":"2016-06-07T13:44:57.8532799+10:00","@m":"Hello, \"nblumhardt\"","@i":"7a8b9c0d","User":"nblumhardt"}
38+
{"@t":"2016-06-07T03:44:57.8532799Z","@m":"Hello, \"nblumhardt\"","@i":"7a8b9c0d","User":"nblumhardt"}
3939
```
4040

4141
### Format details
@@ -98,18 +98,21 @@ ngs":{"N":[{"Format":"x8","Rendering":"0000007b"}]}}
9898

9999
**`CompactJsonFormatter`**
100100

101-
192 bytes (**0.66**).
101+
187 bytes (**0.64**).
102102

103103
```
104-
{"@t":"2016-06-07T13:44:57.8532799+10:00","@mt":"Hello, {@User}, {N:x8} at {Now}
105-
","@r":["0000007b"],"User":{"Name":"nblumhardt","Tags":[1,2,3]},"N":123,"Now":20
106-
16-06-07T13:44:57.8532799+10:00}
104+
{"@t":"2016-06-07T03:44:57.8532799Z","@mt":"Hello, {@User}, {N:x8} at {Now}","@r
105+
":["0000007b"],"User":{"Name":"nblumhardt","Tags":[1,2,3]},"N":123,"Now":2016-06
106+
-07T13:44:57.8532799+10:00}
107107
```
108108

109109
**Formatting benchmark**
110110

111-
| Iterations | Formatter | Time (s) | Time (rel) |
112-
| ---------- | --------- | -------- | ---------- |
113-
| 5,000,000 | `JsonFormatter` | 55.368 | 1.0 |
114-
| 5,000,000 | `CompactJsonFormatter` | 32.223 | **0.58** |
111+
See `test/Serilog.Formatting.Compact.Tests/FormattingBenchmarks.cs`.
115112

113+
| Method | Median | StdDev | Scaled |
114+
|--------------------------------- |----------- |---------- |------- |
115+
| JsonFormatter1000 | 10.9891 ms | 0.4127 ms | 1.00 |
116+
| CompactJsonFormatter1000 | 5.9689 ms | 0.0556 ms | 0.54 |
117+
| RenderedJsonFormatter1000 | 13.5988 ms | 0.0846 ms | 1.24 |
118+
| RenderedCompactJsonFormatter1000 | 6.9933 ms | 0.0793 ms | 0.64 |

‎src/Serilog.Formatting.Compact/Formatting/Compact/CompactJsonFormatter.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -62,7 +62,7 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo
6262
if (valueFormatter == null) throw new ArgumentNullException(nameof(valueFormatter));
6363

6464
output.Write("{\"@t\":\"");
65-
output.Write(logEvent.Timestamp.ToString("O"));
65+
output.Write(logEvent.Timestamp.UtcDateTime.ToString("O"));
6666
output.Write("\",\"@mt\":");
6767
JsonValueFormatter.WriteQuotedJsonString(logEvent.MessageTemplate.Text, output);
6868

‎src/Serilog.Formatting.Compact/Formatting/Compact/RenderedCompactJsonFormatter.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -61,7 +61,7 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo
6161
if (valueFormatter == null) throw new ArgumentNullException(nameof(valueFormatter));
6262

6363
output.Write("{\"@t\":\"");
64-
output.Write(logEvent.Timestamp.ToString("O"));
64+
output.Write(logEvent.Timestamp.UtcDateTime.ToString("O"));
6565
output.Write("\",\"@m\":");
6666
var message = logEvent.MessageTemplate.Render(logEvent.Properties);
6767
JsonValueFormatter.WriteQuotedJsonString(message, output);

‎src/Serilog.Formatting.Compact/project.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
{
1+
{
22
"version": "1.0.0-rc-*",
33
"description": "A simple, compact JSON-based event format for Serilog.",
44
"authors": [ "Serilog Contributors" ],

‎test/Serilog.Formatting.Compact.Tests/BenchmarkDotNet.Artifacts/results/FormattingBenchmarks-report-github.md

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
```ini
2+
3+
BenchmarkDotNet=v0.9.7.0
4+
OS=Windows
5+
Processor=?, ProcessorCount=8
6+
Frequency=2533317 ticks, Resolution=394.7394 ns, Timer=TSC
7+
HostCLR=CORE, Arch=64-bit RELEASE [RyuJIT]
8+
JitModules=?
9+
1.0.0-preview1-002702
10+
11+
Type=FormattingBenchmarks Mode=Throughput Toolchain=Core
12+
13+
```
14+
Method | Median | StdDev | Scaled |
15+
--------------------------------- |----------- |---------- |------- |
16+
JsonFormatter1000 | 11.6479 ms | 0.3343 ms | 1.00 |
17+
CompactJsonFormatter1000 | 6.1992 ms | 0.0448 ms | 0.53 |
18+
RenderedJsonFormatter1000 | 14.9243 ms | 0.1439 ms | 1.28 |
19+
RenderedCompactJsonFormatter1000 | 7.0540 ms | 0.0535 ms | 0.61 |

‎test/Serilog.Formatting.Compact.Tests/BenchmarkDotNet.Artifacts/results/FormattingBenchmarks-report.csv

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
Type;Method;Mode;Platform;Jit;Framework;Toolchain;Runtime;LaunchCount;WarmupCount;TargetCount;Affinity;Median;StdDev;Scaled
2+
FormattingBenchmarks;JsonFormatter1000;Throughput;Host;Host;Host;Core;Host;Auto;Auto;Auto;Auto;11.6479 ms;0.3343 ms;1.00
3+
FormattingBenchmarks;CompactJsonFormatter1000;Throughput;Host;Host;Host;Core;Host;Auto;Auto;Auto;Auto;6.1992 ms;0.0448 ms;0.53
4+
FormattingBenchmarks;RenderedJsonFormatter1000;Throughput;Host;Host;Host;Core;Host;Auto;Auto;Auto;Auto;14.9243 ms;0.1439 ms;1.28
5+
FormattingBenchmarks;RenderedCompactJsonFormatter1000;Throughput;Host;Host;Host;Core;Host;Auto;Auto;Auto;Auto;7.0540 ms;0.0535 ms;0.61

‎test/Serilog.Formatting.Compact.Tests/BenchmarkDotNet.Artifacts/results/FormattingBenchmarks-report.html

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
<pre><code>
2+
BenchmarkDotNet=v0.9.7.0
3+
OS=Windows
4+
Processor=?, ProcessorCount=8
5+
Frequency=2533317 ticks, Resolution=394.7394 ns, Timer=TSC
6+
HostCLR=CORE, Arch=64-bit RELEASE [RyuJIT]
7+
JitModules=?
8+
1.0.0-preview1-002702
9+
</code></pre>
10+
<pre><code>Type=FormattingBenchmarks Mode=Throughput Toolchain=Core
11+
</code></pre>
12+
13+
<table>
14+
<tr><th> Method</th><th>Median</th><th>StdDev</th><th>Scaled</th>
15+
</tr><tr><td> JsonFormatter1000</td><td>11.6479 ms</td><td>0.3343 ms</td><td>1.00</td>
16+
</tr><tr><td> CompactJsonFormatter1000</td><td>6.1992 ms</td><td>0.0448 ms</td><td>0.53</td>
17+
</tr><tr><td> RenderedJsonFormatter1000</td><td>14.9243 ms</td><td>0.1439 ms</td><td>1.28</td>
18+
</tr><tr><td>RenderedCompactJsonFormatter1000</td><td>7.0540 ms</td><td>0.0535 ms</td><td>0.61</td>
19+
</tr></table>

‎test/Serilog.Formatting.Compact.Tests/Benchmarks.cs

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
using BenchmarkDotNet.Running;
2+
using Xunit;
3+
4+
namespace Serilog.Formatting.Compact.Tests
5+
{
6+
public class Benchmarks
7+
{
8+
[Fact]
9+
public void Benchmark()
10+
{
11+
BenchmarkRunner.Run<FormattingBenchmarks>();
12+
}
13+
}
14+
}

‎test/Serilog.Formatting.Compact.Tests/CompactJsonFormatterTests.cs

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -66,5 +66,16 @@ public void AtPrefixedPropertyNamesAreEscaped()
6666
Assert.True(jobject.TryGetValue("@@Mistake", out val));
6767
Assert.Equal(42, val.ToObject<int>());
6868
}
69+
70+
[Fact]
71+
public void TimestampIsUtc()
72+
{
73+
// Not possible in message templates, but accepted this way
74+
var jobject = AssertValidJson(log => log.Information("Hello"));
75+
76+
JToken val;
77+
Assert.True(jobject.TryGetValue("@t", out val));
78+
Assert.EndsWith("Z", val.ToObject<string>());
79+
}
6980
}
7081
}

‎test/Serilog.Formatting.Compact.Tests/FormattingBenchmarks.cs

Lines changed: 63 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,63 @@
1+
using System;
2+
using System.IO;
3+
using BenchmarkDotNet.Attributes;
4+
using Serilog.Events;
5+
using Serilog.Formatting.Compact.Tests.Support;
6+
using Serilog.Formatting.Json;
7+
8+
namespace Serilog.Formatting.Compact.Tests
9+
{
10+
public class FormattingBenchmarks
11+
{
12+
readonly LogEvent _evt;
13+
readonly ITextFormatter _jsonFormatter = new JsonFormatter(),
14+
_compactFormatter = new CompactJsonFormatter(),
15+
_renderedJsonFormatter = new JsonFormatter(renderMessage: true),
16+
_renderedCompactFormatter = new RenderedCompactJsonFormatter();
17+
18+
public FormattingBenchmarks()
19+
{
20+
var collectorSink = new CollectorSink();
21+
22+
new LoggerConfiguration()
23+
.WriteTo.Sink(collectorSink)
24+
.CreateLogger()
25+
.Information("Hello, {@User}, {N:x8} at {Now}", new { Name = "nblumhardt", Tags = new[] { 1, 2, 3 } }, 123, DateTime.Now);
26+
27+
_evt = collectorSink.LastCollected;
28+
}
29+
30+
void Run(ITextFormatter formatter, int iterations)
31+
{
32+
for (var i = 0; i < iterations; ++i)
33+
{
34+
var sw = new StringWriter();
35+
formatter.Format(_evt, sw);
36+
}
37+
}
38+
39+
[Benchmark(Baseline = true)]
40+
public void JsonFormatter1000()
41+
{
42+
Run(_jsonFormatter, 1000);
43+
}
44+
45+
[Benchmark]
46+
public void CompactJsonFormatter1000()
47+
{
48+
Run(_compactFormatter, 1000);
49+
}
50+
51+
[Benchmark]
52+
public void RenderedJsonFormatter1000()
53+
{
54+
Run(_renderedJsonFormatter, 1000);
55+
}
56+
57+
[Benchmark]
58+
public void RenderedCompactJsonFormatter1000()
59+
{
60+
Run(_renderedCompactFormatter, 1000);
61+
}
62+
}
63+
}

0 commit comments

Comments
 (0)