From fbce3a88c3422abed24532a2238f1b640cb04cb9 Mon Sep 17 00:00:00 2001 From: Strilanc Date: Tue, 5 Jun 2012 02:28:02 -0300 Subject: [PATCH] Fixing bugs and logging future lazy messages --- Bnet/Bnet Client.vb | 24 +++++++------ Bnet/Protocol/Bnet Protocol Packers.vb | 2 +- Components/Component Extensions.vb | 3 +- HostBotTests/BnetProtocolPackersTest.vb | 2 +- Interface/LoggerControl.vb | 47 ++++++++++++++----------- Library/Logging.vb | 15 ++++++-- Library/Reactive.vb | 10 +++--- 7 files changed, 60 insertions(+), 43 deletions(-) diff --git a/Bnet/Bnet Client.vb b/Bnet/Bnet Client.vb index f0747682..77a82610 100644 --- a/Bnet/Bnet Client.vb +++ b/Bnet/Bnet Client.vb @@ -349,14 +349,16 @@ Namespace Bnet _socket.ObservePackets().InCurrentSyncContext().Observe( Sub(data) Dim id = DirectCast(data(1), Bnet.Protocol.PacketId) - Logger.Log(Function() "Received {0} from {1}".Frmt(id, "bnet"), LogMessageType.DataEvent) + Dim t = New TaskCompletionSource(Of String)() Dim body = data.SkipExact(4) - Call Async Sub() - Dim parsed = Await _manualPacketHandler.Push(id, body) - If parsed Is Nothing Then Throw New IO.IOException("Unhandled packet: {0}".Frmt(id)) - If parsed.Data.Count < data.Count Then Logger.Log("Data left over after parsing.", LogMessageType.Problem) - Logger.Log(Function() "Received {0} from {1}: {2}".Frmt(id, "bnet", parsed.Description()), LogMessageType.DataParsed) - End Sub() + Dim description = Async Function() As Task(Of Func(Of String)) + Dim parsed = Await _manualPacketHandler.Push(id, body) + If parsed Is Nothing Then Throw New IO.IOException("Unhandled packet: {0}".Frmt(id)) + If parsed.Data.Count < body.Count Then Logger.Log("Data left over after parsing.", LogMessageType.Problem) + Return Function() "Received {0} from {1}: {2}".Frmt(id, "bnet", parsed.Description()) + End Function() + Logger.Log(Function() "Received {0} from {1}".Frmt(id, "bnet"), LogMessageType.DataEvent) + Logger.FutureLog(Function() "Received {0} from {1}: Parsing...".Frmt(id, "bnet"), description, LogMessageType.DataParsed) End Sub, Sub() End Sub, @@ -433,8 +435,9 @@ Namespace Bnet BeginHandlingPacketsPresync() - TrySendPacketSynq(Protocol.MakeAuthenticationBegin(_productInfoProvider.MajorVersion, New Net.IPAddress(GetCachedIPAddressBytes(external:=False)))) - Dim authBeginVals = Await walker.WalkValueAsync(Protocol.Packets.ServerToClient.ProgramAuthenticationBegin) + Dim authBeginVals = Await SendReceivePacketAsync( + Protocol.MakeAuthenticationBegin(_productInfoProvider.MajorVersion, New Net.IPAddress(GetCachedIPAddressBytes(external:=False))), + Protocol.Packets.ServerToClient.ProgramAuthenticationBegin) If ct.IsCancellationRequested Then Throw New TaskCanceledException() If authBeginVals.ItemAs(Of Protocol.ProgramAuthenticationBeginLogOnType)("logon type") <> Protocol.ProgramAuthenticationBeginLogOnType.Warcraft3 Then Throw New IO.InvalidDataException("Unrecognized logon type from server.") @@ -570,10 +573,9 @@ Namespace Bnet Dim clientProof = Me._userCredentials.ClientPasswordProof(accountPasswordSalt, serverPublicKey) Dim expectedServerProof = Me._userCredentials.ServerPasswordProof(accountPasswordSalt, serverPublicKey) - 'Finish authentication Dim authFinishVals = Await SendReceivePacketAsync( - Protocol.MakeAccountLogOnFinish(clientProof), + Protocol.MakeUserAuthenticationFinish(clientProof), Protocol.Packets.ServerToClient.UserAuthenticationFinish) If ct.IsCancellationRequested Then Throw New TaskCanceledException() Dim result = authFinishVals.ItemAs(Of Protocol.UserAuthenticationFinishResult)("result") diff --git a/Bnet/Protocol/Bnet Protocol Packers.vb b/Bnet/Protocol/Bnet Protocol Packers.vb index 0a3d9165..dec1cd2c 100644 --- a/Bnet/Protocol/Bnet Protocol Packers.vb +++ b/Bnet/Protocol/Bnet Protocol Packers.vb @@ -83,7 +83,7 @@ Namespace Bnet.Protocol End Function - Public Function MakeAccountLogOnFinish(clientPasswordProof As IRist(Of Byte)) As Packet + Public Function MakeUserAuthenticationFinish(clientPasswordProof As IRist(Of Byte)) As Packet Contract.Requires(clientPasswordProof IsNot Nothing) Contract.Ensures(Contract.Result(Of Packet)() IsNot Nothing) Return Packet.FromValue(Packets.ClientToServer.UserAuthenticationFinish, clientPasswordProof) diff --git a/Components/Component Extensions.vb b/Components/Component Extensions.vb index 36c3aca6..08a0f750 100644 --- a/Components/Component Extensions.vb +++ b/Components/Component Extensions.vb @@ -14,7 +14,8 @@ component.Logger.Log("Command: {0}".Frmt(argDesc), LogMessageType.Typical) component.Logger.FutureLog(placeholder:="[running command {0}...]".Frmt(argDesc), - message:=SafeInvokeCommand(component, argument).AssumeNotNull()) + message:=SafeInvokeCommand(component, argument).AssumeNotNull(), + messageType:=LogMessageType.Typical) Catch e As Exception e.RaiseAsUnexpected("UIInvokeCommand for {0}:{1}".Frmt(component.Type, component.Name)) End Try diff --git a/HostBotTests/BnetProtocolPackersTest.vb b/HostBotTests/BnetProtocolPackersTest.vb index d70ebdff..01cb6730 100644 --- a/HostBotTests/BnetProtocolPackersTest.vb +++ b/HostBotTests/BnetProtocolPackersTest.vb @@ -17,7 +17,7 @@ Public Class BnetProtocolPackersTest End Sub Public Sub MakeAccountLogOnFinishTest() - MakeAccountLogOnFinish(CByte(1).Repeated(20)) + MakeUserAuthenticationFinish(CByte(1).Repeated(20)) End Sub Public Sub MakeAuthenticationBeginTest() diff --git a/Interface/LoggerControl.vb b/Interface/LoggerControl.vb index 9bef1780..02432042 100644 --- a/Interface/LoggerControl.vb +++ b/Interface/LoggerControl.vb @@ -271,43 +271,48 @@ Public Class LoggerControl e.RaiseAsUnexpected("Exception rose post LoggerControl.emptyQueue") End Try End Sub - Private Sub LogFutureMessage(placeholder As String, futureMessage As Task(Of String)) + Private Async Sub LogFutureMessage(type As LogMessageType, placeholder As Func(Of String), futureMessage As Task(Of Func(Of String))) Contract.Requires(placeholder IsNot Nothing) Contract.Requires(futureMessage IsNot Nothing) - Dim m = New QueuedMessage(placeholder, Color.DarkGoldenrod) - LogMessage(m) - futureMessage.ContinueWith( - Sub(task) - SyncLock lock - Dim message = If(task.Status = TaskStatus.Faulted, - task.Exception.Summarize, - task.Result) - Dim color = callbackColorMap(If(task.Status = TaskStatus.RanToCompletion AndAlso Not message Like "Failed: *", - LogMessageType.Positive, - LogMessageType.Problem)) - LogMessage(New QueuedMessage(message, color, m)) - End SyncLock - End Sub - ) + Dim fileOnly As Boolean + SyncLock lock + If callbackModeMap(type) = CallbackMode.Off Then Return + fileOnly = callbackModeMap(type) = CallbackMode.File + End SyncLock + + Dim m = New QueuedMessage(placeholder(), Color.DarkGoldenrod) + LogMessage(m, fileOnly) + + Try + Dim f = Await futureMessage + Dim message = f() + Dim color = callbackColorMap(type) + If message.StartsWith("Failed:") Then color = callbackColorMap(LogMessageType.Problem) + LogMessage(New QueuedMessage(message, color, m), fileOnly) + Catch ex As Exception + SyncLock lock + LogMessage(New QueuedMessage(ex.Summarize, callbackColorMap(LogMessageType.Problem), m)) + End SyncLock + End Try End Sub #End Region #Region "Log Events" Private Sub OnLoggedMessage(type As LogMessageType, message As Lazy(Of String)) Handles _logger.LoggedMessage - Dim color As Color Dim fileOnly As Boolean SyncLock lock If callbackModeMap(type) = CallbackMode.Off Then Return - color = callbackColorMap(type) fileOnly = callbackModeMap(type) = CallbackMode.File End SyncLock + Dim color = callbackColorMap(type) LogMessage(message, color, fileOnly) End Sub - Private Sub OnLoggedFutureMessage(placeholder As String, - out As Task(Of String)) Handles _logger.LoggedFutureMessage - uiRef.QueueAction(Sub() LogFutureMessage(placeholder, out)) + Private Sub OnLoggedFutureMessage(type As LogMessageType, + placeholder As Func(Of String), + out As Task(Of Func(Of String))) Handles _logger.LoggedFutureMessage + uiRef.QueueAction(Sub() LogFutureMessage(type, placeholder, out)) End Sub #End Region diff --git a/Library/Logging.vb b/Library/Logging.vb index 9335475d..be355ecc 100644 --- a/Library/Logging.vb +++ b/Library/Logging.vb @@ -10,7 +10,7 @@ End Enum Public NotInheritable Class Logger Public Event LoggedMessage(type As LogMessageType, message As Lazy(Of String)) - Public Event LoggedFutureMessage(placeholder As String, message As Task(Of String)) + Public Event LoggedFutureMessage(type As LogMessageType, placeholder As Func(Of String), message As Task(Of Func(Of String))) Private ReadOnly outQueue As CallQueue Private Sub ObjectInvariant() @@ -21,10 +21,19 @@ Public NotInheritable Class Logger Me.outQueue = If(outQueue, MakeTaskedCallQueue()) End Sub - Public Sub FutureLog(placeholder As String, message As Task(Of String)) + Public Sub FutureLog(placeholder As String, message As Task(Of String), messageType As LogMessageType) Contract.Requires(placeholder IsNot Nothing) Contract.Requires(message IsNot Nothing) - outQueue.QueueAction(Sub() RaiseEvent LoggedFutureMessage(placeholder, message)) + Dim msg = Async Function() As Task(Of Func(Of String)) + Dim r = Await message + Return Function() r + End Function() + outQueue.QueueAction(Sub() RaiseEvent LoggedFutureMessage(messageType, Function() placeholder, msg)) + End Sub + Public Sub FutureLog(placeholder As Func(Of String), message As Task(Of Func(Of String)), messageType As LogMessageType) + Contract.Requires(placeholder IsNot Nothing) + Contract.Requires(message IsNot Nothing) + outQueue.QueueAction(Sub() RaiseEvent LoggedFutureMessage(messageType, placeholder, message)) End Sub Public Sub Log(message As Lazy(Of String), messageType As LogMessageType) Contract.Requires(message IsNot Nothing) diff --git a/Library/Reactive.vb b/Library/Reactive.vb index e867d313..cd22b515 100644 --- a/Library/Reactive.vb +++ b/Library/Reactive.vb @@ -237,7 +237,7 @@ Public Class ManualValuePusher(Of T, R) Interlocked.Decrement(_headRefCount) End Sub Public Sub PassWithoutHandling() - If Interlocked.Decrement(_headRefCount) = 1 Then + If Interlocked.Decrement(_headRefCount) = 0 Then _parsed.TrySetResult(Nothing) End If End Sub @@ -273,12 +273,12 @@ Public Class ManualValuePusher(Of T, R) Public Async Function WalkAsync(filter As Func(Of T, Boolean), parser As Func(Of T, R)) As Task(Of R) Implements IValueWalker(Of T, R).WalkAsync Do - Dim n = _head - If n Is Nothing Then Throw New ObjectDisposedException("Walker") - n = Await n.NextAsync + Dim p = _head + If p Is Nothing Then Throw New ObjectDisposedException("Walker") + Dim n = Await p.NextAsync SyncLock _lock If _head Is Nothing Then Throw New ObjectDisposedException("Walker") - If n IsNot _head Then Throw New InvalidOperationException("Overlapping WalkAsync calls") + If p IsNot _head Then Throw New InvalidOperationException("Overlapping WalkAsync calls") If filter(n.Data) Then Dim r = parser(n.Data) _head = n