pvandervelde
commented
10 years ago Relevant section of log file from Sherlock.Executor
2014/03/18T11:55:33.87312 +13:00 - Debug: Sherlock.Executor - Executing test step of type: Sherlock.Shared.DataAccess.XCopyTestStep
2014/03/18T11:55:33.87312 +13:00 - Debug: Sherlock.Executor-XCopy - Copying from: C:\Users\test\AppData\Local\Temp\2224\3\readme.txt; To: c:\temp\reports\readme.txt
2014/03/18T11:55:33.88869 +13:00 - Info: Sherlock.Executor-XCopy - Installed: C:\Users\test\AppData\Local\Temp\2224\3\readme.txt.
2014/03/18T11:55:33.93562 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task PrepareReportFilesForTransfer(Int32, Nuclei.Communication.EndpointId, Nuclei.Communication.UploadToken)
2014/03/18T11:55:33.95130 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel while waiting for the response.
2014/03/18T11:55:33.95130 +13:00 - Trace: Communication - Sending message [MessageId: [cbdd33f5-5825-418f-93a0-20aff290ea80]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:33.98252 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.DataDownloadRequestMessage.
2014/03/18T11:55:33.98252 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.DataDownloadRequestMessage with action of type Nuclei.Communication.Messages.Processors.DataDownloadProcessAction.
2014/03/18T11:55:33.99819 +13:00 - Debug: Communication - Transferring file: C:\Users\test\AppData\Local\Temp\2224\TestStepReport-3.zip
2014/03/18T11:55:33.99819 +13:00 - Trace: Communication - Sending data to [AKL-SHERLOCK-01:3700].
2014/03/18T11:55:34.01380 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel without waiting for the response.
2014/03/18T11:55:34.01380 +13:00 - Trace: Communication - Sending message [MessageId: [c10a4c9d-274f-4e3e-9009-7258a0672161]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.16999 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.16999 +13:00 - Trace: Communication - Message [MessageId: [acd1a77f-a909-4a45-bcf8-af27bafd3150]] is a response to message [MessageId: [cbdd33f5-5825-418f-93a0-20aff290ea80]].
2014/03/18T11:55:34.16999 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel without waiting for the response.
2014/03/18T11:55:34.16999 +13:00 - Trace: Communication - Sending message [MessageId: [240ed52d-79ad-4d59-b095-3b698933546a]] of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:34.18566 +13:00 - Debug: Sherlock.Executor - Executing test step of type: Sherlock.Shared.DataAccess.ConsoleExecuteTestStep
2014/03/18T11:55:34.20120 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Running C:\Program Files (x86)\Microsoft Visual Studio 11.0\Common7\IDE\MSTest.exe /testcontainer:"c:\temp\emulator\Rakon.Emulator.Regression.dll" /resultsfile:"c:\temp\reports\emulator.regression.trx"
2014/03/18T11:55:37.32660 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Microsoft (R) Test Execution Command Line Tool Version 11.0.61030.0
2014/03/18T11:55:37.34218 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Copyright (c) Microsoft Corporation. All rights reserved.
2014/03/18T11:55:37.34218 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output:
2014/03/18T11:55:37.34218 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Loading c:\temp\emulator\Rakon.Emulator.Regression.dll...
2014/03/18T11:55:40.37343 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Starting execution...
2014/03/18T11:58:48.95226 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Results Top Level Tests
2014/03/18T11:58:48.95226 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: ------- ---------------
2014/03/18T11:58:48.95226 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.CRAMMRegression.RunCrammBackplaneConfig
2014/03/18T12:09:20.29049 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.CRAMMRegression.RunCrammRackConfig
2014/03/18T12:12:41.53154 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.CRAMMRegression.RunCrammShelfConfig
2014/03/18T12:15:37.85627 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.PaRTRegression.RunPaRT3x3Module
2014/03/18T12:19:57.83985 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.PaRTRegression.RunPaRT6x4Module
2014/03/18T12:22:26.55753 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.PaRTRegression.RunPaRTModule
2014/03/18T12:24:55.22932 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.PaRTRegression.RunPaRTModuleBank
2014/03/18T12:24:57.01067 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.ScreenUICheck.ValidateApplicationWindow
2014/03/18T12:25:11.68332 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.ScreenUICheck.ValidateExecutionView
2014/03/18T12:25:54.38842 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed Rakon.Emulator.Regression.Scripts.ScreenUICheck.ValidateMainSelectionView
2014/03/18T12:26:15.70256 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: 10/10 test(s) Passed
2014/03/18T12:26:15.73379 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Summary
2014/03/18T12:26:15.73379 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: -------
2014/03/18T12:26:15.73379 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Test Run Completed.
2014/03/18T12:26:15.74941 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Passed 10
2014/03/18T12:26:15.74941 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: ----------
2014/03/18T12:26:15.76505 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Total 10
2014/03/18T12:26:15.76505 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Results file: c:\temp\reports\emulator.regression.trx
2014/03/18T12:26:15.78072 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Output: Test Settings: Default Test Settings
2014/03/18T12:26:17.02132 +13:00 - Trace: Sherlock.Executor-Console - MSTest output: Process finished. Total time: -735308.22:55:34.2793386
Process statistics for C:\Program Files (x86)\Microsoft Visual Studio 11.0\Common7\IDE\MSTest.exe
Start time: 03/18/2014 11:55:34 +13:00
Exit time: 03/18/2014 12:26:16 +13:00
Total time: 00:30:41.7513447
Privileged CPU time: 00:00:01.2187500
User CPU time: 00:00:02.2656250
Total CPU time: 00:00:03.4843750
Private memory (Kb): 340
Virtual memory (Kb): 4892
Working set memory (Kb): 156
Peak paged memory (Kb): 340
Peak virtual memory (Kb): 4892
Peak working set memory (Kb): 156
Non-paged system memory (Kb): 1
Paged system memory (Kb): 18
Paged system memory (Kb): 340
2014/03/18T12:26:17.09345 +13:00 - Info: Sherlock.Executor-Console - Executed: MSTest.exe /testcontainer:"c:\temp\emulator\Rakon.Emulator.Regression.dll" /resultsfile:"c:\temp\reports\emulator.regression.trx". 2014/03/18T12:26:22.62484 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task PrepareReportFilesForTransfer(Int32, Nuclei.Communication.EndpointId, Nuclei.Communication.UploadToken) 2014/03/18T12:26:22.64051 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel while waiting for the response. 2014/03/18T12:26:22.64051 +13:00 - Trace: Communication - Sending message [MessageId: [eb866499-2b09-48ca-9c3d-4037b46e8d52]] of type Nuclei.Communication.Messages.CommandInvokedMessage. 2014/03/18T12:26:22.90608 +13:00 - Error: Communication - Tried to invoke System.Threading.Tasks.Task PrepareReportFilesForTransfer(Int32, Nuclei.Communication.EndpointId, Nuclei.Communication.UploadToken), but failed to send the message. 2014/03/18T12:26:23.40615 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel without waiting for the response. 2014/03/18T12:26:23.40615 +13:00 - Info: Communication - Channel for endpoint at net.pipe://localhost/nuclei.communication/pipe_3700/NamedPipe.Nuclei.Communication_3700 has faulted. Aborting channel. 2014/03/18T12:26:23.43742 +13:00 - Info: Communication - Creating channel for endpoint at net.pipe://localhost/nuclei.communication/pipe_3700/NamedPipe.Nuclei.Communication_3700. 2014/03/18T12:26:23.43742 +13:00 - Trace: Communication - Sending message [MessageId: [c0c0e6dc-b39a-4f90-bc9a-ebec28cf3739]] of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T12:26:23.53116 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel without waiting for the response. 2014/03/18T12:26:23.53116 +13:00 - Trace: Communication - Sending message [MessageId: [da36db54-feba-4003-9f76-9955365351c7]] of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T12:26:23.56238 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-SHERLOCK-01:3700) via the NamedPipe channel without waiting for the response. 2014/03/18T12:26:23.56238 +13:00 - Trace: Communication - Sending message [MessageId: [f713b019-68e0-4563-bec9-24bc263cb9a0]] of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T12:26:23.62489 +13:00 - Info: Sherlock.Executor - Test result is: Passed 2014/03/18T12:26:23.71869 +13:00 - Trace: Communication - Sending message [MessageId: [bf8d83e0-55e7-42b8-9059-7c8178565073]] of type Nuclei.Communication.Messages.EndpointDisconnectMessage. 2014/03/18T12:26:24.07819 +13:00 - Debug: Communication - Disposed of channel for net.pipe://localhost/nuclei.communication/pipe_3700/NamedPipe.Nuclei.Communication_3700 2014/03/18T12:26:24.09368 +13:00 - Debug: Communication - Disposed of data channel for net.pipe://localhost/nuclei.communication/pipe_3700/NamedPipe.Nuclei.Communication_3700/Data 2014/03/18T12:26:24.28115 +13:00 - Trace: Communication - Closed channel of type: NamedPipe 2014/03/18T12:26:24.31242 +13:00 - Trace: Communication - Closed channel of type: NamedPipe 2014/03/18T12:26:24.35929 +13:00 - Trace: Communication - Closed channel of type: NamedPipe 2014/03/18T12:26:24.35929 +13:00 - Trace: Communication - Closed channel of type: NamedPipe 2014/03/18T12:26:24.35929 +13:00 - Trace: Communication - Sign off process finished. Stopping logger.
Relevant section from Sherlock.Service.Executor
2014/03/18T11:55:33.34180 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.35744 +13:00 - Trace: Communication - Message [MessageId: [ff24e104-db01-4c4f-9dee-d8b36c28660d]] is a response to message [MessageId: [da6fe832-b5d7-4c7a-a2bf-25f33e8b6263]].
2014/03/18T11:55:33.35744 +13:00 - Trace: Communication - Processing Task return value from command.
2014/03/18T11:55:33.35744 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:2224) via the NamedPipe channel without waiting for the response.
2014/03/18T11:55:33.35744 +13:00 - Trace: Communication - Sending message [MessageId: [d361e81e-6e01-4846-9421-000d60144aa2]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.38866 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:33.38866 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction.
2014/03/18T11:55:33.38866 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress
2014/03/18T11:55:33.40429 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T11:55:33.40429 +13:00 - Trace: Communication - Sending message [MessageId: [7afe8260-ccca-4b97-9afc-c46cd4ca9c43]] of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:33.41991 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:33.41991 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction.
2014/03/18T11:55:33.43554 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.ITransferTestReportDataCommands.PrepareReportFilesForTransfer
2014/03/18T11:55:33.43554 +13:00 - Trace: Sherlock.Service.Executor - Transfering test step report files for test step: 2.
2014/03/18T11:55:33.43554 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.DataDownloadRequestMessage to endpoint (AKL-SHERLOCK-01:2224) via the NamedPipe channel while waiting for the response.
2014/03/18T11:55:33.43554 +13:00 - Trace: Communication - Sending message [MessageId: [31152440-f60e-4324-a81b-d19f6cad0abe]] of type Nuclei.Communication.Messages.DataDownloadRequestMessage.
2014/03/18T11:55:33.48251 +13:00 - Trace: Communication - Received data from AKL-SHERLOCK-01:2224.
2014/03/18T11:55:33.49804 +13:00 - Trace: Communication - Received data stream from AKL-SHERLOCK-01:2224.
2014/03/18T11:55:33.51367 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.51367 +13:00 - Trace: Communication - Message [MessageId: [46139a0d-0927-414c-bef9-7b25df289bd9]] is a response to message [MessageId: [31152440-f60e-4324-a81b-d19f6cad0abe]].
2014/03/18T11:55:33.51367 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task PrepareReportFilesForTransfer(Int32, Int32, Nuclei.Communication.EndpointId, Nuclei.Communication.UploadToken)
2014/03/18T11:55:33.51367 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel while waiting for the response.
2014/03/18T11:55:33.52929 +13:00 - Trace: Communication - Sending message [MessageId: [384c8c29-cea9-46ed-b04d-9a9c3a986d4f]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:33.54494 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.DataDownloadRequestMessage.
2014/03/18T11:55:33.56070 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.DataDownloadRequestMessage with action of type Nuclei.Communication.Messages.Processors.DataDownloadProcessAction.
2014/03/18T11:55:33.56070 +13:00 - Debug: Communication - Transferring file: C:\Users\test\AppData\Local\Temp\2ac65064-fb7a-4f05-8c25-ca8926cfdcc4\5289a5f4-e2a7-4045-8b3c-7c23f0b32905.zip
2014/03/18T11:55:33.56070 +13:00 - Trace: Communication - Sending data to [AKL-HYPERV-01:4204].
2014/03/18T11:55:33.57617 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T11:55:33.59182 +13:00 - Trace: Communication - Sending message [MessageId: [a8131c13-c07b-464e-85b9-b02ae949837b]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.82633 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.82633 +13:00 - Trace: Communication - Message [MessageId: [9f64e180-aa78-4742-9692-369216c35289]] is a response to message [MessageId: [384c8c29-cea9-46ed-b04d-9a9c3a986d4f]].
2014/03/18T11:55:33.84181 +13:00 - Trace: Communication - Processing Task return value from command.
2014/03/18T11:55:33.84181 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:2224) via the NamedPipe channel without waiting for the response.
2014/03/18T11:55:33.84181 +13:00 - Trace: Communication - Sending message [MessageId: [68e0bc13-c05e-4cf4-9938-0081bd27e555]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:33.87312 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:33.87312 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction.
2014/03/18T11:55:33.88869 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress
2014/03/18T11:55:33.88869 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T11:55:33.88869 +13:00 - Trace: Communication - Sending message [MessageId: [b3099674-c8a2-4346-bc4c-cc27cbc9f4a0]] of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:33.95130 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:33.96684 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction.
2014/03/18T11:55:33.96684 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.ITransferTestReportDataCommands.PrepareReportFilesForTransfer
2014/03/18T11:55:33.96684 +13:00 - Trace: Sherlock.Service.Executor - Transfering test step report files for test step: 3.
2014/03/18T11:55:33.98252 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.DataDownloadRequestMessage to endpoint (AKL-SHERLOCK-01:2224) via the NamedPipe channel while waiting for the response.
2014/03/18T11:55:33.98252 +13:00 - Trace: Communication - Sending message [MessageId: [4b1daca1-73e6-4933-9347-d095a4e2e1cb]] of type Nuclei.Communication.Messages.DataDownloadRequestMessage.
2014/03/18T11:55:33.99819 +13:00 - Trace: Communication - Received data from AKL-SHERLOCK-01:2224.
2014/03/18T11:55:33.99819 +13:00 - Trace: Communication - Received data stream from AKL-SHERLOCK-01:2224.
2014/03/18T11:55:34.01380 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.02938 +13:00 - Trace: Communication - Message [MessageId: [c10a4c9d-274f-4e3e-9009-7258a0672161]] is a response to message [MessageId: [4b1daca1-73e6-4933-9347-d095a4e2e1cb]].
2014/03/18T11:55:34.02938 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task PrepareReportFilesForTransfer(Int32, Int32, Nuclei.Communication.EndpointId, Nuclei.Communication.UploadToken)
2014/03/18T11:55:34.02938 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel while waiting for the response.
2014/03/18T11:55:34.04502 +13:00 - Trace: Communication - Sending message [MessageId: [02a31076-e2a8-4841-ad42-20303c8e41e4]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:34.06066 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.DataDownloadRequestMessage.
2014/03/18T11:55:34.07629 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.DataDownloadRequestMessage with action of type Nuclei.Communication.Messages.Processors.DataDownloadProcessAction.
2014/03/18T11:55:34.07629 +13:00 - Debug: Communication - Transferring file: C:\Users\test\AppData\Local\Temp\2ac65064-fb7a-4f05-8c25-ca8926cfdcc4\5967ef41-2f38-441c-83ba-112282c659c8.zip
2014/03/18T11:55:34.07629 +13:00 - Trace: Communication - Sending data to [AKL-HYPERV-01:4204].
2014/03/18T11:55:34.09182 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T11:55:34.09182 +13:00 - Trace: Communication - Sending message [MessageId: [d3e71b9b-ba61-4109-88cc-78e1609ea885]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.13891 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.13891 +13:00 - Trace: Communication - Message [MessageId: [501a9bb8-d526-4b52-ba14-12cbadf4b21e]] is a response to message [MessageId: [02a31076-e2a8-4841-ad42-20303c8e41e4]].
2014/03/18T11:55:34.15441 +13:00 - Trace: Communication - Processing Task return value from command.
2014/03/18T11:55:34.15441 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:2224) via the NamedPipe channel without waiting for the response.
2014/03/18T11:55:34.15441 +13:00 - Trace: Communication - Sending message [MessageId: [acd1a77f-a909-4a45-bcf8-af27bafd3150]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T11:55:34.18566 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:34.18566 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction.
2014/03/18T11:55:34.18566 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress
2014/03/18T11:55:34.20120 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.NotificationRaisedMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T11:55:34.20120 +13:00 - Trace: Communication - Sending message [MessageId: [430bdb42-187c-4298-b16f-03b952b65a1a]] of type Nuclei.Communication.Messages.NotificationRaisedMessage.
2014/03/18T11:55:49.45198 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T11:55:49.46763 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction.
2014/03/18T11:55:49.46763 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.IExecuteTestStepsCommands.State
2014/03/18T11:55:49.46763 +13:00 - Trace: Communication - Processing Task
2014/03/18T12:25:50.29451 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedResponseMessage to endpoint (AKL-HYPERV-01:4204) via the TcpIP channel without waiting for the response.
2014/03/18T12:25:50.30251 +13:00 - Trace: Communication - Sending message [MessageId: [c50543a8-f38e-417d-9049-de7e618b5684]] of type Nuclei.Communication.Messages.CommandInvokedResponseMessage.
2014/03/18T12:26:20.73416 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T12:26:20.74977 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction.
2014/03/18T12:26:20.74977 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.IExecuteTestStepsCommands.State
2014/03/18T12:26:20.74977 +13:00 - Trace: Communication - Processing Task
Server stack trace: at System.ServiceModel.Channels.PipeConnection.Write(Byte[] buffer, Int32 offset, Int32 size, Boolean immediate, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.BufferedConnection.WriteNow(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.BufferedConnection.Write(Byte[] buffer, Int32 offset, Int32 size, Boolean immediate, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.FramingDuplexSessionChannel.OnSendCore(Message message, TimeSpan timeout) at System.ServiceModel.Channels.TransportDuplexSessionChannel.OnSend(Message message, TimeSpan timeout) at System.ServiceModel.Channels.OutputChannel.Send(Message message, TimeSpan timeout) at System.ServiceModel.Dispatcher.DuplexChannelBinder.Send(Message message, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation) at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
at Nuclei.Communication.IMessageReceivingEndpoint.AcceptMessage(ICommunicationMessage message)
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
--- End of inner exception stack trace ---
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
at Nuclei.Communication.SendingEndpoint.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationChannel.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationLayer.SendMessageAndWaitForResponse(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationModule.SendMessageWithResponse(IConfiguration configuration, ISendDataViaChannels layer, EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationModule.<>cDisplayClass8f.
Server stack trace: at System.ServiceModel.Channels.SocketConnectionInitiator.Connect(Uri uri, TimeSpan timeout) at System.ServiceModel.Channels.BufferedConnectionInitiator.Connect(Uri uri, TimeSpan timeout) at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnection(TimeSpan timeout) at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpen(TimeSpan timeout) at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.OnOpen(TimeSpan timeout) at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.Call(ServiceChannel channel, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.CallOnce(TimeSpan timeout, CallOnceManager cascade) at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation) at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
at Nuclei.Communication.IMessageReceivingEndpoint.AcceptMessage(ICommunicationMessage message)
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
--- End of inner exception stack trace ---
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
at Nuclei.Communication.SendingEndpoint.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationChannel.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationLayer.SendMessageTo(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.HandshakeProtocolLayer.ContinueHandshakeWith(ChannelConnectionInformation connection, CommunicationDescription information, MessageId messageId)
at Nuclei.Communication.Messages.Processors.EndpointConnectProcessAction.Invoke(ICommunicationMessage message)
at Nuclei.Communication.MessageHandler.ProcessMessage(ICommunicationMessage message)
at Nuclei.Communication.CommunicationModule.<>cDisplayClass7.
Relevant section from Sherlock.Service.Master 2014/03/18T11:55:33.34985 +13:00 - Trace: Communication - Processing Task return value from command. 2014/03/18T11:55:33.34985 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel without waiting for the response. 2014/03/18T11:55:33.34985 +13:00 - Trace: Communication - Sending message [MessageId: [ff24e104-db01-4c4f-9dee-d8b36c28660d]] of type Nuclei.Communication.Messages.SuccessMessage. 2014/03/18T11:55:33.41236 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T11:55:33.42798 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction. 2014/03/18T11:55:33.42798 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress 2014/03/18T11:55:33.53737 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage. 2014/03/18T11:55:33.53737 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction. 2014/03/18T11:55:33.55298 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.IStoreTestReportDataCommands.PrepareReportFilesForTransfer 2014/03/18T11:55:33.55298 +13:00 - Trace: Sherlock.Service.Master - Storing report file for test 98 step 2 in report directory. 2014/03/18T11:55:33.55298 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.DataDownloadRequestMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response. 2014/03/18T11:55:33.55298 +13:00 - Trace: Communication - Sending message [MessageId: [212e1704-d921-4c8e-bcdb-147535e2828d]] of type Nuclei.Communication.Messages.DataDownloadRequestMessage. 2014/03/18T11:55:33.58423 +13:00 - Trace: Communication - Received data from AKL-SHERLOCK-01:3700. 2014/03/18T11:55:33.58423 +13:00 - Trace: Communication - Received data stream from AKL-SHERLOCK-01:3700. 2014/03/18T11:55:33.59985 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage. 2014/03/18T11:55:33.59985 +13:00 - Trace: Communication - Message [MessageId: [a8131c13-c07b-464e-85b9-b02ae949837b]] is a response to message [MessageId: [212e1704-d921-4c8e-bcdb-147535e2828d]]. 2014/03/18T11:55:33.81862 +13:00 - Trace: Communication - Processing Task return value from command. 2014/03/18T11:55:33.83424 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel without waiting for the response. 2014/03/18T11:55:33.83424 +13:00 - Trace: Communication - Sending message [MessageId: [9f64e180-aa78-4742-9692-369216c35289]] of type Nuclei.Communication.Messages.SuccessMessage. 2014/03/18T11:55:33.91237 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T11:55:33.91237 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction. 2014/03/18T11:55:33.91237 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress 2014/03/18T11:55:34.05299 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedMessage. 2014/03/18T11:55:34.05299 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.CommandInvokedMessage with action of type Nuclei.Communication.Messages.Processors.CommandInvokedProcessAction. 2014/03/18T11:55:34.06862 +13:00 - Trace: Communication - Received request to execute command: Sherlock.Shared.Core.IStoreTestReportDataCommands.PrepareReportFilesForTransfer 2014/03/18T11:55:34.06862 +13:00 - Trace: Sherlock.Service.Master - Storing report file for test 98 step 3 in report directory. 2014/03/18T11:55:34.06862 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.DataDownloadRequestMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response. 2014/03/18T11:55:34.06862 +13:00 - Trace: Communication - Sending message [MessageId: [55c687da-a324-46e1-9127-4b61b8ebb86f]] of type Nuclei.Communication.Messages.DataDownloadRequestMessage. 2014/03/18T11:55:34.09986 +13:00 - Trace: Communication - Received data from AKL-SHERLOCK-01:3700. 2014/03/18T11:55:34.09986 +13:00 - Trace: Communication - Received data stream from AKL-SHERLOCK-01:3700. 2014/03/18T11:55:34.11550 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.SuccessMessage. 2014/03/18T11:55:34.11550 +13:00 - Trace: Communication - Message [MessageId: [d3e71b9b-ba61-4109-88cc-78e1609ea885]] is a response to message [MessageId: [55c687da-a324-46e1-9127-4b61b8ebb86f]]. 2014/03/18T11:55:34.13114 +13:00 - Trace: Communication - Processing Task return value from command. 2014/03/18T11:55:34.14675 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel without waiting for the response. 2014/03/18T11:55:34.14675 +13:00 - Trace: Communication - Sending message [MessageId: [501a9bb8-d526-4b52-ba14-12cbadf4b21e]] of type Nuclei.Communication.Messages.SuccessMessage. 2014/03/18T11:55:34.22486 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T11:55:34.22486 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction. 2014/03/18T11:55:34.22486 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress
2014/03/18T12:26:20.72982 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task1[Sherlock.Shared.Core.TestExecutionState] State() 2014/03/18T12:26:20.72982 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response. 2014/03/18T12:26:20.72982 +13:00 - Trace: Communication - Sending message [MessageId: [3ca98e14-afbb-466d-a588-23b347bb8df8]] of type Nuclei.Communication.Messages.CommandInvokedMessage. 2014/03/18T12:26:20.77670 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedResponseMessage. 2014/03/18T12:26:20.79231 +13:00 - Trace: Communication - Message [MessageId: [4b4f62e5-3e19-48a0-8016-2dc77febf98d]] is a response to message [MessageId: [3ca98e14-afbb-466d-a588-23b347bb8df8]]. 2014/03/18T12:26:20.80795 +13:00 - Debug: Sherlock.Service.Master - Environment [AKL-SHERLOCK-01]: State: Running 2014/03/18T12:26:23.72987 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T12:26:23.72987 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction. 2014/03/18T12:26:23.72987 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress 2014/03/18T12:26:23.74549 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.NotificationRaisedMessage. 2014/03/18T12:26:23.74549 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.NotificationRaisedMessage with action of type Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction. 2014/03/18T12:26:23.74549 +13:00 - Trace: Communication - Received request to raise event: Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.3, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnExecutionProgress 2014/03/18T12:26:50.18350 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task1[Sherlock.Shared.Core.TestExecutionState] State()
2014/03/18T12:26:50.18350 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response.
2014/03/18T12:26:50.18350 +13:00 - Trace: Communication - Sending message [MessageId: [0447636f-724b-454b-8655-50d8e849deb8]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T12:26:50.23037 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedResponseMessage.
2014/03/18T12:26:50.23037 +13:00 - Trace: Communication - Message [MessageId: [550fec26-7802-43ba-8a4e-f9d12c5f2e57]] is a response to message [MessageId: [0447636f-724b-454b-8655-50d8e849deb8]].
2014/03/18T12:26:50.23037 +13:00 - Debug: Sherlock.Service.Master - Environment [AKL-SHERLOCK-01]: State: Running
2014/03/18T12:27:19.84032 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task1[Sherlock.Shared.Core.TestExecutionState] State() 2014/03/18T12:27:19.84032 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response. 2014/03/18T12:27:19.84032 +13:00 - Trace: Communication - Sending message [MessageId: [c0dba649-3851-416e-a816-a7a97d747d9d]] of type Nuclei.Communication.Messages.CommandInvokedMessage. 2014/03/18T12:27:19.90280 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedResponseMessage. 2014/03/18T12:27:19.90280 +13:00 - Trace: Communication - Message [MessageId: [4e032e99-6440-47d4-b803-d9ffa3090427]] is a response to message [MessageId: [c0dba649-3851-416e-a816-a7a97d747d9d]]. 2014/03/18T12:27:19.90280 +13:00 - Debug: Sherlock.Service.Master - Environment [AKL-SHERLOCK-01]: State: Running 2014/03/18T12:27:49.43460 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task1[Sherlock.Shared.Core.TestExecutionState] State()
2014/03/18T12:27:49.43460 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response.
2014/03/18T12:27:49.43460 +13:00 - Trace: Communication - Sending message [MessageId: [925acb4c-ac17-42af-b982-5c4171bc3c3c]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T12:27:49.46587 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedResponseMessage.
2014/03/18T12:27:49.48149 +13:00 - Trace: Communication - Message [MessageId: [1c1c9fb4-665a-427b-a621-116df3a57637]] is a response to message [MessageId: [925acb4c-ac17-42af-b982-5c4171bc3c3c]].
2014/03/18T12:27:49.48149 +13:00 - Debug: Sherlock.Service.Master - Environment [AKL-SHERLOCK-01]: State: Running
2014/03/18T12:28:05.26303 +13:00 - Trace: Communication - New endpoint (AKL-SHERLOCK-03:3588) discovered via the TcpIP channel. Endpoint URL: net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588.
2014/03/18T12:28:05.26303 +13:00 - Trace: Communication - New endpoint connected via the TcpIP channel. Endpoint AKL-SHERLOCK-03:3588 is at net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588.
2014/03/18T12:28:05.27866 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.EndpointConnectMessage to endpoint (AKL-SHERLOCK-03:3588) via the TcpIP channel while waiting for the response.
2014/03/18T12:28:05.27866 +13:00 - Info: Communication - Creating channel for endpoint at net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588.
2014/03/18T12:28:05.27866 +13:00 - Trace: Communication - Sending message [MessageId: [53a2943d-96af-43bb-9ec1-1b53c4a15778]] of type Nuclei.Communication.Messages.EndpointConnectMessage.
2014/03/18T12:28:06.49744 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.EndpointConnectMessage.
2014/03/18T12:28:06.51305 +13:00 - Trace: Communication - Processing message of type Nuclei.Communication.Messages.EndpointConnectMessage with action of type Nuclei.Communication.Messages.Processors.EndpointConnectProcessAction.
2014/03/18T12:28:21.24773 +13:00 - Trace: Communication - Invoking System.Threading.Tasks.Task`1[Sherlock.Shared.Core.TestExecutionState] State()
2014/03/18T12:28:21.24773 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.CommandInvokedMessage to endpoint (AKL-SHERLOCK-01:3700) via the TcpIP channel while waiting for the response.
2014/03/18T12:28:21.26335 +13:00 - Trace: Communication - Sending message [MessageId: [006df942-11c7-4e01-b120-b9838291aad4]] of type Nuclei.Communication.Messages.CommandInvokedMessage.
2014/03/18T12:28:21.31022 +13:00 - Trace: Communication - Received message of type Nuclei.Communication.Messages.CommandInvokedResponseMessage.
2014/03/18T12:28:21.31022 +13:00 - Trace: Communication - Message [MessageId: [8d94b5de-99d3-4996-ace4-116ccf85cb3c]] is a response to message [MessageId: [006df942-11c7-4e01-b120-b9838291aad4]].
2014/03/18T12:28:21.31022 +13:00 - Debug: Sherlock.Service.Master - Environment [AKL-SHERLOCK-01]: State: Running
2014/03/18T12:28:26.29467 +13:00 - Trace: Communication - Endpoint information for AKL-SHERLOCK-03:3588 updated.
2014/03/18T12:28:26.29467 +13:00 - Trace: Communication - Sending msg of type Nuclei.Communication.Messages.SuccessMessage to endpoint (AKL-SHERLOCK-03:3588) via the TcpIP channel without waiting for the response.
2014/03/18T12:28:26.29467 +13:00 - Info: Communication - Channel for endpoint at net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588 has faulted. Aborting channel.
2014/03/18T12:28:26.31030 +13:00 - Info: Communication - Creating channel for endpoint at net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588.
2014/03/18T12:28:26.31030 +13:00 - Trace: Communication - Sending message [MessageId: [05bc2fd2-eee5-45d1-beda-179403c44f1c]] of type Nuclei.Communication.Messages.SuccessMessage.
2014/03/18T12:28:47.32633 +13:00 - Error: Communication - Exception occurred during the handling of a message of type Nuclei.Communication.Messages.EndpointConnectMessage. Exception was: Nuclei.Communication.FailedToSendMessageException: Failed to send the message. ---> System.ServiceModel.EndpointNotFoundException: Could not connect to net.tcp://akl-sherlock-03:53267/Tcp.Nuclei.Communication_message_3588. The connection attempt lasted for a time span of 00:00:21.0003981. TCP error code 10060: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 172.20.6.222:53267. ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 172.20.6.222:53267
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
at System.ServiceModel.Channels.SocketConnectionInitiator.Connect(Uri uri, TimeSpan timeout)
--- End of inner exception stack trace ---
Server stack trace: at System.ServiceModel.Channels.SocketConnectionInitiator.Connect(Uri uri, TimeSpan timeout) at System.ServiceModel.Channels.BufferedConnectionInitiator.Connect(Uri uri, TimeSpan timeout) at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnection(TimeSpan timeout) at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpen(TimeSpan timeout) at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.OnOpen(TimeSpan timeout) at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.Call(ServiceChannel channel, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.CallOnce(TimeSpan timeout, CallOnceManager cascade) at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation) at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
at Nuclei.Communication.IMessageReceivingEndpoint.AcceptMessage(ICommunicationMessage message)
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
--- End of inner exception stack trace ---
at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message)
at Nuclei.Communication.SendingEndpoint.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationChannel.Send(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.CommunicationLayer.SendMessageTo(EndpointId endpoint, ICommunicationMessage message)
at Nuclei.Communication.HandshakeProtocolLayer.ContinueHandshakeWith(ChannelConnectionInformation connection, CommunicationDescription information, MessageId messageId)
at Nuclei.Communication.Messages.Processors.EndpointConnectProcessAction.Invoke(ICommunicationMessage message)
at Nuclei.Communication.MessageHandler.ProcessMessage(ICommunicationMessage message)
at Nuclei.Communication.CommunicationModule.<>cDisplayClass7.
Error while raising event Sherlock.Shared.Core.ITestExecutionNotifications, Sherlock.Shared.Core, Version=0.4.8.1, Culture=neutral, PublicKeyToken=ee5b68ec5ad4ef93.OnTestCompletion. Exception is: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> Nuclei.Communication.FailedToSendMessageException: Failed to send the message. ---> System.ServiceModel.CommunicationException: There was an error writing to the pipe: Unrecognized error 232 (0xe8). ---> System.IO.PipeException: There was an error writing to the pipe: Unrecognized error 232 (0xe8). at System.ServiceModel.Channels.PipeConnection.StartSyncWrite(Byte[] buffer, Int32 offset, Int32 size, Object& holder) at System.ServiceModel.Channels.PipeConnection.StartSyncWrite(Byte[] buffer, Int32 offset, Int32 size) at System.ServiceModel.Channels.PipeConnection.Write(Byte[] buffer, Int32 offset, Int32 size, Boolean immediate, TimeSpan timeout, BufferManager bufferManager) --- End of inner exception stack trace ---
Server stack trace: at System.ServiceModel.Channels.PipeConnection.Write(Byte[] buffer, Int32 offset, Int32 size, Boolean immediate, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.BufferedConnection.WriteNow(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.BufferedConnection.Write(Byte[] buffer, Int32 offset, Int32 size, Boolean immediate, TimeSpan timeout, BufferManager bufferManager) at System.ServiceModel.Channels.FramingDuplexSessionChannel.OnSendCore(Message message, TimeSpan timeout) at System.ServiceModel.Channels.TransportDuplexSessionChannel.OnSend(Message message, TimeSpan timeout) at System.ServiceModel.Channels.OutputChannel.Send(Message message, TimeSpan timeout) at System.ServiceModel.Dispatcher.DuplexChannelBinder.Send(Message message, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout) at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation) at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
Exception rethrown at [0]: at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg) at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type) at Nuclei.Communication.IMessageReceivingEndpoint.AcceptMessage(ICommunicationMessage message) at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message) --- End of inner exception stack trace --- at Nuclei.Communication.RestoringMessageSendingEndpoint.Send(ICommunicationMessage message) at Nuclei.Communication.SendingEndpoint.Send(EndpointId endpoint, ICommunicationMessage message) at Nuclei.Communication.CommunicationChannel.Send(EndpointId endpoint, ICommunicationMessage message) at Nuclei.Communication.CommunicationLayer.SendMessageAndWaitForResponse(EndpointId endpoint, ICommunicationMessage message) at Nuclei.Communication.CommunicationModule.SendMessageWithResponse(IConfiguration configuration, ISendDataViaChannels layer, EndpointId endpoint, ICommunicationMessage message) at Nuclei.Communication.CommunicationModule.<>cDisplayClass8f.b 8c(EndpointId endpoint, ICommunicationMessage msg)
at Nuclei.Communication.NotificationProxyBuilder.<>cDisplayClassf.b d(ISerializedEventRegistration eventInfo)
at Nuclei.Communication.NotificationEventRemoveMethodInterceptor.Intercept(IInvocation invocation)
at Castle.DynamicProxy.AbstractInvocation.Proceed()
at Castle.Proxies.ITestExecutionNotificationsProxy.remove_OnExecutionProgress(EventHandler`1 value)
at Sherlock.Service.Executor.TestStepExecutionCommands.<>cDisplayClass2f.b 2e(Object s, TestExecutionResultEventArgs e) in c:\documents\skydrive\Documents\source\sherlock\master\src\service.executor\TestStepExecutionCommands.cs:line 461
--- End of inner exception stack trace ---
at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor)
at System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments)
at System.Delegate.DynamicInvokeImpl(Object[] args)
at Nuclei.Communication.NotificationSetProxy.RaiseEvent(String eventName, EventArgs args)
at Nuclei.Communication.Messages.Processors.NotificationRaisedProcessAction.Invoke(ICommunicationMessage message)