[Bug 46830] Gaea 1.0.14.8002 installer stops: err:msi: ITERATE_Actions Execution halted, action L"WixSchedInternetShortcuts" returned 1603 (MsiViewGetErrorA/W() needs to be RPC-compatible)

wine-bugs at winehq.org wine-bugs at winehq.org
Wed Mar 13 18:11:41 CDT 2019 

https://bugs.winehq.org/show_bug.cgi?id=46830

Anastasius Focht <focht at gmx.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |Installer
                 CC|                            |focht at gmx.net
          Component|-unknown                    |msi
            Summary|Gaea 1.0.14.8002 installer  |Gaea 1.0.14.8002 installer
                   |stops:                      |stops:
                   |err:msi:ITERATE_Actions     |err:msi:ITERATE_Actions
                   |Execution halted, action    |Execution halted, action
                   |L"WixSchedInternetShortcuts |L"WixSchedInternetShortcuts
                   |" returned 1603             |" returned 1603
                   |                            |(MsiViewGetErrorA/W() needs
                   |                            |to be RPC-compatible)

--- Comment #1 from Anastasius Focht <focht at gmx.net> ---
Hello folks,

confirming.

Relevant part of trace log:

--- snip ---
$ WINEDEBUG=+seh,+relay,+msi wine msiexec -i Gaea-1.0.15.8003.msi >>log.txt
2>&1
...
0036:trace:msi:ACTION_CustomAction Handling custom action
L"WixSchedInternetShortcuts" (1 L"WixCA" L"WixSchedInternetShortcuts") 
...
0036:trace:msi:HANDLE_CustomType1 Calling function L"WixSchedInternetShortcuts"
from L"C:\\users\\focht\\Temp\\msi18b0.tmp" 
...
003d:trace:msi:MsiGetComponentStateW 1 L"InternetShortcut" 0x92bfbb8 0x92bfbc0
003d:trace:msi:MSI_GetComponentStateW 0x17c678 L"InternetShortcut" 0x92bfbb8
0x92bfbc0
003d:trace:msi:MSI_GetComponentStateW states (2, 3)
...
003b:Call msi.MsiRecordSetStringA(00000005,00000000,100330b0
"WixSchedInternetShortcuts:  Adding folder
'ProgramMenuFolder.QuadSpinner.Gaea', component 'InternetShortcut' to the
CreateFolder table") ret=1000da1a 
...
003e:Call KERNEL32.WideCharToMultiByte(00000000,00000000,00696a88
L"WixSchedInternetShortcuts:  Adding folder
'ProgramMenuFolder.QuadSpinner.Gaea', component 'InternetShortcut' to the
CreateFolder table",ffffffff,00000000,00000000,00000000,00000000) ret=7e942181 
...
003b:Call msi.MsiDatabaseOpenViewW(00000002,0016b810 L"SELECT * FROM
`CreateFolder`",0055fce0) ret=1000ed0a
003b:trace:msi:MsiDatabaseOpenViewW L"SELECT * FROM `CreateFolder`" 0x55fce0
...
003d:trace:msi:MsiDatabaseOpenViewW L"SELECT * FROM `CreateFolder`" 0x92bfbc0
003d:trace:msi:MSI_DatabaseOpenViewW L"SELECT * FROM `CreateFolder`" 0x92bf990
...
003d:trace:msi:MSI_ParseSQL Parse returned 0
003d:trace:msi:alloc_msihandle 0x6962b8 -> 4
...
003b:trace:msi:alloc_msi_remote_handle 4 -> 5
003b:Ret  msi.MsiDatabaseOpenViewW() retval=00000000 ret=1000ed0a
003b:Call msi.MsiViewExecute(00000005,00000000) ret=1000ed45
003b:trace:msi:MsiViewExecute 5 0
...
003e:trace:msi:MsiViewExecute 4 0
003e:trace:msi:MSI_ViewExecute 0x6962b8 (nil)
003e:trace:msi:MsiCloseHandle 0
...
003b:Ret  msi.MsiViewExecute() retval=00000000 ret=1000ed45
003b:Call msi.MsiViewGetColumnInfo(00000005,00000001,0055fcdc) ret=1000dc5a
003b:trace:msi:MsiViewGetColumnInfo 5 1 0x55fcdc
...
003d:trace:msi:MsiViewGetColumnInfo 4 1 0x92bf9d8
...
003d:trace:msi:msi_set_record_type_string type 2d48 -> L"s72"
...
003d:trace:msi:msi_set_record_type_string type 2d48 -> L"s72"
...
003d:trace:msi:alloc_msihandle 0x696260 -> 5
...
003b:Ret  msi.MsiViewGetColumnInfo() retval=00000000 ret=1000dc5a
003b:Call msi.MsiCreateRecord(00000002) ret=1000dc99
...
003b:trace:msi:alloc_msihandle 0x16cf88 -> 7
003b:Ret  msi.MsiCreateRecord() retval=00000007 ret=1000dc99
...
003b:Call msi.MsiRecordGetStringW(00000006,00000001,0016cfd8,0055fa48)
ret=1000ea59
003b:Ret  msi.MsiRecordGetStringW() retval=00000000 ret=1000ea59
003b:Call msi.MsiRecordSetStringW(00000007,00000001,0016ceb8
L"ProgramMenuFolder.QuadSpinner.Gaea") ret=1000de02
...
003b:Ret  msi.MsiRecordSetStringW() retval=00000000 ret=1000de02
...
003b:Call msi.MsiRecordGetStringW(00000006,00000002,0016cfd8,0055fa48)
ret=1000ea59
003b:Ret  msi.MsiRecordGetStringW() retval=00000000 ret=1000ea59
003b:Call msi.MsiRecordSetStringW(00000007,00000002,0016d870
L"InternetShortcut") ret=1000de02
...
003b:Ret  msi.MsiRecordSetStringW() retval=00000000 ret=1000de02
003b:Call msi.MsiViewModify(00000005,00000007,00000007) ret=1000de26
003b:trace:msi:MsiViewModify 5 7 7 
...
003e:trace:msi:alloc_msihandle 0x696260 -> 5
003e:trace:msi:MsiViewModify 4 7 5
003e:trace:msi:MsiCloseHandle 5
003e:trace:msi:MsiCloseHandle handle 5 destroyed
...
003b:Ret  msi.MsiViewModify() retval=0000065b ret=1000de26
003b:Call msi.MsiViewModify(00000005,00000009,00000007) ret=1000de4c
003b:trace:msi:MsiViewModify 5 9 7
...
003d:trace:msi:alloc_msihandle 0x6947e8 -> 5
003d:trace:msi:MsiViewModify 4 9 5
003d:trace:msi:MsiCloseHandle 5
003d:trace:msi:MsiCloseHandle handle 5 destroyed 
...
003b:Ret  msi.MsiViewModify() retval=0000000d ret=1000de4c
003b:Call msi.MsiViewGetErrorW(00000005,0055fa74,0055fa60) ret=1000de7a
003b:trace:msi:MsiViewGetErrorW 5 0x55fa74 0x55fa60
003b:Ret  msi.MsiViewGetErrorW() retval=fffffffd ret=1000de7a
003b:Ret  msi.MsiViewGetErrorW() retval=fffffffd ret=1000de7a
003b:Call KERNEL32.GetLastError() ret=10017048
...
003b:Call msi.MsiRecordSetStringA(00000008,00000000,100330b0
"WixSchedInternetShortcuts:  Error 0x8007000d: failed to add temporary row,
dberr: -3, err: ") ret=1000da1a
...
003b:Call msi.MsiRecordSetStringA(00000007,00000000,100330b0
"WixSchedInternetShortcuts:  Error 0x8007000d: Couldn't add temporary
CreateFolder row") ret=1000da1a 
...
0036:err:msi:ITERATE_Actions Execution halted, action
L"WixSchedInternetShortcuts" returned 1603
--- snip ---

Debug session:

--- snip ---
Wine-gdb> bt
#0  table_validate_new (tv=0x5bb490, rec=0x5bbea0, column=0x0) at
/home/focht/projects/wine/mainline-src/dlls/msi/table.c:1636
#1  0x00007fb3ef2d2921 in TABLE_modify (view=0x5bb490,
eModifyMode=MSIMODIFY_INSERT_TEMPORARY, rec=0x5bbea0, row=0xffffffff) at
/home/focht/projects/wine/mainline-src/dlls/msi/table.c:1889
#2  0x00007fb3ef296ed5 in MSI_ViewModify (query=0x5b90b0,
mode=MSIMODIFY_INSERT_TEMPORARY, rec=0x5bbea0) at
/home/focht/projects/wine/mainline-src/dlls/msi/msiquery.c:712
#3  0x00007fb3ef29722f in MsiViewModify (hView=0x4,
eModifyMode=MSIMODIFY_INSERT_TEMPORARY, hRecord=0x5) at
/home/focht/projects/wine/mainline-src/dlls/msi/msiquery.c:763
#4  0x00007fb3ef299681 in s_remote_ViewModify (view=0x4,
mode=MSIMODIFY_INSERT_TEMPORARY, remote_rec=0x5bbe20,
remote_refreshed=0x2cbf668)
    at /home/focht/projects/wine/mainline-src/dlls/msi/msiquery.c:1235
#5  0x00007fb3ef2e930b in IWineMsiRemote_remote_ViewModify
(_pRpcMessage=0x5baa10) at winemsi_s.c:651
#6  0x00007fb3ee6a74ca in process_request_packet (conn=0x5b71c0, hdr=0x5bbbe0,
msg=0x5baa10) at
/home/focht/projects/wine/mainline-src/dlls/rpcrt4/rpc_server.c:439
#7  0x00007fb3ee6a7a4f in RPCRT4_process_packet (conn=0x5b71c0, hdr=0x5bbbe0,
msg=0x5baa10, auth_data=0x0, auth_length=0x0)
    at /home/focht/projects/wine/mainline-src/dlls/rpcrt4/rpc_server.c:517
#8  0x00007fb3ee6a7c8e in RPCRT4_worker_thread (the_arg=0x86d30) at
/home/focht/projects/wine/mainline-src/dlls/rpcrt4/rpc_server.c:539
#9  0x000000007bd433df in process_rtl_work_item (instance=0x2cbfbe0,
userdata=0x5b7320) at
/home/focht/projects/wine/mainline-src/dlls/ntdll/threadpool.c:349
#10 0x000000007bd49036 in threadpool_worker_proc (param=0x5b8760) at
/home/focht/projects/wine/mainline-src/dlls/ntdll/threadpool.c:2126
#11 0x000000007bd30fba in call_thread_func (entry=0x7bd48bd5
<threadpool_worker_proc>, arg=0x5b8760) at
/home/focht/projects/wine/mainline-src/dlls/ntdll/signal_x86_64.c:4454
#12 0x0000000000000000 in ?? ()

Wine-gdb> p *tv
$14 = {view = {hdr = {magic = 0x0, type = 0x0, refcount = 0x0, destructor =
0x0}, ops = 0x7fb3ef33dc80 <table_ops>, error = MSIDBERROR_NOERROR,
error_column = 0x0}, db = 0x76040, 
  table = 0x94cc0, columns = 0x94d30, num_cols = 0x2, row_size = 0x6, name =
{0x43}}

Wine-gdb> p *rec
$15 = {hdr = {magic = 0x4d434923, type = 0x4, refcount = 0x2, destructor =
0x7fb3ef2a8fcd <MSI_CloseRecord>}, count = 0x2, cookie = 0x0, fields = {{type =
0x0, u = {iVal = 0x0, 
        szwVal = 0x0, stream = 0x0}, len = 0x0}}}

Wine-gdb> x/sh str
0x5bbf20:    u"ProgramMenuFolder.QuadSpinner.Gaea"
...
Wine-gdb> x/sh str
0x5bb550:    u"InternetShortcut"

...
Wine-gdb> bt
#0  msi_table_find_row (tv=0x5bb490, rec=0x5bbea0, row=0x2cbefb4, column=0x0)
at /home/focht/projects/wine/mainline-src/dlls/msi/table.c:2492
#1  0x00007fb3ef2d1ce4 in table_validate_new (tv=0x5bb490, rec=0x5bbea0,
column=0x0) at /home/focht/projects/wine/mainline-src/dlls/msi/table.c:1661

2494            r = msi_row_matches( tv, i, data, column );
Wine-gdb> n
2495            if( r == ERROR_SUCCESS )
Wine-gdb> n
2497                *row = i;
Wine-gdb> info locals
i = 0x5
r = 0x0
data = 0x5bbf80

Wine-gdb> n
table_validate_new (tv=0x5bb490, rec=0x5bbea0, column=0x0) at
/home/focht/projects/wine/mainline-src/dlls/msi/table.c:1662
1662        if (r == ERROR_SUCCESS)
Wine-gdb> n
1663            return ERROR_FUNCTION_FAILED;

...
Thread 3 hit Breakpoint 1, MSI_ViewModify (query=0x5b90b0,
mode=MSIMODIFY_VALIDATE_NEW, rec=0x5bbea0) at
/home/focht/projects/wine/mainline-src/dlls/msi/msiquery.c:699
699        MSIVIEW *view = NULL;
...
Wine-gdb> n
712        r = view->ops->modify( view, mode, rec, query->row - 1 );
...
Wine-gdb> n
TABLE_modify (view=0x5bb4e0, eModifyMode=MSIMODIFY_VALIDATE_NEW, rec=0x5bbea0,
row=4294967295) at /home/focht/projects/wine/mainline-src/dlls/msi/table.c:1873
1873            if (r != ERROR_SUCCESS)
Wine-gdb> n
1875                tv->view.error = MSIDBERROR_DUPLICATEKEY;
Wine-gdb> n
...
Wine-gdb> n
713        if (mode == MSIMODIFY_DELETE && r == ERROR_SUCCESS)
Wine-gdb> p r
$2 = 0xd

--- snip ---

Relevant dump of 'CreateFolder' table with ORCA:

--- snip ---
Directory_    Component_
s72    s72

ProgramFiles64Folder    Registry.1
ProgramFiles64Folder    Registry.2
ProgramMenuFolder.QuadSpinner.Gaea    Component.Gaea_
ProgramMenuFolder.QuadSpinner.Gaea    Component.Gaea__Safe_Mode_
ProgramMenuFolder.QuadSpinner.Gaea    Component.Watson_Diagnostics_Tool
ProgramMenuFolder.QuadSpinner.Gaea    InternetShortcut
DesktopFolder    Component.Gaea.1
TARGETDIR    TARGETDIR
--- snip ---

Relevant dump of 'CustomAction' table with ORCA:

--- snip ---
WixSchedInternetShortcuts    1    WixCA    WixSchedInternetShortcuts    
--- snip ---

Relevant dump of 'InstallExecuteSequence' table with ORCA

--- snip ---
WixSchedInternetShortcuts    VersionNT > 400    3599
--- snip ---

The user-visible symptom is essentially bug 27338 which was fixed 8 years ago.

I already did a thorough accurate analysis there, hence I only repeat the
summary:

--- quote ---
...
The insertion of last temporary WixInternetShortcut record fails due to folder
already existing in "CreateFolder" table -> duplicate item.
This error is usually harmless but must be propagated somehow.
Msi only returns ERROR_FUNCTION_FAILED on temporary row insertion failure.
The installer tries to figure out exact error and issues
MSIMODIFY_VALIDATE_NEW,
...
The following MsiViewGetErrorW() to fetch the detailed error should actually
return MSIDBERROR_DUPLICATEKEY. The installer recognizes this error code and
does not fail if returned.
--- quote ---

The MSI remoting rework (MSI custom actions run in separate server process)
from April 2018 by Zebediah missed this one. MsiViewGetErrorA/W() needs to be
remotable (RPC compatible) too - currently it's not.

https://source.winehq.org/git/wine.git/blob/HEAD:/dlls/msi/msiquery.c#l770

--- snip ---
 770 MSIDBERROR WINAPI MsiViewGetErrorW( MSIHANDLE handle, LPWSTR buffer,
LPDWORD buflen )
 771 {
 772     MSIQUERY *query;
 773     const WCHAR *column;
 774     MSIDBERROR r;
 775     DWORD len;
 776 
 777     TRACE("%u %p %p\n", handle, buffer, buflen);
 778 
 779     if (!buflen)
 780         return MSIDBERROR_INVALIDARG;
 781 
 782     query = msihandle2msiinfo( handle, MSIHANDLETYPE_VIEW );
 783     if( !query )
 784         return MSIDBERROR_INVALIDARG;
 785 
 786     if ((r = query->view->error)) column = query->view->error_column;
 787     else column = szEmpty;
 788 
 789     len = strlenW( column );
 790     if (buffer)
 791     {
 792         if (*buflen > len)
 793             strcpyW( buffer, column );
 794         else
 795             r = MSIDBERROR_MOREDATA;
 796     }
 797     *buflen = len;
 798     msiobj_release( &query->hdr );
 799     return r;
 800 }
--- snip ---

$ sha1sum Gaea-1.0.15.8003.msi 
173154a11ce7730cf65f7a32d7616c0952e35f71  Gaea-1.0.15.8003.msi

$ du -sh Gaea-1.0.15.8003.msi 
46M    Gaea-1.0.15.8003.msi

$ wine --version
wine-4.3-338-gf34f13825f

Regards

-- 
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