[Bug 34989] Atlassian SourceTree (Mercurial and Git client) v1.3.2 installer hangs (deferred type 1 custom action executed before regular type 1 custom action)
wine-bugs at winehq.org
wine-bugs at winehq.org
Sun Nov 24 15:23:08 CST 2013
http://bugs.winehq.org/show_bug.cgi?id=34989
Anastasius Focht <focht at gmx.net> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|UNCONFIRMED |NEW
CC| |focht at gmx.net
Component|-unknown |msi
Summary|SourceTree can't install |Atlassian SourceTree
| |(Mercurial and Git client)
| |v1.3.2 installer hangs
| |(deferred type 1 custom
| |action executed before
| |regular type 1 custom
| |action)
Ever Confirmed|0 |1
--- Comment #2 from Anastasius Focht <focht at gmx.net> 2013-11-24 15:23:08 CST ---
Hello folks,
confirming.
--- quote ---
In terminal output, I found
--
fixme:shell:SHGetKnownFolderPath flags 0x00004400 not supported
--
So I guess this is a shell32 bug
--- quote ---
FIXME's are not necessarily bugs.
The installer creates a child process and some bidirectional (message mode)
pipes which both processes use to communicate with each other.
At the point of the "hang" the client is blocking on a pipe read in some msi
custom action.
--- snip ---
Wine-dbg>info process
pid threads executable (all id:s are in hex)
>00000023 4 'SourceTreeSetup_1.3.2.exe'
00000032 2 \_ 'SourceTreeSetup_1.3.2.exe'
00000021 1 'explorer.exe'
0000000e 5 'services.exe'
0000001a 3 \_ 'plugplay.exe'
00000012 4 \_ 'winedevice.exe'
Wine-dbg>info thread
process tid prio (all id:s are in hex)
...
00000023 (D) Z:\home\focht\Downloads\SourceTreeSetup_1.3.2.exe
0000002b 0
0000002a 0
00000025 0
00000024 0
00000032 (D) Z:\home\focht\Downloads\SourceTreeSetup_1.3.2.exe
00000039 0
00000033 0 <==
--- snip ---
Server/parent creating two pipes:
--- snip ---
002a:Call KERNEL32.CreateNamedPipeW(0014db28
L"\\\\.\\pipe\\ToServerAdvinst_Estimate_Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe",00000003,00000006,000000ff,00007f90,00007f90,00001388,00000000)
ret=00480d7c
002a:Ret KERNEL32.CreateNamedPipeW() retval=0000009c ret=00480d7c
...
002a:Call KERNEL32.CreateNamedPipeW(0014f020
L"\\\\.\\pipe\\ToServerAdvinst_Extract_Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe",00000003,00000006,000000ff,00007f90,00007f90,00001388,00000000)
ret=00480d7c
002a:Ret KERNEL32.CreateNamedPipeW() retval=000000a0 ret=00480d7c
...
--- snip ---
Server thread tid 0x2a waiting for client connect to
"\\\\.\\pipe\\ToServerAdvinst_Estimate_Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe":
--- snip ---
002a:Call KERNEL32.ConnectNamedPipe(0000009c,00000000) ret=00480f8a
--- snip ---
Another pipe (served from tid 0x2b) for child process which is created a short
time later:
--- snip ---
002b:Call KERNEL32.CreateNamedPipeW(005bf580
L"\\\\.\\pipe\\ToServer35",00000003,00000006,000000ff,00000400,00000400,00001388,00000000)
ret=00498839
002b:Ret KERNEL32.CreateNamedPipeW() retval=000000f8 ret=00498839
...
002b:Call KERNEL32.CreateProcessW(005bf5f8
L"Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe",005c0cd0
L"Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe /i
\"C:\\users\\Public\\Application Data\\Atlassian\\SourceTree
1.3.2\\install\\SourceTreeSetup_1.3.2.msi\" EXECUTEACTION=\"INSTALL\"
SECONDSEQUENCE=\"1\" CLIENTPROCESSID=\"35\" ADDLOCAL=\"MainFeature\"
ACTION=\"INSTALL\" CLIENTUILEVEL=\"0\"
ALLUS"...,00000000,00000000,00000000,00000000,00000000,00000000,00bade0c,00bae104)
ret=004a086a
...
0032:Call KERNEL32.__wine_kernel_init() ret=7bc599cc
002b:Ret KERNEL32.CreateProcessW() retval=00000001 ret=004a086a
...
002b:Call KERNEL32.ConnectNamedPipe(000000f8,00000000) ret=00498a35
...
--- snip ---
(working) sequence of client<->server pipe "\\\\.\\pipe\\ToServer35"
communication:
--- snip ---
0032:Call KERNEL32.CreateFileW(0058e768
L"\\\\.\\pipe\\ToServer35",c0000000,00000000,00000000,00000003,00000000,00000000)
ret=0049885f
0032:Ret KERNEL32.CreateFileW() retval=000000b0 ret=0049885f
...
0032:Call KERNEL32.WriteFile(000000b0,0058e768,00000010,0033e108,00000000)
ret=00498b95
002b:Ret KERNEL32.ConnectNamedPipe() retval=00000001 ret=00498a35
0032:Ret KERNEL32.WriteFile() retval=00000001 ret=00498b95
002b:Call KERNEL32.ReadFile(000000f8,005bf8d8,00000400,00badcc4,00000000)
ret=00498aaf
0032:Call KERNEL32.ReadFile(000000b0,0058aa58,00000400,0033e074,00000000)
ret=00498aaf
002b:Ret KERNEL32.ReadFile() retval=00000001 ret=00498aaf
...
002b:Call
KERNEL32.PeekNamedPipe(000000f8,00000000,00000000,00000000,00000000,00badcc8)
ret=00498b09
002b:Ret KERNEL32.PeekNamedPipe() retval=00000001 ret=00498b09
...
002b:Call KERNEL32.WriteFile(000000f8,00badd3c,0000000a,00badd20,00000000)
ret=00498bea
002b:Ret KERNEL32.WriteFile() retval=00000001 ret=00498bea
0032:Ret KERNEL32.ReadFile() retval=00000001 ret=00498aaf
002b:Call KERNEL32.FlushFileBuffers(000000f8) ret=00498bf3
0032:Call
KERNEL32.PeekNamedPipe(000000b0,00000000,00000000,00000000,00000000,0033e078)
ret=00498b09
0032:Ret KERNEL32.PeekNamedPipe() retval=00000001 ret=00498b09
0032:Call ntdll.RtlFreeHeap(00584000,00000000,0058e768) ret=004b0df8
0032:Ret ntdll.RtlFreeHeap() retval=00000001 ret=004b0df8
002b:Ret KERNEL32.FlushFileBuffers() retval=00000001 ret=00498bf3
...
002b:Call KERNEL32.ConnectNamedPipe(000000f8,00000000) ret=00498a35
0032:Call KERNEL32.WriteFile(000000b0,0058fb10,0000004a,0033e108,00000000)
ret=00498b95
0032:Ret KERNEL32.WriteFile() retval=00000001 ret=00498b95
0032:Call KERNEL32.ReadFile(000000b0,0058aa58,00000400,0033e074,00000000)
ret=00498aaf
002b:Ret KERNEL32.ConnectNamedPipe() retval=00000000 ret=00498a35
--- snip ---
Messages containing unicode ascii strings are exchanged over pipe.
Looks like some proprietary installer protocol.
At some point a custom action "AI_ExtractFiles" (ExtractSourceFiles) is
executed on the client side:
--- snip ---
...
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_ExtractFiles"
(401 L"Prereq.dll" L"ExtractSourceFiles")
...
0032:trace:msi:HANDLE_CustomType1 Calling function L"ExtractSourceFiles" from
L"C:\\users\\focht\\Temp\\msicd98.tmp"
...
0032:Call ole32.CoCreateGuid(008fd7b4) ret=7d531a09
0032:Call rpcrt4.UuidCreate(008fd7b4) ret=7e69c445
0032:Call advapi32.SystemFunction036(008fd7b4,00000010) ret=7e639113
0032:Ret advapi32.SystemFunction036() retval=00000001 ret=7e639113
0032:Ret rpcrt4.UuidCreate() retval=00000000 ret=7e69c445
0032:Ret ole32.CoCreateGuid() retval=00000000 ret=7d531a09
0032:Call
KERNEL32.CreateThread(00000000,00000000,7d531866,008fd7b4,00000000,00000000)
ret=7d531a7b
0032:Ret KERNEL32.CreateThread() retval=000000d8 ret=7d531a7b
0032:trace:msi:wait_thread_handle waiting for L"AI_ExtractFiles"
...
0038:Starting thread proc 0x7d531866 (arg=0x8fd7b4)
...
0038:Call KERNEL32.LoadLibraryW(0015e964
L"C:\\users\\focht\\Temp\\msicd98.tmp") ret=7d5314d7
0038:Ret KERNEL32.LoadLibraryW() retval=00340000 ret=7d5314d7
...
0038:Call KERNEL32.GetProcAddress(00340000,00919c48 "ExtractSourceFiles")
ret=7d531577
0038:Ret KERNEL32.GetProcAddress() retval=0035980b ret=7d531577
...
0038:trace:msi:alloc_msi_remote_handle 0x9067f8 -> 4
0038:trace:msi:ACTION_CallDllFunction calling L"ExtractSourceFiles"
...
0038:Call KERNEL32.CreateFileA(0091ad78
"\\\\.\\pipe\\ToServerAdvinst_Extract_Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe",c0000000,00000000,00000000,00000003,00000000,00000000)
ret=00348e1f
0038:Ret KERNEL32.CreateFileA() retval=000000dc ret=00348e1f
...
0038:Call KERNEL32.WriteFile(000000dc,0091afb8,00000004,093ce7c4,00000000)
ret=003490ca
0038:Ret KERNEL32.WriteFile() retval=00000001 ret=003490ca
0038:Call KERNEL32.FlushFileBuffers(000000dc) ret=003490d3
0038:Ret KERNEL32.FlushFileBuffers() retval=00000001 ret=003490d3
0038:Call ntdll.RtlFreeHeap(00110000,00000000,0091afa8) ret=00362277
0038:Ret ntdll.RtlFreeHeap() retval=00000001 ret=00362277
0038:Call KERNEL32.ConnectNamedPipe(000000dc,00000000) ret=00349011
0038:fixme:ntdll:server_ioctl_file Unsupported ioctl 110008 (device=11 access=0
func=2 method=0)
0038:Ret KERNEL32.ConnectNamedPipe() retval=00000000 ret=00349011
0038:Call KERNEL32.GetLastError() ret=0034901b
0038:Ret KERNEL32.GetLastError() retval=00000032 ret=0034901b
0038:Call KERNEL32.ReadFile(000000dc,091c30b0,00007f90,093ce7c0,00000000)
ret=0034904e
0025:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=00472b8c
0025:Call KERNEL32.WaitForSingleObject(00000060,000000c8) ret=00472b8c
0025:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=00472b8c
0025:Call KERNEL32.WaitForSingleObject(00000060,000000c8) ret=00472b8c
...
--- snip ---
At this point the client (tid 0x38) hangs.
The strange ConnectNamedPipe() call which looks like server-side pipe code can
be safely ignored.
It's a no-op on pipe client and for whatever reason executed here (app bug?).
The hang results from the second pipe being opened and written to/read from
"\\\\.\\pipe\\ToServerAdvinst_Extract_Z:\\home\\focht\\Downloads\\SourceTreeSetup_1.3.2.exe"
for which the pipe server has no pending ConnectNamedPipe() call.
Looking at the exports list of that custom action dll:
--- snip ---
...
EstimateExtractFiles
ExtractSourceFiles
...
--- snip ---
It seems "EstimateExtractFiles" which connects to first pipe must be called
prior "ExtractSourceFiles".
Searching the trace log with "custom action" yields:
--- snip ---
...
002b:trace:msi:ACTION_CustomAction Handling custom action L"AI_SET_INSTALL" (33
L"AI_INSTALL" L"1")
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_ResolveLocalizedCredentials" (1 L"aicustact.dll"
L"GetLocalizedCredentials")
002c:trace:msi:DllThread custom action (2c) started
002c:trace:msi:DllThread custom action (2c) returned 0
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_ResolveKnownFolders" (1 L"aicustact.dll" L"AI_ResolveKnownFolders")
002d:trace:msi:DllThread custom action (2d) started
002d:trace:msi:DllThread custom action (2d) returned 0
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_BACKUP_AI_SETUPEXEPATH" (33 L"AI_SETUPEXEPATH_ORIGINAL"
L"[AI_SETUPEXEPATH]")
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_RESTORE_AI_SETUPEXEPATH" (33 L"AI_SETUPEXEPATH"
L"[AI_SETUPEXEPATH_ORIGINAL]")
002b:trace:msi:ACTION_CustomAction Handling custom action L"AI_AppSearchEx" (1
L"Prereq.dll" L"DoAppSearchEx")
002e:trace:msi:DllThread custom action (2e) started
002e:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
002e:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
002e:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
002e:trace:msi:DllThread custom action (2e) returned 0
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_SETMIXINSTLOCATION" (1 L"aicustact.dll" L"MixedAllUsersInstallLocation")
002f:trace:msi:DllThread custom action (2f) started
002f:trace:msi:DllThread custom action (2f) returned 0
002b:trace:msi:ACTION_CustomAction Handling custom action
L"AI_RESTORE_LOCATION" (41 L"aicustact.dll" L"RestoreLocation")
0030:trace:msi:DllThread custom action (30) started
0030:trace:msi:DllThread custom action (30) returned 0
002b:trace:msi:ACTION_CustomAction Handling custom action L"SET_APPDIR" (133
L"APPDIR" L"[AI_UserProgramFiles][Manufacturer]\\[ProductName]")
002b:trace:msi:ACTION_CustomAction Handling custom action L"SET_SHORTCUTDIR"
(133 L"SHORTCUTDIR" L"[ProgramMenuFolder][Manufacturer]\\[ProductName]")
...
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_GetArpIconPath"
(1 L"aicustact.dll" L"GetArpIconPath")
0033:trace:msi:DllThread custom action (33) started
0033:trace:msi:DllThread custom action (33) returned 0
0032:trace:msi:ACTION_CustomAction Handling custom action
L"AI_ResolveLocalizedCredentials" (1 L"aicustact.dll"
L"GetLocalizedCredentials")
0034:trace:msi:DllThread custom action (34) started
0034:trace:msi:DllThread custom action (34) returned 0
0032:trace:msi:ACTION_CustomAction Handling custom action
L"AI_ResolveKnownFolders" (1 L"aicustact.dll" L"AI_ResolveKnownFolders")
0035:trace:msi:DllThread custom action (35) started
0035:trace:msi:DllThread custom action (35) returned 0
0032:trace:msi:ACTION_CustomAction Handling custom action
L"AI_BACKUP_AI_SETUPEXEPATH" (33 L"AI_SETUPEXEPATH_ORIGINAL"
L"[AI_SETUPEXEPATH]")
0032:trace:msi:ACTION_CustomAction Handling custom action
L"AI_RESTORE_AI_SETUPEXEPATH" (33 L"AI_SETUPEXEPATH"
L"[AI_SETUPEXEPATH_ORIGINAL]")
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_AppSearchEx" (1
L"Prereq.dll" L"DoAppSearchEx")
0036:trace:msi:DllThread custom action (36) started
0036:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
0036:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
0036:warn:msi:MsiGetDatabaseState MsiGetDatabaseState not allowed during a
custom action!
0036:trace:msi:DllThread custom action (36) returned 0
0032:trace:msi:ACTION_CustomAction Handling custom action
L"AI_SETMIXINSTLOCATION" (1 L"aicustact.dll" L"MixedAllUsersInstallLocation")
0037:trace:msi:DllThread custom action (37) started
0037:trace:msi:DllThread custom action (37) returned 0
0032:trace:msi:ACTION_CustomAction Handling custom action
L"SET_TARGETDIR_TO_APPDIR" (33 L"TARGETDIR" L"[APPDIR]")
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_STORE_LOCATION"
(33 L"ARPINSTALLLOCATION" L"[APPDIR]")
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_DATA_SETTER" (33
L"AI_ExtractFiles" L"[AI_SETUPEXEPATH]")
0032:trace:msi:ACTION_CustomAction Handling custom action L"AI_ExtractFiles"
(401 L"Prereq.dll" L"ExtractSourceFiles")
0038:trace:msi:DllThread custom action (38) started
--- snip ---
Dumping the "custom action" table from extracted "SourceTreeSetup_1.3.2.msi"
with ORCA:
--- snip ---
Action Type Source Target ExtendedType
s72 i2 S72 S0 I4
...
AI_ExtractFiles 1025 Prereq.dll ExtractSourceFiles
...
AI_EstimateExtractFiles 1 Prereq.dll EstimateExtractFiles
--- snip ---
Dumping "InstallExecuteSequence" table:
--- snip ---
Action Condition Sequence
s72 S255 I2
...
AI_ExtractFiles 3998
...
AI_EstimateExtractFiles 3999
--- snip ---
"AI_EstimateExtractFiles" has a higher sequence id than "AI_ExtractFiles".
The important thing here is the type of custom action (see "custom action"
table):
"AI_EstimateExtractFiles" -> type 1 custom action
"AI_ExtractFiles" -> type 1025 = type 1 custom action that is deferred (+1024).
Wine's msi executes "AI_ExtractFiles" as standard type 1 custom action in order
of sequence id.
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