Enhanced Logging in ClickOnce Deployment

With the .NET 4.0 Framework, Microsoft has added the ability to turn on verbose logging for the install, update, and uninstall of a ClickOnce application. Of course, it doesn’t do much good to modify the amount of logging without providing access to the log file, so they have also added the ability to let you specify the location and name of the output file for the logging. When you define the log file path, it creates or appends to the log file every time a ClickOnce application is installed, updated, or uninstalled. It even works if you are doing programmatic updates.

What’s particularly keen about these features is that they work for any ClickOnce application as long as .NET 4.0 is installed. In other words, if your ClickOnce application targets the .NET 2.0, 3.0, or 3.5 Framework, you can still install the .NET 4.0 Framework on the computer and take advantage of the new logging features. (Installing .NET 4.0 also installs the updated ClickOnce engine, which is more stable.)

Now what you really want to know is what the log files look like, so you’ll know whether this is worth the trouble. I created a small application that has one Windows Form, and I deployed it with ClickOnce. I installed and uninstalled it with verbose logging turned on and with verbose logging turned off. Then I added programmatic updates and let it update asynchronously and restart the application. The logging for automatic updates is the same as an install, but it’s less detailed if you are using programmatic updates. Here are the log files:

ClickOnceLog_Verbose_Install
ClickOnceLog_Verbose_Uninstall
ClickOnceLog_Verbose_Update_Programmatic
ClickOnceLog_NotVerbose_Install
ClickOnceLog_NotVerbose_Uninstall
Zip file of all five log files

Since you’re still reading this, you probably want to know how to turn on the verbose logging and set up the log file. Or at least, how to set up the log file (you may think the verbose logging is too chatty). It’s very simple. You need to add some entries to the Windows registry.

The log file path goes here:
HKEY_Current_User\Software\Classes\Software\Microsoft\Windows\CurrentVersion\Deployment\LogFilePath

The registry key for verbose logging goes here:
HKEY_Current_User\Software\Classes\Software\Microsoft\Windows\CurrentVersion\Deployment\LogVerbosityLevel

To add these, open the registry editor and drill down to the Deployment sub-key. Right-click on Deployment and select “New” and then “String Value” as displayed here:

Type in the key name and press Enter. Then press Enter again or double-click on the entry to set the value.

Type in the value and press Enter.

If you want to stop outputting the logging, delete the registry key for the LogFilePath.

If you change or set the LogFilePath, it takes effect immediately. If you change or set the LogVerbosityLevel, it does not take effect until the user logs off and logs back in.

Another fun piece of information: If you set the LogFilePath to an empty string instead of deleting the registry entry, every time you run the ClickOnce application, you will get an error that dfsvc.exe (the ClickOnce service) is no longer working. (I’m thinking that’s not a feature.)

One word of caution: there is no automatic cleanup of the log file, no rollover when it gets to a certain size or anything like that. ClickOnce continues to append to the log file with every install, update, and uninstall. So if you start up the logging on someone’s computer, you must remember to come back around and turn it back off.

If you want to leave the logging turned on, I strongly recommend that you have your application manage the log file. For example, you could rename the log file every time a new one is created, and make sure you only keep the most recent one. You can tell if the application is newly installed or if an update is newly installed by checking the IsNetworkDeployed property of System.Deployment.Application.ApplicationDeployment. If true, the user just installed the application, or installed an update, and you could manage the log file at that time.

Programmatically modifying the registry

Editing the registry is fraught with peril. I remember the old days when you used to be able to call Microsoft for help with Windows (the REALLY old days). One of the first things they would ask you was, “Did you edit the Windows registry?” It only took one phone call to learn that if you said “Yes”, they would not help you. This taught many developers to, well, lie.

So just for grins, I wrote a small .NET application that provides a user interface you can use to change the registry entries for the ClickOnce logging. Basically it displays a screen where you can browse to the folder where you want your log files, and you can turn verbose logging on and off. Here’s what the UI looks like:

You could take this project and set the target Framework to the same as your application. If your user has the .NET Framework installed on their computer, you can just build this application and then copy the executable to the user’s machine and run it to set the values.  Or better yet, put it on a thumb drive and run the executable from there.

Since the registry entries are in HKCU, you could also have your ClickOnce application update these values, but that’s not helpful for the first install!

Let’s take a look at the LogSettings class that does all the work. This is in C#, but the whole solution is available in both C# and VB at the end of this article.

First, here are the namespaces you need to include. Microsoft.Win32 is for the registry changes.

using System.IO;
using Microsoft.Win32;

Next are the constants and properties. This includes the registry sub-key name. When you retrieve the registry sub-key, you specify which hive, such as HKCU, so it is not part of the sub-key name.

//This is where the values go for the ClickOnce logging, in HKEY_Current_User.
private static string ClickOnceLoggingSubKeyName = 
  @"Software\Classes\Software\Microsoft\Windows\CurrentVersion\Deployment";

/// <summary>
///This is the registry value name for the log file path. 
///The value should be the fully-qualified path and file name of the log file.
/// </summary>
private static string rkName_LogFilePath = "LogFilePath";
      
/// <summary>
/// This is the registry value name for the logging level. 
/// The value should be = 1 if you want verbose logging. 
/// To turn off verbose logging, you can delete the entry or set it to 0.
/// </summary>
private static string rkName_LogVerbosityLevel = "LogVerbosityLevel";

/// <summary>
/// Fully-qualified path and name of the log file.
/// </summary>
public string LogFileLocation { get; set; }

/// <summary>
/// Set this to 1 for verbose logging.
/// </summary>
public int LogVerbosityLevel { get; set; }

/// <summary>
/// Set to true if doing verbose logging.
/// </summary>
public bool VerboseLogging { get; set; }

Here is the method called to create an instance of the class; this reads the current entries from the registry and stores them in the class properties. First you open the sub-key, and then you retrieve the two values that you need.

/// <summary>
/// Create a new instance of this class and get the value for the registry entries (if found).
/// </summary>
/// <returns>An instance of this class.</returns>
public static LogSettings Create()
{
  LogSettings ls = new LogSettings();

  //open the Deployment sub-key.
  RegistryKey rk = Registry.CurrentUser.OpenSubKey(ClickOnceLoggingSubKeyName);

  //get the values currently saved (if they exist) and set the fields on the screen accordingly
  string logLevel = rk.GetValue(rkName_LogVerbosityLevel, string.Empty).ToString();
  if (logLevel == "1")
  {
    ls.VerboseLogging = true;
    ls.LogVerbosityLevel = 1;
  }
  else
  {
    ls.VerboseLogging = false;
    ls.LogVerbosityLevel = 0;
  }
  ls.LogFileLocation = rk.GetValue(rkName_LogFilePath, string.Empty).ToString();           
  return ls;
}

And last, but not least, here is the method to save the entries back to the registry. You open the sub-key in write mode, so you can modify the associated values. If the log level is not set to verbose, this deletes the value for the logging level from the registry. If no file name is specified for the log file, this deletes that registry entry. Otherwise, the entries are updated with the values set on the screen.

/// <summary>
/// Save the values to the registry.
/// </summary>
/// <returns></returns>
public bool Save()
{
  bool success = false;
  try
  {
    //Open the Deployment sub-key.
    RegistryKey rk = Registry.CurrentUser.OpenSubKey(ClickOnceLoggingSubKeyName, true);
    //Set the values associated with that sub-key.
    if (this.VerboseLogging)
      rk.SetValue(rkName_LogVerbosityLevel, "1");
    else
    {
      //check to make sure the [value] exists before trying to delete it 
      object chkVal = rk.GetValue(rkName_LogVerbosityLevel);
      if (chkVal != null)
      {
        rk.DeleteValue(rkName_LogVerbosityLevel);
      }
    }

    if (this.LogFileLocation.Length == 0)
    {
      //check to make sure the [value] exists before trying to delete it 
      //Note: If you set the values to string.Empty instead of deleting it,
      //  it will crash the dfsvc.exe service.
      object chkPath = rk.GetValue(rkName_LogFilePath);
      if (chkPath != null)
        rk.DeleteValue(rkName_LogFilePath);
    }
    else
    {
      rk.SetValue(rkName_LogFilePath, this.LogFileLocation);
      string logFolder = Path.GetDirectoryName(this.LogFileLocation);
      if (!Directory.Exists(logFolder))
          Directory.CreateDirectory(logFolder);
    }
    success = true;
  }
  catch
  {
    throw;
  }
  return success;
}

The Visual Studio 2010 solutions can be downloaded in either CSharp or VB.

Download the C# version

Download the VB version

Acknowledgements

Thanks very much to Jason Salameh at Microsoft, who I believe was largely responsible for adding this feature. I believe it will provide some clarity and help with troubleshooting when people have problems installing ClickOnce applications.

[Edit 7/7/2011 Move downloads to Azure blob storage]

[Edit 3/8/2014 Move to different Azure blob storage]

Tags:

12 Responses to “Enhanced Logging in ClickOnce Deployment”

  1. Windows Client Developer Roundup for June 7, 2010 - Pete Brown's 10rem.net Says:

    […] Enhanced Logging in ClickOnce Deployment (RobinDotNet) […]

  2. MDXNovice Says:

    As suggested by you in the forum thread – http://social.msdn.microsoft.com/Forums/en/vsto/thread/bfda4576-29cb-485a-aaf8-f9d21b5425b1
    I tried it but ist not working for me

    • robindotnet Says:

      Thanks, I responded in the thread on the forum. I track threads I’m responding to, and when you respond I get an e-mail. Sometimes it takes me a couple of days to answer, because I work a *lot* of hours at my regular job.

  3. Rick Harrison Says:

    Thanks. That’s good to know. I tried it out and it works for me.

    I wish this had been available when I was first setting up my ClickOnce applications. It would have saved me a lot of fumbling around in the dark!

    I see that you’ve got several very useful posts here — I only wish I had found your blog sooner!

    On the subject of “abusing ClickOnce install”, I’ve actually written a ClickOnce application that deploys and updates a legacy (but still changing) VB6 application. If that’s not abusing ClickOnce, I don’t know what is! To make matters worse, I’ve got another ClickOnce application (for the same customer) which is straight DotNet, but which needs to invoke the legacy application (via ClickOnce) with parameters. I just noticed your other post about passing parameters. Boy could I have used that one earlier too! I ended up having the invoking application first store the parameters in the registry and then having the invoked application check for them when it starts up. Ugly for sure, but it works… most of the time.

    Before I get around to combining both of these applications into a single Azure app, I have been considering hosting the ClickOnce files in blobs on Azure. I’m delighted to see that you’ve got a post on that too!

    But the reason I found your site in the first place is that I am trying to solve a nasty problem has just cropped up on my VB6 deployment. I’m wondering if you can shed any light on it.

    My ClickOnce “VB6 Deployment” application has been relatively trouble free for a few years and has successfully deployed dozens of VB6 updates. The last new deployment was several months ago. However, when I recently made a small change to the VB6 code and tried to deploy it again, it started getting the dreaded “(program) has stopped working. A problem has caused the program to stop working correctly. Windows will close the program and notify you if a solution is available.” error. The ClickOnce deployment itself is working fine, but the DotNet code that is trying to deploy the VB6 application fails. Part of what this program does is to unzip an archive file into a regular application folder within “C:\Program Files”. It’s the unzip operation that fails; and I haven’t yet been able to get any exception information on exactly what’s happening. However, if after the install, I drill down into the ClickOnce folder on the target machine and manually run the DotNet deployment application as administrator, the program unzips the file successfully and proceeds to execute the VB6 application like it should. If I run it manually without selecting “run as administrator”, I get the same error that occurs during the deployment. So I’m pretty sure it’s just a permissions problem. What’s killing me is that it has been working like this for years and now suddenly when I redeploy it, it fails. Do you have any ideas about why this would occur? Has some Windows UAC security update recently made windows more strict about permissions for ClickOnce applications, so that my application can no longer unzip a file into folder within C:\Program Files?

    Rick.

    • robindotnet Says:

      If you are getting the ‘program has stopped working’, this means the application is crashing before ClickOnce has even let go of the process. If you drill down to the cache and double-click on the exe for your application, it will crash. So this is not a ClickOnce problem.

      Second, ClickOnce will not run with administrative privileges, and on any Vista or Windows 7 machine, you can’t write to Program Files w/o admin privileges. So what OS are you trying to run it on? Is the ClickOnce app itself trying to run the VB6 install?

      Robin

  4. ClickOnce Publish and Deploy from Team Foundation Server 2010 Says:

    […] will be prompted to grant the requested minimum trust permissions. Regarding debugging, read this blog post that shows how to enable verbose logging of ClickOnce installs and updates. After installation […]

  5. Donald Plugge (@dgplugge) Says:

    Robin, I use your blog all the time when I run into a ClickOnce wall. This deployment logging trick is nice to know and I thought it might help me in troubleshooting my manifest mismatch error. It was nice to have the extended report, unfortunately the report didn’t lead me to the solution.

    I would like to give back a little and mention my problem and the eventual fix. In working with the Model / View / Presentation pattern I created a main VB.NET Windows Application project along with separate projects for each member of the pattern. In code the view I found that it worked best to create the project as a Windows Application, so I had the form library and initial form automatically created. Then I switched it over to a Class Library.

    I had been working on several projects in this fashion. When I attempted to ClickOnce install one of these projects, I got that pesky error “Reference in the manifest does not match the identity of the downloaded assembly”. After checking and double checking my manifest files and even using your installation logging tip, I finally stumbled upon the solution. I one of my View Projects, I left the project type set to “Windows Application”, rather than making it a “Class Library”. Everything functioned just fine in the Visual Studio IDE, but the ClickOnce deployment would not allow it to install.

    I guess the lesson is to make sure you only have one Windows Application project in a ClickOnce deployment.

    dgp

  6. My Website – ClickOnce Publish and Deploy from Team Foundation Server 2010 Says:

    […] debugging, read this blog post that shows how to enable verbose logging of ClickOnce installs and […]

  7. monty241070 Says:

    Thanks a lot for this feature; it helps when analyzing what goes wrong. At this moment I run into a problem with VSTO and clickonce. It ends with “The application could not be downloaded because a connection to the network could not be established. Ensure that you can connect to the network, and try again.” (Not a real network issue, running across LAN and only occurs after all files have been downloaded).
    In the logging it ends with: “WaitForAssertApplicationRequirements() called.\nMethod Call: InPlaceHostingManager.Dispose() called.\nInternal state=Done”. The error does not occur in the log. Could you ask the ClickOnce responsible product manager to also log this type of error to the clickonce log? Makes it even more easy to analyze.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s


Follow

Get every new post delivered to your Inbox.

Join 70 other followers

%d bloggers like this: