How to debug a USMT log like a Pro

The Scanstate and Loadstate logs contain a wealth of information on each problem that is encountered, however it does take a little bit of work to root cause a problem.  For example, lets take a look at an example.  A few weeks ago our team got an email from someone who was finding that Scanstate would fail every time they tried to create a migration store to an external hard drive.  At the end of the log, the following lines appeared:

> Error [0x000000] Unable to Complete Migration. MigDoMigration Failed= 0x4
> Error [0x000000] Migration failed to complete successfully

Not particularly helpful, right?  I imagine that the person running Scanstate already knew that the migration failed since they were bothering to look at the log in the first place.  However, if you scroll up a few lines in the log, the real cause of the migration failure can be found:

> Error [0x000000] Unable to process object C:\Documents and Settings\userA\Desktop\dvd.iso -> 733, aborting...
> Error [0x000000] USMT is shutting down due to errors. If the error is non-fatal, you can use /c to ignore these errors and continue migration.
> Error [0x0802e9] CopyStream: Can't copy streams from {"C:\Documents and Settings\userA\Desktop\dvd.iso"} to {"733"} object. Error 112. Exception class UnBCL::IOException: unable to write to FileStream.
enum Mig::SendObjectResult __thiscall Mig::CMediaManager::SendObjectInternal(class UnBCL::Stream *,const unsigned short *,const unsigned short *,int)
void __thiscall UnBCL::FileStream::Write(const unsigned char *,int,int)

These lines are much more helpful that the first two that we looked at.  The first line in this section lets us know that the problem was encountered while trying to process the dvd.iso file.  This narrows the problem space greatly.  The next line lets us know that we might be able to skip this error if it is non-fatal.  Although the last line contains a great deal of information only really relevant to a developer, it also contains the final hint we need to root cause this problem.  Lets take this step by step and break the final line into to five pieces:

    1. Error [0x0802e9]
    2. CopyStream: Can't copy streams from {"C:\Documents and Settings\userA\Desktop\dvd.iso"} to {"733"} object.
    3. Error 112.
    4. Exception class UnBCL::IOException: unable to write to FileStream.
    5. enum Mig::SendObjectResult __thiscall Mig::CMediaManager::SendObjectInternal(class UnBCL::Stream *,const unsigned short *,const unsigned short *,int)
      void __thiscall UnBCL::FileStream::Write(const unsigned char *,int,int)

We can immediately discard parts1, 2, and 5 as they either contain information that we already know or that is far to detailed to help us.  However, parts 3 and 4 are really telling.  Part 4 lets us know that the problem wasn't while accessing dvd.iso, but rather while trying to write dvd.iso to the migration store.  Part 3 contains the immediate reason why dvd.iso couldn't be written, however the reason is encoded in the form of a numerical error message.  Thankfully, the command line application net can translate the numerical error message into a textual error message for us:

C:\>net helpmsg 112

There is not enough space on the disk.

Piecing this all together we can surmise that dvd.iso couldn't be written to the migration store because there wasn't enough space on the external hard drive it was being written to.  Although this would typically be the end of a USMT log root cause exercise, there happened to be one final twist to this particular problem.  The external hard drive showed that it had many, many, gigabytes of free space.

How can this be?  Doesn't this contradict the message above?  Some quick thinking on the part of my test colleague got to the actual root cause which dealt with the filesystem used on the external hard disk.  Every storage device utilizes a filesystem to organize the data that it contains.  Currently, the two most commonly used filesystems developed by Microsoft are FAT32 and NTFS.  Every filesystem has limits in regards to the number of files and size of files that it can support, but FAT32, developed for Windows 95 OSR2 in August 1996, has some antiquated limits.  Namely, FAT32 cannot support any single file being larger than 4 GB.  In this case, adding dvd.iso to the migration store pushed the migration store up against the 4 GB limit of FAT32 and triggered the sequence of errors that we just walked through.  The user reformatted the external drive to be NTFS and the migration completed successfully.

The key thing to take away from this post is to always look for "Error ##" in a Scanstate or Loadstate log when a problem is encountered, and feed that number through "net helpmsg."  Note, it may be necessary to turn the logging verbosity all the way up for the best debugging experience (/v:13 on the Scanstate and Loadstate command line).