https://bugs.winehq.org/show_bug.cgi?id=46830
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- Keywords| |Installer CC| |focht@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@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