Tuesday, 8 September 2015

Powershell execution from C#

This article will display an entertaining example how to execute Powershell from C#. We will use Linqpad, available here: Download LinqPad now The code executes a Powershell scripts, then uses different objects in System.Management.Automation for working with Powershell from C#. The Powershell script is executed inside Linqpad, where C# code is pasted. The code itself will animate the active processes on the computer running the Linqpad C# code, executing the Powershell script. The code is listed below. Paste the code into Linqpad. You might want to adjust the Task.Delay and for loop for controlling how quick you want to refresh and how long to run (# iterations).










public class CpuNode {

 public CpuNode(string name, int percentage){
  ProcessName = name; 
  Percentage = percentage; 
 }

 public string ProcessName { get; set; }
 
 public int Percentage { get; set; }

}


async void Main()
{
 Chart c = new Chart(); 
 
 Series s  = c.Series.Add("ActiveProcesses"); 
 s.ChartType = SeriesChartType.Column;  

 Title title = new Title("Active processes using CPU (%)", Docking.Top, new Font("Verdana", 18), Color.MidnightBlue); 
 c.Titles.Add(title); 
 
 var ca = new ChartArea();  
 var ca3D = new ChartArea3DStyle(); 
 ca3D.Enable3D = true; 
 ca.Area3DStyle = ca3D; 
 ca.AxisY.Maximum = 100;
 ca.AxisY.Minimum = 0; 
 ca.BackColor = Color.AliceBlue;
 ca.AxisX.Title = "Process name"; 
 ca.AxisY.Title = "CPU Percentage %"; 
 
 Legend lg = new Legend(); 
 lg.Title = "CPU"; 
 lg.BackColor = Color.AliceBlue; 
 c.Legends.Add(lg); 
  
  c.ChartAreas.Add(ca); 
  
  c.Dump(""); 
  
 
 string cpuPsScript = @"get-wmiobject Win32_PerfFormattedData_PerfProc_Process| 
Select-Object -Property Name, PercentProcessorTime | Where-Object { $_.Name -ne '_Total'  } | 
Where-Object { $_.Name -ne 'Idle' } "; 
 
 using (PowerShell powerShellInstance = PowerShell.Create()){
  powerShellInstance.AddScript(cpuPsScript); 
  
  List<CpuNode> nodes = new List<CpuNode>();
 
  for (int i=0; i<1000; i++){
 
  Collection<PSObject> psOutput = powerShellInstance.Invoke();
  
  s.Points.Clear(); 
  
  nodes.Clear();  
 
  int n = 1; 
  foreach (PSObject outputItem in psOutput){
    try {
    string processName = outputItem.Properties["Name"].Value.ToString();
    int processPercentage = int.Parse(outputItem.Properties["PercentProcessorTime"].Value.ToString()); 
    var node = new CpuNode(processName, processPercentage);              
    nodes.Add(node);
    } //try 
    catch (Exception err){
     err.Message.Dump(); 
    } //try-catch  
       
  } //foreach
  
  
  foreach (var node in nodes.OrderBy(x => x.ProcessName)){
   var dt = new DataPoint(n, node.Percentage); 
   if (node.Percentage > 1){
    dt.Label = node.ProcessName + " (" + node.Percentage + "%)"; 
   }
   dt.Color = ColorTranslator.FromHtml("#FF418CF0"); 
   
   s.Points.Add(dt);
   n = n + 1; 
  }
  
  c.ResumeLayout(); 
  
   await Task.Delay(250);
  
 } //for  
  
}

}

// Define other methods and classes here


The code uses the Powershell cmdlet get-mwiobject and uses the performance counter Win32_PerfFormatttedData_PerfProc_Process We use the PowerShell.Create() method to create the Powershell instance and add a script using the .AddScript method. We then Invoke the Powershell instance, grab hold of the PsObject items and then readily accesses the Properties inside. We build up a Chart object with a chart series, having data points and setting up a nice formatting. When the Chart object is created, we let LinqPad display it for us in a tab pane. Now that was fun, wasn't it? Now go code some more :-)

Wednesday, 2 September 2015

EventLogDisplayer

EventLogDisplayer

EventLogDisplayer is a general-purpose tool to harvest and display contents from the Event Log in a simple dedicated web application implemented in ASP.NET MVC. To make it work, one must enable Remote Event Log on the target server, set up a powershell script as a scheduled task and then create a database to commit the Event Log items. Also make sure that the directory configured to write the scratch XML files to, already exists. The harvest script will harvest last 24 hours from the Event Log and write new items to the database. This can easily be adjusted. The script is usually set up to run once an hour, so retrieving the Event Log items can of course be reduced down to an hour. Regarding how often the Event Log is harvested, this must correspond to the intervals of the scheduled tasks that executes the script, so that all Event Logs items are retrieved. Only Event Log items of type Warning and Error/Exception is retrieved (Information event log type is skipped).

Harvesting the Event Log

Powershell script
Write-Host Starting the harvesting from EventLog ... 
#Setup the parameters of the script to harvest the eventlog here  
$username = "myusername"
$password = "mypassword"
$targetServer = "myserver.somedomain.no"
$logName = "MyLogName" 
$datestamp = Get-Date -Format ddMMyyyy
$outputFile = "C:\temp\EventLogs\EventsLogFile_" + $dateStamp + ".xml"
$daysBack = 1  
$secstr = New-Object -TypeName System.Security.SecureString
$password.ToCharArray() | ForEach-Object {$secstr.AppendChar($_)}
$cred = new-object -typename System.Management.Automation.PSCredential -argumentlist $username, $secstr
 
$yesterday = (Get-Date) - (New-TimeSpan -Day $daysBack)
 
#Write-Host $yesterday
 
$sb = New-Object -TypeName "System.Text.StringBuilder" 
$sb.AppendLine("<?xml version='1.0' ?>")
$sb.Append("<Events xml='http://schemas.microsoft.com/win/2004/08/events/event'>")
Get-WinEvent -ComputerName $targetServer -Credential $cred -LogName $logName | Where-Object { $_.TimeCreated -ge $yesterday -and $_.Level -ge 2 } | ForEach-Object {
 $eventXml =  $_.ToXml()
 $sb.AppendLine($eventXml) 
} 
$sb.AppendLine("</Events>")
$sb.ToString() | Out-File $outputFile
#Invoke-Item $outputFile

Link to EventLogDisplayer


Sample web solution
(Link is not active) This web site targets the server MYSERVER, Event Log name is set to MyLogName.

Screenshots of Event Log Displayer


It is easy to monitor another server, but note that the Remote Event Log feature must be added to the server.

Scheduling task to harvest the Event Log remotely
Sample task from Task Scheduler
The following task will set up a hourly schedule, harvesting event log from the remote computer.


<?xml version="1.0" encoding="UTF-16"?>
<Task version="1.2" xmlns="http://schemas.microsoft.com/windows/2004/02/mit/task">
  <RegistrationInfo>
    <Date>2015-08-28T20:02:29.8065626</Date>
    <Author>somedomain\someuser-he</Author>
  </RegistrationInfo>
  <Triggers>
    <CalendarTrigger>
      <Repetition>
        <Interval>PT1H</Interval>
        <StopAtDurationEnd>false</StopAtDurationEnd>
      </Repetition>
      <StartBoundary>2015-08-28T00:00:00</StartBoundary>
      <Enabled>true</Enabled>
      <ScheduleByDay>
        <DaysInterval>1</DaysInterval>
      </ScheduleByDay>
    </CalendarTrigger>
  </Triggers>
  <Principals>
    <Principal id="Author">
      <UserId>somedomain\someuser</UserId>
      <LogonType>InteractiveToken</LogonType>
      <RunLevel>LeastPrivilege</RunLevel>
    </Principal>
  </Principals>
  <Settings>
    <MultipleInstancesPolicy>IgnoreNew</MultipleInstancesPolicy>
    <DisallowStartIfOnBatteries>true</DisallowStartIfOnBatteries>
    <StopIfGoingOnBatteries>true</StopIfGoingOnBatteries>
    <AllowHardTerminate>true</AllowHardTerminate>
    <StartWhenAvailable>false</StartWhenAvailable>
    <RunOnlyIfNetworkAvailable>false</RunOnlyIfNetworkAvailable>
    <IdleSettings>
      <StopOnIdleEnd>true</StopOnIdleEnd>
      <RestartOnIdle>false</RestartOnIdle>
    </IdleSettings>
    <AllowStartOnDemand>true</AllowStartOnDemand>
    <Enabled>true</Enabled>
    <Hidden>false</Hidden>
    <RunOnlyIfIdle>false</RunOnlyIfIdle>
    <WakeToRun>false</WakeToRun>
    <ExecutionTimeLimit>P3D</ExecutionTimeLimit>
    <Priority>7</Priority>
  </Settings>
  <Actions Context="Author">
    <Exec>
      <Command>Powershell</Command>
      <Arguments>C:\Users\toaurs-he\Documents\Powershell\HarvestEventLog.ps1</Arguments>
    </Exec>
  </Actions>
</Task>



The task above defined in the XML can be saved to an XML file, adjusted as necessary and imported in Task Scheduler: The task can also be adjusted using the command line (as Administrator) with the command:

schtasks.exe /Create /XML task.xml /tn taskname

Enabling Remote Event Log feature on target server Remote Event Log Management is enabled in the Windows Firewall with Advanced Security as an Inbound Rule, predefined as Remote Event Log Management.

Tick off all the three choices here:



SQL Script

The following script creates the database required to persist data to the database.


USE [OpPlan4EventLog] GO /****** Object: Table [dbo].[Events] Script Date: 02.09.2015 20:03:14 ******/ SET ANSI_NULLS ON GO SET QUOTED_IDENTIFIER ON GO CREATE TABLE [dbo].[Events]( [Id] [INT] NOT NULL, [Message] [nvarchar](MAX) NULL, [TimeCreated] [datetime] NULL, [Level] [INT] NULL, [Channel] [nvarchar](300) NULL, [Computer] [nvarchar](300) NULL, CONSTRAINT [PK_Events] PRIMARY KEY CLUSTERED ( [Id] ASC)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY] GO

Sample MVC web solution


The EventLogDisplayer is a MVC web solution and is available here. Available on OneDrive here:

Sample MVC web solution [40,15 MB | Zip-file | Visual Studio 2013 Solution ]

Thursday, 27 August 2015

EventLogParserUtility - Parsing Event Log Files and exporting to Excel

Parsing Event Log Files

Filtering and searching an event log using the Event Log Viewer (eventvwr) is often unpractical and it is quicker to save the selected content of the Event Log to a Event Log File of the format .evtx. This is done using the following classes in System.Diagnostics.Eventing.Reader:
  • EventLogReader
  • EventLogQuery
  • EventLogRecord
The following code is a console line application written in C# generating excel files with filtered contents of the event log file.

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Eventing.Reader;
using System.Drawing;
using System.IO;
using System.Linq;
using System.Text;
using System.Text.RegularExpressions;
using System.Threading;
using OfficeOpenXml;
using OfficeOpenXml.Style;

namespace EventLogParserUtility
{
    class Program
    {

        private static void Main(string[] args)
        {

            bool outputToExcel = false;
            string eventLogFileName = null;
            string excelFileName = null;

            Console.WriteLine("Starting analysis of target Event Log file: ");

            Timer timer = new Timer(TimerTick, null, 0, 100);


            if (args.Any(a => a.StartsWith(@"-f:")))
            {
                eventLogFileName = args.First(a => a.StartsWith(@"-f:")).Split(':')[1];
            }

            if (string.IsNullOrEmpty(eventLogFileName))
            {
                ShowUsageInfo();
                return;
            }

            var events = from l in LogRecordCollection(eventLogFileName)
                         where l.Properties.Any()
                               && l.Properties[0].Value != null
                         select l;

            if (args.Any(a => a.StartsWith(@"-t:")))
            {
                string timeArgument = args.First(a => a.StartsWith(@"-t:")).Split(':')[1];
                DateTime fromTime;
                if (DateTime.TryParse(timeArgument, out fromTime))
                {
                    events = events.Where(e => e.TimeCreated >= fromTime);

                } //if 
            } //if 

            if (args.Any(a => a.StartsWith(@"-m:")))
            {
                string messageArgument = args.First(a => a.StartsWith(@"-m:")).Split(':')[1].Replace("'", "");
                events =
                    events.Where(
                        e => Regex.IsMatch(e.Properties[0].Value.ToString(), messageArgument, RegexOptions.IgnoreCase));
            }

            if (args.Any(a => a.StartsWith(@"-excel:")))
            {
                excelFileName = DateTime.Now.ToString("ddmmyyyyhhmmss") + args.First(a => a.StartsWith(@"-excel:")).Split(':')[1].Replace("'", "");
                outputToExcel = true;
            }


            if (!outputToExcel)
            {
                foreach (var e in DistinctBy(events, e => e.RecordId).OrderByDescending(e => e.TimeCreated))
                {
                    Console.WriteLine(Environment.NewLine + e.TimeCreated + Environment.NewLine +
                                      GetFilteredValue(e.Properties[0].Value, args));
                    Console.WriteLine("Hit enter to go to NEXT.");
                    Console.ReadKey();
                }
            }
            else
            {
                using (var excelPackage = new ExcelPackage(new FileInfo(Path.Combine(Directory.GetCurrentDirectory(), excelFileName))))
                {
                    excelPackage.Workbook.Worksheets.Add("Eventlog matches:" + DateTime.Now.ToShortDateString());

                    var workSheet = excelPackage.Workbook.Worksheets[1];

                    int rowIndex = 2;

                    workSheet.Cells[1, 1].Value = "Level";
                    workSheet.Cells[1, 2].Value = "Date and Time";
                    workSheet.Cells[1, 3].Value = "Source";
                    workSheet.Cells[1, 4].Value = "Details";
                    workSheet.Cells[1, 5].Value = "Computer Name";
                    workSheet.Cells[1, 6].Value = "Filtered Details";

                    workSheet.Cells[1, 1, 1, 6].Style.Font.Bold = true;
                    workSheet.Cells[1, 1, 1, 6].Style.Font.Size = 14;




                    foreach (var e in DistinctBy(events, e => e.RecordId).OrderByDescending(e => e.TimeCreated))
                    {
                        workSheet.Cells[rowIndex, 1].Value = e.Level;
                        workSheet.Cells[rowIndex, 2].Value = e.TimeCreated;
                        workSheet.Cells[rowIndex, 2].Style.Numberformat.Format = "dd.mm.yyyy hh:mm";
                        workSheet.Cells[rowIndex, 3].Value = e.ProviderName;
                        workSheet.Cells[rowIndex, 4].Value = e.Properties[0].Value;
                        workSheet.Cells[rowIndex, 5].Value = e.MachineName;
                        workSheet.Cells[rowIndex, 6].Value = GetFilteredValue(e.Properties[0].Value, args);
                        workSheet.Cells[rowIndex, 1, rowIndex, 5].Style.Fill.PatternType = ExcelFillStyle.Solid;
                        workSheet.Cells[rowIndex, 1, rowIndex, 5].Style.Fill.BackgroundColor.SetColor(rowIndex % 2 == 0
                            ? Color.AliceBlue
                            : Color.White);
                        rowIndex++;
                    }



                    workSheet.Cells[workSheet.Dimension.Address].AutoFitColumns();

                    excelPackage.Save();

                }



                Process.Start(Path.Combine(Directory.GetCurrentDirectory(), excelFileName));

            }

            timer.Dispose();

            Console.WriteLine("All done. Press the any key to continue ..");
            Console.ReadKey();


        }

        private static string GetFilteredValue(object value, string[] args)
        {
            if (args.Any(a => a.StartsWith("-o:")))
            {
                var pattern = string.Join(":", args.First(a => a.StartsWith("-o:")).Split(':').Skip(1)).Replace("&lt", "<")
                    .Replace("&gt;", ">").Replace("'", "").Trim();
                Regex filterMatch =
                    new Regex(pattern, RegexOptions.IgnoreCase);
                Match mc = filterMatch.Match(value.ToString());

                StringBuilder sb = new StringBuilder();

                foreach (Group group in mc.Groups)
                {
                    sb.Append(group.Value + " ");
                }

                return sb.ToString();
            }
            return value.ToString();
        }

        private static void TimerTick(object state)
        {
            Console.Write(".");
        }

        private static void ShowUsageInfo()
        {
            Console.WriteLine("Example Usage: EventLogParserUtility -f:MyEventLogFile.evtx "
                + Environment.NewLine + "Additional parameters: -t:1.1.2015 [TimeCreated larger than] "
                + Environment.NewLine + "-m:MySearchKey [Properties[0].Value or Message contains] "
                + Environment.NewLine + "-excel:SomeFileName.xlsx [Outputting to Excel file]"
                + Environment.NewLine + "-o:MyFilter [Filter output by regex]");
        }

        static IEnumerable<EventLogRecord> LogRecordCollection(string filename, string xpathquery = "*")
        {
            var eventLogQuery = new EventLogQuery(filename, PathType.FilePath, xpathquery);

            using (var eventLogReader = new EventLogReader(eventLogQuery))
            {
                EventLogRecord eventLogRecord;

                while ((eventLogRecord = (EventLogRecord)eventLogReader.ReadEvent()) != null)
                {
                    yield return eventLogRecord;
                }
            }
        }

        static IEnumerable<T> DistinctBy<T, TKey>(IEnumerable<T> inputList, Func<T, TKey> keySelector, IEqualityComparer<TKey> comparer = null)
        {
            var distinctItems = inputList.GroupBy(keySelector, comparer).Select(g => g.First()).ToList();
            return distinctItems;
        }

    }
}


The command line application is able to output content of the event log file that matches a given search term key and also output a filtered column specified by a Regex.


cd EventLogParserUtility\bin\Debug EventLogParserUtility -f:EventLogs\hendelseslogg.evtx -m:'OfficialId' -excel:MyOutputExcelFile.xlsx -o:'<OfficialId>(?<x>.*)</OfficialId>' Supported switches in EventLogParserUtility:

-f: File name of event log file (obligatory column) -m: Search messages in event log specified by search term. It is possible to type in a regex here (optional parameter) -excel: filename to output to excel (optional parameter) -o: Regular expression to use to filter the message additionally for targeted output (will be displayed in filtered column) -t: Filtering to output content where TimeCreated of Event Log Item above specified date (optional parameter, specify as datetime value To use this utilty, put the arguments of the switches inside quotes if the arguments got spaces.

Monday, 20 July 2015

Calculating PI in C# using Monte-Carlo simulation

The following code sample shows numeric compuation of the number PI using Monte-Carlo simulation. First, a sequential approach is used. Then the Parallel.For construct in TPL is used. In the end, we use Tasks in TPL.


To compute PI we use the same approach. We consider the unit circle inscribed in a square around origo with corners at coordinates (-1,-1), (-1, 1), (1,1) and (1,-1). The number PI can be defined as generating random numbers and looking at the ratio of the numbers inside the circle M divided upon the total numbers generated N. We know that the following can then be expected:

(a) M / N = PI / 4

Why? Because the square has got an area equal to four, remember that the unit square got sides equal to the number 2 and its area is therefore 2 * 2 = 4. The unit circle got a radius of 1, hence its area is PI * 1^2 = PI. The ratio to be expected between the areas of the unit circle and unit rectangle therefore gives the formula above. We can further compute the approximated numeric value of PI equal to:

(b) PI = 4 * (M / N)

This expression (b) is directly from the previous expression (a)
Let's move on the code sample, review the code. I have included a screen shot at the end. The conclusion I got after testing showed after several runs shows that the sequential version runs in about 3.5 seconds on my eight core system with about half the time, about 1.8 seconds using Parallel.For - The last version using Tasks and Tasks.WaitAll give about 1.7 seconds and the quickest compuation, about twice as fast. The iterations I used in the demo was 80 million.
Here is the code written in C#:

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;

namespace MonteCarloPiApproximation
{
    class Program
    {
        static int numberOfCores = Environment.ProcessorCount; 
        static int iterations = 10000000 * numberOfCores;

        static void Main(string[] args)
        {
            Console.WriteLine("Monte Carlo numeric simulation of PI");
            Console.WriteLine("Iteration limit: " + iterations);
            Console.WriteLine("Number of processor cores on system: " + Environment.ProcessorCount);
            var sw = new Stopwatch();
            sw.Start();

            Console.WriteLine("\nMONTE CARLO SIMULATION");

            MonteCarloPiApproximationSerialSimulation();
            sw.Stop();

            Console.WriteLine("Serial simulation: (ms)" + sw.ElapsedMilliseconds);
            Console.WriteLine();

            sw.Restart();

            Console.WriteLine("\nMONTE CARLO SIMULATION");
            MonteCarloPiApproximationParallellForSimulation(); 

            sw.Stop();

            Console.WriteLine("Parallell simulation using Parallel.For: (ms)" + sw.ElapsedMilliseconds);
            Console.WriteLine();

            sw.Restart();

            Console.WriteLine("\nMONTE CARLO SIMULATION");

            MonteCarloPiApproximationParallelTasksSimulation(); 

            Console.WriteLine("Parallell simulation using parallell Tasks: (ms)" + sw.ElapsedMilliseconds);
            Console.WriteLine();

            sw.Stop();           

            Console.WriteLine("Press Enter Key");



            Console.ReadKey(); 
        }

        private static void MonteCarloPiApproximationParallelTasksSimulation()
        {
            double piApproximation = 0;
            int inCircle = 0;
            double x, y = 0;

            int[] localCounters = new int[numberOfCores];
            Task[] tasks = new Task[numberOfCores];

            for (int i = 0; i < numberOfCores; i++)
            {
                int procIndex = i; //closure capture 
                tasks[procIndex] = Task.Factory.StartNew(() =>
                {
                    int localCounterInside = 0;

                    Random rnd = new Random();

                    for (int j = 0; j < iterations / numberOfCores; j++)
                    {
                        x = rnd.NextDouble();
                        y = rnd.NextDouble();
                        if (Math.Sqrt(x * x + y * y) <= 1.0)
                            localCounterInside++;
                    } 
                    localCounters[procIndex] = localCounterInside;

                });               
            }

            Task.WaitAll(tasks);
            inCircle = localCounters.Sum(); 

            piApproximation = 4 * ((double)inCircle / (double)iterations);

            Console.WriteLine();
            Console.WriteLine("Approximated Pi = {0}", piApproximation.ToString("F8"));
           
        }      

        private static void MonteCarloPiApproximationParallellForSimulation()
        {
            double piApproximation = 0;
            int inCircle = 0;
            double x, y = 0;
                   
            Parallel.For(0, numberOfCores, new ParallelOptions{ MaxDegreeOfParallelism = numberOfCores }, i =>
            {
              
                int localCounterInside = 0;

                Random rnd = new Random(); 

                for (int j = 0; j < iterations / numberOfCores; j++)
                {
                    x = rnd.NextDouble();
                    y = rnd.NextDouble();
                    if (Math.Sqrt(x*x+y*y) <= 1.0)
                        localCounterInside++;                                                        
                }

                Interlocked.Add(ref inCircle, localCounterInside); 
                            
            }); 

            piApproximation = 4 * ((double)inCircle / (double)iterations);

            Console.WriteLine();
            Console.WriteLine("Approximated Pi = {0}", piApproximation.ToString("F8"));
            
        }

        private static void MonteCarloPiApproximationSerialSimulation()
        {
            double piApproximation = 0;
            int total = 0;
            int inCircle = 0; 
            double x,y = 0;
            Random rnd = new Random(); 

            while (total < iterations)
            {
                x = rnd.NextDouble(); 
                y = rnd.NextDouble();

                if ((Math.Sqrt(x*x+y*y) <= 1.0))
                    inCircle++;

                total++;                
                piApproximation =  4 * ((double)inCircle / (double)total); 
            } //while 


            Console.WriteLine();
            Console.WriteLine("Approximated Pi = {0}", piApproximation.ToString("F8"));

        }




    }
}


Wednesday, 15 July 2015

Data block types in Task Parallel Library

The following code sample shows data block types in Task Parallel Libary (TPL). The code is written in C# and can be run in a simple Console Application. Dataflow in TPL makes it possible to build actor-based programming and orchestrate coarse-grained dataflow and pipelining tasks, maintaining robustness and supporting concurrency-enabled applications. This makes it easier to construct high-performance, low latency systems.

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using System.Threading.Tasks.Dataflow;

namespace TplDataFlowSimpleTests
{
    class Program
    {

        static void Main(string[] args)
        {
            ActionBlockPostingAndFaulting();

            //BufferBlockPostingAndReceiving();

            //BroadCastPostAndMultipleReceive();

            //WriteOnceBlockParallellPostsAndSingleReceive();

            //ActionBlockPostingCompleting();

            //TransformBlockPostingAndProducingOutput(); 

            //TransformManyBlockPostingsAndReceive(); 

            //BatchBlockSeveralBatches();

            //JoinBlockAritmeticCombinations(); 

            //BatchedJoinBlockPropagatingValuesAndException();

            Console.WriteLine("Press the any key to continue ..");
            Console.ReadKey();

        }

        private static void BatchedJoinBlockPropagatingValuesAndException()
        {
            Func<int, int> doWork = n =>
            {
                if (n < 0)
                    throw new ArgumentOutOfRangeException();
                return n;
            };

            var batchedJoinBlock = new BatchedJoinBlock<int, Exception>(7);

            foreach (int i in new int[] {5, 6, -7, -22, 13, 55, 0})
            {
                try
                {
                    batchedJoinBlock.Target1.Post(doWork(i));
                }
                catch (ArgumentOutOfRangeException e)
                {
                    batchedJoinBlock.Target2.Post(e);
                }
            }

            var results = batchedJoinBlock.Receive();

            foreach (int n in results.Item1)
            {
                Console.WriteLine(n);
            }

            foreach (Exception e in results.Item2)
            {
                Console.WriteLine(e.Message);
            }
        }

        private static void JoinBlockAritmeticCombinations()
        {
            var joinBlock = new JoinBlock<int, int, char>(new GroupingDataflowBlockOptions{ Greedy = true});

            joinBlock.Target1.Post(3);
            joinBlock.Target1.Post(6);

            joinBlock.Target2.Post(5);
            joinBlock.Target2.Post(4);

            joinBlock.Target3.Post('+');
            joinBlock.Target3.Post('-');

            for (int i = 0; i < 2; i++)
            {
                var data = joinBlock.Receive();

                switch (data.Item3)
                {
                    case '+':
                        Console.WriteLine("{0} + {1} = {2}", data.Item1, data.Item2, data.Item1 + data.Item2);
                        break;
                    case '-':
                        Console.WriteLine("{0} - {1} = {2}", data.Item1, data.Item2, data.Item1 - data.Item2);
                        break;
                    default:
                        Console.WriteLine("Unknown operator '{0}'.", data.Item3);
                        break;
                } //switch 
            } //for 

        }

        private static void BatchBlockSeveralBatches()
        {
            var batchBlock = new BatchBlock<int>(10);

            for (int i = 0; i < 13; i++)
            {
                batchBlock.Post(i);
            }

            batchBlock.Complete();


            Console.WriteLine("The elements of the first batch are: [{0}] ", string.Join(",", batchBlock.Receive()));
            Console.WriteLine("The elements of the second batch are: [{0}]", string.Join(",", batchBlock.Receive()));
        }

        private static void TransformManyBlockPostingsAndReceive()
        {
            var transformManyBlock = new TransformManyBlock<string, char>(s => s.ToCharArray());

            transformManyBlock.Post("Hello");
            transformManyBlock.Post("World");

            for (int i = 0; i < ("Hello" + "World").Length; i++)
            {
                Console.WriteLine(transformManyBlock.Receive());
            }
        }

        private static void TransformBlockPostingAndProducingOutput()
        {
            var transformBlock = new TransformBlock<int, double>(n => Math.Sqrt(n));

            transformBlock.Post(10);
            transformBlock.Post(20);
            transformBlock.Post(30);

            for (int i = 0; i < 3; i++)
            {
                Console.WriteLine(transformBlock.Receive());
            }
        }

        private static void ActionBlockPostingCompleting()
        {
            var cts = new CancellationTokenSource();
            var actionBlock = new ActionBlock<int>(n =>
            {
                Console.WriteLine(n);
                Thread.Sleep(1000);
                if (n > 50)
                    cts.Cancel();
            }, new ExecutionDataflowBlockOptions{ MaxDegreeOfParallelism = 2, MaxMessagesPerTask = 1, CancellationToken = cts.Token });

            for (int i = 0; i < 10; i++)
            {
                actionBlock.Post(i*10); 
         
            }

            actionBlock.Complete();
            try
            {
                actionBlock.Completion.Wait(cts.Token);
            }
            catch (OperationCanceledException ex)
            {
                Console.WriteLine(ex.Message);
            }
        }

        private static void WriteOnceBlockParallellPostsAndSingleReceive()
        {
            var writeOnceBlock = new WriteOnceBlock<string>(null);

            Parallel.Invoke(
                () => writeOnceBlock.Post("Message 1"),
                () => writeOnceBlock.Post("Message 2"),
                () => writeOnceBlock.Post("Message 3"));

            Console.WriteLine(writeOnceBlock.Receive());
        }

        private static void BroadCastPostAndMultipleReceive()
        {
            var broadcastBlock = new BroadcastBlock<double>(null);

            broadcastBlock.Post(Math.PI);

            for (int i = 0; i < 3; i++)
            {
                Console.WriteLine(broadcastBlock.Receive());
            }
        }

        private static void BufferBlockPostingAndReceiving()
        {
            var bufferBlock = new BufferBlock<int>();

            for (int i = 0; i < 3; i++)
            {
                bufferBlock.Post(i);
            }

            for (int i = 0; i < 4; i++)
            {
                try
                {
                    Console.WriteLine(bufferBlock.Receive(new TimeSpan(0, 0, 2)));
                }
                catch (TimeoutException tie)
                {
                    Console.WriteLine("Exception of type: {0} with message: {1}", tie.GetType().Name, tie.Message);
                }
            }
        }

        private static void ActionBlockPostingAndFaulting()
        {
            var throwIfNegative = new ActionBlock<int>(n =>
            {
                Console.WriteLine("n = {0}", n);
                if (n < 0)
                    throw new ArgumentOutOfRangeException();
            });

            throwIfNegative.Completion.ContinueWith(
                task => { Console.WriteLine("The status of the completion task is '{0}'", task.Status); });

            throwIfNegative.Post(0);
            throwIfNegative.Post(-1);
            throwIfNegative.Post(1);
            throwIfNegative.Post(2);

            throwIfNegative.Complete();

            try
            {
                throwIfNegative.Completion.Wait();
            }
            catch (AggregateException ae)
            {
                ae.Handle(e =>
                {
                    Console.WriteLine("Encountered {0}: {1}", e.GetType().Name, e.Message);
                    return true;
                });
            }

          
        }
    }
}

Monday, 13 July 2015

Producer-consumer scenario with BlockingCollection of Task Parallell Library

The BlockingCollection of Task Parallel Library or TPL supports Producer-Consumer scenarios well. This is a scenario or pattern, where you want to start processing items as soon as they are available. BlockingCollection makes this easy, as long as you follow the convention. In this article, a simple scenario with five producers and one consumer is presented. We create an array of tasks (Task[]) that we wait on, using the Task.WaitAll(Task[]) method. This creates a barrier in our main method of which we call the CompleteAdding() method of BlockingCollection to signal that we have no more items to add. The consumer, which here is a single Task, will use standard foreach iteration and call the method GetConsumingEnumerable() on the BlockingCollection to get the collection to iterate over. Note that we will be inside the foreach loop until the CompleteAdding() method is called on the BlockingCollection, i.e. the iteration is halted until CompleteAdding() is called and no more items are available.

using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;

namespace TestBlockingCollectionSecond
{

    public class Node
    {

        public int ManagedThreadId { get; set; }

        public int Value { get; set; }

        public override string ToString()
        {
            return string.Format("Inside ManagedThreadId {0}, Value: {1}", ManagedThreadId, Value);
        }

    }

    class Program
    {
        static void Main(string[] args)
        {

            BlockingCollection<Node> bc = new BlockingCollection<Node>();

            Console.WriteLine("Producer-consumer scenario BlockingCollection.\nFive producers, one consumer scenario");

            var rnd = new Random();

            var producers = new List<Task>();

            for (int i = 0; i < 5; i++)
            {

                var producer = Task.Factory.StartNew(() =>
                {                  
                    for (int j = 0; j < 5; j++)
                    {
                        Thread.Sleep(rnd.Next(100,300));
                        bc.Add(new Node { ManagedThreadId = Thread.CurrentThread.ManagedThreadId, Value = rnd.Next(1, 100) });
                    }
                });

                producers.Add(producer);

            }

            var consumer = Task.Factory.StartNew(() =>
            {
                foreach (Node item in bc.GetConsumingEnumerable())
                {
                    Console.WriteLine(item);
                }

                Console.WriteLine("Consumer all done!");             
            });

            Task.WaitAll(producers.ToArray());

            bc.CompleteAdding();
       

            Console.WriteLine("Hit any key to exit program");
            Console.ReadKey();         


        }
    }
}


If you are not sure when to signal CompleteAdding(), you can keep taking items from the BlockingCollection, using one single consumer or multiple, but remember to catch InvalidOperationException, in case there are no more items available, that is - after CompleteAdding() method has been called on the BlockingCollection. Note that the while loop below is wrapped in a consumer Task that is once again started before the Task.WaitAll call on the producers array, to start consuming right away. Our exit condition here is the flag bc.IsAddingCompleted is set to true, i.e. a call to CompleteAdding is performed. The benefit of using the GetConsumingEnumerable() here is having not to deal with exceptions and boolean flag of completed adding items in the consumer Block, since calling the Take() method on the collection after the CompleteAdding() method is called will throw an InvalidOperationException.



            var consumer = Task.Factory.StartNew(() => {

                try{
                while (!bc.IsAddingCompleted){
                    Console.WriteLine("BlockingCollection element: " + bc.Take());
                }
                }
                Console.WriteLine("Consumer all done!");
                catch (InvalidOperationException ioe){
                    //Console.WriteLine(ioe.Message);
                }
            });

Wednesday, 8 July 2015

Logging the SQL of Entity Framework exceptions in EF 6

If you use EF 6, it is possible to add logging functionality that will reveal why an exception in the data layer of your app or system occured and in addition creating a runnable SQL that you might try out in your testing/production environment inside a transaction that is rollbacked for quicker diagnosis-cause-fix cycle! First off, create a class that implements the interface IDbCommandInterceptor in the System.Data.Entity.Infrastructure.Interception namespace. This class is then added using in your ObjectContext / DbContext class (this is a usually a partial class that you can extend) using the DbInterception.Add method. I add this class in the static constructor of my factory class inside a try-catch block. The important part is that you call the DbInterception.Add method and instantiate the class you create. Let's consider a code example of this. I am only focusing on logging exceptions, other kind of interceptions can of course be performed. Here is the sample class for logging exceptions, I have replaced the namespaces of the system of mine with the more generic "Acme":

using System;
using System.Data;
using System.Data.Common;
using System.Data.Entity.Infrastructure.Interception;
using System.Diagnostics;
using System.Linq;
using System.Text;
using System.Text.RegularExpressions;
using MySoftware.Common.Log;



namespace Acme.Data.EntityFramework
{
    
    /// <summary>
    /// Intercepts exceptions that is raised by the database running an operation and propagated to the eventlog for logging 
    /// </summary>
    public class AcmeDbCommandInterceptor : IDbCommandInterceptor
    {

        public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
        {
            LogIfError(command, interceptionContext);
        }

        public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
        {
            LogIfError(command, interceptionContext);          
        }

        public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
        {
            LogIfError(command, interceptionContext);          
        }

        public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
        {
            LogIfError(command, interceptionContext);
        }

        public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
        {
            LogIfError(command, interceptionContext);            
        }

        public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
        {
            LogIfError(command, interceptionContext);           
        }

        private void LogIfError<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
        {
            try
            {
                if (interceptionContext != null && interceptionContext.Exception != null)
                {
                    bool isLogged = false;
                    try
                    {
                        LogInterpolatedEfQueryString(command, interceptionContext);
                        isLogged = true; 
                    }
                    catch (Exception err)
                    {
                        LogRawEfQueryString(command, interceptionContext, err);
                    }
                    if (!isLogged)
                        LogRawEfQueryString(command, interceptionContext, null);
                   
                }
            }
            catch (Exception err)
            {
                Debug.WriteLine(err.Message);
            }
        }

        /// <summary>
        /// Logs the raw EF query string 
        /// </summary>
        /// <typeparam name="TResult"></typeparam>
        /// <param name="command"></param>
        /// <param name="interceptionContext"></param>
        /// <param name="err"></param>
        private static void LogRawEfQueryString<TResult>(DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext,
            Exception err)
        {
            if (err != null)
                Debug.WriteLine(err.Message);

            string queryParameters = LogEfQueryParameters(command);

            EventLogProvider.Log(
                string.Format(
                    "Acme serverside DB operation failed: Exception: {0}. Parameters involved in EF query: {1}. SQL involved in EF Query: {2}",
                    Environment.NewLine + interceptionContext.Exception.Message,
                    Environment.NewLine + queryParameters,
                    Environment.NewLine + command.CommandText
                    ), EventLogProviderEnum.Warning);
        }

        /// <summary>
        /// Return a string with the list of EF query parameters 
        /// </summary>
        /// <param name="command"></param>
        /// <returns></returns>
        private static string LogEfQueryParameters(DbCommand command)
        {
            var sb = new StringBuilder(); 
            for (int i = 0; i < command.Parameters.Count; i++)
            {
                if (command.Parameters[i].Value != null)
                    sb.AppendLine(string.Format(@"Query param {0}: {1}", i, command.Parameters[i].Value));
            }
            return sb.ToString();
        }

        private static DbType[] QuoteRequiringTypes
        {
            get
            {
                return new[]
                {
                        DbType.AnsiString, DbType.AnsiStringFixedLength, DbType.String,
                            DbType.StringFixedLength, DbType.Date, DbType.Date, DbType.DateTime,
                            DbType.DateTime2, DbType.Guid
                };
            }
        }


        private static void LogInterpolatedEfQueryString<TResult>(DbCommand command,
            DbCommandInterceptionContext<TResult> interceptionContext)
        {
            var paramRegex = new Regex("@\\d+");
            string interpolatedSqlString = paramRegex.Replace(command.CommandText,
                m => GetInterpolatedString(command, m));

            EventLogProvider.Log(string.Format(
                "Acme serverside DB operation failed: Exception: {0}. SQL involved in EF Query: {1}",
                Environment.NewLine + interceptionContext.Exception.Message,
                Environment.NewLine + interpolatedSqlString),
                EventLogProviderEnum.Warning);

        }

        private static string GetInterpolatedString(DbCommand command, Match m)
        {
            try
            {
                int matchIndex;
                if (string.IsNullOrEmpty(m.Value))
                    return m.Value;
                int.TryParse(m.Value.Replace("@", ""), out matchIndex);
                    //Entity framework will usually build parametrized queries with @1, @2 and so on .. 
                if (matchIndex < 0 || matchIndex >= command.Parameters.Count)
                    return m.Value;

                //Ok matchIndex from here 
                DbParameter dbParameter = command.Parameters[matchIndex];
                var dbParameterValue = dbParameter.Value;
                if (dbParameterValue == null)
                    return m.Value;

                try
                {
                    return GetAdjustedDbParameterValue(dbParameter, dbParameterValue);
                }
                catch (Exception err)
                {
                    Debug.WriteLine(err.Message);
                }
            }
            catch (Exception err)
            {
                Debug.WriteLine(err.Message);
            }

            return m.Value;
        }

        /// <summary>
        /// There are some cases where one have to adjust the Db Parametre value in case it is a boolean 
        /// </summary>
        /// <param name="dbParameter"></param>
        /// <param name="dbParameterValue"></param>
        /// <returns></returns>
        private static string GetAdjustedDbParameterValue(DbParameter dbParameter, object dbParameterValue)
        {
            if (QuoteRequiringTypes.Contains(dbParameter.DbType))
                return string.Format("'{0}'", dbParameterValue); //Remember to put quotes on parameter value 

            if (dbParameter.DbType == DbType.Boolean)
            {
                bool dbParameterBitValue;
                bool.TryParse(dbParameterValue.ToString(), out dbParameterBitValue);
                return dbParameterBitValue ? "1" : "0"; //BIT
            }

            return dbParameterValue.ToString(); //Default case (not a quoted value and not a bit value)
        }
    }
}


The code above uses a class EventLogProvider that will record to the Event Log of the system running the Entity Framework code in the data layer, usually the application server of your system. Here is the relevant code for logging to the Eventlog:

using System.Diagnostics;
using System;
using Acme.Common.Security;

namespace Acme.Common.Log
{
    public enum EventLogProviderEnum
    {
        Warning, Error
    }

    public static class EventLogProvider
    {
        private static string _applicationSource = "Acme";
        private static string _applicationEventLogName = "Application";

        public static void Log(Exception exception, EventLogProviderEnum logEvent)
        {
            Log(ErrorUtil.ConstructErrorMessage(exception), logEvent);
        }

        public static void Log(string logMessage, EventLogProviderEnum logEvent)
        {
            try
            {
                if (!EventLog.SourceExists(_applicationSource))
                    EventLog.CreateEventSource(_applicationSource, _applicationEventLogName);

                EventLog.WriteEntry(_applicationSource, logMessage, GetEventLogEntryType(logEvent));
            }
            catch { } // If the event log is unavailable, don't crash.
        }

        private static EventLogEntryType GetEventLogEntryType(EventLogProviderEnum logEvent)
        {
            switch(logEvent)
            {
                case EventLogProviderEnum.Error:
                    return EventLogEntryType.Error;
                case EventLogProviderEnum.Warning:
                default:
                    return EventLogEntryType.Warning;
            }
        }
    }
}


It is also necessary to add an instance of the db interception class in your ObjectContext or DbContext class as noted. Example:

try {
DbInterception.Add(new AcmeDbCommandInterceptor());
}
catch (Exception err){
 //Log error here (consider using the EventLogProvider above for example)
}

The interpolated string will often be the one that is interesting when EF queries fail. Entity Framework (EF) uses stored procedures and parameters to prevent SQL injection attacks. To get a SQL you can actually run, you will usually interpolate the EF query CommandText and look at the parameters, that is named as @0, @1, @2 and so on.. I use a Regex here to search after this. Note that my code uses a lot of try-catch in case something goes wrong. You also do NOT want to run any heavy code here, as the DbInterception will run on ANY query. I only do further processing IF an exception has occured, to avoid bogging down the system with performance drain. I also first try to get the interpolated EF query string that I can run in my Production or Test environment, usually inside a BEGIN TRAN.. and ROLLBACK statement just to see why the database call failed. In addition, the code will try to log the Raw EF Query in form of logging the EF query CommandText and the command parameters, but without the interpolation technique. I have also done some adjustment, by adding single quotes around strings and considering booleans as the value 0 or 1 (BIT). This code is new and there might be some additional adjustments here. The bottom line to note here is that it is important to LOG the EF query SQL to INFER the real REASON why the SQL query FAILED, i.e. a quicker DIAGNOSE-INFER-FIX cycle leading to more success on your projects, if you use .NET and Entity Framework (version 6 or newer)!

Tuesday, 26 May 2015

Recording network traffic between clients and WCF services to a database

Developers working with WCF services might have come accross the excellent tool Fiddler - which is a HTTP web debugging proxy. In some production environments, it could be interesting to be able to log network traffic in the form of requests and responses to database.There are several approaches possible to this, one is to implement a WCF Message Inspector, which will also act as a WCF servicebehavior.

RecordingMessageBehavior

The following class implements the two interfaces IDispatchMessageInspector, IServiceBehavior. Please note that the code contains some domain-specific production code. The code can be adjusted to work on other code bases of course. The core structure of the code is the required code for recording network traffic. The code below contains some claims-specific code handling that is not required, but perhaps your code base also use some similar code?
In other words, you have to adjusted the code below to make it work with your code base, but the core structure of the code should be of general interest for WCF developers.


using System;
using System.Configuration;
using System.ServiceModel;
using System.ServiceModel.Channels;
using System.ServiceModel.Description;
using System.ServiceModel.Dispatcher;

using Microsoft.IdentityModel.Claims;
using System.Diagnostics;

namespace Hemit.OpPlan.Service.Host
{
    public class RecordingMessageBehavior : IDispatchMessageInspector, IServiceBehavior
    {

        private readonly bool _useTrafficRecording;

        private static DateTime _lastClearTime = DateTime.Now; 

        private readonly ITrafficLogManager _trafficLogManager;


        public RecordingMessageBehavior()
        {
            _trafficLogManager = new TrafficLogManager(); 

            try
            {
                if (ConfigurationManager.AppSettings[Constants.UseTrafficRecording] != null)
                {
                    _useTrafficRecording = bool.Parse(ConfigurationManager.AppSettings[Constants.UseTrafficRecording]); 
                }
            }
            catch (Exception err)
            {
                Debug.WriteLine(err.Message);
            }
        }


        #region IDispatchMessageInspector Members

        public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext)
        {
            MessageBuffer buffer = request.CreateBufferedCopy(Int32.MaxValue);
            request = buffer.CreateMessage();
            Message messageToWorkWith = buffer.CreateMessage(); 

            if (IsTrafficRecordingDeactivated())
                return request;
            InspectMessage(messageToWorkWith, true);
            return request;
        }

        public void BeforeSendReply(ref Message reply, object correlationState)
        {
            MessageBuffer buffer = reply.CreateBufferedCopy(Int32.MaxValue);
            reply = buffer.CreateMessage();
            Message messageToWorkWith = buffer.CreateMessage(); 

            if (IsTrafficRecordingDeactivated())
                return;

            InspectMessage(messageToWorkWith, false);
        }

        private bool IsTrafficRecordingDeactivated()
        {
            return !_useTrafficRecording || !IsCurrentUserLoggedIn();
        }

        #endregion

        private void InspectMessage(Message message, bool isRequest)
        {
            try
            {
                string serializedContent = message.ToString();
                string remoteIp = null;

                if (isRequest)
                {
                    try
                    {
                        RemoteEndpointMessageProperty remoteEndpoint = message.Properties[RemoteEndpointMessageProperty.Name] as RemoteEndpointMessageProperty;
                        if (remoteEndpoint != null) remoteIp = remoteEndpoint.Address + ":" + remoteEndpoint.Port;
                    }
                    catch (Exception err)
                    {
                        Debug.WriteLine(err.Message);
                    }
                }

                var trafficLogData = new TrafficLogItemDataContract
                {
                    IsRequest = isRequest,
                    RequestIP = remoteIp,
                    Recorded = DateTime.Now,
                    SoapMessage = serializedContent,
                    ServiceMethod = GetSoapActionPart(message.Headers.Action, 1),
                    ServiceName = GetSoapActionPart(message.Headers.Action, 2)
                };

                _trafficLogManager.InsertTrafficLogItem(trafficLogData, ResolveCurrentClaimsIdentity());

                if (DateTime.Now.Subtract(_lastClearTime).TotalHours > 1)
                {
                    _trafficLogManager.ClearOldTrafficLog(ResolveCurrentClaimsIdentity()); //check if clearing old traffic logs older than an hour 
                    _lastClearTime = DateTime.Now; 
                }
            }
            catch (Exception ex)
            {
                InterfaceBinding.GetInstance<ILog>().WriteError(ex.Message, ex);

            }
        }

        private string GetSoapActionPart(string soapAction, int rightOffset)
        {
            if (string.IsNullOrEmpty(soapAction) || !soapAction.Contains("/"))
                return soapAction;

            string[] soapParts = soapAction.Split('/');
            int soapPartCount = soapParts.Length;
            if (rightOffset >= soapPartCount)
                return soapAction;
            else
                return soapParts[soapPartCount - rightOffset]; 
        }

        private IClaimsIdentity ResolveCurrentClaimsIdentity()
        {
            if (ServiceSecurityContext.Current != null && ServiceSecurityContext.Current.AuthorizationContext != null)
            {
                var claimsIdentity = ServiceSecurityContext.Current.PrimaryIdentity as IClaimsIdentity; //Retrieval of current claims identity from WCF ServiceSecurityContext
                return claimsIdentity;
            }
            return null;
        }

        private bool IsCurrentUserLoggedIn()
        {
            IClaimsIdentity claimsIdentity = ResolveCurrentClaimsIdentity();
            if (claimsIdentity == null || claimsIdentity.Claims == null || claimsIdentity.Claims.Count == 0 
                || claimsIdentity.FindClaim(WellKnownClaims.AuthorizedForOrganizationalUnit) == null)
                return false;
            return true;
        }

        #region IServiceBehavior Members

        public void AddBindingParameters(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase, System.Collections.ObjectModel.Collection<ServiceEndpoint> endpoints, BindingParameterCollection bindingParameters)
        {
        }

        public void ApplyDispatchBehavior(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase)
        {
            foreach (var channelDispatcherBase in serviceHostBase.ChannelDispatchers)
            {
                var chdisp = channelDispatcherBase as ChannelDispatcher;
                if (chdisp == null)
                    continue; 

                foreach (var endpoint in chdisp.Endpoints)
                {
                    endpoint.DispatchRuntime.MessageInspectors.Add(new RecordingMessageBehavior()); 
                }
            }
        }

        public void Validate(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase)
        {
        }

        #endregion
    }
}

To turn on and off this WCF recording message behavior, toggle the app setting UseTrafficRecording to true in web.config:



In the code above, the first thing to do in the two methods AfterReceiveRequest and BeforeSendReply, is to clone the messages. This is because WCF messages are just like messages in MSMQ message queues - they can be consumed once. Actually we create a copy of a copy here to avoid errors.

   public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext)
        {

            MessageBuffer buffer = request.CreateBufferedCopy(Int32.MaxValue);
            request = buffer.CreateMessage();
            Message messageToWorkWith = buffer.CreateMessage(); 

            if (IsTrafficRecordingDeactivated())
                return request;
            InspectMessage(messageToWorkWith, true);
            return request;
        }

        public void BeforeSendReply(ref Message reply, object correlationState)
        {
 
            MessageBuffer buffer = reply.CreateBufferedCopy(Int32.MaxValue);
            reply = buffer.CreateMessage();
            Message messageToWorkWith = buffer.CreateMessage(); 


            if (IsTrafficRecordingDeactivated())
                return;

            InspectMessage(messageToWorkWith, false);
        }


Retrieving the serialized SOAP XML contents of the WCF messsage is easy, just running the ToString() method on the Message object. In addition, the code above requires some data access layer logic that will persist the data to database. Using EntityFramework and SQL Server her, logging is performed to the table TrafficLog. Please note that the code below will retain 24 hours of network traffic. In a production environment, database will fill up quickly if the traffic and intensity of data transfer in the form of request and response from and to the clients by the WCF services, will quickly grow into Gigabytes (GB). Usually you only want to record traffic when security demands this, or for error tracking and diagnostics.






using System;
using System.Collections.Generic;
using System.Linq;

using Microsoft.IdentityModel.Claims;


namespace Hemit.OpPlan.Service.Implementation
{

    public class TrafficLogManager : ITrafficLogManager
    {

        public List<TrafficLogItemDataContract> GetTrafficLog(DateTime startWindow, DateTime endWindow, IClaimsIdentity claimsIdentity)
        {
            using (var dbContext = ObjectContextManager.DbContextFromClaimsPrincipal(claimsIdentity))
            {
                var trafficLogs = dbContext.TrafficLogs.Where(tl => tl.Recorded >= startWindow && tl.Recorded <= endWindow).ToList();
                return trafficLogs.ForEach(tl =>
                {
                    return CreateTrafficLogDataContract(tl);
                });
            }
        }

        public void ClearOldTrafficLog(IClaimsIdentity claimsIdentity)
        {
            AggregateExceptionExtensions.CallActionLogAggregateException(() =>
            {
                System.Threading.ThreadPool.QueueUserWorkItem((object state) =>
                {
                    try
                    {
                        //Run on new thread 
                        using (var dbContext = ObjectContextManager.DbContextFromClaimsPrincipal(claimsIdentity))
                        {
                            //Use your own DbContext or ObjectContext here (EF)
                            DateTime obsoleteLogDate = DateTime.Now.Date.AddDays(-1);

                            var trafficLogs = dbContext.TrafficLogs.Where(tl => tl.Recorded <= obsoleteLogDate).ToList();
                            foreach (var tl in trafficLogs)
                            {
                                dbContext.TrafficLogs.DeleteObject(tl);
                            }
                            dbContext.SaveChanges();
                        }
                    }
                    catch (Exception err)
                    {
                        InterfaceBinding.GetInstance<ILog>().WriteError(err.Message); 
                    }
                });
            });
        }

        public void InsertTrafficLogItem(TrafficLogItemDataContract trafficLogItemdata, IClaimsIdentity claimsIdentity)
        {

            //string defaultConnectionString =  ObjectContextManager.GetConnectionString();

            using (var dbContext = ObjectContextManager.DbContextFromClaimsPrincipal(claimsIdentity))
            {
                var trafficLog = new TrafficLog();
                MapTrafficLogFromDataContract(trafficLogItemdata, trafficLog);
                dbContext.TrafficLogs.AddObject(trafficLog);
                dbContext.SaveChanges(); 
            }
        }

        private static void MapTrafficLogFromDataContract(TrafficLogItemDataContract trafficLogItem, TrafficLog trafficLog)
        {
            trafficLog.Recorded = trafficLogItem.Recorded;
            trafficLog.RequestIP = trafficLogItem.RequestIP;
            trafficLog.ServiceName = trafficLogItem.ServiceName;
            trafficLog.ServiceMethod = trafficLogItem.ServiceMethod;
            trafficLog.SoapMessage = trafficLogItem.SoapMessage;
            trafficLog.TrafficLogId = trafficLogItem.TrafficLogId;
            trafficLog.IsRequest = trafficLogItem.IsRequest;
        }

        private static TrafficLogItemDataContract CreateTrafficLogDataContract(TrafficLog trafficLog)
        {
            return new TrafficLogItemDataContract
            {
                IsRequest = trafficLog.IsRequest,
                Recorded = trafficLog.Recorded,
                ServiceMethod = trafficLog.ServiceMethod,
                ServiceName = trafficLog.ServiceName,
                SoapMessage = trafficLog.SoapMessage,
                TrafficLogId = trafficLog.TrafficLogId
            };
        }

    }    
   
}


In addition, we need to add the WCF message inspector to our service. I use a ServiceHostFactory and a class implementing ServiceHost class and override the OnOpening method:

        protected override void OnOpening()
        {
            ..


            if (Description.Behaviors.Find<RecordingMessageBehavior>() == null)
                Description.Behaviors.Add(new RecordingMessageBehavior()); 


            base.OnOpening();
        }

Here we register the service behavior for each WCF service to intercept the network traffic, clone the messages as required and log the contents to a database table, effectively gaining a way to get an overview of the requests and responses and to perform security audits, inspections and logging capabilities. You will need to do some adjustments to the code above to make it work against your codebase, but I hope this article is of general interest. The capability of recording WCF network traffic between services and clients is a very powerful feature giving the developer teams more control of their running environments. In addition, this is an important security boost. However, note that in many production environments, huge amounts of data will accumulate. Therefore, this implementation will clear the contents of the traffic log table every 24 hours. The following SQL query is a very convenient one to display data in SQL Management Studio. An XML column can be displayed and read as a documents conveniently.



select top 100 convert(xml, SoapMessage) as Payload, * from trafficlog

Obviously adjusting the Recorded datestamp column critera will pinpoint the returned data from this table more effectively. Retrieving and analysing the data might be problematic, if the amount of data reaches several gigabytes. Here is a powershell to retrieve data in a chunked fashion. Here, the data is being retrieved as 1-minute sized segments, which in a specific case chunked data up into 40 MB sized XML-files. This makes it possible to search the data using a text editor.


Powershell for retrieving traffic log data contents in a chunked fashion


#Traffic Log Bulk Copy Util

$databaseName='MYDATABASE_INSTANCENAME'
$databaseServer='MYDATABASE_SERVER'
$dateStamp = '130415'
$starthours = 12
$minuteSegmentSize = 1
$minuteSegmentNumbers = 160
$dateToInvestigate = '13.04.2015 00:00:00'
$outputFolder='SOMESHARE_UNC_PATH'

Write-Host "Traffic Log Request Bulk Output Logger"


for($i=0; $i -le $minuteSegmentNumbers; $i++){
 $dt = [datetime]::ParseExact($dateToInvestigate, "dd.MM.yyyy hh:mm:ss", $null)
 $hoursToAdd = $i / 60
 $minutesToAdd = $i % 60
 $dt = $dt.AddHours($hoursToAdd + $starthours).AddMinutes($minutesToAdd)
 $dtEnd = $dt.AddMinutes($minuteSegmentSize).AddSeconds(59)
 $startWindow = $dt.ToString("yyyy-MM-dd HH:mm:ss")
 $endWindow = $dtEnd.ToString("yyyy-MM-dd HH:mm:ss")
 $destinationFile = Join-Path -Path $outputFolder $ChildPath 
 $destinationFile += "trafficLog_$dateStamp_bulkcopy_" + $i + ".xml"
 Write-Host $("StartWindow: " + $startWindow + " EndWindow: " + $endWindow + "Destination file: " + $destinationFile)


 $bcpCmd = "bcp ""SELECT SoapMessage FROM TrafficLog WHERE IsRequest=1 AND Recorded >= '$startWindow' and Recorded <= '$endWindow'"" queryout $destinationFile -S $databaseServer -d $databaseName -c -t"","" -r""\n"" -T -x"

  Write-Host $("Bulk copy cmd: ")
  Write-Host $bcpCmd
  Write-Host "GO!"

  Invoke-Expression $bcpCmd

  Write-Host "DONE!"
 
}

By following this article, you should be now ready to write your WCF message inspector and record network traffic to your database, for increased security boost, logging and security audit capabilities and better overview of the raw data involved in the form of SOAP XML. Please read my previous article, if you want to gain insight into how to compress SOAP XML and sending it as binary data (byte arrays), even with GZip compression! Happy coding!