Driver install completes with success message, but no files are copied

scott_smith · April 24, 2020, 6:40pm

I’m working on my first driver, based upon Microsoft’s IddCx Indirect Display sample. I can’t seem to get it to install, and I’m having trouble figuring out what the problem might be.

On my test machine, I connect to the remote build output folder (containing .cat, .dll, and .inf), right-click on the .inf file, and choose Install. Install finishes successfully; here’s an excerpt from %WinDir%\INF\setupapi.dev.log:

>>>  [Device Install (DiInstallDriver) - <dev-pc-share>\MY_DRIVER.inf]
>>>  Section start 2020/04/23 21:34:01.152
      cmd: "C:\WINDOWS\System32\InfDefaultInstall.exe" "<dev-pc-share>\MY_DRIVER.inf"
     ndv: Flags: 0x0
     ndv: INF path: <dev-pc-share>\MY_DRIVER.inf
     inf: {SetupCopyOEMInf: <dev-pc-share>\MY_DRIVER.inf} 21:34:01.174
     inf:      Copy style: 0x0
     sto:      {Setup Import Driver Package: <dev-pc-share>\MY_DRIVER.inf} 21:34:01.328
     inf:           Provider: MyCompany
     inf:           Class GUID: {4D36E968-E325-11CE-BFC1-08002BE10318}
     inf:           Driver Version: 04/23/2020,19.41.30.482
     inf:           Catalog File: MY_DRIVER.cat
     sto:           {Copy Driver Package: <dev-pc-share>\MY_DRIVER.inf} 21:34:01.365
     sto:                Driver Package = <dev-pc-share>\MY_DRIVER.inf
     sto:                Flags = 0x00000007
     sto:                Destination = <appdata-local-temp>
     sto:                Copying driver package files to '<appdata-local-temp>'.
     flq:                Copying '<dev-pc-share>\MY_DRIVER.cat' to '<appdata-local-temp>\MY_DRIVER.cat'.
     flq:                Copying '<dev-pc-share>\MY_DRIVER.dll' to '<appdata-local-temp>\MY_DRIVER.dll'.
     flq:                Copying '<dev-pc-share>\MY_DRIVER.inf' to '<appdata-local-temp>\MY_DRIVER.inf'.
     sto:           {Copy Driver Package: exit(0x0)} 21:34:01.515
     pol:           {Driver package policy check} 21:34:01.534
     pol:           {Driver package policy check - exit(0x0)} 21:34:01.534
     sto:           {Stage Driver Package: <appdata-local-temp>\MY_DRIVER.inf} 21:34:01.537
     inf:                {Query Configurability: <appdata-local-temp>\MY_DRIVER.inf} 21:34:01.543
!    inf:                     Using WDF schema version 2.0 when section requires version 2.25. Section = [MY_DEVICE_MODEL.Wdf]
     inf:                     Driver package uses WDF.
     inf:                     Driver package 'MY_DRIVER.inf' is configurable.
     inf:                {Query Configurability: exit(0x0)} 21:34:01.554
     flq:                Copying '<appdata-local-temp>\MY_DRIVER.cat' to '<driverstore-temp>\MY_DRIVER.cat'.
     flq:                Copying '<appdata-local-temp>\MY_DRIVER.dll' to '<driverstore-temp>\MY_DRIVER.dll'.
     flq:                Copying '<appdata-local-temp>\MY_DRIVER.inf' to '<driverstore-temp>\MY_DRIVER.inf'.
     sto:                {DRIVERSTORE IMPORT VALIDATE} 21:34:01.586
     sig:                     {_VERIFY_FILE_SIGNATURE} 21:34:01.653
     sig:                          Key = MY_DRIVER.inf
     sig:                          FilePath = <driverstore-temp>\MY_DRIVER.inf
     sig:                          Catalog = <driverstore-temp>\MY_DRIVER.cat
!    sig:                          Verifying file against specific (valid) catalog failed.
!    sig:                          Error 0x800b0109: A certificate chain processed, but terminated in a root certificate which is not trusted by the trust provider.
     sig:                     {_VERIFY_FILE_SIGNATURE exit(0x800b0109)} 21:34:01.670
     sig:                     {_VERIFY_FILE_SIGNATURE} 21:34:01.672
     sig:                          Key = MY_DRIVER.inf
     sig:                          FilePath = <driverstore-temp>\MY_DRIVER.inf
     sig:                          Catalog = <driverstore-temp>\MY_DRIVER.cat
!    sig:                          Verifying file against specific Authenticode(tm) catalog failed.
!    sig:                          Error 0x800b0109: A certificate chain processed, but terminated in a root certificate which is not trusted by the trust provider.
     sig:                     {_VERIFY_FILE_SIGNATURE exit(0x800b0109)} 21:34:01.680
!    sig:                     Driver package catalog file certificate does not belong to Trusted Root Certificates, but user wants to install anyway.
     sto:                {DRIVERSTORE IMPORT VALIDATE: exit(0x0)} 21:34:07.844
     sig:                Signer Score = 0x80000000 (Unsigned)
     sto:                {Core Driver Package Import: MY_DRIVER.inf_amd64_df40ef6fef35ece9} 21:34:07.878
     sto:                     {DRIVERSTORE IMPORT BEGIN} 21:34:07.888
     bak:                          Create system restore point:
     bak:                               Description = Device Driver Package Install: MyCompany Display adapters
     bak:                               Time = 17625ms
     bak:                               Status = 0x0 (SUCCESS)
     sto:                     {DRIVERSTORE IMPORT BEGIN: exit(0x0)} 21:34:24.443
     cpy:                     {Copy Directory: <driverstore-temp>} 21:34:24.457
     cpy:                          Target Path = <driverstore-filerepo>\MY_DRIVER.inf_amd64_df40ef6fef35ece9
     cpy:                     {Copy Directory: exit(0x0)} 21:34:24.469
     idb:                     {Register Driver Package: <driverstore-filerepo>\MY_DRIVER.inf_amd64_df40ef6fef35ece9\MY_DRIVER.inf} 21:34:24.473
     idb:                          Created driver package object 'MY_DRIVER.inf_amd64_df40ef6fef35ece9' in DRIVERS database node.
     idb:                          Created driver INF file object 'oem5.inf' in DRIVERS database node.
     idb:                          Registered driver package 'MY_DRIVER.inf_amd64_df40ef6fef35ece9' with 'oem5.inf'.
     idb:                     {Register Driver Package: exit(0x0)} 21:34:24.495
     idb:                     {Publish Driver Package: <driverstore-filerepo>\MY_DRIVER.inf_amd64_df40ef6fef35ece9\MY_DRIVER.inf} 21:34:24.495
     idb:                          Activating driver package 'MY_DRIVER.inf_amd64_df40ef6fef35ece9'.
     cpy:                          Published 'MY_DRIVER.inf_amd64_df40ef6fef35ece9\MY_DRIVER.inf' to 'oem5.inf'.
     idb:                          Indexed 3 device IDs for 'MY_DRIVER.inf_amd64_df40ef6fef35ece9'.
     sto:                          Flushed driver database node 'DRIVERS'. Time = 78 ms
     sto:                          Flushed driver database node 'SYSTEM'. Time = 16 ms
     idb:                     {Publish Driver Package: exit(0x0)} 21:34:24.624
     sto:                     {DRIVERSTORE IMPORT END} 21:34:24.629
     dvi:                          Flushed all driver package files to disk. Time = 15 ms
     sig:                          Installed catalog 'MY_DRIVER.cat' as 'oem5.cat'.
     bak:                          Commit system restore point:
     bak:                               Description = Device Driver Package Install: MyCompany Display adapters
     bak:                               Time = 0ms
     bak:                               Status = 0x0 (SUCCESS)
     sto:                     {DRIVERSTORE IMPORT END: exit(0x0)} 21:34:24.927
     sto:                {Core Driver Package Import: exit(0x0)} 21:34:24.929
     sto:           {Stage Driver Package: exit(0x0)} 21:34:24.930
     sto:      {Setup Import Driver Package - exit (0x0)} 21:34:24.963
     inf:      Driver Store Path: <driverstore-filerepo>\MY_DRIVER.inf_amd64_df40ef6fef35ece9\MY_DRIVER.inf
     inf:      Published Inf Path: C:\WINDOWS\INF\oem5.inf
     inf: {SetupCopyOEMInf exit (0x0)} 21:34:24.984
<<<  Section end 2020/04/23 21:34:25.012
<<<  [Exit status: SUCCESS]

After install, I don’t find my driver DLL in %WinDir%\System32\Drivers\UMDF as expected
I also don’t find any registry settings related to my driver

After running the test app (which instantiates a software device using the driver), I see MyCompany Virtual Display Adapter (with a warning icon overlay) show up in Device Manager. Looking at properties on that item, there are no driver files…

My .inf file looks like this:

[Version]
Signature = "$Windows NT$"
CatalogFile = MY_DRIVER.cat
Class = Display
ClassGUID = {4D36E968-E325-11CE-BFC1-08002BE10318} 
ClassVer = 2.0
DriverVer = 04/24/2020,10.52.58.972
PnpLockDown = 1
Provider = %PROVIDER_STRING%

[SourceDisksNames]
1 = %DISK_NAME%,,,

[SourceDisksFiles]
MY_DRIVER.dll = 1

[DestinationDirs]
MY_DRIVER_FileList = 12, UMDF

[Manufacturer]
%MFG_NAME% = Models, NTamd64

[Models.NTamd64]
%DEVICE_NAME% = MY_DEVICE_MODEL, Root\Models
%DEVICE_NAME% = MY_DEVICE_MODEL, Models

[MY_DEVICE_MODEL]
CopyFiles = MY_DRIVER_FileList

[MY_DRIVER_FileList]
MY_DRIVER.dll

[MY_DEVICE_MODEL.HW]
AddReg = MY_DEVICE_MODEL_HwAddReg

[MY_DEVICE_MODEL_HwAddReg]
HKR,, "UpperFilters", %REG_MULTI_SZ%, "IndirectKmd"
HKR, "WUDF", "DeviceGroupId", %REG_SZ%, "MY_GROUP"

[MY_DEVICE_MODEL.Services]
AddService = WUDFRd, 0x000001fa, WUDFRD_ServiceInstall

[WUDFRD_ServiceInstall]
DisplayName = %WUDFR_DISP_NAME%
ServiceType = %SERVICE_KERNEL_DRIVER%
StartType = %SERVICE_DEMAND_START%
ErrorControl = %SERVICE_ERROR_NORMAL%
ServiceBinary = %12%\WUDFRd.sys

[MY_DEVICE_MODEL.Wdf]
UmdfService = MY_DRIVER, UMDF_ServiceInstall
UmdfServiceOrder = MY_DRIVER
UmdfKernelModeClientPolicy = AllowKernelModeClients

[UMDF_ServiceInstall]
UmdfLibraryVersion = $UMDFVERSION$
ServiceBinary = %12%\UMDF\MY_DRIVER.dll
UmdfExtensions = IddCx0102

[Strings]
DEVICE_NAME = "MyCompany Virtual Display Adapter"
DISK_NAME = "MyCompany Virtual Display Installation Disk"
MFG_NAME = "MyCompany Inc"
PROVIDER_STRING = "MyCompany"
WUDFR_DISP_NAME = "Windows Driver Foundation - User-mode Driver Framework Reflector"

REG_DWORD = 0x00010001
REG_EXPAND_SZ = 0x00020000
REG_MULTI_SZ = 0x00010000
REG_SZ = 0x00000000

SERVICE_DEMAND_START = 3
SERVICE_ERROR_NORMAL = 1
SERVICE_KERNEL_DRIVER = 1

This has been blocking me for a few weeks now. Can anyone explain what might be wrong?

Tim_Roberts · April 24, 2020, 7:47pm

Your first step “pre-installs” the driver into the driver cache. That appears to have worked.

After that, as you say, you need to instantiate a device to be driven. Have you looked at the setup log for that? Have you triple checked that the software device you’re creating has hardware ID “Root\Models”? That’s the link between these two steps. You probably want to pick a more unique name than that anyway.

scott_smith · April 27, 2020, 2:38pm

Tim, thanks so much for your reply.

Ah! OK, I didn’t know about the pre-install thing. I have a copy of Developing Drivers with the Microsoft Windows Driver Foundation
by Penny Orwick and Guy Smith, but it’s pretty out of date (2007). It mentions things like enumerators and software drivers only once, and only in passing…

Have you looked at the setup log for that?
Have you triple checked that the software device you’re creating has hardware ID “Root\Models”?
That’s the link between these two steps. You probably want to pick a more unique name than that anyway.

Yes, so here’s what happens when I run the driver test program:

A call is made to SwDeviceCreate (BTW, Models is just a keyword I’m using when posting):

const ULONG capabilityFlags =
    SWDeviceCapabilitiesDriverRequired | SWDeviceCapabilitiesRemovable | SWDeviceCapabilitiesSilentInstall;

const SW_DEVICE_CREATE_INFO createInfo = {
    /* cbSize               */ sizeof(SW_DEVICE_CREATE_INFO),
    /* pszInstanceId        */ L"Models",
    /* pszzHardwareIds      */ L"Models\0",
    /* pszzCompatibleIds    */ L"Models\0",
    /* pContainerId         */ nullptr,
    /* CapabilityFlags      */ capabilityFlags,
    /* pszDeviceDescription */ L"MyCompany Virtual Display Adapter",
    /* pszDeviceLocation    */ nullptr,
    /* pSecurityDescriptor  */ nullptr
};

const auto hr = SwDeviceCreate(
    L"Models",                      // Enumerator-specific-device-id (enumerator name)
    L"HTREE\\ROOT\\0",              // Device instance ID of the device that is the parent of our software device (parent device [system root])
    &createInfo,                    // Info that PnP uses to create our device
    0,                              // Properties count
    nullptr,                        // Properties
    DriverTest::OnDeviceCreated,    // Our callback function
    this,                           // Context info to pass into callback
    &_hSwDevice);                   // Variable to receive the handle to our device

The main thread waits for the callback
The SW device is created successfully
The test app waits for a keypress (I don’t actually do anything with the hSwDevice yet)
There’s no indication that my driver files were copied, or that DriverEntry was called
I exit my test program (it calls SwDeviceClose) and I look at %SystemRoot%\INF\setupapi.dev.log:

>>>  [Device Install (Hardware initiated) - SWD\Models\Models]
>>>  Section start 2020/04/27 06:46:27.720

Four minutes later (after my test app has exited), the following is appended to the log:

<<<  Section end 2020/04/27 06:50:28.014
<<<  [Exit status: FAILURE(0x000005b4) - ERROR_TIMEOUT]

My test program is based upon Windows-driver-samples\video\IndirectDisplay\IddSampleApp, so perhaps it’s incomplete and I’m too new at this to realize what Microsoft left out?

scott_smith · April 27, 2020, 2:45pm

As an aside, pretty much the only source of up-to-date information I have right now is docs.microsoft.com, and it sometimes seems like Microsoft is trying to keep this stuff a secret.

Any recommendations on books, videos, or other sources of (reasonably) up-to-date information would be greatly appreciated.

Tim_Roberts · April 28, 2020, 6:41am

Well, interestingly, I’ve never used the relatively new SWDeviceCreate APIs. The log shows that you’ve created SWD\Models\Models, but the instance ID is Models. Those have to match exactly.

scott_smith · April 28, 2020, 8:39pm

This was a point of confusion for me; specifically the mapping between the values in the INF and params we set in the test app.

My code is based upon the IndirectDisplay sample’s test program - here’s the original (unmodified) sample code:

// These match the PnP IDs in the INF file so OS will load the driver when the device is created    
createInfo.pszzCompatibleIds = L"IddSampleDriver\0";
createInfo.pszInstanceId = L"IddSampleDriver";
createInfo.pszzHardwareIds = L"IddSampleDriver\0";

(snip)

// Create the device
HRESULT hr = SwDeviceCreate(L"IddSampleDriver",
                            L"HTREE\\ROOT\\0",
                            &createInfo,
                            0,
                            nullptr,
                            CreationCallback,
                            &hEvent,
                            &hSwDevice);

…and in their sample driver INF file:

[Standard.NT$ARCH$]
%DeviceName%=MyDevice_Install, Root\IddSampleDriver ; TODO: edit hw-id, this hardware id is used by Visual Studio remote debugging
%DeviceName%=MyDevice_Install, IddSampleDriver      ; TODO: edit hw-id, this hardware if is used by the IddSampleApp.exe

(snip)

; (the only other place "IddSampleDriver" appears as a keyword)
[MyDevice_Install.NT.Wdf]
UmdfService=IddSampleDriver,IddSampleDriver_Install
UmdfServiceOrder=IddSampleDriver

In my driver’s INF file and test app, IddSampleDriver is replaced with Models**. This is something I’ve verified multiple times in an effort to find any differences between my code and the sample.

For what it’s worth, when I build, deploy and attempt to install/test Microsoft’s IndirectDisplay sample, it seems to fail in the same way as mine (more testing needed).

I’ve been assuming that it was something I was doing wrong, but your reply makes me wonder if this is just a bug in their sample test app?

I’ll look at the other samples and see if there’s similar test code with any differences. If it is a bug, they can’t all have it…

** Well, actually ‘Models’ is what I use when posting…

scott_smith · April 28, 2020, 9:09pm

Hmmm, there is similar test code that looks like this:

    GUID instanceId;
    CoCreateGuid(&instanceId);

    WCHAR instanceIdString[40];
    (void) StringFromGUID2(instanceId, instanceIdString, _countof(instanceIdString));

    SW_DEVICE_CREATE_INFO deviceCreateInfo = {};
    deviceCreateInfo.cbSize = sizeof(SW_DEVICE_CREATE_INFO);
    deviceCreateInfo.pszInstanceId = instanceIdString;
    deviceCreateInfo.pszzHardwareIds = L"root\\NfcCxTestDevice\0"; // Multi-string (i.e. null-null terminated list of strings)
    deviceCreateInfo.CapabilityFlags = SWDeviceCapabilitiesSilentInstall | SWDeviceCapabilitiesDriverRequired;

    // Install the device.
    VerifyHresultSucceeded(SwDeviceCreate(...

I read that in a path like <device-id>\<instance-specific-id>, the second part is a “system-supplied ID that uniquely identifies a device in the system”. I thought that meant that my code would always get this from Windows, but maybe “system-supplied” means “as opposed to being vendor-defined”?

The IndirectDisplay sample test uses “IddSampleDriver” as both device-id and instance-specific-id, rather than generating a GUID for the latter. I’m not sure whether making this change to my code would have any effect, other than to change the path in log messages from SWD\Models\Models to SWD\Models\<some-guid>.

What am I missing?

scott_smith · April 28, 2020, 9:39pm

Whoops, didn’t notice another difference at first. The hardware ID in this other sample includes “root\”. The IndirectDisplay example (and mine) do not.