Browse Source

Stopwatch fixed and serializer improved.

pull/294/head
Sebastian 8 years ago
parent
commit
85a83082cf
  1. 8
      src/Squidex.Infrastructure/Log/Profiler.cs
  2. 8
      src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs
  3. 12
      src/Squidex.Infrastructure/Orleans/J{T}.cs
  4. 88
      src/Squidex.Infrastructure/Orleans/StreamReaderWrapper.cs
  5. 79
      src/Squidex.Infrastructure/Orleans/StreamWriterWrapper.cs
  6. 56
      src/Squidex.Infrastructure/ValueStopwatch.cs
  7. 1
      src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs
  8. 8
      src/Squidex/Config/Orleans/SiloWrapper.cs
  9. 8
      src/Squidex/Pipeline/ApiCostsFilter.cs
  10. 1
      src/Squidex/Pipeline/LocalCacheMiddleware.cs
  11. 9
      src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs
  12. 26
      tests/Squidex.Infrastructure.Tests/Orleans/JsonExternalSerializerTests.cs

8
src/Squidex.Infrastructure/Log/Profiler.cs

@ -6,7 +6,6 @@
// ========================================================================== // ==========================================================================
using System; using System;
using System.Diagnostics;
using System.Runtime.CompilerServices; using System.Runtime.CompilerServices;
using System.Threading; using System.Threading;
using Squidex.Infrastructure.Tasks; using Squidex.Infrastructure.Tasks;
@ -56,14 +55,13 @@ namespace Squidex.Infrastructure.Log
return NoopDisposable.Instance; return NoopDisposable.Instance;
} }
var startTime = Stopwatch.GetTimestamp(); var watch = ValueStopwatch.StartNew();
return new DelegateDisposable(() => return new DelegateDisposable(() =>
{ {
var endTime = Stopwatch.GetTimestamp(); var elapsedMs = watch.Stop();
var elapsed = endTime - startTime;
session.Measured(key, elapsed); session.Measured(key, elapsedMs);
}); });
} }
} }

8
src/Squidex.Infrastructure/Log/SemanticLogExtensions.cs

@ -6,7 +6,6 @@
// ========================================================================== // ==========================================================================
using System; using System;
using System.Diagnostics;
namespace Squidex.Infrastructure.Log namespace Squidex.Infrastructure.Log
{ {
@ -94,18 +93,17 @@ namespace Squidex.Infrastructure.Log
private static IDisposable Measure(this ISemanticLog log, SemanticLogLevel logLevel, Action<IObjectWriter> objectWriter) private static IDisposable Measure(this ISemanticLog log, SemanticLogLevel logLevel, Action<IObjectWriter> objectWriter)
{ {
var startTime = Stopwatch.GetTimestamp(); var watch = ValueStopwatch.StartNew();
return new DelegateDisposable(() => return new DelegateDisposable(() =>
{ {
var endTime = Stopwatch.GetTimestamp(); var elapsedMs = watch.Stop();
var elapsed = endTime - startTime;
log.Log(logLevel, writer => log.Log(logLevel, writer =>
{ {
objectWriter?.Invoke(writer); objectWriter?.Invoke(writer);
writer.WriteProperty("elapsedMs", elapsed); writer.WriteProperty("elapsedMs", elapsedMs);
}); });
}); });
} }

12
src/Squidex.Infrastructure/Orleans/J{T}.cs

@ -59,7 +59,7 @@ namespace Squidex.Infrastructure.Orleans
{ {
var jsonSerializer = GetSerializer(context); var jsonSerializer = GetSerializer(context);
var stream = new MemoryStream(); var stream = new StreamWriterWrapper(context.StreamWriter);
using (var writer = new JsonTextWriter(new StreamWriter(stream))) using (var writer = new JsonTextWriter(new StreamWriter(stream)))
{ {
@ -67,11 +67,6 @@ namespace Squidex.Infrastructure.Orleans
writer.Flush(); writer.Flush();
} }
var outBytes = stream.ToArray();
context.StreamWriter.Write(outBytes.Length);
context.StreamWriter.Write(outBytes);
} }
} }
@ -82,10 +77,7 @@ namespace Squidex.Infrastructure.Orleans
{ {
var jsonSerializer = GetSerializer(context); var jsonSerializer = GetSerializer(context);
var outLength = context.StreamReader.ReadInt(); var stream = new StreamReaderWrapper(context.StreamReader);
var outBytes = context.StreamReader.ReadBytes(outLength);
var stream = new MemoryStream(outBytes);
using (var reader = new JsonTextReader(new StreamReader(stream))) using (var reader = new JsonTextReader(new StreamReader(stream)))
{ {

88
src/Squidex.Infrastructure/Orleans/StreamReaderWrapper.cs

@ -0,0 +1,88 @@
// ==========================================================================
// Squidex Headless CMS
// ==========================================================================
// Copyright (c) Squidex UG (haftungsbeschraenkt)
// All rights reserved. Licensed under the MIT license.
// ==========================================================================
using System;
using System.IO;
using Orleans.Serialization;
namespace Squidex.Infrastructure.Orleans
{
internal sealed class StreamReaderWrapper : Stream
{
private readonly IBinaryTokenStreamReader reader;
public override bool CanRead
{
get { return true; }
}
public override bool CanSeek
{
get { return false; }
}
public override bool CanWrite
{
get { return false; }
}
public override long Length
{
get { return reader.Length; }
}
public override long Position
{
get
{
return reader.CurrentPosition;
}
set
{
throw new NotSupportedException();
}
}
public StreamReaderWrapper(IBinaryTokenStreamReader reader)
{
this.reader = reader;
}
public override void Flush()
{
}
public override int Read(byte[] buffer, int offset, int count)
{
var bytesLeft = reader.Length - reader.CurrentPosition;
if (bytesLeft < count)
{
count = bytesLeft;
}
reader.ReadByteArray(buffer, offset, count);
return count;
}
public override long Seek(long offset, SeekOrigin origin)
{
throw new NotSupportedException();
}
public override void SetLength(long value)
{
throw new NotSupportedException();
}
public override void Write(byte[] buffer, int offset, int count)
{
throw new NotSupportedException();
}
}
}

79
src/Squidex.Infrastructure/Orleans/StreamWriterWrapper.cs

@ -0,0 +1,79 @@
// ==========================================================================
// Squidex Headless CMS
// ==========================================================================
// Copyright (c) Squidex UG (haftungsbeschraenkt)
// All rights reserved. Licensed under the MIT license.
// ==========================================================================
using System;
using System.IO;
using Orleans.Serialization;
namespace Squidex.Infrastructure.Orleans
{
internal sealed class StreamWriterWrapper : Stream
{
private readonly IBinaryTokenStreamWriter writer;
public override bool CanRead
{
get { return false; }
}
public override bool CanSeek
{
get { return false; }
}
public override bool CanWrite
{
get { return true; }
}
public override long Length
{
get { return writer.CurrentOffset; }
}
public override long Position
{
get
{
return writer.CurrentOffset;
}
set
{
throw new NotSupportedException();
}
}
public StreamWriterWrapper(IBinaryTokenStreamWriter writer)
{
this.writer = writer;
}
public override void Flush()
{
}
public override void Write(byte[] buffer, int offset, int count)
{
writer.Write(buffer, offset, count);
}
public override int Read(byte[] buffer, int offset, int count)
{
throw new NotSupportedException();
}
public override long Seek(long offset, SeekOrigin origin)
{
throw new NotSupportedException();
}
public override void SetLength(long value)
{
throw new NotSupportedException();
}
}
}

56
src/Squidex.Infrastructure/ValueStopwatch.cs

@ -0,0 +1,56 @@
// ==========================================================================
// Squidex Headless CMS
// ==========================================================================
// Copyright (c) Squidex UG (haftungsbeschraenkt)
// All rights reserved. Licensed under the MIT license.
// ==========================================================================
using System.Diagnostics;
namespace Squidex.Infrastructure
{
public struct ValueStopwatch
{
private const long TicksPerMillisecond = 10000;
private const long TicksPerSecond = TicksPerMillisecond * 1000;
private static double tickFrequency;
private readonly long startTime;
static ValueStopwatch()
{
if (Stopwatch.IsHighResolution)
{
tickFrequency = (double)TicksPerSecond / Stopwatch.Frequency;
}
}
public ValueStopwatch(long startTime)
{
this.startTime = startTime;
}
public static ValueStopwatch StartNew()
{
return new ValueStopwatch(Stopwatch.GetTimestamp());
}
public long Stop()
{
var elapsed = Stopwatch.GetTimestamp() - startTime;
if (elapsed < 0)
{
return elapsed;
}
if (Stopwatch.IsHighResolution)
{
elapsed = unchecked((long)(elapsed * tickFrequency));
}
return elapsed / TicksPerMillisecond;
}
}
}

1
src/Squidex/Areas/Api/Controllers/Contents/ContentsController.cs

@ -19,7 +19,6 @@ using Squidex.Domain.Apps.Entities.Contents;
using Squidex.Domain.Apps.Entities.Contents.Commands; using Squidex.Domain.Apps.Entities.Contents.Commands;
using Squidex.Domain.Apps.Entities.Contents.GraphQL; using Squidex.Domain.Apps.Entities.Contents.GraphQL;
using Squidex.Infrastructure.Commands; using Squidex.Infrastructure.Commands;
using Squidex.Infrastructure.Reflection;
using Squidex.Pipeline; using Squidex.Pipeline;
namespace Squidex.Areas.Api.Controllers.Contents namespace Squidex.Areas.Api.Controllers.Contents

8
src/Squidex/Config/Orleans/SiloWrapper.cs

@ -6,7 +6,6 @@
// ========================================================================== // ==========================================================================
using System; using System;
using System.Diagnostics;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.DependencyInjection;
@ -144,19 +143,18 @@ namespace Squidex.Config.Orleans
public void Initialize() public void Initialize()
{ {
var startTime = Stopwatch.GetTimestamp(); var watch = ValueStopwatch.StartNew();
try try
{ {
silo.Value.StartAsync().Wait(); silo.Value.StartAsync().Wait();
} }
finally finally
{ {
var endTime = Stopwatch.GetTimestamp(); var elapsedMs = watch.Stop();
var elapsed = endTime - startTime;
log.LogInformation(w => w log.LogInformation(w => w
.WriteProperty("message", "Silo started") .WriteProperty("message", "Silo started")
.WriteProperty("elapsedMs", elapsed)); .WriteProperty("elapsedMs", elapsedMs));
} }
} }

8
src/Squidex/Pipeline/ApiCostsFilter.cs

@ -11,6 +11,7 @@ using System.Threading.Tasks;
using Microsoft.AspNetCore.Mvc; using Microsoft.AspNetCore.Mvc;
using Microsoft.AspNetCore.Mvc.Filters; using Microsoft.AspNetCore.Mvc.Filters;
using Squidex.Domain.Apps.Entities.Apps.Services; using Squidex.Domain.Apps.Entities.Apps.Services;
using Squidex.Infrastructure;
using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Log;
using Squidex.Infrastructure.UsageTracking; using Squidex.Infrastructure.UsageTracking;
@ -61,7 +62,7 @@ namespace Squidex.Pipeline
} }
} }
var startTime = Stopwatch.GetTimestamp(); var watch = ValueStopwatch.StartNew();
try try
{ {
@ -69,10 +70,9 @@ namespace Squidex.Pipeline
} }
finally finally
{ {
var endTime = Stopwatch.GetTimestamp(); var elapsedMs = watch.Stop();
var elapsed = endTime - startTime;
await usageTracker.TrackAsync(appFeature.App.Id.ToString(), FilterDefinition.Weight, elapsed); await usageTracker.TrackAsync(appFeature.App.Id.ToString(), FilterDefinition.Weight, elapsedMs);
} }
} }
else else

1
src/Squidex/Pipeline/LocalCacheMiddleware.cs

@ -5,7 +5,6 @@
// All rights reserved. Licensed under the MIT license. // All rights reserved. Licensed under the MIT license.
// ========================================================================== // ==========================================================================
using System;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
using Squidex.Infrastructure; using Squidex.Infrastructure;

9
src/Squidex/Pipeline/RequestLogPerformanceMiddleware.cs

@ -5,9 +5,9 @@
// All rights reserved. Licensed under the MIT license. // All rights reserved. Licensed under the MIT license.
// ========================================================================== // ==========================================================================
using System.Diagnostics;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
using Squidex.Infrastructure;
using Squidex.Infrastructure.Log; using Squidex.Infrastructure.Log;
namespace Squidex.Pipeline namespace Squidex.Pipeline
@ -23,7 +23,7 @@ namespace Squidex.Pipeline
public async Task InvokeAsync(HttpContext context, RequestDelegate next) public async Task InvokeAsync(HttpContext context, RequestDelegate next)
{ {
var startTime = Stopwatch.GetTimestamp(); var watch = ValueStopwatch.StartNew();
using (Profiler.StartSession()) using (Profiler.StartSession())
{ {
@ -33,14 +33,13 @@ namespace Squidex.Pipeline
} }
finally finally
{ {
var endTime = Stopwatch.GetTimestamp(); var elapsedMs = watch.Stop();
var elapsed = endTime - startTime;
log.LogInformation(w => log.LogInformation(w =>
{ {
Profiler.Session?.Write(w); Profiler.Session?.Write(w);
w.WriteProperty("elapsedRequestMs", elapsed); w.WriteProperty("elapsedRequestMs", elapsedMs);
}); });
} }
} }

26
tests/Squidex.Infrastructure.Tests/Orleans/JsonExternalSerializerTests.cs

@ -8,6 +8,7 @@
using System; using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.IO;
using FakeItEasy; using FakeItEasy;
using Orleans.Serialization; using Orleans.Serialization;
using Xunit; using Xunit;
@ -48,28 +49,29 @@ namespace Squidex.Infrastructure.Orleans
{ {
var value = new J<List<int>>(new List<int> { 1, 2, 3 }); var value = new J<List<int>>(new List<int> { 1, 2, 3 });
var writtenLength = 0; var buffer = new MemoryStream();
var writtenBuffer = (byte[])null;
var writer = A.Fake<IBinaryTokenStreamWriter>(); var writer = A.Fake<IBinaryTokenStreamWriter>();
var writerContext = new SerializationContext(null) { StreamWriter = writer }; var writerContext = new SerializationContext(null) { StreamWriter = writer };
A.CallTo(() => writer.Write(A<int>.Ignored)) A.CallTo(() => writer.Write(A<byte[]>.Ignored, A<int>.Ignored, A<int>.Ignored))
.Invokes(new Action<int>(x => writtenLength = x)); .Invokes(new Action<byte[], int, int>(buffer.Write));
A.CallTo(() => writer.CurrentOffset)
A.CallTo(() => writer.Write(A<byte[]>.Ignored)) .ReturnsLazily(x => (int)buffer.Position);
.Invokes(new Action<byte[]>(x => writtenBuffer = x));
J<object>.Serialize(value, writerContext, value.GetType()); J<object>.Serialize(value, writerContext, value.GetType());
buffer.Position = 0;
var reader = A.Fake<IBinaryTokenStreamReader>(); var reader = A.Fake<IBinaryTokenStreamReader>();
var readerContext = new DeserializationContext(null) { StreamReader = reader }; var readerContext = new DeserializationContext(null) { StreamReader = reader };
A.CallTo(() => reader.ReadInt()) A.CallTo(() => reader.ReadByteArray(A<byte[]>.Ignored, A<int>.Ignored, A<int>.Ignored))
.Returns(writtenLength); .Invokes(new Action<byte[], int, int>((b, o, l) => buffer.Read(b, o, l)));
A.CallTo(() => reader.CurrentPosition)
A.CallTo(() => reader.ReadBytes(writtenLength)) .ReturnsLazily(x => (int)buffer.Position);
.Returns(writtenBuffer); A.CallTo(() => reader.Length)
.ReturnsLazily(x => (int)buffer.Length);
var copy = (J<List<int>>)J<object>.Deserialize(value.GetType(), readerContext); var copy = (J<List<int>>)J<object>.Deserialize(value.GetType(), readerContext);

Loading…
Cancel
Save