You’ve got to restart that process …

… in order to pick up the changes you’ve recently made to the environment variables.

Alright, to cut a long story short, I’m using the Microsoft Natural Ergonomic Keyboard at work. It has these (5) ‘My Favorits’ keys on top to which you can assign custom commands. I typically make heavy use of that to

  1. Start a new console for the build environment
  2. Start PowerShell
  3. Start a lightweight editor with syntax hightlighting for many file types
  4. Start PaintDotNet
  5. Start a new (blank) console

I typically use #5 for checking out small things and starting remote user debugging sessions. From time to time, I tweak the environment a little bit by adding new environment variables or modifying existing ones (like e.g. adding new places to the %PATH% environment variable). To verify, I use the command line. Except that existing processes don’t automatically get the new variables. I was recently tricked by this, since I pressed #5 to get a new console and test the changes. Nothing there. Hmmm. When I start %COMSPEC% they are there. So why not with #5?

Well, the process which starts #5 was started when the changes to the environment variables where not yet made. That’s why also the processes started from this process don’t have the changes. So all I’ve got to do in this case is to kill itype.exe and then start it right away again. Now it works!

PowerShell Script to trace OCS Components

Tracing OCS components may be vital in troubleshooting various issues you may face in your deployment. On machines where you have OCS components installed, you’ll typically find a tool called OCSLogger.exe which allows you to start/stop/view traces of OCS components. However, sometimes this is not enough, for instance when you see problems at the startup of a machine. It’s kind of hard to run the GUI if you cannot logon yet. But you can typically run a scheduled task. Or maybe you are — just like me — more like the console guy and thus want to have a script/cmdline tool for everything.

Let’s start with the config file used by the script (TraceConfig.xml) which defines the components you want to trace, to what level the traces are supposed to be and some more things. The sample given here traces mostly the components which are useful in troubleshooting issues related to the Response Group Service of OCS.

<?xml version="1.0" encoding="utf-8"?>
<Config>
    <!--
        Levels:
            TL_FATAL        1
            TL_ERROR        2
            TL_WARN         3
            TL_INFO         4
            TL_VERBOSE      5
            TL_NOISE        6

        Flags:
            TF_COMPONENT    0x00000001
            TF_PROTOCOL     0x00000002
            TF_CONNECTION   0x00000004
            TF_SECURITY     0x00000008
            TF_DIAG         0x00000010
            TF_AUTH         0x00000020
            TF_PARSE        0x00000040
            TF_NETWORK      0x00000080
            TF_STACKTRACE   0x00000100
    -->
    <Default Level="6" Flags="0xffff" />
    <Paths Tracer="C:\Program Files\Common Files\Microsoft Communications Server 2007 R2\Tracing"
           Etl="D:\Tracing"
           Log="D:\Tracing"
           TmfSearchPath="C:\Program Files\Common Files\Microsoft Communications Server 2007 R2\Tracing">
    </Paths>
    <Components>
        <Component Name="LcsWMI" Enabled="no" />
        <Component Name="LcsWMIUserServices" Enabled="no" />

        <Component Name="PowerShell" Enabled="yes" />

        <Component Name="ApplicationServer" Enabled="yes" />

        <Component Name="RgsClientsLib" Enabled="yes" />
        <Component Name="RgsCommonLibrary" Enabled="yes" />
        <Component Name="RgsDatastores" Enabled="yes" />
        <Component Name="RgsDeploymentApi" Enabled="yes" />
        <Component Name="RgsDeploymentLibrary" Enabled="yes" />
        <Component Name="RgsDiagnostics" Enabled="yes" />
        <Component Name="RgsHostingFramework" Enabled="yes" />
        <Component Name="RgsMatchMakingService" Enabled="yes" />
    </Components>
</Config>

I added the most importan trace levels and flags in the comment. Right now, the Default element defines the levels and flags for all components, but there’s no reason why you shouldn’t be able to do that per component you want to trace.

The PS1 script itself (Tracer.ps1) heavily relies on the OcsTracer.exe tool which also comes with OCS and is typically installed in the same place as OcsLogger.exe. It has four main actions:

  1. Start tracing components
  2. Stop tracing components and format the traces
  3. Format traces of ETL files (e.g. from a different machine)
  4. Show the configuration details from a particular config XML file
<#
.SYNOPSIS
        Starts or Stops tracing of Office Communications Server components.
.DESCRIPTION
        Starts or Stops tracing of Office Communications Server components.
.PARAMETER Action
        The action to perform. Must be one of 'Start', 'Stop', 'Config' or
        'Format'.
.PARAMETER ConfigPath
        The path to the configuration XML file. If not specified,
        "TraceConfig.xml" is used.
.LINK
        This script was originally posted to
        http://www.cymbeline.ch/post/2009/12/11/PowerShell-Script-to-trace-OCS-Components.aspx
.EXAMPLE
        .\Tracer.ps1 Start

        Starts tracing all the enabled components from the "TraceConfig.xml" file.
.EXAMPLE
        .\Tracer.ps1 Stop

        Stops tracing all the enabled components from the "TraceConfig.xml" file
        and formats the traces.
.EXAMPLE
        .\Tracer.ps1 Format "MyOtherConfig.xml"

        Formats the traces of the enabled components from the "MyOtherConfig.xml"
        file with all the settings from the "MyOtherConfig.xml" file.
.EXAMPLE
        .\Tracer.ps1 Config

        Shows the configuration of the "TraceConfig.xml" file.
#>
param(
    [Parameter(Mandatory=$true)]
    [ValidateSet("Start", "Stop", "Config", "Format", IgnoreCase=$true)]
    [String] $Action,
    [String] $ConfigPath = "TraceConfig.xml"
)

$configXml = ((Get-Content $ConfigPath))
$tracerPath = $configXml.Config.Paths.Tracer
$etlDir = $configXml.Config.Paths.Etl
$logDir = $configXml.Config.Paths.Log
$tmfSearchPath = $configXml.Config.Paths.TmfSearchPath

# Construct the parameters for the 'Start' command to OcsTracer.exe
function getStartParams()
{
    $ret = @()

    $configXml.Config.Components.Component |
        ? {$_.Enabled -eq "yes"} |
        foreach {
            $ret = $ret +
                ("/Component:" + $_.Name + "," + $configXml.Config.Default.Level +
                    "," + $configXml.Config.Default.Flags + " ")
        }

    return $ret
}

# Construct the parameters for the 'Stop' command to OcsTracer.exe
function getStopParams()
{
    $ret = @()

    $configXml.Config.Components.Component |
        ? {$_.Enabled -eq "yes"} |
        foreach { $ret = $ret + ("/Component:" + $_.Name) }

    return $ret
}

# Format the ETL files for enabled components to a human readable format
function formatFiles(
    [Parameter(Mandatory=$true)]
    [String] $Timestamp
)
{
    md $logDir\$timestamp -ea silentlycontinue | Out-Null

    $configXml.Config.Components.Component |
        ? {$_.Enabled -eq "yes"} |
        foreach {
            $etlFile = $_.Name + ".etl";

            if (Test-Path $etlFile)
            {
                $logFile = $Timestamp + "\" + $Timestamp + "_" + $_.Name + ".log";

                & "$tracerPath\OcsTracer.exe" Format /LogFilePath:"$etlDir\$etlFile" /OutputFile:"$logDir\$logFile" /TmfSearchPath:"$tmfSearchPath" | Write-Verbose
            }
            else
            {
                Write-Warning "File $etlFile not found.";
            }
        }
}

Write-Host "Using Config File: $ConfigPath"
$timestamp = Get-Date -format "yyyy-MM-dd_HH.mm.ss"

if ($Action -eq "start")
{
    Write-Host "Removing all .etl files ..."
    ls $etlDir *.etl | ri

    Write-Host "Start tracing components ..."
    $params = getStartParams

    & "$tracerPath\OcsTracer.exe" Start $params /LogFileFolder:"$etlDir" | Write-Verbose
}
elseif ($Action -eq "stop")
{
    Write-Host "Stop tracing components ..."
    $params = getStopParams

    md $logDir\$timestamp | Out-Null

    & "$tracerPath\OcsTracer.exe" Stop $params /OutputFile:"$logDir\$timestamp\$($timestamp)_All.log" /TmfSearchPath:"$tmfSearchPath" | Write-Verbose

    if (!$?)
    {
        rd $logDir\$timestamp | Out-Null
    }
    else
    {
        Write-Host "Sessions stopped. Start formatting ..."
        formatFiles $timestamp
    }
}
elseif ($Action -eq "format")
{
    Write-Host "Formatting traces from ETL files ..."
    formatFiles $timestamp
}
elseif ($Action -eq "config")
{
    Write-Host "Default values"
    Write-Host "--------------"
    $configXml.Config.Default | ft Level,Flags

    Write-Host "Paths"
    Write-Host "-----"
    $configXml.Config.Paths | fl

    Write-Host "Components"
    Write-Host "----------"
    $configXml.Config.Components.Component | ft Name,Enabled
}
else
{
    Write-Error "Unknown action."
}

For samples on how to run the script, please run man .\Tracer.ps1 -Examples
Have fun 🙂

Debugging Service Startup

If you are like me working on server development you may run into the situation that a service fails early during startup, i.e. within the first couple of seconds. You’ll soon realize that manually attaching a debugger doesn’t work well, if at all. Even if you’ll be running

windbg -pn MyService.exe

you may not actually be fast enough. Or there are multiple instances of that image running (e.g. SvcHost.exe) and the above command becomes kind of useless. Now if you have been reading the ‘Debugging Tools for Windows’ documentation (or have debugged services before) you’ll already know what I am about to tell you here.

As I mentioned above, the first problem you’re fighting with is that the failure happens very early. Another problem you may have is that your service is running e.g. as ‘NT AUTHORITY\NETWORK SERVICE’ and thus may not be able to interact with your desktop. But Windows’ right here to help you out with ‘Image File Execution Options’. This basically allows you to execute a command when a particular image is being executed.

You start by creating a key for the image file in the registry:

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\MyService.exe

There you create a new string value of the name ‘Debugger’ and set its value to the path of the debugger you want to invoke, e.g. something like ‘C:\Debuggers\cdb.exe’. To mitigate the problem of the non-interactive service, you’ll probably want to use the debugger remotely, so you’ll create a debugging server: ‘C:\Debuggers\cdb.exe -server npipe:pipe=MyDebuggingSession’. What you have now is a debugger which is attached as soon as the service starts and which is accessible remotely. Thus, you can either on the server itself or another machine which has access run for instance

windbg -remote npipe:server=my-machine,pipe=MyDebuggingSession

and there you go: you are now debugging the service. Use the various command line options for the debuggers to

  • ignore the initial break point (-g)
  • run commands right after the debugger is attached (-c)
  • create a script which sets some useful breakpoints and run it when the debugger is attached (e.g. -c “$<MyScript.txt”)

You may actually have to adjust the service control timeout. To do so, add a DWORD called ‘ServicesPipeTimeout’ to the registry key

HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control

and set its value to the number of milliseconds you want the service to wait before timing out.

You’ll find pretty much all of this information also in the help file for ‘Debugging Tools for Windows’ under ‘Debugging a Service Application’. Enjoy!