-- Log file for all dbTracef messages --

17:59:43.19   NetworkManager::Create - creating network manager
17:59:43.19   Read 567 bytes from network datastore login_cache.bin
17:59:43.19   Read 109962 bytes from network datastore global_cache.bin
17:59:43.19   Read 5266 bytes from network datastore ping_cache.bin
17:59:43.19   QuazalInitializer - static initializing Quazal library
17:59:43.19   PingCache - populating cache with 291 pings
17:59:43.19   Transport - Header Size = 4 bytes + 4 byte nonce + 2 byte consolidation header
17:59:43.22   WinTransport - CreateSocket exclusive broadcast socket was available.
17:59:43.22   WinTransport - CreateSocket listening for broadcasts on default port
17:59:43.23   WinTransport - Host Name: Alex-PC, aliases: , type=AF_INET, len=4
17:59:43.23   WinTransport - Host IP Address #0: 192.168.0.199
17:59:43.23   WinTransport - Interface #0: ip:192.168.0.199, broadcast:192.168.0.199, flags=IFF_UP IFF_BROADCAST IFF_MULTICAST
17:59:43.23   WinTransport - Interface #1: ip:127.0.0.1, broadcast:127.0.0.1, flags=IFF_UP IFF_LOOPBACK IFF_MULTICAST
17:59:43.23   Transport::OpenInternal request to WINaddr:255.255.255.255:6112;
17:59:43.23   WinTransport - Quazal address string = udp:/address=192.168.0.199;port=6112
17:59:43.23   SessionManager - Peer Header Size = 16 bytes
17:59:43.23   SessionManager - Game Data overhead = 7 bytes
17:59:43.23   SessionManager - Proxy overhead = 7 bytes
17:59:43.23   MessageInternal::CreateChannel: Created channel 47535450
17:59:43.23   Session::Initialize - info, initializing session object, using threads.
17:59:43.23   SessionManager::RegisterSession - Registering new session 0687b618
17:59:43.23   Transport::OpenInternal request to WINaddr:255.255.255.255:6112;
17:59:43.23   AutomatchInternal: Instantiating
17:59:43.23   PartyInternal: Instantiating
17:59:43.23   MessageInternal::CreateChannel: Created channel 50525459
17:59:43.23   MessageInternal::CreateChannel: Created channel 51434b4d
17:59:43.23   Net::ThreadFunction - Entering network thread function...
17:59:43.23   Session::GetState - info, session's state changed to [1:STATE_DISCONNECTED].
17:59:43.23   MessageInternal::CreateChannel: Created channel 534d5347
17:59:43.23   MessageInternal::CreateChannel: Created channel 474d4343
17:59:43.23   MessageInternal::CreateChannel: Created channel 474f424a
17:59:43.23   MessageInternal::CreateChannel: Created channel 4d4f444d
17:59:43.23   MessageInternal::CreateChannel: Created channel 53594e43
17:59:43.23   MessageInternal::DestroyChannel: Destroyed channel 534d5347
17:59:43.23   MessageInternal::DestroyChannel: Destroyed channel 474d4343
17:59:43.23   MessageInternal::DestroyChannel: Destroyed channel 474f424a
17:59:43.23   MessageInternal::DestroyChannel: Destroyed channel 4d4f444d
17:59:43.23   MessageInternal::DestroyChannel: Destroyed channel 53594e43
17:59:43.23   GAME -- Available memory: 3325MB Physical RAM, 3526MB Pagefile, 2047 Virtual Address Space
17:59:43.25   Transport - Largest received is now 19
17:59:43.25   Transport::OpenInternal request to WINaddr:192.168.0.199:6112;
17:59:47.62   DLLDriverLinker -- Adding driver 'spDx10.dll'.
17:59:47.63   DLLDriverLinker -- Adding driver 'spDx9.dll'.
17:59:47.63   DLLDriverLinker -- 2 DLL drivers found.
17:59:47.67   SPDx10 -- Adapter [NVIDIA GeForce 8800 GT ]: 497MB dedicated video memory, 0MB dedicated system memory and 1407MB shared system memory.
17:59:49.55   DLLDriverLinker -- 2 DLL drivers found.
17:59:49.72   SPOOGE - Driver[DirectX10 Rendering Device] version[4,36]
17:59:49.72   GAME -- Resolution set to 1680x1050 (fullscreen).
17:59:49.75   SPDx10 -- Adapter Description = NVIDIA GeForce 8800 GT
17:59:49.75   SPDx10 -- Driver Vendor = 0x000010de  Device = 0x00000611  SubSys = 0x080110b0  Rev = 0x000000a2
17:59:49.75   SPDx10 -- Driver Version  Product = 0x0008  Version = 0x0011  SubVersion = 0x00  Build = 196.21
17:59:49.75   SPDx10 -- Driver LUID = 0x00000000-0x0000fc32
17:59:49.75   SPDx10 -- 497MB dedicated video memory, 0MB dedicated system memory and 1407MB shared system memory available.
17:59:49.75   ShaderDatabase: using shader profile [ps40]
17:59:51.39   SPDx10 -- Gamma Caps - Scale/Offset supported: no, Max: 1.00, Min: 0.00, Number of Control Points: 256.
17:59:51.63   SPDx10 -- Gamma Caps - Scale/Offset supported: no, Max: 1.00, Min: 0.00, Number of Control Points: 256.
17:59:51.71   FILESYSTEM -- filepath failure, missing alias 'TOOLSDATA:autoloddecimator.lua'
17:59:52.39   GameObjLoader 03397368 - resetting counters
17:59:52.39   GameObjLoader 03397368 - Created loader
17:59:52.39   GameObjLoader 033974c8 - resetting counters
17:59:52.39   GameObjLoader 033974c8 - Created loader
17:59:52.75   GAME -- Beginning FE
17:59:52.75   Sent message game CompanyOfHeroes started 4352 601 allowtraffic
17:59:52.75   RemoteDLManager - Connection Restored.
17:59:52.75   UIFrontEnd - Loading Front End
17:59:52.75   THREAD: Hyper-Threading Technology Processors are not detected.
17:59:52.88   SOUND -- Initializing ...
17:59:52.96   INNIMapDCA Key not found: sp_speechducker::time
17:59:53.74   SOUND -- Initialization completed!
17:59:53.74   UIFrontEnd - Initializing Forms
17:59:55.91   CampaignFilter::BindFilterSpecificWidgets()
17:59:56.00   Activating screen: AppLoadingForm
17:59:56.00   SetupProductLoadingArt - choosing bgArt = 0 (gold=0)
17:59:56.00   Got dlman msg [dlmanager version 1.0 peertraffic 1 uploadlimit 2147483647 seedratio 3]
17:59:56.94   GAME -- Loaded campaign 'Invasion of Normandy' (DATA:SCENARIOS\SP\COH.CAMP) with 15 missions, [coh]
17:59:56.94   GAME -- Loaded campaign 'Liberation of Caen' (DATA:SCENARIOS\SP\CXP1.CAMP) with 9 missions, [cxp1]
17:59:56.95   GAME -- Loaded campaign 'Operation Market Garden' (DATA:SCENARIOS\SP\CXP2.CAMP) with 8 missions, [cxp2]
17:59:56.95   GAME -- Loaded campaign 'Falaise Pocket' (DATA:SCENARIOS\SP\DLC3.CAMP) with 3 missions, [dlc3]
17:59:56.95   GAME -- Loaded campaign 'Causeway' (DATA:SCENARIOS\SP\DLC2.CAMP) with 3 missions, [dlc2]
17:59:56.96   GAME -- Loaded campaign 'Tiger Ace' (DATA:SCENARIOS\SP\DLC1.CAMP) with 3 missions, [dlc1]
17:59:57.32   GAME -- Using player profile ALEX-PC
17:59:58.58   Dx10Program : Unable to find shader script for 'fxshader_multiply' in the ShaderDatabase.
17:59:59.16   Dx10Program : Unable to find shader script for 'fxshader_depthadditive' in the ShaderDatabase.
18:00:00.30   QuazalLoginService - *** Connecting to server: reliclive.quazal.net:30260
18:00:00.30   RendezvousManager: CreateSession - starting profile=Guest login
18:00:01.47   RendezvousManager: Login complete and successfull
18:00:01.47   RendezvousManager initialized
18:00:01.60   Current server English:live version is 601.0, client is 601.0
18:00:01.60   OnConnect: successful connection established, enabling reconnect
18:00:01.60   OnConnect: this wasnt a reconnect, no need for autologin
18:00:01.60   Logging in xB1aSTeRx on controller:0
18:00:01.96   Login completed: ACCOUNT_VALIDATED
18:00:01.96   Found 1 profiles for account xB1aSTeRx
18:00:01.96   Found profile: xB1aSTeRx
18:00:01.96   installed_products = ( DLC1 DLC2 DLC3 CXP1 COH )
18:00:01.96   OnLogin: no previous login, auto selecting profile not required
18:00:01.96   SetupProductLoadingArt - choosing bgArt = 4 (gold=0)
18:00:01.97   CRC & Version Info : 00000259:6aa29d62:48d2c5df eastern_front:601:ww2mod.dll 1
18:00:01.97   Activating screen: FEMovie
18:00:01.97   Activating screen: OnlineWidget
18:00:01.97   Activating screen: RelicOnlineProfileSelect
18:00:01.98   SetupProductLoadingArt - choosing bgArt = 4 (gold=0)
18:00:01.98   Activating screen: RelicOnlineWait
18:00:01.98   RendezvousManager - destroying chat handler
18:00:01.98   RendezvousManager: CreateSession - starting logout profile = 100:Guest
18:00:02.17   RendezvousManager: Logout complete
18:00:02.17   RendezvousManager - terminating all server calls in progress
18:00:02.17   CallManager - terminating all server calls in progress (1 in progress)
18:00:02.17   RendezvousManager: OnCredentialsEvent - starting profile login
18:00:03.26   RendezvousManager: Login complete and successfull
18:00:03.26   RendezvousManager - creating chat handler
18:00:03.26   RendezvousManager::CreateNATTraversalClient - NAT traversal available.
18:00:03.45   QuazalSelectProfileAsync - Got UserID
18:00:03.46   Transport - Largest sent is now 16
18:00:03.59   Transport - Largest received is now 42
18:00:03.61   GetUserStats requested stats for PIDs ( 3052293 ) (best:0, full:1)
18:00:03.72   SelectProfileAsync - RegisterLocalURLs public [udp:/address=90.231.136.27;port=6112;PID=3052293;RVCID=87618257], private [udp:/address=192.168.0.199;port=6112;PID=3052293]
18:00:03.86   QuazalSelectProfileAsync - Got Full Stats
18:00:04.01   GetAutomatchMaps: Got [32] maps
18:00:04.03   PopulateArmyListBox - skipping race 2
18:00:04.03   PopulateArmyListBox - skipping race 0
18:00:04.03   PopulateArmyListBox - skipping race 1
18:00:04.03   PopulateArmyListBox - skipping race 3
18:00:04.03   AutoMatchForm::OnArmySelectionChanged - sending request info
18:00:04.03   GetMaxFrameTimeFromProfile: players=2 expected FPS=100.000000, bars=5, max avg=0.000, sd=0.000, 0 samples =
18:00:04.03   AutoMatchForm::OnMatchTypeSelectionChanged - sending team info
18:00:04.03   QuazalSelectProfileAsync - Got Automatch maps
18:00:04.87   QuazalSelectProfileAsync - GetFriends result - CacheState = 1
18:00:05.01   Profile [00000000:002e9305] selected on controller#0
18:00:05.01   Activating screen: FEMovie
18:00:05.01   Activating screen: OnlineWidget
18:00:05.01   Activating screen: FE_mm_01
18:00:05.01   Activating screen: RelicOnlineWait
18:00:05.01   GAME -- Setting campaign state to 'coh'
18:00:05.01   GAME -- Closing state 'coh'
18:00:05.02   GAME -- Setting campaign state to 'cxp2'
18:00:05.02   GAME -- Closing state 'cxp2'
18:00:05.02   GAME -- Setting campaign state to 'cxp1'
18:00:05.02   GAME -- Closing state 'cxp1'
18:00:05.03   GAME -- Setting campaign state to 'dlc1'
18:00:05.03   GAME -- Closing state 'dlc1'
18:00:05.03   GAME -- Setting campaign state to 'dlc2'
18:00:05.03   GAME -- Closing state 'dlc2'
18:00:05.04   GAME -- Setting campaign state to 'dlc3'
18:00:05.04   GAME -- Closing state 'dlc3'
18:00:44.01   Transport - median kBPS [hi/cur] sent = 0.0/0.0, recvd = 0.0/0.0, #p/sec[s/r] = 0.0/0.3, max unsent 0, version err 0, merge 0
18:01:45.01   Transport - median kBPS [hi/cur] sent = 0.0/0.0, recvd = 0.0/0.0, #p/sec[s/r] = 0.0/0.2, max unsent 0, version err 0, merge 0
18:01:58.59   Activating screen: MessageBoxPopup
18:01:58.59   Created Matchinfo
18:01:58.59   Session::Reset with reason 999 and AdvertisementInternal::ResetSession()
18:01:58.59   starting online hosting
18:01:58.60   OnlineHostAsync: initiating CallCreateMatch
18:01:58.75   OnlineHostAsync: created gid=152011637
18:01:58.75   RendezvousNotifier - Received Participate ParticipationEvent.
18:01:58.76   Transport - Largest sent is now 79
18:01:58.89   Transport - Largest received is now 105
18:01:59.02   OnlineHostAsync - RegisterLocalURLs public [udp:/address=90.231.136.27;port=6112;PID=3052293;RVCID=87618257], private [udp:/address=192.168.0.199;port=6112;PID=3052293]
18:01:59.16   OnlineHostAsync: initiating UpdateSessionURL [gid=152011637, url=udp:/address=90.231.136.27;port=6112;PID=3052293;RVCID=87618257]
18:01:59.31   OnJoinAdvertisementSuccess - joined online match, server leave notification required
18:01:59.31   starting local hosting
18:01:59.31   Transport::OpenInternal request to WINaddr:255.255.255.255:6112;
18:01:59.31   Allocated route ID=0 for PeerID 1 at WINaddr:192.168.0.199:6112;
18:01:59.31   Transport::OpenInternal request to WINaddr:192.168.0.199:6112;
18:01:59.31   Session::Host sid = 90F8375, hostURL = , local addresses = WINaddr:192.168.0.199:6112;
18:01:59.31   ValidateCustomData: called with 463 bytes of custom data
18:01:59.31   Host accepted Peer 1 into the match at address list=WINaddr:192.168.0.199:6112;, routes=WINaddr:192.168.0.199:6112;
18:01:59.31   AdvertisementInternal::Process - EVENT_NEWPEER
18:01:59.31   Session::GetState - info, session's state changed to [2:STATE_CONNECTING].
18:01:59.31   Session::GetState - info, session's state changed to [3:STATE_CONNECTED].
18:01:59.31   hosting - Session is connected
18:01:59.31   Net::Session::SetVisible - session is set to INVISIBLE.
18:01:59.32   hosting completed successfully
18:01:59.32   HostAsync - completed with HostResult = 0
18:01:59.32   UIFrontEnd::StartRelicOnlineTabs deactivating FE_mm_01
18:01:59.32   Activating screen: OnlineGameSetup
18:01:59.32   MessageInternal::CreateChannel: Created channel 534d5347
18:01:59.32   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:01:59.32   MatchInternal::SetMatchType - new type 14 - updating server
18:01:59.33   SetVisible called while !IsConnected
18:01:59.33   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:01:59.33   Activating screen: RelicOnlineChat
18:01:59.33   Activating screen: RelicOnlineNewsScreen
18:01:59.33   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:01:59.33   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:01:59.39   Activating screen: RelicOnlineStatsScreen
18:01:59.39   Activating screen: Achievements
18:01:59.39   GAME -- Setting campaign state to 'coh'
18:01:59.39   GAME -- Closing state 'coh'
18:01:59.39   GAME -- Setting campaign state to 'cxp2'
18:01:59.39   GAME -- Closing state 'cxp2'
18:01:59.40   GAME -- Setting campaign state to 'cxp1'
18:01:59.40   GAME -- Closing state 'cxp1'
18:01:59.40   GAME -- Setting campaign state to 'dlc1'
18:01:59.40   GAME -- Closing state 'dlc1'
18:01:59.41   GAME -- Setting campaign state to 'dlc2'
18:01:59.41   GAME -- Closing state 'dlc2'
18:01:59.41   GAME -- Setting campaign state to 'dlc3'
18:01:59.41   GAME -- Closing state 'dlc3'
18:01:59.42   GAME -- Setting campaign state to 'dlc1'
18:01:59.42   GAME -- Closing state 'dlc1'
18:01:59.43   Activating screen: GameHistory
18:01:59.43   GAME -- Setting campaign state to 'coh'
18:01:59.43   GAME -- Closing state 'coh'
18:01:59.44   GAME -- Setting campaign state to 'cxp2'
18:01:59.44   GAME -- Closing state 'cxp2'
18:01:59.44   GAME -- Setting campaign state to 'cxp1'
18:01:59.44   GAME -- Closing state 'cxp1'
18:01:59.45   GAME -- Setting campaign state to 'dlc1'
18:01:59.45   GAME -- Closing state 'dlc1'
18:01:59.45   GAME -- Setting campaign state to 'dlc2'
18:01:59.45   GAME -- Closing state 'dlc2'
18:01:59.46   GAME -- Setting campaign state to 'dlc3'
18:01:59.46   GAME -- Closing state 'dlc3'
18:01:59.46   Activating screen: OnlineGameSetup
18:01:59.46   Activating screen: RelicOnlineTabs
18:01:59.46   AutomatchInternal::OnHostComplete - Completed Host with success=1
18:01:59.46   AutomatchInternal::OnHostComplete - automatcher is no longer active - ignoring
18:01:59.46   QuickMatchInternal::OnHostComplete - Quickmatch not in host state.
18:01:59.47   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:01:59.47   Net::Session::SetVisible - session is set to INVISIBLE.
18:01:59.47   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:01:59.54   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:01:59.55   GAME -- Setting campaign state to 'coh'
18:01:59.55   GAME -- Closing state 'coh'
18:01:59.56   GAME -- Setting campaign state to 'cxp2'
18:01:59.56   GAME -- Closing state 'cxp2'
18:01:59.56   GAME -- Setting campaign state to 'cxp1'
18:01:59.56   GAME -- Closing state 'cxp1'
18:01:59.57   GAME -- Setting campaign state to 'dlc1'
18:01:59.57   GAME -- Closing state 'dlc1'
18:01:59.57   GAME -- Setting campaign state to 'dlc2'
18:01:59.57   GAME -- Closing state 'dlc2'
18:01:59.58   GAME -- Setting campaign state to 'dlc3'
18:01:59.58   GAME -- Closing state 'dlc3'
18:01:59.59   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:01:59.63   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:00.39   Requesting Relic Downloader soft throttle call [GetNewsAsync] has time 805
18:02:00.39   Sent message game CompanyOfHeroes softthrottle
18:02:00.43   Got dlman msg [ack game CompanyOfHeroes softthrottle]
18:02:01.18   GetUserStats requested stats for PIDs ( 3055263 3060096 ) (best:2, full:0)
18:02:01.18   QueryMatches: Got [48] maps, [127] ids, [17] advertisements, startID [1]
18:02:01.18   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 110 matches
18:02:02.88   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:02.88   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:02.88   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:02.94   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:02.96   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:02:02.99   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:04.43   QueryMatches: Got [48] maps, [127] ids, [17] advertisements, startID [152010131]
18:02:04.44   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 93 matches
18:02:05.45   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:05.45   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:05.45   GetMaxFrameTimeFromProfile: players=6 expected FPS=100.000000, bars=5, max avg=0.000, sd=0.000, 0 samples =
18:02:05.55   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:05.57   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:02:05.59   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:09.60   QueryMatches: Got [48] maps, [124] ids, [17] advertisements, startID [152010917]
18:02:09.60   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 75 matches
18:02:10.34   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:10.34   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:10.34   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:10.48   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:10.50   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:02:10.53   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:12.88   Activating screen: DynamicPopupMenu
18:02:14.21   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:14.21   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:14.21   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:14.22   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:14.24   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:02:14.25   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:14.45   QueryMatches: Got [45] maps, [122] ids, [17] advertisements, startID [152011169]
18:02:14.45   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 57 matches
18:02:15.05   Activating screen: RaceSelectionPopup
18:02:15.87   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:15.87   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:15.87   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:15.88   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:15.89   UpdateMatch: Call to UpdateGathering started, matchTypeID = 14.
18:02:15.91   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:17.07   Activating screen: RaceSelectionPopup
18:02:17.77   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:17.77   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:17.77   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:17.78   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:17.82   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:19.55   QueryMatches: Got [46] maps, [119] ids, [17] advertisements, startID [152011366]
18:02:19.55   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 38 matches
18:02:19.79   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:19.79   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:19.79   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:19.80   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:19.83   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:21.12   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:21.12   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:21.13   GetMaxFrameTimeFromProfile: players=4 expected FPS=17.759417, bars=5, max avg=0.055, sd=0.002, 3 samples =  0.06 0.06 0.05
18:02:21.14   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:21.17   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:23.60   Transport - Largest sent is now 80
18:02:24.45   QueryMatches: Got [44] maps, [116] ids, [17] advertisements, startID [152011477]
18:02:24.46   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 21 matches
18:02:26.42   GameSetupForm - UpdateMatchType: Setting match type to 14: CLASSIC_COOP_SKIRMISH
18:02:26.42   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:26.42   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:26.42   MatchInternal::SetMatchState - state 1 - updating server
18:02:26.42   Net::Session::SetVisible - session is set to INVISIBLE.
18:02:26.42   MatchSetup: Sending start game message!
18:02:26.42   GameSetupForm - Starting game
18:02:26.42   GameInfo::ResetInfo - SyncLevel set to 0 on reset
18:02:26.43   PopulateGameInfo - random seed:[1289235746], guid:[{9e47ab87-65fe-438e-a707-9fb180f43ad3}], sync level:[0]
18:02:26.43   Error loading [DATA:levelingCurve.lua]
18:02:26.43   Error loading [DATA:levelingCurve.lua]
18:02:26.44   Error loading [DATA:levelingCurve.lua]
18:02:26.44   Error loading [DATA:levelingCurve.lua]
18:02:26.44   MOD - Setting player (0) race to: allies_soviets
18:02:26.44   MOD - Setting player (0) race to: 2
18:02:26.44   MOD - Setting player (1) race to: allies
18:02:26.44   MOD - Setting player (1) race to: 1
18:02:26.44   MOD - Setting player (2) race to: axis
18:02:26.44   MOD - Setting player (2) race to: 3
18:02:26.44   MOD - Setting player (3) race to: axis_panzer_elite
18:02:26.44   MOD - Setting player (3) race to: 4
18:02:26.45   OnlineUpdateStateAsync: initiating state change, id = 152011637, state=2
18:02:26.47   APP -- Game Start
18:02:26.47   Sent message game CompanyOfHeroes allowtraffic
18:02:26.47   GAME -- Setting campaign state to 'coh'
18:02:26.47   GAME -- Closing state 'coh'
18:02:26.47   GAME -- Setting campaign state to 'cxp2'
18:02:26.47   GAME -- Closing state 'cxp2'
18:02:26.48   GAME -- Setting campaign state to 'cxp1'
18:02:26.48   GAME -- Closing state 'cxp1'
18:02:26.48   GAME -- Setting campaign state to 'dlc1'
18:02:26.48   GAME -- Closing state 'dlc1'
18:02:26.49   GAME -- Setting campaign state to 'dlc2'
18:02:26.49   GAME -- Closing state 'dlc2'
18:02:26.49   GAME -- Setting campaign state to 'dlc3'
18:02:26.49   GAME -- Closing state 'dlc3'
18:02:26.50   MessageInternal::DestroyChannel: Destroyed channel 534d5347
18:02:26.51   GAME -- Ending FE
18:02:26.51   UIFrontEnd - Unloading Front End
18:02:26.53   SOUND -- Shutting down ...
18:02:26.58   SOUND -- Shutdown completed!
18:02:26.60
18:02:26.60   GAME -- *** Beginning mission 4p_point_du_hoc (1 Humans, 3 Computers) ***
18:02:26.60
18:02:26.80   GAME -- Recording game
18:02:26.87   Activating screen: GameLoadScreen
18:02:26.87   Got dlman msg [ack game CompanyOfHeroes allowtraffic]
18:02:27.05   OnlineUpdateStateAsync: updated state for gid=152011637
18:02:27.23   QuazalPostStatsAsync: Simulation results sent to server for gid=0
18:02:27.23   THREAD: Hyper-Threading Technology Processors are not detected.
18:02:27.30   SOUND -- Initializing ...
18:02:28.40   SOUND -- Initialization completed!
18:02:28.44   PHYSICS: detected processor(s) capable of handling 2 threads.
18:02:28.49   MOD -- Locating MOD for scenario 'DATA:scenarios\mp\classic\4p_point_du_hoc\4p_point_du_hoc'
18:02:28.49   MOD -- Using Mod 'Eastern_Front'
18:02:28.54   Unable to load/parse precache file [DATA:scenarios\mp\classic\4p_point_du_hoc\4p_point_du_hoc_precache.lua]
18:02:28.63   Re-winding a compressed stream for file 'data:sound\wav\music_nonstream\coh_force_beyond_reckoning_lower_load.smf'.  Expensive operation
18:02:28.63   Re-winding a compressed stream for file 'data:sound\wav\music_nonstream\coh_force_beyond_reckoning_lower_load.smf'.  Expensive operation
18:02:33.48   GameObjLoader - upgrading load_count from 0 to 1136
18:02:33.95   QueryMatches: Got [41] maps, [110] ids, [17] advertisements, startID [152011592]
18:02:33.95   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 7 matches
18:02:38.29   GameObjLoader - upgrading load_count from 1136 to 1850
18:02:38.57   PHYSICS -- Created node factory 'HVOK'
18:02:38.57   PHYSICS -- Created node factory 'DMMY'
18:02:38.86   QueryMatches: Got [40] maps, [111] ids, [17] advertisements, startID [152011668]
18:02:38.86   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 2 matches
18:02:44.05   QueryMatches: Got [39] maps, [112] ids, [17] advertisements, startID [152009683]
18:02:44.05   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 4 matches
18:02:46.01   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.1/0.0, #p/sec[s/r] = 0.2/0.2, max unsent 0, version err 0, merge 0
18:02:49.00   QueryMatches: Got [39] maps, [112] ids, [17] advertisements, startID [152010885]
18:02:49.00   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 3 matches
18:02:54.01   QueryMatches: Got [42] maps, [115] ids, [17] advertisements, startID [152011171]
18:02:54.01   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 9 matches
18:02:54.89   GameObjLoader - upgrading load_count from 37 to 4259
18:02:59.02   QueryMatches: Got [43] maps, [118] ids, [17] advertisements, startID [152011415]
18:02:59.03   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 13 matches
18:03:00.00   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:03:00.02   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:03:01.08   GameObjLoader 03397368 - resetting counters
18:03:01.08   GameObjLoader 03397368 - LOAD_DONE
18:03:01.08   GAME - SessionSetup
18:03:02.13   CommandBPDatabase - Unable to register function [splat_attach] due to missing CommandBP.
18:03:02.13   TERRAINTEXTURE -- compositor added RenderTarget [0] of size 2048 x 2048
18:03:02.13   TERRAINTEXTURE -- compositor added RenderTarget [1] of size 1024 x 1024
18:03:05.58   Re-winding a compressed stream for file 'data:sound\wav\music_nonstream\coh_force_beyond_reckoning_lower_load.smf'.  Expensive operation
18:03:07.77   Warning: RenderCompositeStrips AddStripSegment : time == FLT_MAX
18:03:07.78   Warning: RenderCompositeStrips AddStripSegment : time == FLT_MAX
18:03:13.19   SPDx10 -- Cannot lock non-4 texel aligned regions of DXT textures. xStart: 1600, yStart: 1162
18:03:13.19   SPDx10 -- Could not lock destination texture for copy.
18:03:13.19   SPDx10 -- Cannot lock non-4 texel aligned regions of DXT textures. xStart: 1600, yStart: 1162
18:03:13.19   SPDx10 -- Could not lock destination texture for copy.
18:03:13.19   SPDx10 -- Cannot lock non-4 texel aligned regions of DXT textures. xStart: 1600, yStart: 1162
18:03:13.19   SPDx10 -- Could not lock destination texture for copy.
18:03:13.19   SPDx10 -- Cannot lock non-4 texel aligned regions of DXT textures. xStart: 1600, yStart: 1162
18:03:13.19   SPDx10 -- Could not lock destination texture for copy.
18:03:13.19   SPDx10 -- Cannot lock non-4 texel aligned regions of DXT textures. xStart: 1600, yStart: 1162
18:03:13.19   SPDx10 -- Could not lock destination texture for copy.
18:03:13.81   GAME - CreateGEWorld in 12729 ms
18:03:13.83   TGAIO -- TGA file 'data:simulation/deformdata/Lock_deform.tga' is RLE compressed. For optimal speed, please re-save uncompressed.
18:03:15.30   GAME - SessionSetup finished in 14220 ms
18:03:15.31   GAME - WaterReflectionManagerSetup
18:03:15.31   GAME - WaterReflectionManagerSetup finished in 0 ms
18:03:16.04   MessageInternal::CreateChannel: Created channel 474d4343
18:03:16.04   QueryMatches: Got [41] maps, [114] ids, [17] advertisements, startID [152011528]
18:03:16.05   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 13 matches
18:03:16.06   Regenerating ImpassMap data...
18:03:16.06       Impass Data was already valid, but regenerating...
18:03:16.24   Generating CanBuild Map.  THIS SHOULD ONLY HAPPEN IN WORLDBUILDER!  IF YOU SEE THIS IN GAME, RE-SAVE THE MAP!
18:03:16.24   Regenerating CanBuildMap data...
18:03:16.24   Generating CanShoot Map.
18:03:16.24   Pathfinder::Regenerate()...
18:03:16.29   Generating PathSectorMap...
18:03:16.62   Pathfinder::Regenerate() Done.
18:03:16.91   ModWorld::LoadWinCondition: - [DATA:Scar/WinConditions/zannihilate.scar] succeeded.
18:03:19.58   MOD -- Player  (unused player) (frame 0) (KillPlayer)
18:03:19.58   MOD -- Player  (unused player) (frame 0) (KillPlayer)
18:03:19.58   MOD -- Player  (unused player) (frame 0) (KillPlayer)
18:03:19.58   MOD -- Player  (unused player) (frame 0) (KillPlayer)
18:03:20.97   MessageInternal::CreateChannel: Created channel 4d4f444d
18:03:22.01   BindingsSystem -- Cannot create binding.  Unknown type 'repair_radius_circle'
18:03:22.01   BindingsSystem -- Cannot create binding.  Unknown type 'repair_radius_circle'
18:03:22.01   BindingsSystem -- Cannot create binding.  Unknown type 'repair_radius_circle'
18:03:22.01   BindingsSystem -- Cannot create binding.  Unknown type 'repair_radius_circle'
18:03:22.01   BindingsSystem -- Cannot create binding.  Unknown type 'repair_radius_circle'
18:03:22.74   SPEECHMANAGER -- Loaded in 0.676742 seconds
18:03:24.59   QueryMatches: Got [39] maps, [114] ids, [17] advertisements, startID [152011631]
18:03:24.59   QuazalGetAdvertisementsAsync: Queuing refresh to obtain unknown 8 matches
18:03:24.74   GameObjLoader - upgrading load_count from 0 to 481
18:03:25.89   QueryMatches: Got [40] maps, [113] ids, [17] advertisements, startID [152011748]
18:03:27.20   GameObjLoader 033974c8 - resetting counters
18:03:27.20   GameObjLoader 033974c8 - LOAD_DONE
18:03:28.54   PreloadResources took 0ms.
18:03:28.92   GAME -- Loading completed (62 seconds)
18:03:28.92   SIM -- Setting SyncErrorChecking level to Low
18:03:33.01   Activating screen: GameScreen
18:03:33.01   Activating screen: Decorators_widescreen
18:03:33.01   Activating screen: Taskbar_widescreen
18:03:33.01   Activating screen: SubtitleScreen
18:03:33.01   Activating screen: TextOverlayScreen
18:03:33.12   PerformanceRecorder::StartRecording for game size 4
18:03:33.12   GAME -- Starting mission...
18:03:34.99   MOD -- Player CPU - Normal set to AI Type: AI Player (frame 1) (CmdAI)
18:03:34.99   MOD -- Player CPU - Normal set to AI Type: AI Player (frame 1) (CmdAI)
18:03:34.99   MOD -- Player CPU - Normal set to AI Type: AI Player (frame 1) (CmdAI)
18:03:40.67   Warning: non auto-match upgrade not found in AE, tuning
18:03:47.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.1, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:03:49.97   Activating screen: Command_Tree
18:03:52.60   Activating screen: Command_Branch
18:04:01.01   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:04:01.01   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:04:14.15   Activating screen: TacticalMap_widescreen
18:04:14.15   Activating screen: TextOverlayScreen
18:04:19.97   Activating screen: GameScreen
18:04:19.97   Activating screen: Decorators_widescreen
18:04:19.97   Activating screen: Taskbar_widescreen
18:04:19.97   Activating screen: SubtitleScreen
18:04:19.97   Activating screen: TextOverlayScreen
18:04:25.26   Warning: binding repeat_0(Ability: abilities\reenable_capture_ability) -- ui index '0' out of bounds; range is [1, 12]
18:04:30.10   Activating screen: TacticalMap_widescreen
18:04:30.10   Activating screen: TextOverlayScreen
18:04:37.55   Activating screen: GameScreen
18:04:37.55   Activating screen: Decorators_widescreen
18:04:37.55   Activating screen: Taskbar_widescreen
18:04:37.55   Activating screen: SubtitleScreen
18:04:37.55   Activating screen: TextOverlayScreen
18:04:43.07   Warning: binding repeat_1(Ability: abilities\reenable_capture_ability) -- ui index '0' out of bounds; range is [1, 12]
18:04:48.01   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:05:02.01   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:05:02.01   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:05:49.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:06:03.00   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:06:03.00   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:06:03.97   Warning: binding selection bindings_child6() -- Binding selection bindings_child6: failed bind to widget 'build_max_background'
18:06:50.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:07:04.00   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:07:04.00   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:07:51.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:07:58.70   Activating screen: Command_Branch
18:08:05.01   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:08:05.01   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:08:08.65   Unable to bind updater for fx [ui\reveal].  It could be looping in a fire-n-forget action.
18:08:18.64   Unable to bind updater for fx [ui\reveal].  It could be looping in a fire-n-forget action.
18:08:40.03   Activating screen: Command_Branch
18:08:42.06   Activating screen: NewObjective_widescreen
18:08:52.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:09:00.77   Unable to bind updater for fx [ui\reveal].  It could be looping in a fire-n-forget action.
18:09:06.01   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:09:06.01   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:09:16.78   Was already stealing a skeleton when told to steal another [mortar_target].
18:09:53.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
18:10:07.01   local host PeerID 1 CONN ack=  0 (  0ms~0) unack=  0, retry=  0, highwaterOOS=0 @WINaddr:192.168.0.199:6112; (ping=0ms) 100.00%, pending=0, dead=0
18:10:07.01   MessageCounts: inval=0/0, seek=0/0, join=0/0, integ=0/0, seek_reply=0/0, join_reply=0/0, add=0/0, remove=0/0, drop=0/0, data=0/0, voice=0/0, rchk=0/0, nudge=0/0, peerhdr=0/0, proxy=0/0, ping=0/0, frag=0/0, Errors=0/0
18:10:52.42   Warning: binding repeat_0() -- widget 'command_button_05' already occupied by 'primary selection commands_child5:'
18:10:54.00   Transport - median kBPS [hi/cur] sent = 0.2/0.0, recvd = 0.2/0.0, #p/sec[s/r] = 0.0/0.0, max unsent 0, version err 0, merge 0
