Archive

Archive for the ‘.Net programming’ Category

Connection strings used for logging should not enlist in transactions

April 15th, 2014 No comments

I was just reminded of an old truth when it comes to logging errors in a database: Do not enlist the error logging operation in the current transaction, if there is one! The default is to do just that, so be sure to add Enlist=false in your connection string used for logging:

Example:

  <connectionStrings>
    <add name="myDb" connectionString="..."  providerName="System.Data.SqlClient"/>
    <add name="logging" connectionString="...;Enlist=false"  providerName="System.Data.SqlClient"/>
  </connectionStrings>

If you don’t, then the error logging will be rolled back with the transaction in case of an error. Not so good…

Also note that it’s a good idea to use separate connection strings for the normal database operations (which should be done inside transactions) and the logging operations (that shouldn’t).

Now that I have written this down I will hopefully remember this the next time I do error logging in a database…

/Emil

Fixing CLR trigger error after installing .Net Framework updates

May 25th, 2012 No comments

Today I discovered an error in one of our CLR triggers in a SQL Server database:

System.Data.SqlClient.SqlException: A .NET Framework error occurred during execution of user-defined routine or aggregate "PersonalChangedTrigger": 
System.IO.FileLoadException: Could not load file or assembly 'System.Messaging, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies. Assembly in host store has a different signature than assembly in GAC. (Exception from HRESULT: 0x80131050) See Microsoft Knowledge Base article 949080 for more information.

This was kind of unexpected since we didn’t modify the trigger. It turns out that it was probably a Windows Update patch that modified the System.Messaging assembly so we had to “re-import” it into the database. This is how to do that, in our case:

ALTER ASSEMBLY Messaging
FROM 'C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\System.Messaging.dll'
WITH PERMISSION_SET = UNSAFE

/Emil

Categories: .Net programming, SQL Server Tags:

Enumerating the current user’s NT groups

April 16th, 2012 No comments

Here’s how to enumerate the currently logged in user’s NT groups (local and domain groups):

// Enumerate current user's NT groups
var i = WindowsIdentity.GetCurrent();

// Translate groups from type System.Security.Principal.SecurityIdentifier
// into System.Security.Principal.NTAccount.
var groups = i.Groups.Select(g => g.Translate(typeof(NTAccount)) as NTAccount);

/Emil

Categories: .Net programming Tags:

Queued WCF services

March 7th, 2012 2 comments

Wcf contains a great feature called queued services. This is basically a Wcf binding, netMsmqBinding, that uses MSMQ queues for message transport. It’s very easy to use (once set up) and allows for asynchronous and decoupled communication. It’s useful in several scenarios:

  • Handling load peaks
  • Robustness, if the service is down the messages are queued up in the MSMQ queue and are consumed by the service again when it’s available.

Requirements

The following is required for queued services to work

  • MSMQ must be installed
  • WAS must be enabled and running
  • All service methods must be one-way

How it works

The client adds a service reference using a normal HTTP meta data endpoint and gets a reference to endpoints that are exposed with the netMsmqBinding. The client endpoint’s address is the MSMQ queue to post to in the following Uri format:

<endpoint address="net.msmq://localhost/private/myservice/myservice.svc" binding="netMsmqBinding"  ... />

The client calls the client proxy just like for any other Wcf service:

var client = new MyService.MyServiceClient();
client.MyMethod(...);

The service is hosted in IIS and WAS (Windows Process Activation Service) is used for listening for messages in the queue. When a message is detected, WAS starts the IIS application containing the service that should receive the message. The service then consumes the message using the netMsmqBinding and processes it.

As already mentioned, the exposed service methods must be one-way:

[ServiceContract]
public interface IMyService
{
    [OperationContract(IsOneWay = true)]
    void MyMethod(...);
}

Throttling

If there are many messages in the queue then our service will process many of them in parallel. I think the default number of simultaneous requests is 12 and this may be too much for our service if the reason we’re doing queued services is to handle peak loads. Luckily this is really easy to configure:

<behaviors>
  <serviceBehaviors>
    <behavior name="MsmqWithMex">
      <!-- Expose metadata via HTTP GET. -->
      <serviceMetadata httpGetEnabled="true"/>
  
      <!-- At most 3 concurrent requests are allowed -->
      <serviceThrottling maxConcurrentCalls="3" />
    </behavior>
  </serviceBehaviors>
</behaviors>

Note: Throttling is available in all Wcf bindings, not just the netMsmqBinding.

Setting it all up

So far we have only discussed the implementation of the service, but we also have to do some configuration in the operating system and in IIS:

  • Install Messaging – if this is not already done, then install it
  • Create queue – Wcf relies on that the necessary queues exist. A good pattern is to check for their existence on application startup and create then if they’re missing.
  • Install/configure WAS for MSMQ in IIS – This is probable the hardest step so I’ll describe in detail:
    1. Enable the net.msmq protocol for the site containing the service:
      %windir%\system32\inetsrv\appcmd.exe set site "Default Web Site" -+bindings.[protocol='net.msmq',bindingInformation='localhost']
      

      The result should be that “net.msmq” is included in the list of protocols:

    2. We can also enable the same protocol in the single application containing the Wcf service:
      %windir%\system32\inetsrv\appcmd.exe set app "Default Web Site/DeltagarloggService" /enabledProtocols:http,net.msmq
      

      Make sure that the protocol is added:

  • Make sure that Net Msmq Listener Adapter service is running:

Troubleshooting
If something goes wrong, here are a few tips:

  • Are the Message Queueing and Net Msmq Listener Adapter services running?
  • net.msmq protocol enable on IIS site and application?
  • Messages still in queue? If empty: check dead-letter queues and outgoing queues.
  • Enable msmq journaling
  • Check event log
  • Restart app pool for the service
  • Restart web site
  • If queue is transactional, check the DTC
  • Browse to the service’s svc file. If that consumes the messages it’s a WAS problem.
  • If the service was hosted in Windows Server AppFabric, then see if it has any logged errors.

For more tips, Tom Hollander have written great blog posts about queued service here.

Happy queueing!

/Emil

Categories: .Net programming, WCF Tags: ,

Viewing assembly binding logs using fuslogvw.exe

March 7th, 2012 No comments

Sometimes it’s very useful analyze how an application binds to referenced assemblies but this process is fairly hidden from us. However, Microsoft has given us a way to look into this process via the fuslogvw tool. This tool is not overly documented so this post describes how to install it on a computer that has neither Visual Studio nor the Windows SDK installed, such as a server.

Follow these steps:

Copy the following files from a computer with Visual Studio or the Windows SDK installed:

  • "C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\Bin\FUSLOGVW.exe"
  • "C:\Program Files (x86)\Microsoft SDKs\Windows\v7.0A\Bin\NETFX 4.0 Tools\1033\flogvwrc.dll"

Put them into a folder on the target computer.

Create logging folder, e.g. c:\fuslog

Start FUSLOGVW.exe. Update the following settings:

  • Log all binds to disk
  • Enable Custom log path
  • Custom lag path = c:\fuslog\

Finally, enable assembly binding logging in the registry by setting the HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Fusion to 1.

Click Refresh in FUSLOGVW.exe and behold! A list of assembly binding events are displayed:

The individual events contain useful details:

/Emil

Categories: .Net programming, Tools Tags:

Retrieving the message count for MSMQ queues

December 11th, 2011 3 comments

Sometimes it can be useful to retrieve the number of messages in an MSMQ queue, for example for monitoring. However, it’s not immediately apparent how to do it if you google it, so here are my thoughts on the subject.

Other blog posts suggest iterating over messages (e.g. Counting Messages in an MSMQ MessageQueue from C#) or doing it using WMI. WMI is the best alternative in my opinion and if you want a quick way of doing it then PowerShell is the easiest:

$queues = Get-WmiObject Win32_PerfFormattedData_msmq_MSMQQueue
$queues | ft -property Name,MessagesInQueue

The result will be something similar to this:

Name                                                         MessagesInQueue
----                                                         ---------------
active714\private$\notify_queue$                                           0
active714\private$\deltagarloggservice\deltagarloggservi...                0
active714\private$\order_queue$                                            0
active714\private$\admin_queue$                                            0
Computer Queues                                                           27

This can also be done on remote machines:

$host = ...
$cred = get-credential
$queues = Get-WmiObject Win32_PerfFormattedData_msmq_MSMQQueue -computer $host -credential $cred
$queues | ft -property Name,MessagesInQueue

The Get-Credential Cmdlet will display a login dialog which is fine in interactive sessions but if you need to set the credentials in a non-interactive script, then the tip in this blog post might help: PowerShell – How to create a PSCredential object.

Retrieving message counts from code takes a little more coding but here’s an example in C# that searches for a given queue and returns its message count:

private static int GetMsmqMessageCount(string queuePath, string machine,
  string username, string password)
{
  var options = new ConnectionOptions
    {Username = username, Password = password};
  var path = string.Format(@"\\{0}\root\CIMv2", machine);
  var scope = new ManagementScope(path, options);
  scope.Connect();

  string queryString = 
    String.Format("SELECT * FROM Win32_PerfFormattedData_msmq_MSMQQueue WHERE Name = '{0}'",
	  queuePath);
  var query = new ObjectQuery(queryString);

  var searcher = new ManagementObjectSearcher(scope, query);

  IEnumerable<int> messageCountEnumerable = 
    from ManagementObject queue in searcher.Get()
    select (int) (UInt64) queue.GetPropertyValue("MessagesInQueue");

  return messageCountEnumerable.First();
}

This code also uses WMI but this time we do a query rather than enumerate all queues.

The above snippets has worked well for us so I felt it would be useful to post them here. Please leave a comment if you have issues with them or suggestions for improvement!

/Emil

Detecting unhandled errors in ASP.Net applications

September 9th, 2011 No comments

For my own reference, here’s how to detect unhandled exceptions in Global.asax:

protected void Application_Error(object sender, EventArgs e)
{
  // Log error
  Exception ex = Server.GetLastError().GetBaseException();
  string msg = String.Format("Ohanterat fel!\r\nAdress: {0}\r\nFelmeddelande: {1}", Request.Url, ex.Message);
  LogHelper.Error(msg, ex);

  Server.ClearError();

  // Display simple error page
  Response.Write("Ett oväntat fel har inträffat...\r\n");
  Response.Write("<br/>\r\n<pre>\r\n");
  Response.Write(ex.ToString());
  Response.Write("<br/>\r\n</pre>\r\n");
  Response.End();
}

We mostly do it like this, if you have a better suggestion, please post a comment :-)

/Emil

log4net configuration examples

August 17th, 2011 1 comment

Almost every application requires, or at least benefits greatly from, some kind of logging of events and errors. I suspect all of us have written custom code for logging to text files, database tables, the event log and other formats. We all know that we shouldn’t do this since there are several frameworks out there to help us, such as Microsoft’s own Tracing functionality, NLog and log4net. The obstacle to using them is often that it can be difficult to know how to configure them to work properly which is why this post will describe a set of configuration examples for log4net to make that framework do it’s magic.

For those of you new to log4net it’s a really useful package but somewhat difficult to configure, which is what I will try to help with in this post. I will not try to write a tutorial for it since others have already done so. Instead I will show a set of confiuration examples I personally find useful.

To use log4net, you need to add a reference to log4net.dll. Then a new section in the application’s config file must be added:

<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />

Log4net logging is based on a provider-like design where each type of logging is done in a so called appender. There are appenders for file system files, databases, etc. and it’s in these appenders that log4net’s power lies.

To configure which appenders to use it easiest to use the root configuration element like this:

<log4net>
  ...
  <root>
    <level value="Debug"/>
    <appender-ref ref="ColoredConsoleAppender"/>
    <appender-ref ref="RollingFileAppender"/>
  </root>
</log4net>

We haven’t configured the referenced appenders yet, so that is the next step. The remainder of the post will be about some of the appenders that comes with log4net.

APPENDERS

Colored console appender
This appender is very useful for console applications and enables different types of events (debug, info, error, etc) to be displayed in different colors.

Here’s how to configure it:

    <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
      <mapping>
        <level value="ERROR"/>
        <foreColor value="Red, HighIntensity"/>
      </mapping>
      <mapping>
        <level value="INFO"/>
        <foreColor value="White"/>
      </mapping>
      <mapping>
        <level value="DEBUG"/>
        <foreColor value="Green"/>
      </mapping>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-5level - %message%newline"/>
      </layout>
    </appender>

RollingFileAppender
This appender is used to write to a file while limiting the file size. When the maximum file size is reached then a new file is created which means that no log file will be unmanagably large.

    <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
      <file value="d:\Logs\WorkflowAborter.log"/>
      <rollingStyle value="Size" />
      <appendToFile value="true"/>
      <maximumFileSize value="2000KB"/>
      <maxSizeRollBackups value="5"/>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %identity %property{log4net:HostName}: %message%newline%exception"/>
      </layout>
    </appender>

The maxSizeRollBackups setting controls how many files will be created before the first one is deleted.

You can control when log4net creates a new file (rolls the file) by setting the rollingStyle attribute. It’s default setting is Composite which combines date and size limitations, whichever occurs first, to decide when a new file is created. The other possible values are Size and Date which are self-explanatory, and Once which creates a new log file for every time the application is executed.

Note however that, for some reason, the maxSizeRollBackups setting does not work when using Composite or Date so the number of files cannot be limited in when using those settings.

NetOutputDebugStringAppender

Logs events using the OutputDebugString Win32 API call whose output is shown in the Visual Studio output window. The appender is also useful in deployed applications since the output is captured by Mark Russinovich’s DebugView tool. (Just remember to enable “Capture Global Win32” setting of DebugView first, or else nothing will be displayed!)

    <appender name="NetOutputDebugStringAppender" type="log4net.Appender.OutputDebugStringAppender" >
      <layout type="log4net.Layout.PatternLayout">
        <param name="ConversionPattern" value="Butler: [%t] %-5p - %m%n" />
        <!--<conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />-->
      </layout>
    </appender>

NetTraceAppender

This appender logs to the Microsofts standard tracing framework in .Net. In Visual Studio, output is shown in the output window by default and for deployed applications it’s possible to configure the tracing to store events in different destinations. The appender could be useful if parts of an application is using the tracing framework and other parts are using log4net since it makes it possible to channel all events through the same framework (trace) but this is probably not used very often.

A more useful side effect is that many test runners (e.g. nUnit and ReSharper’s built-in test runner) captures trace calls and stores them with the test result making test failure analysis much easier.

Screen shot of ReSharper with log4net trace output

Configuration:

    <!-- Logga till .Net trace-listeners, t.ex- Outputfönstret i Visual Studio...-->
    <!-- Hamnar i output-fönstret om körs i VS, kan annars visas i DebugView -->
    <appender name="NetTraceAppender" type="log4net.Appender.TraceAppender, log4net">
      <layout type="log4net.Layout.PatternLayout,log4net">
        <param name="ConversionPattern" value="%d [%t] %-5p - %m%n" />
      </layout>
    </appender>

SmtpAppender
This appender is often overlooked, I have at least not seen many references to using it. It’s very useful for sending mail when an error occurs:

<appender name="SmtpAppender" type="log4net.Appender.SmtpAppender">
  <to value="foo@foobar.se, bar@foobar.se" />
  <from value="helpdesk@foobar.se" />
  <subject value="Error occured in MyApp" />
  <smtpHost value="smtp.foobar.se" />
  <bufferSize value="512" />
  <lossy value="true" />
  <evaluator type="log4net.Core.LevelEvaluator">
  	<threshold value="WARN"/>
  </evaluator>
  <layout type="log4net.Layout.PatternLayout">
  	<conversionPattern value="%n%d %-5level [%t] - %m" />
  </layout>
</appender>

Using configuration similar to the above, a mail such as the following is sent when a WARN or ERROR log occurs:

2011-02-04 03:00:06,958 INFO  [1] - ###############################################
2011-02-04 03:00:07,328 INFO  [1] - Startar...
2011-02-04 03:00:07,362 INFO  [1] - ###############################################
2011-02-04 03:00:07,429 INFO  [1] - Läser upp kursdeltagare 
2011-02-04 03:00:31,265 INFO  [1] - 6437 ska bearbetas.
2011-02-04 03:21:17,153 INFO  [1] - Timmar per vecka omräknade
2011-02-04 03:21:17,263 INFO  [1] - Tidsåtgång timmar per vecka: 00:21:09
2011-02-04 03:21:17,278 INFO  [1] - ----------------------------------------------------------------------------
2011-02-04 03:21:17,479 INFO  [1] - Läser upp kursdeltagare 
2011-02-04 03:22:08,793 INFO  [1] - 26532 ska bearbetas.
2011-02-04 04:10:28,050 ERROR [1] - Kunde inte ändra preliminärt slutdatum för timpott för sfi kd 24085 (Butler kd 83237)

Note that the 10 events prior to the ERROR event that triggered the mail is also included which makes error analysis very much easier.

MemoryAppender
This appender is useful for automated tests.

<appender name="unitTestMemoryAppender" type="log4net.Appender.MemoryAppender">
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] %-5level %identity %property{log4net:HostName} %logger: %message%newline%exception"/>
  </layout>
</appender>

To create unit tests that checks whether logging is performed correctly, code such as this can be used:


using ActiveSolution.Lernia.Utils.Logging;
using log4net;
using log4net.Appender;
using log4net.Core;
using log4net.Repository.Hierarchy;
using NUnit.Framework;

namespace UtilsTests
{
    [TestFixture]
    public class LoggingTests
    {
        [SetUp]
        public void SetUp()
        {
            var appender = GetAppender();
            if (appender != null)   // Appender kommer vara null om inet loggats ännu.
            {
                appender.Clear();
            }
        }

        [Test]
        public void Logger_ErrorFormat_WithException_ShouldLogMessage()
        {
            // Arrange -----------------------------
            var ex = new ArgumentNullException("foo");

            // Act ---------------------------------
            LogHelper.ErrorFormat(ex, "Oväntat fel för id = {0}", 42);    // Call custom wrapper function for log4net

            // Assert ------------------------------
            var loggedEvents = GetLoggedEvents();
            Assert.That(loggedEvents.Length, Is.EqualTo(1));
            Assert.That(loggedEvents[0].RenderedMessage, Contains.Substring("Oväntat fel för id = 42"));
            Assert.That(loggedEvents[0].RenderedMessage, Contains.Substring("Value cannot be null"));
            Assert.That(loggedEvents[0].RenderedMessage, Contains.Substring("Parameter name: foo"));
        }

        private static LoggingEvent[] GetLoggedEvents()
        {
            MemoryAppender ma = GetAppender();
            return ma.GetEvents();
        }

        private static MemoryAppender GetAppender()
        {
            var h = LogManager.GetRepository() as Hierarchy;
            return h.Root.GetAppender("unitTestMemoryAppender") as MemoryAppender;
        }
    }
}

AdoAppender

The AdoAppender is used to store events in a database. Here’s a configuration example for using a stored procedure to store the events:

<appender name="ErrorHandlerAppender" type="log4net.Appender.AdoNetAppender">
  <filter type="log4net.Filter.LevelRangeFilter">
    <param name="LevelMin" value="WARN" />
  </filter>

  <bufferSize value="1" />
  <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" />
  <connectionString value="Data Source=XXXXXXXXX;Initial Catalog=Errorhand;User ID=XXX;Password=XXX" />
  <commandType value="StoredProcedure" />
  <commandText value="ap_errorhandler_ins" />

  <parameter>
    <parameterName value="@APPLICATIONID" />
    <dbType value="String" />
    <size value="16"/>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="Butler.EducationSI" />
    </layout>
  </parameter>

  <parameter>
    <parameterName value="@USERID" />
    <dbType value="String" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%identity" />
    </layout>
  </parameter>

  <parameter>
    <parameterName value="@SEVERITY" />
    <dbType value="String" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%level" />
    </layout>
  </parameter>

  <parameter>
    <parameterName value="@DESCRIPTION" />
    <dbType value="String" />
    <size value="4000"/>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%message%newline%exception" />
    </layout>
  </parameter>

  <parameter>
    <parameterName value="@LOCAL_ADDR" />
    <dbType value="String" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%property{log4net:HostName}" />
    </layout>
  </parameter>
  <parameter>
    <parameterName value="@REMOTE_ADDR" />
    <dbType value="String" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%property{log4net:HostName}" />
    </layout>
  </parameter>
</appender>

The configuration segment for AdoAppenders tend to be rather long but the example is fairly self explaining. For more so called “conversionPattern fields” to use in parameters, look here. These are the same fields used in the other appenders to format the log strings. There’s quite a lot of interesting data that can be retrieved so make sure to have a look at the list.

FILTERING

Another powerful feature of log4net is the possibility of filtering. For example, if you’re referencing a 3rd party assembly such as NHibernate.dll that logs its events using log4net then those events can be configured separately like this:

<logger name="NHibernate">
  <level value="Error" />
</logger>

This tells log4net that DEBUG and INFO events from NHibernate should be ignored. The logger name is a string with the start of the logger names the filter should match. Other loggers can be configured in the same way and loggers that aren’t configured fall back to the root logger we defined in the beginning of this post.

TROUBLESHOOTING

Q: What do you do when having trouble with log4net logging?
A: You enable internal logging!

<appSettings>
  <add key="log4net.Internal.Debug" value="true"/>
</appSettings>

Note that these events are logged using the System.Diagnostics.Trace system so that may have to be configured as well. For more info about internal logging, see here.

That’s all for now. I’ll keep updating this post when I find more interesting settings.

/Emil

Assembly version redirection

June 30th, 2011 No comments

Here’s how to redirect an assembly reference from one version (or version interval) to another:

  <runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
      <dependentAssembly>
        <assemblyIdentity name="log4net" publicKeyToken="b32731d11ce58905" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-65535.65535.65535.65535" newVersion="1.2.10.0"/>
      </dependentAssembly>
    </assemblyBinding>
  </runtime>

Note that for this to work, put it as early in your config file as possible since it must occur before the assemblies are referenced. Also note that both the new and old version of the assembly must have the same public key token, if they don’t you’ll get a System.IO.FileNotFoundException during binding.

/Emil

Categories: .Net programming Tags:

Retrieving domain information in Powershell

March 17th, 2011 No comments

Here’s how to retrieve the current domain:

[reflection.assembly]::loadwithpartialname("System.DirectoryServices")
[System.DirectoryServices.ActiveDirectory.Domain]::GetComputerDomain()

The result is a System.DirectoryServices.ActiveDirectory.Domain object:

Forest                  : i.activesolution.se
DomainControllers       : {ACTIVESERVER101.i.activesolution.se, ACTIVESERVER102.i.activesolution.se}
Children                : {}
DomainMode              : Windows2008R2Domain
Parent                  :
PdcRoleOwner            : ACTIVESERVER102.i.activesolution.se
RidRoleOwner            : ACTIVESERVER102.i.activesolution.se
InfrastructureRoleOwner : ACTIVESERVER102.i.activesolution.se
Name                    : i.activesolution.se

/Emil

Switch to our mobile site

Web Analytics