Kelly's Space

Coding 'n stuff

Category Archives: Uncategorized

Configuring Event Log Permissions in C#

In NetCOBOL, programs can be configured so that errors are written to the Application event log through the environment variable @CBR_MESSAGE=EVENTLOG.  We set this for all COBOL program steps in NeoBatch automatically, but sometimes the user accounts do not have appropriate permissions to write to the event log.  There is no easy way to configure the event log to adjust permissions, you have to use a special registry key with an SDDL string.

SDDL strings (MSDN doc: http://msdn.microsoft.com/en-us/library/aa379567(v=VS.85).aspx) can be a pain to generate by hand.  Luckily the .NET framework comes to the rescue through the RegistrySecurity class.  It has the ability to initialize itself from an SDDL string and return and SDDL string after it has been configured.

To modify permissions of the event log, you need to create a string value called “CustomSD” under the named event log key in HKLM\SYSTEM\CurrentControlSet\Services\EventLog\.  In the case of the application event log, the key would be under “HKLM\SYSTEM\CurrentControlSet\Services\EventLog\Application”.  The value of the CustomSD key is an SDDL string.

I’ve written a C# program that takes the log name and user name as parameters, and creates and sets the CustomSD key so the user can write to the event log.  Below is the code:

using System;
using System.Collections.Generic;
using System.Text;
using System.Security.Principal;
using Microsoft.Win32;
using System.Security.AccessControl;

namespace EventLogAccessTool
{
    class Program
    {
        static void Main(string[] args)
        {
            string usage = @"Event Log Access Tool
Usage: EventLogAccessTool <logname> <user>
Where:   logname    - Name of the Windows event log, e.g., Application
         user       - User account (or group) to change access for
         ";
            if (args.Length != 2)
            {
                Console.Error.WriteLine(usage);
                return;
            }

            string logName = args[0];
            if (logName.Trim().Length == 0)
            {
                Console.Error.WriteLine("Invalid logname specified");
                Console.Error.WriteLine(usage);
                return;
            }

            string userAccount = args[1];
            if (userAccount.Trim().Length == 0)
            {
                Console.Error.WriteLine("Invalid user account specified");
                Console.Error.WriteLine(usage);
                return;
            }

            try
            {
                string keyName = @"SYSTEM\CurrentControlSet\Services\EventLog\" + logName;

                using (RegistryKey eventLogKey = Registry.LocalMachine.CreateSubKey(keyName, RegistryKeyPermissionCheck.Default))
                {
                    string existing = eventLogKey.GetValue("CustomSD") as string;
                    if (existing == null)
                    {
                        existing = "O:BAG:SY";  // Owner is built-in administrators and system
                    }
                    else
                    {
                        Console.WriteLine("Existing SDDL is: " + existing);
                    }

                    // We'll use the RegistrySecurity class for creating the SDDL string.
                    // Initialize it with the existing SDDL string.
                    RegistrySecurity acl = new RegistrySecurity();
                    acl.SetSecurityDescriptorSddlForm(existing);

                    // Add the user account so it can query values and set values 
                    // so that it can read and write to the event log
                    RegistryAccessRule ace = new RegistryAccessRule(userAccount, 
                        RegistryRights.QueryValues | RegistryRights.SetValue, 
                        AccessControlType.Allow);

                    acl.AddAccessRule(ace);

                    string newSDDL = acl.GetSecurityDescriptorSddlForm(AccessControlSections.All);
                    
                    Console.WriteLine("New SDDL is: " + newSDDL);
                    // Write out the new SDDL in the CustomSD string value.
                    eventLogKey.SetValue("CustomSD", newSDDL);
                }
            }
            catch(Exception e)
            {
                Console.Error.WriteLine("An error occurred: " + e.Message);
                return;
            }

            Console.WriteLine("Successfully updated the registry");
        }
    }
}

In the event that the event log security gets messed up, simply delete the CustomSD key.

Diagnosing a Resource Leak

We had a customer report an issue with their NeoKicks converted application, where NeoData was apparently exhausting pooled SQL connections.  It certainly seemed odd, given the fact that their load was relatively low.  To help us debug, we had them create a crash dump of IIS using the Debug Diagnostic Tool from Microsoft

Once I got a crash dump, I fired up Windbg, attached to the crash dump, and loaded SOS by issuing:

.loadby sos mscorwks

Since this is a .NET solution and the error was related to running out of pooled connections, I could dump the objects with references (that the GC won’t collect) using !dumpheap

Glancing through the output, I found the following:

image

The highlighted number above is the count of the object for each type.  The reason this one in particular is odd is that the WorkerSession object represents a current, running transaction.  The WorkerSession object contains things like open file handles, etc.  If there are 525 active transactions with each containing a few NeoData files, then it is certainly possible the SQL connection pool is exhausted.  Since this server wasn’t under a lot of load (just had been running for a while), 525 seems way too high.  I would expect this to be in the 1-10 range.  Luckily, we can dig in a little deeper to see who has a reference to these objects in Windbg. 

The next step is to get more information about each one of these objects.  You can use:

!dumpheap -type Alchemy.NeoKicks.WorkerSession

to dump out the references to that object type. 

image

I’ve highlighted the address for one of the objects in the listing from !dumpheap.  I just picked one at random.  I want to find out what has references to this object, to see what might be preventing this object from being garbage collected.  To do this, I use the following:

!gcroot 000000016fa53470

image

I looked at a few other objects (again, using !gcroot) and found that they were all being ultimately held by a System.Threading._TimerCallback object. 

This was getting interesting!  Why in the world would a TimerCallback object have a reference to my WorkerSession object?  I decided it was time to go looking through our NeoKicks code to see where a TimerCallback was used.  It turns out, a WorkerSession object can contain a Timer object that is used when a CICS START is issued so that the transaction will execute on a thread pool thread (and optionally on a time interval).  These objects should have gotten cleaned up by the GC, since these tasks run immediately and return.

I decided to look through the documentation for Timer objects in the MSDN documentation and found the following:

“When a timer is no longer needed, use the Dispose method to free the resources held by the timer.”

Now we’re getting somewhere.  Sure enough, although we implement IDisposable for the WorkerSession object, we were not calling Dispose on the Timer object.  I added the Dispose() call, and re-ran a test that reproduced the problem and the issue went away.

The moral of this story – if you are using System.Threading.Timer objects in your code, you must call Dispose() on the object when you’re done.  Otherwise, you will end up with a memory leak!

JIT debugging in Windows Server 2008 R2

I have my development machine configured with Windows Server 2008 R2 (which is a great desktop OS) but certain Just-In-Time debugging scenarios that worked in previous OS versions do not work out of the box in Server 2008 R2.  Consider the following code:

        static void Main(string[] args)
        {
            if (args.Length == 1 && string.Compare(args[0], "/debug", true) == 0)
            {
                System.Diagnostics.Debugger.Break();
            }
        }

Under Server 2008 R2, this doesn’t launch the JIT debugger dialog.  If the Debugger.Break() is changed Debugger.Launch(), then the dialog is displayed. 

Another scenario that fails to show the JIT debugger is when you have an unhandled exception.  Instead of raising the JIT debugger dialog when an unhandled exception occurs, the system would just return. 

The root cause of this behavior turns out to be Windows Error Reporting (WER) getting in the way.   If you look at the registry key HKLM\SOFTWARE\Microsoft\Windows\Windows Error Reporting, there is value for DontShowUI that is set to 1.  Changing this value to zero will result in a dialog like this being displayed:

I should also point out that I have Visual Studio, so I have JIT debuggers registered.  If you have the DontShowUI set, then the Debugger.Break() will also work again. 

Unexplained failures running debug x64 builds

I was getting random null reference exceptions with a vanilla NetCOBOL for .NET COBOL program.  I tracked it down to a weird behavior in which the .NET runtime was losing my byte array reference inside of an internal struct.  It would be valid before a call to a method, but then upon return the array was empty.  I created a C# sample unrelated to COBOL in C# and sent it to Microsoft.  Apparently, there is a bug introduced in .NET Framework 3.5 SP1.  It is also fixed in .NET Framework 4.0.  The KB article is 974168.

If you are running x64, using NetCOBOL for .NET, and compiling as debug then there is a high probability that you will experience this problem.  Make sure to have the hotfix applied!  You can request it here: http://support.microsoft.com/kb/974168.

Missing performance counters on x64 – Fix!

I’ve noticed on x64 versions of Windows that performance counter information gets corrupted for apparent reason.  I have seen it happen on a clean machine, right after installing custom performance counters using installutil and a custom .NET performance counter installer class. 

The symptoms are that if you start up perfmon you might get an error saying “MMC failed to initialize the snap-in”, or you might find that certain perf counters are missing (like ones in the Processor category).  In the past, I have resolved problems like this by running lodctr /R from the command line.  This instructs Windows to rebuild the performance counters using the backup perf database that it maintains. 

I had a case today where this approach didn’t work.  I went digging through the registry, and started searching for “Disable Performance Counters” in HKLM\SYSTEM\CurrentControlSet\Services using the Find dialog.  I found there were several entries with a hex value 4 or 1 listed.  I changed all the occurrences of that key to 0, and it fixed the problem!

Random process hangs while reading output

I’ve been debugging an intermittent problem that occurs under load where launched processes exit and threads reading the output from the process hang while reading the output.  Below is a common snippet of code to launch a process, and redirect the output to separate threads (to avoid deadlock that occurs if the client process fills the output buffer and cannot exit because the host process isn’t reading the pipe):

        public void LaunchProgram(string programName)
        {
            Process p = new Process();
            ProcessStartInfo psi = new ProcessStartInfo();
            psi.FileName = programName;

            psi.CreateNoWindow = true;
            psi.WindowStyle = ProcessWindowStyle.Hidden;
            psi.RedirectStandardError = true;
            psi.RedirectStandardOutput = true;
            psi.UseShellExecute = false;
            psi.RedirectStandardInput = false;
            psi.WorkingDirectory = Directory.GetCurrentDirectory();
            p.StartInfo = psi;
            p.Start();

            OutputReader stdOutReader = new OutputReader(p.StandardOutput);
            Thread stdOutThread = new Thread(new ThreadStart(stdOutReader.ReadOutput));
            stdOutThread.Start();
            OutputReader stdErrReader = new OutputReader(p.StandardError);
            Thread stdErrThread = new Thread(new ThreadStart(stdErrReader.ReadOutput));
            stdErrThread.Start();

            p.WaitForExit();

            stdOutThread.Join();
            stdErrThread.Join();
        }

 

The OutputReader class looks like this:

    public class OutputReader
    {
        StreamReader stream;

        public OutputReader(StreamReader stream)
        {
            this.stream = stream;
        }

        public void ReadOutput()
        {
            string line = null;

            while ((line = stream.ReadLine()) != null)
            {
                // do something with the output
            }
        }
    }

The problem occurs when the LaunchProgram method is called in a multithreaded app. 

The core issue is that the Process class creates pipes for redirecting the output using CreatePipe and then calls CreateProcess with the inheritHandles parameter set to true.  Under load there is a race condition where a process can inherit handles that it shouldn’t.  In the case I was debugging, each of the programs were synchronizing with a database for shared resources that were only released when the process exited.  Since another process had a copy of the pipes the OutputReader thread was still waiting for data to come in because there was still an open pipe handle on the other side.  The other executable was deadlocked because it was waiting for shared resources held by the first process.

The fix for this is to make sure that the CreatePipe and CreateProcess calls happen synchronously in a process.  An easy fix is to add a static lock object, and lock it before the call to p.Start().  That is:

static object ProcessLockObj = new object();

public void LaunchProgram(string programName)
        {
            Process p = new Process();
            ProcessStartInfo psi = new ProcessStartInfo();
            psi.FileName = programName;

            psi.CreateNoWindow = true;
            psi.WindowStyle = ProcessWindowStyle.Hidden;
            psi.RedirectStandardError = true;
            psi.RedirectStandardOutput = true;
            psi.UseShellExecute = false;
            psi.RedirectStandardInput = false;
            psi.WorkingDirectory = Directory.GetCurrentDirectory();
            p.StartInfo = psi;

            lock (ProcessLockObj)
            {
                p.Start();
            }

            OutputReader stdOutReader = new OutputReader(p.StandardOutput);
            Thread stdOutThread = new Thread(new ThreadStart(stdOutReader.ReadOutput));
            stdOutThread.Start();
            OutputReader stdErrReader = new OutputReader(p.StandardError);
            Thread stdErrThread = new Thread(new ThreadStart(stdErrReader.ReadOutput));
            stdErrThread.Start();

            p.WaitForExit();

            stdOutThread.Join();
            stdErrThread.Join();
        }

The problem can also manifest itself if you are not using the Process class, but are calling CreateProcess directly.  If you are doing this, then make sure that you place CreateProcess and the CreatePipe calls in a critical section.

Lots of debugging and searching narrowed down the problem, and then the following article explained what was going on: http://support.microsoft.com/kb/315939

Improving cursor performance

In NetCOBOL for .NET v3.1 you can get fast forward, read-only cursors provided you configure the ODBC settings in your configuration file accordingly.  By default, all cursors will be read only.  Unfortunately, many people use cursors for updating as well, and usually get this to work by changing the @SQL_CONCURRENCY option to something other than READ_ONLY.  This option will affect all cursors in the application, and turn read only cursors into dynamic ones (which perform much slower than their read only counterparts).

You can get around this by using SQL Options in the NetCOBOL configuration section.  Basically you create two options, one for read only cursors, and the other for updatable cursors.  Then, set the @SQL_ODBC_CURSOR_DEFAULT and @SQL_ODBC_CURSOR_UPDATE settings to point to these two options so that NetCOBOL can pick the correct SQL Option depending on the cursor type.  You are probably asking: How does it know what type the cursor is?  The answer is that it looks for the FOR UPDATE clause in the cursor declaration.  In order for this setup to work, you will need to change all of the cursor declarations for any cursor that is used for updating.

Here’s a sample of what your SQL settings might look like:

   1: <sqlSettings>
   2:     <sqlOptionInf>
   3:         <option name="OPTION1" description="Read Only Cursor Settings
   4:             <add key="@SQL_CONCURRENCY" value="READ_ONLY" />
   5:             <add key="@SQL_ROW_ARRAY_SIZE" value="1" />
   6:             <add key="@SQL_CURSOR_TYPE" value="FORWARD_ONLY" />
   7:         </option>
   8:         <option name="OPTION2" description="Update cursor settings">
   9:             <add key="@SQL_CONCURRENCY" value="ROWVER" />
  10:             <add key="@SQL_ROW_ARRAY_SIZE" value="1" />
  11:             <add key="@SQL_CURSOR_TYPE" value="DYNAMIC" />
  12:         </option>
  13:     </sqlOptionInf>
  14:     <connectionScope>
  15:         <add key="@SQL_CONNECTION_SCOPE" value="THREAD" />
  16:     </connectionScope>
  17:     <serverList>
  18:         <server name="SERVER1" type="odbc" description="SERVER1">
  19:             <add key="@SQL_DATASRC" value="VidRent" />
  20:             <add key="@SQL_USERID" value="" />
  21:             <add key="@SQL_PASSWORD" value="" />
  22:             <add key="@SQL_ODBC_CURSOR_DEFAULT" value="OPTION1" />
  23:             <add key="@SQL_COMMIT_MODE" value="MANUAL" />
  24:             <add key="@SQL_ODBC_CURSOR_UPDATE" value="OPTION2" />
  25:         </server>
  26:     </serverList>
  27:     <sqlDefaultInf>
  28:         <add key="@SQL_SERVER" value="SERVER1" />
  29:         <add key="@SQL_USERID" value="video" />
  30:         <add key="@SQL_PASSWORD" value="AGMEJJBJKNFPGMAOBPNE" />
  31:     </sqlDefaultInf>
  32: </sqlSettings>

Here is a sample SQL cursor declaration for an updatable cursor:

   1: EXEC SQL DECLARE VIDCUSTBR CURSOR FOR                     
   2:     SELECT                                                   
   3:       VIDEO_NUMBER,
   4:       TITLE,
   5:       MEDIA_TYPE,
   6:       STATUS,
   7:       CUSTOMER_NUMBER,
   8:       DATE_OUT                                     
   9:     FROM                                                     
  10:       VIDMAST                                         
  11:     WHERE                                                    
  12:        CUSTOMER_NUMBER = :CM-CUSTOMER-NUMBER 
  13:     FOR UPDATE                                
  14: END-EXEC.
  15:    

cscript error when running under a non-interactive user session

If you are launching cscript on behalf of a user using a delegated token or by creating a token via LogonUser on a server that the user has never interactively logged on before, you will probably get an error like "Loading your settings failed. (Access is denied)."

This problem is caused by not having the Windows Scripting Host registry settings in the users HKCU registry hive. You can solve this for all users by adding the following keys:

HKEY_USERS\.DEFAULT\Software\Microsoft\Windows Scripting Host\Settings\
HKEY_USERS\.DEFAULT\Software\Microsoft\Windows Script Host\Settings\

You’ll want to make sure that the users also have read access to these keys as well.