[Bug 29354] Multiple Microsoft product installers fail due to ProductID being set during client side "ValidateProductID" standard action (Microsoft Virtual PC 2007, Visual Studio 2008 Prof)

wine-bugs at winehq.org wine-bugs at winehq.org
Sun Feb 12 11:11:16 CST 2012 

http://bugs.winehq.org/show_bug.cgi?id=29354

Anastasius Focht <focht at gmx.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Summary|Microsoft Virtual PC 2007   |Multiple Microsoft product
                   |SP1 installer fails to get  |installers fail due to
                   |past the "Product Key"      |ProductID being set during
                   |dialog                      |client side
                   |                            |"ValidateProductID"
                   |                            |standard action (Microsoft
                   |                            |Virtual PC 2007, Visual
                   |                            |Studio 2008 Prof)

--- Comment #4 from Anastasius Focht <focht at gmx.net> 2012-02-12 11:11:16 CST ---
Hello,

the "Visual Studio 2008 Professional" installer also suffers from this (and
possibly others).

Prerequisite: clean WINEPREFIX, 'winetricks -q dotnet30'

When the main installer processes the "Visual Studio 2008" component there is a
custom action "CA_SetPidProps_x86_deu" -> "SetPidProps" failing (also happens
with eng. version).

--- snip ---
0033:trace:msi:ACTION_CustomAction Handling custom action
L"CA_SetPidProps_x86_deu" (1 L"BIN_File_301630_x86_deu" L"SetPidProps") 
...
0033:Ret  PE DLL (proc=0x3b1b85b6,module=0x3b1b0000
L"msi2361.tmp",reason=PROCESS_ATTACH,res=(nil)) retval=1 
...
0033:trace:msi:HANDLE_CustomType1 Calling function L"SetPidProps" from
L"C:\\users\\focht\\Temp\\msi2361.tmp" 
...
0062:trace:msi:ACTION_CallDllFunction calling L"SetPidProps" 
...
0062:trace:msi:msi_get_property returning L"1031" for property
L"ProductLanguage" 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: LANGID: [2]") ret=3b1b3e5c
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
1031 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Entry: SetPidProps started") ret=3b1b3d72 
...
0062:Call msi.MsiGetPropertyW(00000003,3b1b3600 L"PIDSEQ",155fe808,155fdd80)
ret=3b1b67af 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\tPIDSEQ: [2]") ret=3b1b3e03 
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiGetPropertyW(00000003,3b1b362c L"PIDRET",155fe828,155fdd80)
ret=3b1b67f9 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\tPIDRET: [2]") ret=3b1b3e03
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
0 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiGetPropertyW(00000003,3b1b3658
L"EDITIONTYPE",155fe7e8,155fdd80) ret=3b1b6846 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\tEDITIONTYPE: [2]") ret=3b1b3e03 
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
pro 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiGetPropertyW(00000003,15ab0e60
L"PIDTemplate",155fdafc,155fdaf4) ret=3b1b5ebc 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\tszMPC: [2]") ret=3b1b3e03 
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
91988 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Error: You have entered an invalid Product Key. Please enter a
valid Product Key to continue.\nThe Product Key may be found on the CD case or
the Certificate of Authenticity.") ret=3b1b3db6 
...
0062:Call KERNEL32.RaiseException(e06d7363,00000001,00000003,155fcc08)
ret=3b1bdbe6
0062:trace:seh:raise_exception code=e06d7363 flags=1 addr=0x7b83924f
ip=7b83924f tid=0062
0062:trace:seh:raise_exception  info[0]=19930520
0062:trace:seh:raise_exception  info[1]=155fdc3c
0062:trace:seh:raise_exception  info[2]=3b1c506c
0062:trace:seh:raise_exception  eax=7b826289 ebx=7b8a96a8 ecx=19930520
edx=155fcb14 esi=155fcbf4 edi=155fcb70
0062:trace:seh:raise_exception  ebp=155fcb58 esp=155fcaf4 cs=0023 ds=002b
es=002b fs=0063 gs=006b flags=00000287
0062:trace:seh:call_stack_handlers calling handler at 0x3b1c4883 code=e06d7363
flags=1 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Error: SetPidProps failed.") ret=3b1b3d72 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,15ab0e60 L"02/11/12
22:22:28 DDSet_CARetVal: 1603") ret=3b1c2c5d 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\t SetPidProps Return Value: [2]") ret=3b1b3e5c 
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
1603 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Status: \t\tSetPidProps Returned PID: [2]") ret=3b1b3e03 
...
0062:trace:msi:MSI_ProcessMessage (nil) 0x39e65180 0x39e64ac4 1f9f 10 L"1: 0 2:
0 3:  4:  5:  6:  7:  8:  9:  10:  " 
...
0062:Call msi.MsiRecordSetStringW(00000004,00000000,155fdd90 L"02/11/12
22:22:28 DDSet_Exit: SetPidProps ended") ret=3b1b3d72 
...
0062:trace:msi:DllThread custom action (62) returned 1603 
...
0033:err:msi:ITERATE_Actions Execution halted, action L"CA_SetPidProps_x86_deu"
returned 1603 
--- snip --- 

The custom action first reads the "PIDSEQ", "PIDRET" and "EDITIONTYPE"
properties.
If "PIDRET" != 0 the installer complains "CA_GeneratePID failed before this CA
was called".
The custom action then reads the "PIDTemplate" property and extracts PID and
MPC.

The first five characters of the PID indicate the Microsoft Product Code (MPC).
The three characters after the MPC indicate the channel ID.

The "PIDSEQ" property value is converted to a number and internally used in
validation process.
The MPC is converted to some kind of SKU and verified with some tables.

I found a Windows MSI log for this kind of custom action here:

ftp://ftp.geoplan.ufl.edu/pub/santafe/AnooshBackup/Fac_expert_web/Backup-05-06/Microsoft%20Visual%20Studio%209.0/Microsoft%20Visual%20Studio%202008%20Professional%20Edition%20-%20ENU/Logs/VSMsiLog65CF.txt

--- snip ---
MSI (s) (78:40) [15:41:19:484]: Doing action: CA_SetPidProps_x86_enu
Action ended 15:41:19: CA_SetEditionType_x86_enu. Return value 1.
MSI (s) (78:24) [15:41:19:515]: Invoking remote custom action. DLL:
C:\WINDOWS\Installer\MSI1DB.tmp, Entrypoint: SetPidProps
Action start 15:41:19: CA_SetPidProps_x86_enu.
02/24/09 15:41:19 DDSet_Status: LANGID: 1033
02/24/09 15:41:19 DDSet_Entry: SetPidProps started
02/24/09 15:41:19 DDSet_Status:         PIDSEQ: 270000001
02/24/09 15:41:19 DDSet_Status:         PIDRET: 0
02/24/09 15:41:19 DDSet_Status:         EDITIONTYPE: pro
MSI (s) (78!80) [15:41:19:765]: PROPERTY CHANGE: Adding PID_Installed property.
Its value is 'xxx'.
MSI (s) (78!80) [15:41:19:765]: PROPERTY CHANGE: Adding PID_Length property.
Its value is 'xxx'.
MSI (s) (78!80) [15:41:19:765]: PROPERTY CHANGE: Adding PID_Mpc property. Its
value is '91605'.
MSI (s) (78!80) [15:41:19:765]: PROPERTY CHANGE: Adding PID_Range property. Its
value is 'xxx'.
02/24/09 15:41:19 DDSet_Status:         szMPC: 91605
02/24/09 15:41:19 DDSet_CARetVal: 0
02/24/09 15:41:19 DDSet_Status:          SetPidProps Return Value: 0
02/24/09 15:41:19 DDSet_Status:         SetPidProps Returned PID: 0
02/24/09 15:41:19 DDSet_Exit: SetPidProps ended
--- snip --- 

As you can see from Windows MSI log, the "PIDSEQ" property has value
"270000001", Wine -> not set/empty.

I searched all temp binaries extracted during MSI run and found the property
name/string in a binary which contained "ValidateProductID" custom action.

Looking at the trace log for that custom action:

--- snip ---
0033:trace:msi:ACTION_CustomAction Handling custom action
L"CA_GeneratePID_x86_deu" (41 L"BIN_File_60348_x86_deu" L"ValidateProductID") 
...
0061:Call KERNEL32.LoadLibraryW(0291dbac
L"C:\\users\\focht\\Temp\\msi63d1.tmp") ret=7d56a792
0061:Ret  KERNEL32.LoadLibraryW() retval=007d0000 ret=7d56a792 
...
0061:trace:msi:ACTION_CallDllFunction calling L"ValidateProductID" 
...
0061:Call msi.MsiGetPropertyA(00000003,007d1190 "PID",15aae7dc,15aae1b4)
ret=007d15a8 
...
0061:Call KERNEL32.WideCharToMultiByte(00000000,00000000,029230d0
L"",ffffffff,00000000,00000000,00000000,00000000) ret=7d589847
0061:Ret  KERNEL32.WideCharToMultiByte() retval=00000001 ret=7d589847 
...
0061:Call msi.MsiGetPropertyA(00000003,007d1184 "ProductID",15aae7dc,15aae1b4)
ret=007d16f7 
...
0061:Call KERNEL32.WideCharToMultiByte(00000000,00000000,029230d8
L"xxxxxxxxxxxxxxxxxxxxxxxxx",ffffffff,00000000,00000000,00000000,00000000)
ret=7d589847
0061:Ret  KERNEL32.WideCharToMultiByte() retval=0000001a ret=7d589847 
...
0061:Call KERNEL32.lstrcmpA(15aae7dc "xxxxxxxxxxxxxxxxxxxxxxxxx",007d117c
"None") ret=007d1714
0061:Ret  KERNEL32.lstrcmpA() retval=00000001 ret=007d1714
...
0061:Call msi.MsiSetPropertyA(00000003,007d10f0 "PIDRET",15aae76c "0")
ret=007d1ddb
...
0061:trace:msi:DllThread custom action (61) returned 0 
--- snip ---

(xxxxxxxxxxxxxxxxxxxxxxxxx = product key)

No sign of "PIDSEQ".

What's not visible and can only be found during debugging/analysis: this CA is
basically short circuited because "ProductID" property value is already set.

Only if "ProductID" property is not set a full evaluation happens by reading
"PIDTemplate" property and triggering setting of various additional properties
-> PIDSEQ.

Current source:
http://source.winehq.org/git/wine.git/blob/bca0fd6a5522933c1dcc5dd87c495091ab16eb7a:/dlls/msi/action.c#l6859

--- snip ---
6859 UINT msi_validate_product_id( MSIPACKAGE *package )
6860 {
6861     LPWSTR key, template, id;
6862     UINT r = ERROR_SUCCESS;
6863 
6864     id = msi_dup_property( package->db, szProductID );
6865     if (id)
6866     {
6867         msi_free( id );
6868         return ERROR_SUCCESS;
6869     }
6870     template = msi_dup_property( package->db, szPIDTemplate );
6871     key = msi_dup_property( package->db, szPIDKEY );
6872     if (key && template)
6873     {
6874         FIXME( "partial stub: template %s key %s\n", debugstr_w(template),
debugstr_w(key) );
6875         r = msi_set_property( package->db, szProductID, key );
6876     }
6877     msi_free( template );
6878     msi_free( key );
6879     return r;
6880 }
--- snip ---

Like the other installers, commenting out line 6875 lets the VS 2008 installer
succeed.

"ValidateProductID" custom action without "ProductID" set:

--- snip ---
...
0044:trace:msi:ACTION_CustomAction Handling custom action
L"CA_GeneratePID_x86_deu" (41 L"BIN_File_60348_x86_deu" L"ValidateProductID") 
...
0019:trace:msi:ACTION_CallDllFunction calling L"ValidateProductID" 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1190 "PID",0e5fe7dc,0e5fe1b4)
ret=007b15a8 
...
0019:Call KERNEL32.WideCharToMultiByte(00000000,00000000,02a20940
L"",ffffffff,00000000,00000000,00000000,00000000) ret=7d58c81f 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1184 "ProductID",0e5fe7dc,0e5fe1b4)
ret=007b16f7 
...
0019:Call KERNEL32.WideCharToMultiByte(00000000,00000000,02a20940
L"",ffffffff,00000000,00000000,00000000,00000000) ret=7d58c81f 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1154
"PIDTemplate",0e5fe6c4,0e5fe1b4) ret=007b1742 
...
0019:Call KERNEL32.WideCharToMultiByte(00000000,00000000,02a20940
L"xxxxx<````=````=````=````=`````>@@@@@",ffffffff,00000000,00000000,00000000,00000000)
ret=7d58c81f 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1148 "OEMRelease",0e5fe804,0e5fe1b4)
ret=007b179c 
...
0019:Call msi.MsiGetPropertyA(00000003,007b113c "OEMID",0e5fe850,0e5fe1b4)
ret=007b17e5 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1134 "PIDSKU",0e5fe814,0e5fe1b4)
ret=007b1805 
...
0019:Call msi.MsiGetPropertyA(00000003,007b1120 "PIDKEY",0e5fe7dc,0e5fe1b4)
ret=007b196b 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1128 "CCPTrigger",0e5fe1ac "1")
ret=007b1be4 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1118 "PKU",0e5fe1ac "0")
ret=007b1c29 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1110 "PIDSEQ",0e5fe77c "270000001")
ret=007b1c6b 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1190 "PID",0e5fe828
"xxxxx-xxx-xxxxxxx-xxxxx") ret=007b1d7c 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1184 "ProductID",0e5fe828
"xxxxx-xxx-xxxxxxx-xxxxx") ret=007b1d8b 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1174 "DPID",0e5fe3c0 "#xxxxxxxxxx
....xxxxx"...) ret=007b1d9d 
...
0019:Call msi.MsiSetPropertyA(00000003,007b1160 "DigitalProductID",0e5fe3c0
"#xxxxxxxxxx...xxxxx"...) ret=007b1daf 
...
0019:Call msi.MsiSetPropertyA(00000003,007b10f0 "PIDRET",0e5fe76c "0")
ret=007b1ddb
...
0019:trace:msi:DllThread custom action (19) returned 0 
--- snip ---

Several properties are set that are required at later verification stage.
The custom action "CA_SetPidProps_x86_deu" succeeds with these set.

If that bug is fixed the installer runs into bug 10601

--- snip ---
fixme:ntdll:server_ioctl_file Unsupported ioctl 900a4 (device=9 access=0
func=29 method=0)
err:msi:msi_install_assembly Failed to install assembly
L"C:\\users\\focht\\Temp\\msi26f.tmp\\WcfSvcHost.exe" (0x80070032)
err:msi:ACTION_InstallFiles Failed to install assembly
err:msi:ITERATE_Actions Execution halted, action L"InstallFiles" returned 1603
--- snip ---

Regards

-- 
Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email
Do not reply to this email, post in Bugzilla using the
above URL to reply.
------- You are receiving this mail because: -------
You are watching all bug changes.

More information about the wine-bugs mailing list