https://bugs.winehq.org/show_bug.cgi?id=47187
Bug ID: 47187 Summary: Star Wars - The Old Republic (SWTOR): BitRaider WISDA 64-Bit filter driver service fails to start (load ordering group specified via REG_MULTI_SZ type) Product: Wine Version: 4.8 Hardware: x86-64 OS: Linux Status: NEW Severity: normal Priority: P2 Component: -unknown Assignee: wine-bugs@winehq.org Reporter: focht@gmx.net Distribution: ---
Hello folks,
continuation of bug 47186 and prior.
The launcher UI sits at 'Initializing' and the logs say 'Waiting for BitRaider to start...'. Suprisingly the failure to start the mini filter driver doesn't affect the functionality of BitRaider - already downloads all assets with full speed in the background due to prior bugs fixed.
--- snip --- .wine/drive_c/ProgramData/BitRaider/common/logs/BR_Debuglog.txt ... .wine/drive_c/Star Wars-The Old Republic/bitraider/logs/swtor_swtor.txt ... .wine/drive_c/Star Wars-The Old Republic/logs/launcher_20190511.log --- snip ---
--- snip --- ... 2019/05/13 09:04:35.902:[INFO]{000DD} - Check HTTP status: 200 2019/05/13 09:04:35.902:[WARN]{000DD} - DLM: Check source done, HTTP code: 200, request pending: false 2019/05/13 09:04:35.902:[DBUG]{000D4}-[XFER]NE+:10000308: U:000 D:000 V:000 X:428 A:00000011 PF:0/0 2019/05/13 09:04:35.903:[DBUG]{000D4}-[XFER]NE+:00000309: U:000 D:000 V:000 X:429 A:00000011 PF:0/0 2019/05/13 09:04:35.903:[DBUG]{000D4}-[XFER]NE+:10000309: U:000 D:000 V:000 X:430 A:00000011 PF:0/0 2019/05/13 09:04:35.903:[DBUG]{000D4}-[XFER]NE+:00000310: U:000 D:000 V:000 X:431 A:00000011 PF:0/0 2019/05/13 09:04:35.904:[DBUG]{000D4}-[XFER]NE+:10000310: U:000 D:000 V:000 X:432 A:00000011 PF:0/0 2019/05/13 09:04:35.907:[INFO]{000D7} - Custom command for http://cdn-patch.swtor.com/bitraider/swtor/swtor_13.bin: Range: bytes=0-39; Request: 0-39 2019/05/13 09:04:35.907:[INFO]{000D7} - Req Length: 40; Chunk size: 524288 2019/05/13 09:04:35.907:[INFO]{000D7} - Range 1: 0-39 2019/05/13 09:04:35.907:[INFO]{000D7} - Queued length: 40; Req length: 40 2019/05/13 09:04:35.907:[INFO]{000DD} - Retrieving http://cdn-patch.swtor.com/bitraider/swtor/swtor_13.bin 2019/05/13 09:04:35.908:[INFO]{000DD} - Request 0 range: 0-39 Length: 40 2019/05/13 09:04:35.927:[INFO]{000DD} - Request 0 done 2019/05/13 09:04:35.927:[INFO]{000DD} - Request 0 done. error code 0, HTTP code: 206 2019/05/13 09:04:35.929:[INFO]{000DD} - Request 0: 40 bytes remaining. 40 bytes avail in buffer 2019/05/13 09:04:35.929:[INFO]{000DD} - Request 0: 40 bytes written at 0 offset. 2019/05/13 09:04:35.929:[INFO]{000DD} - DownloadManager: Fulfilled 40 of 40 bytes requested. Reqs done: 1 2019/05/13 09:04:35.929:[INFO]{000DD} - Clearing custom ranges.. 2019/05/13 09:04:35.929:[INFO]{000DD} - Request 0 stats: isFinished:1 bytesRequested:40 bytesWritten:40 2019/05/13 09:04:35.939:[DBUG]{000D7}-XFER: Saved RemoteCopy object 2019/05/13 09:04:35.941:[INFO]{000D7} - WebCopyDestOpen: Opened c:\star wars-the old republic\BitRaider\BAOC\00000001.bac for writing 2019/05/13 09:04:35.941:[INFO]{000D7} - Custom command for http://cdn-patch.swtor.com/bitraider/swtor/swtor_13.bin: Range: bytes=2654338-23216217; Request: 2654338-3178625 2019/05/13 09:04:35.941:[INFO]{000D7} - Req Length: 20561880; Chunk size: 3426986 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 1: 2654338-6081323 2019/05/13 09:04:35.941:[DBUG]{000DD} - DownloadManager: Ratelimit set to 33554432B/s 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 2: 6081324-9508309 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 3: 9508310-12935295 2019/05/13 09:04:35.941:[DBUG]{000DD} - DownloadManager: Setting read buffer size to 3355443B 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 4: 12935296-16362281 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 5: 16362282-19789267 2019/05/13 09:04:35.941:[INFO]{000D7} - Range 6: 19789268-23216217 2019/05/13 09:04:35.941:[INFO]{000DD} - Retrieving http://cdn-patch.swtor.com/bitraider/swtor/swtor_13.bin 2019/05/13 09:04:35.941:[INFO]{000DD} - Request 0 range: 2654338-6081323 Length: 3426986 2019/05/13 09:04:35.941:[INFO]{000DD} - Request 1 range: 6081324-9508309 Length: 3426986 2019/05/13 09:04:35.942:[INFO]{000DD} - Request 2 range: 9508310-12935295 Length: 3426986 2019/05/13 09:04:35.942:[INFO]{000DD} - Request 3 range: 12935296-16362281 Length: 3426986 2019/05/13 09:04:35.942:[INFO]{000DD} - Request 4 range: 16362282-19789267 Length: 3426986 2019/05/13 09:04:35.942:[INFO]{000DD} - Request 5 range: 19789268-23216217 Length: 3426950 ... 2019/05/13 09:04:39.245:[INFO]{000D7} - DownloadManager Cleanup done, destroying DownloadManager.. 2019/05/13 09:04:39.278:[DBUG]{000E5}- [VLDT]PD-:00000001: U:000 D:000 V:000 X:5286 [ST:0] 2019/05/13 09:04:39.279:[DBUG]{000E5}- [DCMP]PQ+:00000001: U:000 D:001 V:000 X:5286 A:00000011 PF:1/0 2019/05/13 09:04:39.279:[DBUG]{000E5}- [DCMP]: Sending priority interrupt signal... 2019/05/13 09:04:39.306:[INFO]{000D7} - DownloadManager destroyed.. 2019/05/13 09:04:39.306:[DBUG]{000D7}-XFER: Cleared RemoteCopy object 2019/05/13 09:04:39.306:[INFO]{000D7} - WebCopy: hostUrl: cdn-patch.swtor.com 2019/05/13 09:04:39.306:[INFO]{000D7} - WebCopy: objectUrl: /bitraider/swtor/swtor_pd_13_42.bin 2019/05/13 09:04:39.306:[INFO]{000D7} - WebCopy: Making sure old source is closed before opening new one... 2019/05/13 09:04:39.306:[DBUG]{000D7} - DownloadManager: Ratelimit set to 67108864B/s 2019/05/13 09:04:39.306:[DBUG]{000D7} - DownloadManager: Setting read buffer size to 6710886B 2019/05/13 09:04:39.309:[INFO]{000E9} - Checking http://cdn-patch.swtor.com/bitraider/swtor/swtor_pd_13_42.bin 2019/05/13 09:04:39.332:[INFO]{000E9} - Check HTTP status: 200 2019/05/13 09:04:39.332:[WARN]{000E9} - DLM: Check source done, HTTP code: 200, request pending: false 2019/05/13 09:04:39.337:[INFO]{000D7} - Custom command for http://cdn-patch.swtor.com/bitraider/swtor/swtor_pd_13_42.bin: Range: bytes=0-39; Request: 0-39 2019/05/13 09:04:39.337:[INFO]{000D7} - Req Length: 40; Chunk size: 524288 2019/05/13 09:04:39.337:[INFO]{000D7} - Range 1: 0-39 2019/05/13 09:04:39.337:[INFO]{000D7} - Queued length: 40; Req length: 40 2019/05/13 09:04:39.337:[INFO]{000E9} - Retrieving http://cdn-patch.swtor.com/bitraider/swtor/swtor_pd_13_42.bin 2019/05/13 09:04:39.337:[INFO]{000E9} - Request 0 range: 0-39 Length: 40 2019/05/13 09:04:39.356:[INFO]{000E9} - Request 0 done 2019/05/13 09:04:39.357:[INFO]{000E9} - Request 0 done. error code 0, HTTP code: 206 2019/05/13 09:04:39.359:[INFO]{000E9} - Request 0: 40 bytes remaining. 40 bytes avail in buffer 2019/05/13 09:04:39.359:[INFO]{000E9} - Request 0: 40 bytes written at 0 offset. 2019/05/13 09:04:39.359:[INFO]{000E9} - DownloadManager: Fulfilled 40 of 40 bytes requested. Reqs done: 1 2019/05/13 09:04:39.359:[INFO]{000E9} - Clearing custom ranges.. 2019/05/13 09:04:39.359:[INFO]{000E9} - Request 0 stats: isFinished:1 bytesRequested:40 bytesWritten:40 2019/05/13 09:04:39.369:[DBUG]{000D7}-XFER: Saved RemoteCopy object 2019/05/13 09:04:39.371:[INFO]{000D7} - WebCopyDestOpen: Opened c:\star wars-the old republic\BitRaider\BAOC\10000001.bac for writing 2019/05/13 09:04:39.371:[INFO]{000D7} - Custom command for http://cdn-patch.swtor.com/bitraider/swtor/swtor_pd_13_42.bin: Range: bytes=3390436-24393454; Request: 3390436-3914723 2019/05/13 09:04:39.371:[INFO]{000D7} - Req Length: 21003019; Chunk size: 3500509 ... --- snip ---
BitRaider consists of two services:
--- snip --- [HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\BRSptStub] "Description"="BitRaider Helper for unelevated driver loading." "DisplayName"="BitRaider Mini-Support Service Stub Loader" "ErrorControl"=dword:00000000 "ImagePath"=""C:\ProgramData\BitRaider\BRSptStub.exe"" "ObjectName"="LocalSystem" "PreshutdownTimeout"=dword:0002bf20 "Start"=dword:00000003 "Type"=dword:00000010 "WOW64"=dword:00000001 --- snip ---
--- snip --- [HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\BRDriver64_1_3_3_E02B25FC] "DependOnService"=hex(7):46,00,6c,00,74,00,4d,00,67,00,72,00,00,00 "DisplayName"="BRDriver64_1_3_3_E02B25FC" "ErrorControl"=dword:00000001 "Group"=hex(7):46,00,73,00,46,00,69,00,6c,00,74,00,65,00,72,00,20,00,41,00,63,\ 00,74,00,69,00,76,00,69,00,74,00,79,00,20,00,4d,00,6f,00,6e,00,69,00,74,00,\ 6f,00,72,00,00,00 "ImagePath"="\??\C:\ProgramData\BitRaider\support\1.3.3\E02B25FC\BRDriver64.sys" "ObjectName"="LocalSystem" "PreshutdownTimeout"=dword:0002bf20 "Start"=dword:00000003 "Tag"=dword:00000002 "Type"=dword:00000002 "WOW64"=dword:00000001
[HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\BRDriver64_1_3_3_E02B25FC\Instances] "DefaultInstance"="BRDriver64_1_3_3_E02B25FC"
[HKEY_LOCAL_MACHINE\System\CurrentControlSet\Services\BRDriver64_1_3_3_E02B25FC\Instances\BRDriver64_1_3_3_E02B25FC] "Altitude"="64000" "Flags"=dword:00000001 --- snip ---
The app writes the load order groups ('Group') of the filter driver as 'REG_MULTI_SZ' type key. As per documentation the type should be 'REG_SZ' hence Wine ignores it -> kernel driver service not loaded.
On each WINEPREFIX startup:
--- snip --- $ WINEDEBUG=+service wineboot ... 000f:trace:service:scmdatabase_load_services Loading service L"BITS" 000f:trace:service:load_service_config Image path = L"C:\windows\system32\svchost.exe -k netsvcs" 000f:trace:service:load_service_config Group = (null) 000f:trace:service:load_service_config Service account name = L"LocalSystem" 000f:trace:service:load_service_config Display name = L"BITS Service" 000f:trace:service:load_service_config Service dependencies : (none) 000f:trace:service:load_service_config Group dependencies : (none) 000f:trace:service:scmdatabase_load_services Loading service L"BRDriver64_1_3_3_E02B25FC" 000f:err:service:load_reg_string Error 1804 while reading value L"Group" 000f:err:service:scmdatabase_load_services Error 1804 reading registry key for service L"BRDriver64_1_3_3_E02B25FC" - skipping 000f:trace:service:scmdatabase_load_services Loading service L"BRSptStub" 000f:trace:service:load_service_config Image path = L""C:\ProgramData\BitRaider\BRSptStub.exe"" 000f:trace:service:load_service_config Group = (null) 000f:trace:service:load_service_config Service account name = L"LocalSystem" 000f:trace:service:load_service_config Display name = L"BitRaider Mini-Support Service Stub Loader" 000f:trace:service:load_service_config Service dependencies : (none) 000f:trace:service:load_service_config Group dependencies : (none) ... --- snip ---
https://docs.microsoft.com/en-us/windows/desktop/api/winsvc/nf-winsvc-create...
--- quote --- ... lpLoadOrderGroup
The names of the load ordering group of which this service is a member. Specify NULL or an empty string if the service does not belong to a group.
The startup program uses load ordering groups to load groups of services in a specified order with respect to the other groups. The list of load ordering groups is contained in the following registry value: HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\ServiceGroupOrder ...
Remarks
Group Load ordering group specified by lpLoadOrderGroup. Note that setting this value can override the setting of the DependOnService value. --- quote ---
Wine source:
https://source.winehq.org/git/wine.git/blob/HEAD:/programs/services/services...
--- snip --- 156 static DWORD load_service_config(HKEY hKey, struct service_entry *entry) 157 { 158 DWORD err, value = 0; 159 WCHAR *wptr; 160 161 if ((err = load_reg_string(hKey, SZ_IMAGE_PATH, TRUE, &entry->config.lpBinaryPathName)) != 0) 162 return err; 163 if ((err = load_reg_string(hKey, SZ_GROUP, 0, &entry->config.lpLoadOrderGroup)) != 0) 164 return err; 165 if ((err = load_reg_string(hKey, SZ_OBJECT_NAME, TRUE, &entry->config.lpServiceStartName)) != 0) 166 return err; 167 if ((err = load_reg_string(hKey, SZ_DISPLAY_NAME, 0, &entry->config.lpDisplayName)) != 0) 168 return err; 169 if ((err = load_reg_string(hKey, SZ_DESCRIPTION, 0, &entry->description)) != 0) 170 return err; 171 if ((err = load_reg_multisz(hKey, SZ_DEPEND_ON_SERVICE, TRUE, &entry->dependOnServices)) != 0) 172 return err; 173 if ((err = load_reg_multisz(hKey, SZ_DEPEND_ON_GROUP, FALSE, &entry->dependOnGroups)) != 0) 174 return err; 175 176 if ((err = load_reg_dword(hKey, SZ_TYPE, &entry->config.dwServiceType)) != 0) 177 return err; 178 if ((err = load_reg_dword(hKey, SZ_START, &entry->config.dwStartType)) != 0) 179 return err; 180 if ((err = load_reg_dword(hKey, SZ_ERROR, &entry->config.dwErrorControl)) != 0) 181 return err; 182 if ((err = load_reg_dword(hKey, SZ_TAG, &entry->config.dwTagId)) != 0) 183 return err; 184 if ((err = load_reg_dword(hKey, SZ_PRESHUTDOWN, &entry->preshutdown_timeout)) != 0) 185 return err; 186 187 if (load_reg_dword(hKey, SZ_WOW64, &value) == 0 && value == 1) 188 entry->is_wow64 = TRUE; 189 190 WINE_TRACE("Image path = %s\n", wine_dbgstr_w(entry->config.lpBinaryPathName) ); 191 WINE_TRACE("Group = %s\n", wine_dbgstr_w(entry->config.lpLoadOrderGroup) ); 192 WINE_TRACE("Service account name = %s\n", wine_dbgstr_w(entry->config.lpServiceStartName) ); 193 WINE_TRACE("Display name = %s\n", wine_dbgstr_w(entry->config.lpDisplayName) ); 194 WINE_TRACE("Service dependencies : %s\n", entry->dependOnServices[0] ? "" : "(none)"); 195 for (wptr = entry->dependOnServices; *wptr; wptr += lstrlenW(wptr) + 1) 196 WINE_TRACE(" * %s\n", wine_dbgstr_w(wptr)); 197 WINE_TRACE("Group dependencies : %s\n", entry->dependOnGroups[0] ? "" : "(none)"); 198 for (wptr = entry->dependOnGroups; *wptr; wptr += lstrlenW(wptr) + 1) 199 WINE_TRACE(" * %s\n", wine_dbgstr_w(wptr)); 200 201 return ERROR_SUCCESS; 202 } --- snip ---
Related article about the topic:
https://docs.microsoft.com/en-us/windows-hardware/drivers/ifs/load-order-gro... ("Load Order Groups and Altitudes for Minifilter Drivers")
$ sha1sum SWTOR_setup.exe c538935eff4ec90ce2e48dc7e515a8dec2f15f58 SWTOR_setup.exe
$ du -sh SWTOR_setup.exe 32M SWTOR_setup.exe
$ wine --version wine-4.8
Regards