Friday, August 27, 2004

Self-Registration vs. Registry tables group

COM Servers are every Setup developer's nightmare. One of my friends, a release engineer, expressed her extreme frustration over the technique that they had used to register COM Servers. The setup developer had written 100s of lines of code to launch RegSvr32 using the '/s' switch to register these COM Servers. In theory, the process of registration of a COM Server is perfectly fine when done via the regsvr32 utility. But there are certain disadvantages while doing that from the MSI Engineer's perspective. Firstly, all the dependencies of the server need to be registered in a specific order. And secondly, the user performing the installation should have administrative rights. The latter aspect makes setup developers and administrators loathe the registration process.

Further, system administrators do not know the registry settings and COM interfaces that are exposed by the COM object. COM objects do not support reflection and hence are essentially black boxes. Windows Installer has a 'SelfReg' table which can be used to self-register COM servers. There are several disadvantages while using this table.


  • Order of registration cannot be specified. Thus if the DLL has dependencies and the dependencies are not registered already, the self-registration would fail.

  • Rollback cannot be done reliably

  • Self-Registration requires administrative privileges

  • You cannot exploit the install-on-demand features of Windows Installer

  • You cannot register EXE (Out of process) servers.


Tools like InstallShield X provide alternative methods to perform self-registration. This works around certain limitations like specifying the order of registration and registering EXE files. But largely there are limitations that are not in sync with Windows Installer's philosophy of a setup. Speaking of Setup Philosophy, RobMen's blog on his philosophical musings is really worth a read. I personally consider performing self-registration a fiendish act. Microsoft does not absolutely recommend it. Instead it recommends the use of Registry Table group. These are a set of tables like Class, ProgId, Typelib, MIME, Extension and so forth that can be used to store COM information. Most of this information should be available in the generated IDL file for the COM component. If you have any trouble figuring it out, you can peep into the registry during the registration process using various registry-spying tools and extract the appropriate information. Thankfully, tools like InstallShield X abstract this process. For example, using InstallShield X you can extract COM information from the key file of the component during the build time by setting the "COM Extract at Build" attribute of the component in the InstallShield X IDE. Although this makes life easy for a lot of setup developers, this technique has its share of pains. Although not perfect, this technique would solve most of the issues related with COM Registration.

InstallShield also provides a simple utility call RegSpyUI.exe that helps users look at COM information for a specific DLL or exe. This tool is undocumented, unsupported and hence I do not know all the bad things that it might do. But it is a really cool utility, which helps us work around such nasty limitations. Search the InstallShield X or DevStudio installation directory for this tool. There are a few references to this tool in the InstallShield Communities. So if something bad happens to your computer, don’t blame me. You have been warned.

Some of the motivating factors for authoring these tables as opposed to self-registration are:


  1. You can forget about dependencies. Since all the information is already authored in the table, you do not need the COM servers registered in order.

  2. You can register all kinds of COM Components (DLL, EXE, OCX and the like.)

  3. You do not need administrative privileges. Since the registration is carried out by the standard actions, you can exploit MSI's support for elevated privileges. This is a boon for people handling locked down environments.

  4. You can now support Installation-on-Demand for these COM Components. I would cover this in detail some other day.



With all these facts by your side, I am now sure that you can convince any setup developer to use the Registry Table Group instead of performing self-registration.

Saturday, August 21, 2004

Reading Windows Installer Logs

As we all know Windows Installer is a complicated and a elegant technology. Its beastly complexities are beautifully abstracted by the authoring packages like InstallShield X, DevStudio and Developer. But we live in a less than perfect world and Murphy’s Law still holds good for the Windows Installer world too. There might be several reasons why an Installation might fail. Some errors might be meaningful while others might just spit out a cryptic error message with an error number during installation. The only way to make sense of these would be to look at the log files generated during installation. You can generate a log file for the installation using the following command line.

msiexec /i productname.msi /l*v package.log

This command generates a verbose log file logging all errors, warnings and debug messages and produces a huge log file in the text format. The first look at the log file might be slightly intimidating. This article tries to break the ice with the basics of reading the log file to troubleshoot problems with installation. Discussing all the error messages and its aspects is out of scope of this article. If you have specific questions, feel free to drop me a word. (at installneo@yahoo.com)

The Bottom Up Approach:

Whenever I read a log file, I start reading it from the bottom of the file. You might dismiss this technique as one of my eccentricities but I believe that this is the quickest, if not the most efficient, way of reading a log file in case of errors like 1603 or 1721. As a convention, the letter 'C' within brackets denotes the client context and the letter 'S' denotes the server context. So all messages in the log, which start as below, are messages in the client's context.

MSI (c) (A0:4C): Doing action: INSTALL
Action start 0:12:20: INSTALL.
MSI (c) (A0:4C): UI Sequence table 'InstallUISequence' is present and populated.
MSI (c) (A0:4C): Running UISequence

All messages in the log which start as below are messages from the MSI running in the server's context.

MSI (s) (1C:7C): Doing action: INSTALL
Action start 0:12:54: INSTALL.
MSI (s) (1C:7C): Running ExecuteSequence

Let us first analyze a successful log file and get ready to compare the anomalies with a not so perfect log file. I have used a simple Basic MSI project created with InstallShield X that just installs notepad.exe and I have disabled Update Ser. What we should be looking at is actions that do not have a return code of 1. You would find lines similar to the ones below just above the Server context property dump.

MSI (c) (04:B0): Doing action: SetupCompleteSuccess
Action start 18:03:47: SetupCompleteSuccess.
Action 18:03:47: SetupCompleteSuccess. Dialog created
Action ended 18:03:48: SetupCompleteSuccess. Return value 2.
Action ended 18:03:48: INSTALL. Return value 1.


Hmm... What does this mean? The "Action ended 18:03:48: SetupCompleteSuccess. Return value 2." message indicates that user cancelled the action or the operation was aborted due to a user instruction. But god knows that I did not instruct it stop. There must be something else that is wrong. The most obvious place to look for it would be the "Finish" button in the SetupCompleteSuccess dialog. You would find a line like the one below once you click on the Behavior tab of the dialog and select the OK control. If you insist on doing it via Orca, you can look at the ControlEvent table for the OK control in the SetupCompleteSuccess dialog.

EndDialog - Exit - 1

BINGO! We have found the culprit. The argument for the control event must be 'Return' instead of 'Exit'. Refer Windows Installer SDK help library article titled "EndDialog ControlEvent" for more information. Rebuild the project after changing it to 'Return' and you would find that none of the actions have return values other than '1'.

We have thus finally solved a trivial problem with the help of the log file, which would have gone unnoticed otherwise. Ah! Sweet Perfection.

:-)

Deferred Custom Actions:

One of the common places where users get confused is with deferred custom actions. Deferred Execution Custom Actions are not executed the first time the installer processes the custom actions in the Execute Sequence table. They are instead written to the MSI script. All these actions are executed within the InstallFinalize action. In these cases, you would have to look at the return value of the InstallFinalize action. A few lines above the line that indicates the return value of InstallFinalize would hint the action that failed. Let us verify this with a simple VBScript Custom Action that does nothing else but cause the install to fail </wink>. This is the code for the VBScript.

function MyFunction
MyFunction=1603
end function

I then create a Type 1030 custom action (VBScript Stored in Binary Table + Deferred Execution). This custom action is scheduled after InstallFiles action in the Install Execute Sequence. Run and log the installation. The installation proceeds and comes up with a dialog, which states that the Installation operation has failed. Let us look into the log for more information.

The final few lines in the log file complain that installation failed. But it still does have not enough information to identify an error.

MSI (c) (34:30): Product: SimpleInstaller -- Installation operation failed.

MSI (c) (34:30): Grabbed execution mutex.
MSI (c) (34:30): Cleaning up uninstalled install packages, if any exist
MSI (c) (34:30): MainEngineThread is returning 1603

Above the client contexts' property dump, the following lines of code indicate that INSTALL (Top level action) returns a value of 3 and the main thread is returning 1603. The SetupCompleteError is the same as we discussed earlier. This does not give much information either.

MSI (s) (DC:D8): MainEngineThread is returning 1603
MSI (c) (34:30): Back from server. Return value: 1603
MSI (c) (34:30): Decrementing counter to disable shutdown. If counter >= 0, shutdown will be denied. Counter after decrement: -1
Action ended 19:24:28: ExecuteAction. Return value 3.
MSI (c) (34:30): Doing action: SetupCompleteError
Action start 19:24:28: SetupCompleteError.
Action 19:24:29: SetupCompleteError. Dialog created
Action ended 19:24:30: SetupCompleteError. Return value 2.
Action ended 19:24:30: INSTALL. Return value 3.

Assuming that you have opened the log in notepad, search quickly for the word 'InstallFinalize' and specify the direction of search as up. You will now be able to see the following lines.

...
Our custom action is being called
MSI (s) (DC:D8): Executing op: ActionStart(Name=NewCustomAction1,,)
Action 19:24:28: NewCustomAction1.
MSI (s) (DC:D8): Executing op: CustomActionSchedule(Action=NewCustomAction1,ActionType=1030,Source=function MyFunction
MyFunction=1603
end function,Target=MyFunction,)
MSI (s) (DC:D8): Creating MSIHANDLE (3) of type 790536 for thread 2008
MSI (s) (DC:D8): Creating MSIHANDLE (4) of type 0 for thread 2008
MSI (s) (DC:D8): Closing MSIHANDLE (4) of type 0 for thread 2008
MSI (s) (DC:D8): Closing MSIHANDLE (3) of type 790536 for thread 2008
Our custom action fails causing the InstallFinalize action to fail
Action ended 19:24:28: InstallFinalize. Return value 3.
Initiate Rollback
MSI (s) (DC:D8): User policy value 'DisableRollback' is 0
MSI (s) (DC:D8): Machine policy value 'DisableRollback' is 0
MSI (s) (DC:D8): Executing op: Header
...
Rolls back changes

As you would have aptly guessed, the lines in bold are my comments. So you can nail most of troublesome deferred custom action using this technique.

I am really sleepy and have got some real work to do. I am sure I would touch on the log files again covering more aspects. Love it or Hate it, feel free to post your comments.

Monday, August 16, 2004

This is the beginning of....

I have just started this blog to document some of the interesting and difficult...ahem..challenging scenarios I faced while supporting people who package applications. I always wanted to write technical articles. I guess this would be a start.