2024-04-23 18:19 CEST
  

View Issue Details [ Jump to Notes ] [ Issue History ] [ Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0004427Spring engineGeneralpublic2014-06-09 20:142014-06-30 13:39
ReporterAnarchid 
Assigned Tocleanrock 
PrioritynormalSeverityminorReproducibilitysometimes
StatusresolvedResolutionreopened 
Product Version97.0.1+git 
Target Version98.0Fixed in Version 
Summary0004427: Jerky unit animations when rejoining a game on 97.0.1-19
DescriptionRejoining a game causes all animations to appear as if at significantly reduced FPS. This appears to everything, most notably metal extractors and windmills make it easily observable.

It applies to both players and spectators. There are sporadic reports on when it does not happen. All cases where it happened thus far were on Linux.

Amount of units on map doesn't seem to matter, the issue was observed with as few as 40.
Steps To Reproduce1) Find an unready game to spectate.
2) Wait for it to start.
3) Observe nice and smooth animations.
4) Quit and rejoin the same game.
5) Windgens, metal extractrs, and everything animate jerkily. Projectiles and unit positions are smooth. Fps is normal.
Additional InformationThus far only tested with ZK, but nature of bug seems to preclude effect of luarules or luaui.

Only seems to affect the actually rejoining players: both players and spectators who did not rejoin reported smooth animations with no disruption.

It was not tested whether this affects players catching-up without rejoin (i.e, after lagout).

Replay with demonstration available at http://zero-k.info/Battles/Detail/267494
TagsNo tags attached.
Checked infolog.txt for Errors
Attached Files
  • txt file icon infolog_traces.txt (64,326 bytes) 2014-06-23 18:03 - 
    [ParseCmdLine] command-line args: "/home/johanr/spring_jitter/bin/spring /home/johanr/.cache/flobby/flobby_script.txt"
Using configuration source: "/home/johanr/.config/spring/springsettings.cfg"
Using additional configuration source: "/home/johanr/.springrc"
Available log sections: KeyBindings, Sound, Font, AutohostInterface, GameServer, Net, VFS, Texture, Path, CSMFGroundTextures, RoamMeshDrawer, BumpWater, DynWater, SkyBox, DecalsDrawerGL4, FarTextureHandler, Shader, Piece, Model, ModelDrawer, OBJParser, WorldObjectModelRenderer, GroundMoveType, UnitScript, CregSerializer, ArchiveScanner, LuaSocket
Enabled log sections: Sound(N)
Enable or disable log sections using the LogSections configuration key
  or the SPRING_LOG_SECTIONS environment variable (both comma separated).
  Use "none" to disable the default log sections.
LogOutput initialized.
Spring 97.0.1-81-g05e4f29 HEAD
Build Date & Time: Jun 23 2014 11:23:35
Build Environment: boost-105500, GNU libstdc++ version 20140604
Compiler Version:  gcc-4.9.0 20140604 (prerelease)
Operating System:  Linux 3.15.1-1-ARCH #1 SMP PREEMPT Tue Jun 17 09:32:20 CEST 2014 x86_64
Word Size:         64-bit (native mode)
         CPU Clock: std::chrono::high_resolution_clock
Physical CPU Cores: 8
 Logical CPU Cores: 8
[CMyMath::Init] CPU SSE mask: 127, flags:
	SSE 1.0:  1,  SSE 2.0:  1
	SSE 3.0:  1, SSSE 3.0:  1
	SSE 4.1:  1,  SSE 4.2:  1
	SSE 4.0A: 0,  SSE 5.0A: 0
	using streflop SSE FP-math mode, CPU supports SSE instructions
Supported Video modes: 640x480, 800x600, 1024x768, 1280x960, 1280x1024, 1440x900, 1600x1200, 1680x1050, 1920x1080, 1920x1200
SDL version:  linked 2.0.3; compiled 2.0.3
GL version:   4.4.0 NVIDIA 337.25
GL vendor:    NVIDIA Corporation
GL renderer:  GeForce GTX 760/PCIe/SSE2
GLSL version: 4.40 NVIDIA via Cg compiler
GLEW version: 1.10.0
Video RAM:    total 2048MB, available 1514MB
FBO::maxSamples: 32
GL info:
	haveARB: 1, haveGLSL: 1, ATI hacks: 0
	FBO support: 1, NPOT-texture support: 1, 24bit Z-buffer support: 1
	maximum texture size: 16384, compress MIP-map textures: 0
	maximum SmoothPointSize: 190, maximum vec4 varying/attributes: 31/16
	maximum drawbuffers: 8, maximum recommended indices/vertices: 1048576/1048576
	number of UniformBufferBindings: 84 (64kB)
Using Adaptive VSync
[InitOpenGL] video mode set to 1920x1200:24bit @59Hz (windowed)
[WatchDogInstall] Installed (HangTimeout: 10sec)
[ThreadPool::SetThreadCount][1] #wanted=8 #current=1
[ThreadPool::SetThreadCount][2] #threads=7
Using read-write data directory: /home/johanr/.config/spring/
Using read-only data directory: /home/johanr/.spring/
Using read-only data directory: /home/johanr/spring_jitter/share/games/spring/
Scanning: /home/johanr/spring_jitter/share/games/spring/base
Scanning: /home/johanr/.spring/maps
Scanning: /home/johanr/.spring/base
Scanning: /home/johanr/.spring/games
Scanning: /home/johanr/.spring/packages
Warning: Found a "kurczak.sd7" already in "/home/johanr/.spring/maps/", ignoring one in "/home/johanr/.spring/maps/"
[f=0000000] [Sound] OpenAL info:
[f=0000000] [Sound]   Available Devices:
[f=0000000] [Sound]               OpenAL Soft
[f=0000000] [Sound]   Device:     OpenAL Soft
[f=0000000] [Sound]   Vendor:         OpenAL Community
[f=0000000] [Sound]   Version:        1.1 ALSOFT 1.15.1
[f=0000000] [Sound]   Renderer:       OpenAL Soft
[f=0000000] [Sound]   AL Extensions:  AL_EXT_ALAW AL_EXT_DOUBLE AL_EXT_EXPONENT_DISTANCE AL_EXT_FLOAT32 AL_EXT_IMA4 AL_EXT_LINEAR_DISTANCE AL_EXT_MCFORMATS AL_EXT_MULAW AL_EXT_MULAW_MCFORMATS AL_EXT_OFFSET AL_EXT_source_distance_model AL_LOKI_quadriphonic AL_SOFT_buffer_samples AL_SOFT_buffer_sub_data AL_SOFTX_deferred_updates AL_SOFT_direct_channels AL_SOFT_loop_points AL_SOFT_source_latency
[f=0000000] [Sound]   ALC Extensions: ALC_ENUMERATE_ALL_EXT ALC_ENUMERATION_EXT ALC_EXT_CAPTURE ALC_EXT_DEDICATED ALC_EXT_disconnect ALC_EXT_EFX ALC_EXT_thread_local_context ALC_SOFT_loopback
[f=0000000] [Sound]   EFX Enabled: yes
[f=0000000] Joysticks found: 0
[f=0000000] Warning: Joystick 0 not found
[f=0000000] [ThreadPool::SetThreadCount][1] #wanted=4 #current=8
[f=0000000] [ThreadPool::SetThreadCount][2] #threads=3
[f=0000000] [Sound]   Max Sounds: 96
[f=0000000] [Threading] Main thread CPU affinity mask set: 248
[f=0000000] [Startup] Loading StartScript from: /home/johanr/.cache/flobby/flobby_script.txt
[f=0000000] Connecting to: 94.23.171.72:8681
[f=0000000] Connecting to 94.23.171.72:8681 using name cleanrock
[f=0000000] Using map: SpeedMetal
[f=0000000] Using game: Zero-K v1.2.6.20
[f=0000000] Using game archive: 28e8a377526a60f986772c8979fe2e2b.sdp
[f=0000000] Warning: Incompatible map-checksum: Checksum of SpeedMetal (checksum 0x441cfac7) differs from the host's copy (checksum 0x1). This may be caused by a corrupted download or there may even be 2 different versions in circulation. Make sure you and the host have installed the chosen archive and its dependencies and consider redownloading it.
[f=0000000] Warning: Incompatible game-checksum: Checksum of 28e8a377526a60f986772c8979fe2e2b.sdp (checksum 0xcc2fcecd) differs from the host's copy (checksum 0x1). This may be caused by a corrupted download or there may even be 2 different versions in circulation. Make sure you and the host have installed the chosen archive and its dependencies and consider redownloading it.
[f=0000000] Recording demo to: /home/johanr/.config/spring/demos/20140623_175400_SpeedMetal_97.0.1-81-g05e4f29 HEAD.sdf
[f=0000000] PreGame::GameDataReceived: 16 ms
[f=0000000] [PreGame::UpdateClientNet] user number 1 (team 0, allyteam 0)
[f=0000000] Warning: MapInfo.lua: Incorrect value "groundShadowDensity=1.500000"! Clamping to 0..1 range!!
[f=0000000] Warning: MapInfo.lua: Incorrect value "unitShadowDensity=1.500000"! Clamping to 0..1 range!!
[f=0000000] [LuaIntro] Searching for new Widgets
[f=0000000] [LuaIntro] Scanning: LuaIntro/Addons/
[f=0000000] [LuaIntro] Scanning: LuaIntro/Widgets/
[f=0000000] [LuaIntro] Scanning: LuaIntro/SystemAddons/
[f=0000000] [LuaIntro] Scanning: LuaIntro/SystemWidgets/
[f=0000000] [LuaIntro] Scanning: LuaIntro/chili/
[f=0000000] [LuaIntro] Found new widget "SpringLogo"
[f=0000000] [LuaIntro] Found new widget "LoadTexture"
[f=0000000] [LuaIntro] Found new widget "LoadProgress"
[f=0000000] [LuaIntro] Found new widget "Main"
[f=0000000] [LuaIntro] Found new widget "Music"
[f=0000000] [LuaIntro] Found new widget "WM Stuff"
[f=0000000] [LuaIntro] Loading widgets   <>=vfs  **=raw  ()=unknown
[f=0000000] [LuaIntro] Loading widget:      WM Stuff               <wm.lua>
[f=0000000] [LuaIntro] Loading widget:      LoadProgress           <loadprogress.lua>
[f=0000000] [LuaIntro] Loading widget:      Main                   <main.lua>
[f=0000000] [LuaIntro] Loading widget:      Music                  <music.lua>
[f=0000000] [LuaIntro] Loading widget:      LoadTexture            <bg_texture.lua>
[f=0000000] [LuaIntro] LuaIntro v1.0 (Lua 5.1)
[f=0000000] Parsing Map Information
[f=0000000] Loading SMF
[f=0000000] Loading Map (42 MB)
[f=0000000] Loading Radar Icons
[f=0000000] Loading GameData Definitions
[f=0000000] Loading all definitions:  0.375000
[f=0000000] Game::LoadDefs (GameData): 413 ms
[f=0000000] Loading Sound Definitions
[f=0000000] [Sound] Warning: Sound incomingchat is missing file tag (ignoring)
[f=0000000] [Sound]  parsed 345 sounds from gamedata/sounds.lua
[f=0000000] [Sound] Error: Unable to open audio file: IncomingChat
[f=0000000] [Sound] Error: CSound::GetSoundId: could not find sound: IncomingChat
[f=0000000] Game::LoadDefs (Sound): 8 ms
[f=0000000] Creating Smooth Height Mesh
[f=0000000] SmoothHeightMesh::MakeSmoothMesh: 13 ms
[f=0000000] Creating QuadField & CEGs
[f=0000000] [CDamageArrayHandler] number of ArmorDefs: 9
[f=0000000] Warning: [CDamageArrayHandler] UnitDef "chicken" in ArmorDef "chicken" already belongs to ArmorDef category 2!
[f=0000000] [RegisterAssimpModelFormats] supported Assimp model formats: *.3ds;*.blend;*.dae;*.lwo;
[f=0000000] Creating Unit Textures
[f=0000000] Creating Sky
[f=0000000] Loading Weapon Definitions
[f=0000000] Loading Unit Definitions
[f=0000000] Loading Feature Definitions
[f=0000000] [IPathManager::GetInstance] using DEFAULT path-manager
[f=0000000] Initializing Map Features
[f=0000000] Creating ShadowHandler & DecalHandler
[f=0000000] Creating GroundDrawer
[f=0000000] Loading Map Tiles
[f=0000000] Loading Square Textures
[f=0000000] CSMFGroundTextures::ConvolveHeightMap: 1 ms
[f=0000000] Switching to ROAM Mesh Rendering
[f=0000000] Creating TreeDrawer
[f=0000000] Creating ProjectileDrawer & UnitDrawer
[f=0000000] Creating Projectile Textures
[f=0000000] Creating Water
[f=0000000] Game::LoadInterface (Camera&Mouse): 40 ms
[f=0000000] [Sound] Error: Unable to open audio file: MultiSelect
[f=0000000] [Sound] Error: CSound::GetSoundId: could not find sound: MultiSelect
[f=0000000] Game::LoadInterface (Console): 5 ms
[f=0000000] [Sound] Error: Unable to open audio file: FailedCommand
[f=0000000] [Sound] Error: CSound::GetSoundId: could not find sound: FailedCommand
[f=0000000] Loading LuaRules
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Chicken configured for 3 players
[f=0000000] Initializing gadget
[f=0000000] [Perks] Warning: Unlock system error: Unlock data entry for player 1 is empty or in invalid format
[f=0000000] [Perks] Warning: Unlock system error: Unlock data entry for player 1 is empty or in invalid format
[f=0000000] [Perks] Warning: Unlock system error: Unlock data entry for player 1 is empty or in invalid format
[f=0000000] [UnitMorph] Warning: Comm Morph warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] [UnitMorph] Warning: Comm Morph warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] [UnitMorph] Warning: Comm Morph warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] Setting morph for custom comms for player: 0
[f=0000000] Setting morph for custom comms for player: 2
[f=0000000] Setting morph for custom comms for player: 3
[f=0000000] [CAI] Error: CAI: Fatal error, map not supported due to metal map.
[f=0000000] [StartSetup] Warning: Start Unit Setup warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] [StartSetup] Warning: Start Unit Setup warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] [StartSetup] Warning: Start Unit Setup warning: Comm data entry for player 1 is empty or in invalid format
[f=0000000] [Planet Wars Structures] Warning: Planetwars warning: Planetwars data entry in modoption is empty or in invalid format
[f=0000000] LUARULES-DRAW  (GADGETS)
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] zombies: unsynced mode
[f=0000000] LUARULES-DRAW  (GADGETS)
[f=0000000] Loading LuaGaia
[f=0000000] Loading LuaUI
[f=0000000] LuaSocketEnabled: yes
[f=0000000] This game has locked LuaUI access
[f=0000000] This game has locked LuaUI access
[f=0000000] Using LUAUI_DIRNAME = LuaUI/
[f=0000000] Reloaded ctrlpanel from file: LuaUI/ctrlpanel.txt
[f=0000000] LuaUI: bound F11 to the widget selector
[f=0000000] LuaUI: bound CTRL+F11 to tweak mode
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Jump Jet Defs checking begining...
[f=0000000] .. Jump Jet Defs checking complete
[f=0000000] Loaded API widget:  Shared Functions    <api_shared_functions.lua>
[f=0000000] Loaded API widget:  Cluster Detection   <api_cluster_detection.lua>
[f=0000000] Loaded API widget:  Modular Comm Info   <api_modularcomms.lua>
[f=0000000] Loaded API widget:  Chili Framework     <api_chili.lua>
[f=0000000] Loaded API widget:  Lag (AFK) monitor   <api_lag_monitor.lua>
[f=0000000] Hardware mouse-cursor is disabled!
[f=0000000] Set "shadows" config-parameter to 1
[f=0000000] Ground-decals rendering is disabled!
[f=0000000] Set maximum particles to: 20000
[f=0000000] Set UnitLodDist to 502
[f=0000000] Set UnitIconDist to 150
[f=0000000] Loaded widget:  EPIC Menu           <gui_epicmenu.lua>
[f=0000000] Loaded widget:  Chili Minimap       <gui_chili_minimap.lua>
[f=0000000] Loaded widget:  Chili Widget Selector  <gui_chili_widgetselector.lua>
[f=0000000] Loaded widget:  Custom Cursor Sets  <gui_customcursorsets.lua>
[f=0000000] Mexspot Fetcher fetching
[f=0000000] Loaded widget:  Mexspot Fetcher     <wg_mexspot_fetcher.lua>
[f=0000000] Loaded widget:  Local Team Colors   <gui_local_colors.lua>
[f=0000000] Loaded widget:  HealthBars          <unit_healthbars.lua>
[f=0000000] Loaded widget:  Noises              <snd_noises.lua>
[f=0000000] Loaded widget:  Unit Icons          <unit_icons.lua>
[f=0000000] Loaded widget:  Team stats          <gui_team_stats.lua>
[f=0000000] Loaded widget:  Chili Vote Display  <gui_chili_vote.lua>
[f=0000000] Loaded widget:  Chili Chicken Panel  <gui_chili_chicken.lua>
[f=0000000] Loaded widget:  TeamCommEnds & Lavarise indicator  <gui_teamcommends.lua>
[f=0000000] Loaded widget:  Cloak Fire State    <unit_cloakfirestate.lua>
[f=0000000] Loaded widget:  EndGame Stats       <gui_chili_endgraph.lua>
[f=0000000] Loaded widget:  BuildETA            <gui_build_eta.lua>
[f=0000000] Loaded widget:  Initial Queue ZK    <unit_initial_queue.lua>
[f=0000000] Loaded widget:  Chili CTF GUI       <gui_chili_ctf.lua>
[f=0000000] Loaded widget:  Auto Patrol Nanos   <unit_auto_patrol_nanos.lua>
[f=0000000] Loaded widget:  Autoquit            <autoquit.lua>
[f=0000000] Spectator mode detected. Removed: Auto First Build Facing
[f=0000000] Loaded widget:  Auto First Build Facing  <init_autofirstbuildfacing.lua>
[f=0000000] Loaded widget:  Blast Radius        <gui_blastradius.lua>
[f=0000000] Loaded widget:  CameraShake         <camera_shake.lua>
[f=0000000] Loaded widget:  Chili Rejoining Progress Bar  <gui_chili_rejoin_progress.lua>
[f=0000000] Loaded widget:  ComCounter          <unit_com_counter.lua>
[f=0000000] Loaded widget:  Constructor Auto Assist  <unit_factory_guard.lua>
[f=0000000] Loaded widget:  Chili Selections & CursorTip  <gui_chili_selections_and_cursortip.lua>
[f=0000000] Loaded widget:  Context Menu        <gui_contextmenu.lua>
[f=0000000] Loaded widget:  Darkening           <gui_darkening.lua>
[f=0000000] Loaded widget:  Defense Range Zero-K  <gui_defenserange.lua>
[f=0000000] Loaded widget:  Ferry Points        <cmd_ferry_points.lua>
[f=0000000] Loaded widget:  Keep Target         <cmd_keep_target.lua>
[f=0000000] Loaded widget:  Local Widgets Config  <localwidgets.lua>
[f=0000000] Loaded widget:  Highlight Geos      <gui_highlight_geos.lua>
[f=0000000] Loaded widget:  MetalFeatures       <gui_metal_features.lua>
[f=0000000] Loaded widget:  Mex Placement Handler  <cmd_mex_placement.lua>
[f=0000000] Loaded widget:  MinimapEvents       <minimap_events.lua>
[f=0000000] Loaded widget:  Missile Silo Range  <missilesilo_range.lua>
[f=0000000] Loaded widget:  Persistent Build Spacing  <gui_persistent_build_spacing.lua>
[f=0000000] Loaded widget:  Point Tracker       <gui_point_tracker.lua>
[f=0000000] Loaded widget:  ReclaimInfo         <gui_reclaiminfo.lua>
[f=0000000] Loaded widget:  Spectate Selected Team  <gui_spectate_selected_team.lua>
[f=0000000] Loaded widget:  State Reverse Toggle  <cmd_state_reverse_toggle.lua>
[f=0000000] Loaded widget:  Stereo3D            <gfx_stereo3d.lua>
[f=0000000] Loaded widget:  Voice Assistant     <unit_voice.lua>
[f=0000000] Loaded widget:  Gui Toolkit API     <api_gui_toolkit.lua>
[f=0000000] Loaded widget:  Showeco and Grid Drawer  <gui_showeco_action.lua>
[f=0000000] Loaded widget:  Chili EndGame Window  <gui_chili_endgamewindow.lua>
[f=0000000] Loaded widget:  Chili Resource Bars  <gui_chili_resource_bars.lua>
[f=0000000] Loaded widget:  Area Attack Tweak   <cmd_area_attack_tweak.lua>
[f=0000000] Loaded widget:  Haven Handler       <gui_havens.lua>
[f=0000000] Loaded widget:  Decoration Handler  <unit_decoration_handler.lua>
[f=0000000] Loaded widget:  Frame Gap Logger    <dbg_frame_gap_logger.lua>
[f=0000000] Cleared Autogroups.
[f=0000000] Loaded widget:  Auto Group          <unit_auto_group.lua>
[f=0000000] Loaded widget:  Clippy Comments     <unit_clippy.lua>
[f=0000000] Loaded widget:  Easy Facing         <gui_easyfacing.lua>
[f=0000000] Loaded widget:  Ghost Site          <unit_ghostsite.lua>
[f=0000000] Loaded widget:  NoDuplicateOrders   <cmd_no_duplicate_orders.lua>
[f=0000000] <Startup Info and Selector> Spectator mode, Junior forced, or replay. Widget removed.
[f=0000000] Loaded widget:  Startup Info and Selector  <init_startup_info_selector.lua>
[f=0000000] <Stockpiler>: disabled for spectators
[f=0000000] Loaded widget:  Stockpiler          <unit_stockpile.lua>
[f=0000000] Loaded widget:  Transport AI        <unit_transport_ai.lua>
[f=0000000] <Unit Marker> Spectator mode or replay. Widget removed.
[f=0000000] Loaded widget:  Unit Marker Zero-K  <unit_marker.lua>
[f=0000000] Loaded widget:  Start Point Remover & Comm Selector  <init_start_point_remover.lua>
[f=0000000] Loaded widget:  Attack Warning      <unit_attack_warning.lua>
[f=0000000] [Engine Setting Fix v2] Warning: Setting UseNetMessageSmoothingBuffer = 1
[f=0000000] [Engine Setting Fix v2] Warning: Setting WorkerThreadSpinTime = 0
[f=0000000] Loaded widget:  Engine Setting Fix v2  <dbg_engine_settingsv2.lua>
[f=0000000] Loaded widget:  PlanetWars Info     <gui_planetwars_info.lua>
[f=0000000] Loaded widget:  Attack AoE          <gui_attack_aoe.lua>
[f=0000000] <Replay control buttons> Live mode. Widget removed.
[f=0000000] Loaded widget:  Replay control buttons  <gui_replay_controls.lua>
[f=0000000] Loaded widget:  MessageBoxes        <mission_messagebox.lua>
[f=0000000] Loaded widget:  Objectives          <mission_objectives.lua>
[f=0000000] Loaded widget:  Select Keys         <gui_selectkeys.lua>
[f=0000000] Loaded widget:  Unit Start State    <unit_start_state.lua>
[f=0000000] Loaded widget:  UnitNoStuckInFactory  <unit_nostuck_infactory.lua>
[f=0000000] Loaded widget:  SmoothScroll        <camera_smooth_move.lua>
[f=0000000] Loaded widget:  Chili Custom Modoptions Info  <gui_custommodoptions_info.lua>
[f=0000000] Loaded widget:  UnitShapes          <unit_shapes.lua>
[f=0000000] Loaded widget:  Commands FX         <gfx_commands_fx.lua>
[f=0000000] Loaded widget:  Ore mexes!          <gui_oremex.lua>
[f=0000000] Loaded widget:  AllyCursors         <gui_ally_cursors.lua>
[f=0000000] Loaded widget:  CommandInsert       <cmd_commandinsert.lua>
[f=0000000] Loaded widget:  Gadget Icons        <unit_gadget_icons.lua>
[f=0000000] Loaded widget:  Rank Icons 2        <unit_rank_icons.lua>
[f=0000000] Loaded widget:  Selection Send      <gui_selectionsend.lua>
[f=0000000] Loaded widget:  Shield Guard        <unit_shield_guard.lua>
[f=0000000] Loaded widget:  State Icons         <unit_state_icons.lua>
[f=0000000] <Building Starter>: disabled for spectators
[f=0000000] Loaded widget:  Building Starter    <unit_building_starter.lua>
[f=0000000] <Cloaker Guard>: disabled for spectators
[f=0000000] Loaded widget:  Cloaker Guard       <unit_cloaker_guard.lua>
[f=0000000] Loaded widget:  Units on Fire       <gfx_lups_units_on_fire.lua>
[f=0000000] Loaded widget:  Receive Units Indicator  <gui_recv_indicator.lua>
[f=0000000] Newton Firezone disabled for spectator.
[f=0000000] Loaded widget:  Newton Firezone     <cmd_newton_firezone.lua>
[f=0000000] Loaded widget:  Auto-toggle false color vision  <gui_auto_engine_falsecolor.lua>
[f=0000000] Loaded widget:  Chili Chat 2.1      <gui_chili_chat2_1.lua>
[f=0000000] Loaded widget:  Chili Docking       <gui_chili_docking.lua>
[f=0000000] Loaded widget:  Chili Deluxe Player List - Alpha 2.02  <gui_chili_deluxeplayerlist.lua>
[f=0000000] Loaded widget:  Chili Window Packer  <gui_chili_windowpacker.lua>
[f=0000000] Loaded widget:  Image Preloader     <dbg_img_preload.lua>
[f=0000000] Loaded widget:  Chili Core Selector  <gui_chili_core_selector.lua>
[f=0000000] Loaded widget:  Default Group Recall Fix  <gui_group_recall_fix.lua>
[f=0000000] Loaded widget:  MiniMap Start Boxes  <minimap_startbox.lua>
[f=0000000] Loaded widget:  Restricted Zones    <gui_restrictedzones.lua>
[f=0000000] Loaded widget:  Jumpjet GUI         <gui_jumpjets.lua>
[f=0000000] Loaded widget:  Chili Gesture Menu  <gui_chili_gesture_menu.lua>
[f=0000000] Loaded widget:  CustomFormations2   <cmd_customformations2.lua>
[f=0000000] cleanrock DISABLE TTS
[f=0000000] Loaded widget:  Text To Speech Control  <snd_text_to_speech.lua>
[f=0000000] Loaded widget:  Chili Integral Menu  <gui_chili_integral_menu.lua>
[f=0000000] Loaded widget:  Lasso Terraform GUI  <gui_lasso_terraform.lua>
[f=0000000] Loaded widget:  GC at >300MB        <dbg_forcegc_spring97.lua>
[f=0000000] LuaUI v0.3
[f=0000000] [LoadFinalize] finalizing PFS
[f=0000000] [Path] [PathEstimator::ReadFile] hash=3275190872

[f=0000000] Reading Estimate PathCosts [8]
[f=0000000] [Path] [PathEstimator::ReadFile] hash=3275190896

[f=0000000] Reading Estimate PathCosts [32]
[f=0000000] [LoadFinalize] finalized PFS (16ms, checksum 29ee44b9)
[f=0000000] Mex Placement Initialised with metal map mode.
[f=0000000] <Easy Facing> Spectator mode. Widget removed.
[f=0000000] Loaded DecalsDrawer: Legacy
[f=0000000] GameID: 594ba853e7db35f3611420c540c2d64e
[f=0000000] Connection attempt from Nermal
[f=0000000]  -> Version: 97.0.1-81-g05e4f29 develop
[f=0000000] <Clippy Comments> Spectator mode or replay. Widget removed.
[f=0000000] Epicmenu: Switching to Total Annihilation camera mode
[f=0000000]  -> Connection established (given id 0)
[f=0000000] Connection attempt from lolasd
[f=0000000]  -> Version: 97.0.1-81-g05e4f29 develop
[f=0000000]  -> Connection established (given id 2)
[f=0000000] Connection attempt from xponen
[f=0000000]  -> Version: 97.0.1-81-g05e4f29 develop
[f=0000000]  -> Connection established (given id 3)
[f=0000000] <Nermal> Allies: I choose: Bob the Builder!
[f=0000000] <lolasd> Allies: I choose: My test com heavy!
[f=0000000] <xponen> Allies: I choose: Machinegun Com!
[f=0000002] [Frame Gap Logger] Warning: Frame gap: 531
[f=0000002] cleanrock DISABLE TTS
[f=0000002] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=-696.272766
[f=0000003] [Frame Gap Logger] Warning: Frame gap: 315
[f=0000005] <Ghost Site> Spectator mode. Widget removed.
[f=0000013] !transmitlobby @voice@buildUnit@add;cornecro;Convict
[f=0000013] !transmitlobby @voice@buildUnit@add;corak;Bandit
[f=0000013] !transmitlobby @voice@buildUnit@add;corstorm;Rogue
[f=0000013] !transmitlobby @voice@buildUnit@add;corthud;Thug
[f=0000013] !transmitlobby @voice@buildUnit@add;cormak;Outlaw
[f=0000013] !transmitlobby @voice@buildUnit@add;shieldfelon;Felon
[f=0000013] !transmitlobby @voice@buildUnit@add;shieldarty;Racketeer
[f=0000013] !transmitlobby @voice@buildUnit@add;corcrash;Vandal
[f=0000013] !transmitlobby @voice@buildUnit@add;corroach;Roach
[f=0000013] !transmitlobby @voice@buildUnit@add;corclog;Dirtbag
[f=0000013] !transmitlobby @voice@buildUnit@add;core_spectre;Aspis
[f=0000013] !transmitlobby @voice@buildUnit@reload
[f=0000025] Skirmish AI "Chicken: Hard" (ID:0) took over control of team 3
[f=0000048] Wind Range: 0 - 2.5. Max Windmill altitude bonus is: 75%
[f=0000060] Terraform cost multipler = 1
[f=0000174] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2451.176758
[f=0000352] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2740.473633
[f=0000530] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2861.502441
[f=0000708] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3038.097900
[f=0000887] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2178.228516
[f=0001065] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2325.048340
[f=0001243] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2327.322510
[f=0001278] [Frame Gap Logger] Warning: Frame gap: 130
[f=0001422] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2002.229736
[f=0001600] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2055.614746
[f=0001778] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2283.202393
[f=0001957] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1361.669922
[f=0002137] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2190.723877
[f=0002316] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1230.467529
[f=0002493] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2544.487793
[f=0002674] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2565.819336
[f=0002850] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=14373.616211
[f=0003041] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1454.833496
[f=0003157] Commanders Remaining: 3
[f=0003221] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3023.134766
[f=0003401] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2389.837891
[f=0003579] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2538.567383
[f=0003757] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2832.108643
[f=0003937] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=888.070923
[f=0003961] Connection attempt from cleanrock
[f=0003961]  -> Version: 97.0.1-81-g05e4f29 HEAD
[f=0003961]  -> Connection established (given id 1)
[f=0004114] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1995.754883
[f=0004292] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2336.211670
[f=0004470] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3024.513916
[f=0004651] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2488.280762
[f=0004829] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2778.268555
[f=0005007] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2912.408691
[f=0005185] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3206.738770
[f=0005358] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=9587.652344
[f=0005538] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1296.633911
[f=0005715] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1140.855103
[f=0005894] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=5500.520508
[f=0006077] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=6786.025391
[f=0006262] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2541.676758
[f=0006440] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2850.369141
[f=0006609] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1834.729736
[f=0006788] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1880.165771
[f=0006963] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1998.495850
[f=0007139] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2341.076904
[f=0007299] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=15325.302734
[f=0007489] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2456.512695
[f=0007667] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2621.742920
[f=0007718] <lolasd> Allies: dont forget aa
[f=0007846] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1772.010742
[f=0007998] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=23727.794922
[f=0008187] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1202.750244
[f=0008362] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3884.858887
[f=0008543] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3070.456055
[f=0008719] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2598.031006
[f=0008897] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3713.031982
[f=0009076] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3407.393555
[f=0009255] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2831.714600
[f=0009435] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2841.279785
[f=0009615] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=6086.928711
[f=0009795] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=5090.200195
[f=0009947] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=34322.722656
[f=0010154] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2527.770996
[f=0010333] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3034.607666
[f=0010510] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=4764.402832
[f=0010690] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2394.539307
[f=0010870] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2191.122803
[f=0011049] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2426.512451
[f=0011123] [Frame Gap Logger] Warning: Frame gap: 108
[f=0011225] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=7420.126465
[f=0011396] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1818.091431
[f=0011470] [Game::ClientReadNet] added new player playerO1 with number 4 to team 0
[f=0011568] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=7384.578125
[f=0011647] > playerO1 has left lobby
[f=0011749] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1362.519287
[f=0011924] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=7104.433105
[f=0012102] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=8521.548828
[f=0012229] [Game::ClientReadNet] added new player Pieger with number 5 to team 0
[f=0012283] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2792.414062
[f=0012463] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=1553.262451
[f=0012626] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=16594.406250
[f=0012731] Connection attempt from Pieger
[f=0012731]  -> Version: 97.0.1-81-g05e4f29 develop
[f=0012731]  -> Connection established (given id 5)
[f=0012804] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=7210.776367
[f=0012987] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2338.541260
[f=0012997] [Frame Gap Logger] Warning: Frame gap: 114
[f=0013164] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=2361.711426
[f=0013320] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=14076.395508
[f=0013488] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=20038.214844
[f=0013641] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=27887.125000
[f=0013810] Spectator cleanrock left the game:  normal quit
[f=0013819] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=13796.576172
[f=0013986] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=17644.742188
[f=0014167] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=3838.201660
[f=0014310] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=28264.707031
[f=0014460] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=41123.398438
[f=0014551] Warning: consumeSpeedMult=178.000000 speedFactor=1.000000 lastNumQueuedSimFrames=150 msgProcTimeLeft=115659.875000
[f=0014720] Warning: consumeSpeedMult=176.996429 speedFactor=0.999873 lastNumQueuedSimFrames=149 msgProcTimeLeft=116343.382812
[f=0015004] Warning: consumeSpeedMult=176.999893 speedFactor=0.999996 lastNumQueuedSimFrames=149 msgProcTimeLeft=6519.476562
[f=0015177] Warning: consumeSpeedMult=176.999985 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=3512.780762
[f=0015335] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=16841.792969
[f=0015522] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=2737.819336
[f=0015701] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=1122.405396
[f=0015871] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=9520.411133
[f=0016053] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=1933.876221
[f=0016099] Connection attempt from cleanrock
[f=0016099]  -> Version: 97.0.1-81-g05e4f29 HEAD
[f=0016099]  -> Connection established (given id 1)
[f=0016231] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=1778.985107
[f=0016406] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=3703.915283
[f=0016587] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=2619.238525
[f=0016700] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=67200.703125
[f=0016805] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=124002.890625
[f=0016923] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=169507.921875
[f=0017048] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=206583.718750
[f=0017153] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=263498.531250
[f=0017274] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=305235.437500
[f=0017340] Warning: consumeSpeedMult=177.000000 speedFactor=1.000000 lastNumQueuedSimFrames=149 msgProcTimeLeft=404387.906250
[f=0017398] Warning: consumeSpeedMult=174.481384 speedFactor=0.981478 lastNumQueuedSimFrames=147 msgProcTimeLeft=519305.562500
[f=0017466] Warning: consumeSpeedMult=154.436722 speedFactor=0.872740 lastNumQueuedSimFrames=130 msgProcTimeLeft=636560.437500
[f=0017532] Warning: consumeSpeedMult=138.933487 speedFactor=0.783339 lastNumQueuedSimFrames=117 msgProcTimeLeft=763130.750000
[f=0017624] Warning: consumeSpeedMult=113.945351 speedFactor=0.640905 lastNumQueuedSimFrames=96 msgProcTimeLeft=873826.812500
[f=0017718] Warning: consumeSpeedMult=125.581253 speedFactor=0.913616 lastNumQueuedSimFrames=100 msgProcTimeLeft=892101.625000
[f=0017812] Warning: consumeSpeedMult=130.790619 speedFactor=0.956808 lastNumQueuedSimFrames=104 msgProcTimeLeft=916241.062500
[f=0017904] Warning: consumeSpeedMult=135.274780 speedFactor=0.974099 lastNumQueuedSimFrames=108 msgProcTimeLeft=943533.125000
[f=0018016] Warning: consumeSpeedMult=139.818695 speedFactor=0.993525 lastNumQueuedSimFrames=112 msgProcTimeLeft=958989.750000
[f=0018092] Warning: consumeSpeedMult=142.909348 speedFactor=0.996762 lastNumQueuedSimFrames=115 msgProcTimeLeft=1008249.750000
[f=0018175] Warning: consumeSpeedMult=145.216324 speedFactor=0.972011 lastNumQueuedSimFrames=118 msgProcTimeLeft=1062151.125000
[f=0018241] Warning: consumeSpeedMult=147.608154 speedFactor=0.986006 lastNumQueuedSimFrames=120 msgProcTimeLeft=1131287.750000
[f=0018328] Warning: consumeSpeedMult=146.782715 speedFactor=0.920811 lastNumQueuedSimFrames=121 msgProcTimeLeft=1190950.875000
[f=0018423] Warning: consumeSpeedMult=149.642151 speedFactor=0.951506 lastNumQueuedSimFrames=123 msgProcTimeLeft=1237040.375000
[f=0018494] Warning: consumeSpeedMult=149.537109 speedFactor=0.912040 lastNumQueuedSimFrames=124 msgProcTimeLeft=1314821.250000
[f=0018553] Warning: consumeSpeedMult=150.087326 speedFactor=0.895975 lastNumQueuedSimFrames=125 msgProcTimeLeft=1408450.750000
[f=0018635] Warning: consumeSpeedMult=140.079895 speedFactor=0.788568 lastNumQueuedSimFrames=118 msgProcTimeLeft=1505551.375000
[f=0018712] Warning: consumeSpeedMult=140.033234 speedFactor=0.786901 lastNumQueuedSimFrames=118 msgProcTimeLeft=1588880.750000
[f=0018794] Warning: consumeSpeedMult=136.545853 speedFactor=0.769495 lastNumQueuedSimFrames=115 msgProcTimeLeft=1678242.500000
[f=0018801] [Frame Gap Logger] Warning: Frame gap: 112
[f=0018859] Warning: consumeSpeedMult=137.202377 speedFactor=0.792943 lastNumQueuedSimFrames=115 msgProcTimeLeft=1774319.500000
[f=0018940] Warning: consumeSpeedMult=124.722008 speedFactor=0.704357 lastNumQueuedSimFrames=105 msgProcTimeLeft=1876630.375000
[f=0019020] Warning: consumeSpeedMult=128.846481 speedFactor=0.815946 lastNumQueuedSimFrames=106 msgProcTimeLeft=1939385.375000
[f=0019104] Warning: consumeSpeedMult=129.098740 speedFactor=0.789241 lastNumQueuedSimFrames=107 msgProcTimeLeft=2005745.125000
[f=0019179] Warning: consumeSpeedMult=133.533951 speedFactor=0.876212 lastNumQueuedSimFrames=109 msgProcTimeLeft=2062598.000000
[f=0019252] Warning: consumeSpeedMult=135.302505 speedFactor=0.867946 lastNumQueuedSimFrames=111 msgProcTimeLeft=2130303.250000
[f=0019346] Warning: consumeSpeedMult=136.389343 speedFactor=0.871048 lastNumQueuedSimFrames=112 msgProcTimeLeft=2179475.750000
[f=0019415] Warning: consumeSpeedMult=139.412674 speedFactor=0.907595 lastNumQueuedSimFrames=114 msgProcTimeLeft=2244707.000000
[f=0019462] Spectator Pieger left the game:  normal quit
[f=0019488] Warning: consumeSpeedMult=138.725769 speedFactor=0.847349 lastNumQueuedSimFrames=115 msgProcTimeLeft=2319330.750000
[f=0019569] > Pieger has left lobby
[f=0019591] Warning: consumeSpeedMult=141.036697 speedFactor=0.894167 lastNumQueuedSimFrames=116 msgProcTimeLeft=2361038.750000
[f=0019681] Warning: consumeSpeedMult=146.259171 speedFactor=0.973542 lastNumQueuedSimFrames=119 msgProcTimeLeft=2399621.750000
[f=0019697] > Pieger has left lobby
[f=0019767] Warning: consumeSpeedMult=148.629593 speedFactor=0.986771 lastNumQueuedSimFrames=121 msgProcTimeLeft=2452494.000000
[f=0019828] Warning: consumeSpeedMult=150.814789 speedFactor=0.993385 lastNumQueuedSimFrames=123 msgProcTimeLeft=2530772.250000
[f=0019918] Warning: consumeSpeedMult=147.629349 speedFactor=0.879620 lastNumQueuedSimFrames=123 msgProcTimeLeft=2598259.000000
[f=0020001] Warning: consumeSpeedMult=122.148865 speedFactor=0.898174 lastNumQueuedSimFrames=97 msgProcTimeLeft=2664624.500000
[f=0020079] cleanrock ENABLE TTS
[f=0020079] Warning: consumeSpeedMult=75.254318 speedFactor=0.937654 lastNumQueuedSimFrames=49 msgProcTimeLeft=2702602.750000
[f=0020157] Warning: consumeSpeedMult=27.021404 speedFactor=0.965050 lastNumQueuedSimFrames=0 msgProcTimeLeft=2681874.500000
[f=0020164] [Frame Gap Logger] Warning: Frame gap: 137
[f=0020169] [Frame Gap Logger] Warning: Frame gap: 144
[f=0020180] [Frame Gap Logger] Warning: Frame gap: 158
[f=0020185] Warning: consumeSpeedMult=27.510702 speedFactor=0.982525 lastNumQueuedSimFrames=0 msgProcTimeLeft=2623778.500000
[f=0020186] [Frame Gap Logger] Warning: Frame gap: 116
[f=0020192] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020198] [Frame Gap Logger] Warning: Frame gap: 109
[f=0020206] [Frame Gap Logger] Warning: Frame gap: 129
[f=0020211] [Frame Gap Logger] Warning: Frame gap: 117
[f=0020216] Warning: consumeSpeedMult=27.510702 speedFactor=0.982525 lastNumQueuedSimFrames=0 msgProcTimeLeft=2566200.250000
[f=0020217] [Frame Gap Logger] Warning: Frame gap: 160
[f=0020229] [Frame Gap Logger] Warning: Frame gap: 121
[f=0020234] [Frame Gap Logger] Warning: Frame gap: 124
[f=0020239] [Frame Gap Logger] Warning: Frame gap: 105
[f=0020243] [Frame Gap Logger] Warning: Frame gap: 111
[f=0020247] Warning: consumeSpeedMult=27.755352 speedFactor=0.991263 lastNumQueuedSimFrames=0 msgProcTimeLeft=2508198.250000
[f=0020248] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020258] [Frame Gap Logger] Warning: Frame gap: 154
[f=0020263] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020267] [Frame Gap Logger] Warning: Frame gap: 117
[f=0020274] [Frame Gap Logger] Warning: Frame gap: 140
[f=0020278] Warning: consumeSpeedMult=27.755352 speedFactor=0.991263 lastNumQueuedSimFrames=0 msgProcTimeLeft=2451310.500000
[f=0020279] [Frame Gap Logger] Warning: Frame gap: 142
[f=0020292] [Frame Gap Logger] Warning: Frame gap: 137
[f=0020301] [Frame Gap Logger] Warning: Frame gap: 113
[f=0020308] Warning: consumeSpeedMult=27.877676 speedFactor=0.995631 lastNumQueuedSimFrames=0 msgProcTimeLeft=2395238.000000
[f=0020309] [Frame Gap Logger] Warning: Frame gap: 145
[f=0020328] [Frame Gap Logger] Warning: Frame gap: 119
[f=0020339] Warning: consumeSpeedMult=27.877676 speedFactor=0.995631 lastNumQueuedSimFrames=0 msgProcTimeLeft=2346836.000000
[f=0020346] [Frame Gap Logger] Warning: Frame gap: 109
[f=0020359] [Frame Gap Logger] Warning: Frame gap: 158
[f=0020366] [Frame Gap Logger] Warning: Frame gap: 127
[f=0020369] Warning: consumeSpeedMult=25.291859 speedFactor=0.903281 lastNumQueuedSimFrames=0 msgProcTimeLeft=2287744.000000
[f=0020375] [Frame Gap Logger] Warning: Frame gap: 169
[f=0020381] [Frame Gap Logger] Warning: Frame gap: 135
[f=0020389] [Frame Gap Logger] Warning: Frame gap: 103
[f=0020400] Warning: consumeSpeedMult=25.291859 speedFactor=0.903281 lastNumQueuedSimFrames=0 msgProcTimeLeft=2229771.750000
[f=0020401] [Frame Gap Logger] Warning: Frame gap: 115
[f=0020406] [Frame Gap Logger] Warning: Frame gap: 134
[f=0020413] [Frame Gap Logger] Warning: Frame gap: 130
[f=0020419] [Frame Gap Logger] Warning: Frame gap: 127
[f=0020423] [Frame Gap Logger] Warning: Frame gap: 120
[f=0020430] Warning: consumeSpeedMult=23.650820 speedFactor=0.844672 lastNumQueuedSimFrames=0 msgProcTimeLeft=2161955.750000
[f=0020431] [Frame Gap Logger] Warning: Frame gap: 124
[f=0020434] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020441] [Frame Gap Logger] Warning: Frame gap: 124
[f=0020447] [Frame Gap Logger] Warning: Frame gap: 136
[f=0020453] [Frame Gap Logger] Warning: Frame gap: 117
[f=0020457] [Frame Gap Logger] Warning: Frame gap: 137
[f=0020462] Warning: consumeSpeedMult=25.288416 speedFactor=0.903158 lastNumQueuedSimFrames=0 msgProcTimeLeft=2095689.125000
[f=0020463] [Frame Gap Logger] Warning: Frame gap: 105
[f=0020470] [Frame Gap Logger] Warning: Frame gap: 165
[f=0020479] [Frame Gap Logger] Warning: Frame gap: 116
[f=0020491] Warning: consumeSpeedMult=25.288416 speedFactor=0.903158 lastNumQueuedSimFrames=0 msgProcTimeLeft=2041787.375000
[f=0020501] [Frame Gap Logger] Warning: Frame gap: 170
[f=0020517] [Frame Gap Logger] Warning: Frame gap: 145
[f=0020521] [Frame Gap Logger] Warning: Frame gap: 121
[f=0020524] Warning: consumeSpeedMult=22.898315 speedFactor=0.817797 lastNumQueuedSimFrames=0 msgProcTimeLeft=1980839.000000
[f=0020525] [Frame Gap Logger] Warning: Frame gap: 122
[f=0020532] [Frame Gap Logger] Warning: Frame gap: 127
[f=0020537] [Frame Gap Logger] Warning: Frame gap: 159
[f=0020541] [Frame Gap Logger] Warning: Frame gap: 102
[f=0020545] [Frame Gap Logger] Warning: Frame gap: 154
[f=0020549] [Frame Gap Logger] Warning: Frame gap: 144
[f=0020554] Warning: consumeSpeedMult=22.898315 speedFactor=0.817797 lastNumQueuedSimFrames=0 msgProcTimeLeft=1909081.875000
[f=0020555] [Frame Gap Logger] Warning: Frame gap: 172
[f=0020563] [Frame Gap Logger] Warning: Frame gap: 125
[f=0020566] [Frame Gap Logger] Warning: Frame gap: 121
[f=0020569] [Frame Gap Logger] Warning: Frame gap: 133
[f=0020575] [Frame Gap Logger] Warning: Frame gap: 129
[f=0020580] [Frame Gap Logger] Warning: Frame gap: 149
[f=0020585] Warning: consumeSpeedMult=21.408478 speedFactor=0.764588 lastNumQueuedSimFrames=0 msgProcTimeLeft=1839235.000000
[f=0020590] [Frame Gap Logger] Warning: Frame gap: 125
[f=0020594] [Frame Gap Logger] Warning: Frame gap: 133
[f=0020598] [Frame Gap Logger] Warning: Frame gap: 110
[f=0020602] [Frame Gap Logger] Warning: Frame gap: 114
[f=0020607] [Frame Gap Logger] Warning: Frame gap: 114
[f=0020613] Warning: consumeSpeedMult=23.856785 speedFactor=0.852028 lastNumQueuedSimFrames=0 msgProcTimeLeft=1776608.625000
[f=0020614] [Frame Gap Logger] Warning: Frame gap: 167
[f=0020620] [Frame Gap Logger] Warning: Frame gap: 107
[f=0020623] [Frame Gap Logger] Warning: Frame gap: 127
[f=0020628] [Frame Gap Logger] Warning: Frame gap: 164
[f=0020633] [Frame Gap Logger] Warning: Frame gap: 138
[f=0020644] Warning: consumeSpeedMult=23.856785 speedFactor=0.852028 lastNumQueuedSimFrames=0 msgProcTimeLeft=1712886.875000
[f=0020645] [Frame Gap Logger] Warning: Frame gap: 172
[f=0020657] [Frame Gap Logger] Warning: Frame gap: 150
[f=0020665] [Frame Gap Logger] Warning: Frame gap: 129
[f=0020671] Warning: consumeSpeedMult=25.870405 speedFactor=0.923943 lastNumQueuedSimFrames=0 msgProcTimeLeft=1649755.000000
[f=0020672] [Frame Gap Logger] Warning: Frame gap: 120
[f=0020677] [Frame Gap Logger] Warning: Frame gap: 156
[f=0020681] [Frame Gap Logger] Warning: Frame gap: 118
[f=0020686] [Frame Gap Logger] Warning: Frame gap: 115
[f=0020690] [Frame Gap Logger] Warning: Frame gap: 145
[f=0020695] [Frame Gap Logger] Warning: Frame gap: 147
[f=0020703] Warning: consumeSpeedMult=25.870405 speedFactor=0.923943 lastNumQueuedSimFrames=0 msgProcTimeLeft=1584377.500000
[f=0020704] [Frame Gap Logger] Warning: Frame gap: 131
[f=0020710] [Frame Gap Logger] Warning: Frame gap: 106
[f=0020712] [Frame Gap Logger] Warning: Frame gap: 145
[f=0020720] [Frame Gap Logger] Warning: Frame gap: 128
[f=0020724] [Frame Gap Logger] Warning: Frame gap: 150
[f=0020729] [Frame Gap Logger] Warning: Frame gap: 112
[f=0020733] Warning: consumeSpeedMult=26.935204 speedFactor=0.961972 lastNumQueuedSimFrames=0 msgProcTimeLeft=1524651.000000
[f=0020737] [Frame Gap Logger] Warning: Frame gap: 114
[f=0020743] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020749] [Frame Gap Logger] Warning: Frame gap: 112
[f=0020753] [Frame Gap Logger] Warning: Frame gap: 110
[f=0020758] [Frame Gap Logger] Warning: Frame gap: 141
[f=0020761] Warning: consumeSpeedMult=26.935204 speedFactor=0.961972 lastNumQueuedSimFrames=0 msgProcTimeLeft=1468766.625000
[f=0020768] [Frame Gap Logger] Warning: Frame gap: 108
[f=0020777] [Frame Gap Logger] Warning: Frame gap: 146
[f=0020789] [Frame Gap Logger] Warning: Frame gap: 160
[f=0020791] Warning: consumeSpeedMult=27.467602 speedFactor=0.980986 lastNumQueuedSimFrames=0 msgProcTimeLeft=1411849.500000
[f=0020802] [Frame Gap Logger] Warning: Frame gap: 154
[f=0020807] [Frame Gap Logger] Warning: Frame gap: 123
[f=0020817] [Frame Gap Logger] Warning: Frame gap: 146
[f=0020824] Warning: consumeSpeedMult=27.467602 speedFactor=0.980986 lastNumQueuedSimFrames=0 msgProcTimeLeft=1358018.875000
[f=0020826] [Frame Gap Logger] Warning: Frame gap: 144
[f=0020836] [Frame Gap Logger] Warning: Frame gap: 134
[f=0020846] [Frame Gap Logger] Warning: Frame gap: 109
[f=0020849] [Frame Gap Logger] Warning: Frame gap: 106
[f=0020853] Warning: consumeSpeedMult=25.832977 speedFactor=0.922606 lastNumQueuedSimFrames=0 msgProcTimeLeft=1302217.125000
[f=0020854] [Frame Gap Logger] Warning: Frame gap: 120
[f=0020872] [Frame Gap Logger] Warning: Frame gap: 150
[f=0020881] [Frame Gap Logger] Warning: Frame gap: 106
[f=0020886] Warning: consumeSpeedMult=25.832977 speedFactor=0.922606 lastNumQueuedSimFrames=0 msgProcTimeLeft=1245457.875000
[f=0020887] [Frame Gap Logger] Warning: Frame gap: 126
[f=0020895] [Frame Gap Logger] Warning: Frame gap: 126
[f=0020898] [Frame Gap Logger] Warning: Frame gap: 109
[f=0020902] [Frame Gap Logger] Warning: Frame gap: 138
[f=0020908] [Frame Gap Logger] Warning: Frame gap: 137
[f=0020916] Warning: consumeSpeedMult=22.924717 speedFactor=0.818740 lastNumQueuedSimFrames=0 msgProcTimeLeft=1183434.375000
[f=0020917] [Frame Gap Logger] Warning: Frame gap: 154
[f=0020924] [Frame Gap Logger] Warning: Frame gap: 124
[f=0020929] [Frame Gap Logger] Warning: Frame gap: 140
[f=0020933] [Frame Gap Logger] Warning: Frame gap: 136
[f=0020940] [Frame Gap Logger] Warning: Frame gap: 176
[f=0020948] Warning: consumeSpeedMult=21.570011 speedFactor=0.770357 lastNumQueuedSimFrames=0 msgProcTimeLeft=1114261.375000
[f=0020949] [Frame Gap Logger] Warning: Frame gap: 160
[f=0020956] [Frame Gap Logger] Warning: Frame gap: 125
[f=0020963] [Frame Gap Logger] Warning: Frame gap: 124
[f=0020970] [Frame Gap Logger] Warning: Frame gap: 126
[f=0020973] [Frame Gap Logger] Warning: Frame gap: 143
[f=0020977] Warning: consumeSpeedMult=21.570011 speedFactor=0.770357 lastNumQueuedSimFrames=0 msgProcTimeLeft=1049331.750000
[f=0020978] [Frame Gap Logger] Warning: Frame gap: 139
[f=0020982] [Frame Gap Logger] Warning: Frame gap: 147
[f=0020988] [Frame Gap Logger] Warning: Frame gap: 174
[f=0020992] [Frame Gap Logger] Warning: Frame gap: 131
[f=0020995] [Frame Gap Logger] Warning: Frame gap: 133
[f=0020999] [Frame Gap Logger] Warning: Frame gap: 101
[f=0021004] [Frame Gap Logger] Warning: Frame gap: 129
[f=0021008] Warning: consumeSpeedMult=20.134544 speedFactor=0.719091 lastNumQueuedSimFrames=0 msgProcTimeLeft=970553.500000
[f=0021009] [Frame Gap Logger] Warning: Frame gap: 188
[f=0021013] [Frame Gap Logger] Warning: Frame gap: 154
[f=0021017] [Frame Gap Logger] Warning: Frame gap: 129
[f=0021022] [Frame Gap Logger] Warning: Frame gap: 125
[f=0021024] [Frame Gap Logger] Warning: Frame gap: 102
[f=0021030] [Frame Gap Logger] Warning: Frame gap: 146
[f=0021037] Warning: consumeSpeedMult=23.229805 speedFactor=0.829636 lastNumQueuedSimFrames=0 msgProcTimeLeft=901106.187500
[f=0021042] [Frame Gap Logger] Warning: Frame gap: 120
[f=0021051] [Frame Gap Logger] Warning: Frame gap: 170
[f=0021057] [Frame Gap Logger] Warning: Frame gap: 143
[f=0021068] Warning: consumeSpeedMult=23.229805 speedFactor=0.829636 lastNumQueuedSimFrames=0 msgProcTimeLeft=836244.812500
[f=0021069] [Frame Gap Logger] Warning: Frame gap: 124
[f=0021072] [Frame Gap Logger] Warning: Frame gap: 115
[f=0021076] [Frame Gap Logger] Warning: Frame gap: 130
[f=0021084] [Frame Gap Logger] Warning: Frame gap: 165
[f=0021089] [Frame Gap Logger] Warning: Frame gap: 125
[f=0021093] [Frame Gap Logger] Warning: Frame gap: 149
[f=0021096] Warning: consumeSpeedMult=22.399868 speedFactor=0.799995 lastNumQueuedSimFrames=0 msgProcTimeLeft=773492.500000
[f=0021103] [Frame Gap Logger] Warning: Frame gap: 127
[f=0021108] [Frame Gap Logger] Warning: Frame gap: 167
[f=0021115] [Frame Gap Logger] Warning: Frame gap: 150
[f=0021128] Warning: consumeSpeedMult=23.100594 speedFactor=0.825021 lastNumQueuedSimFrames=0 msgProcTimeLeft=709298.562500
[f=0021131] [Frame Gap Logger] Warning: Frame gap: 166
[f=0021145] [Frame Gap Logger] Warning: Frame gap: 153
[f=0021150] [Frame Gap Logger] Warning: Frame gap: 117
[f=0021156] [Frame Gap Logger] Warning: Frame gap: 101
[f=0021159] Warning: consumeSpeedMult=23.100594 speedFactor=0.825021 lastNumQueuedSimFrames=0 msgProcTimeLeft=653672.625000
[f=0021160] [Frame Gap Logger] Warning: Frame gap: 126
[f=0021165] [Frame Gap Logger] Warning: Frame gap: 106
[f=0021178] [Frame Gap Logger] Warning: Frame gap: 135
[f=0021186] [Frame Gap Logger] Warning: Frame gap: 152
[f=0021191] Warning: consumeSpeedMult=21.529823 speedFactor=0.768922 lastNumQueuedSimFrames=0 msgProcTimeLeft=602921.562500
[f=0021192] [Frame Gap Logger] Warning: Frame gap: 134
[f=0021206] [Frame Gap Logger] Warning: Frame gap: 168
[f=0021212] [Frame Gap Logger] Warning: Frame gap: 126
[f=0021218] [Frame Gap Logger] Warning: Frame gap: 137
[f=0021223] Warning: consumeSpeedMult=19.503628 speedFactor=0.696558 lastNumQueuedSimFrames=0 msgProcTimeLeft=534876.125000
[f=0021224] [Frame Gap Logger] Warning: Frame gap: 153
[f=0021228] [Frame Gap Logger] Warning: Frame gap: 110
[f=0021230] [Frame Gap Logger] Warning: Frame gap: 108
[f=0021237] [Frame Gap Logger] Warning: Frame gap: 114
[f=0021240] [Frame Gap Logger] Warning: Frame gap: 124
[f=0021250] [Frame Gap Logger] Warning: Frame gap: 136
[f=0021253] Warning: consumeSpeedMult=19.503628 speedFactor=0.696558 lastNumQueuedSimFrames=0 msgProcTimeLeft=467145.812500
[f=0021254] [Frame Gap Logger] Warning: Frame gap: 107
[f=0021257] [Frame Gap Logger] Warning: Frame gap: 133
[f=0021261] [Frame Gap Logger] Warning: Frame gap: 145
[f=0021268] [Frame Gap Logger] Warning: Frame gap: 166
[f=0021272] [Frame Gap Logger] Warning: Frame gap: 169
[f=0021282] [Frame Gap Logger] Warning: Frame gap: 116
[f=0021284] Warning: consumeSpeedMult=19.165298 speedFactor=0.684475 lastNumQueuedSimFrames=0 msgProcTimeLeft=388793.843750
[f=0021285] [Frame Gap Logger] Warning: Frame gap: 171
[f=0021288] [Frame Gap Logger] Warning: Frame gap: 107
[f=0021291] [Frame Gap Logger] Warning: Frame gap: 130
[f=0021295] [Frame Gap Logger] Warning: Frame gap: 124
[f=0021299] [Frame Gap Logger] Warning: Frame gap: 133
[f=0021307] [Frame Gap Logger] Warning: Frame gap: 168
[f=0021313] [Frame Gap Logger] Warning: Frame gap: 101
[f=0021316] Warning: consumeSpeedMult=17.847366 speedFactor=0.637406 lastNumQueuedSimFrames=0 msgProcTimeLeft=302133.718750
[f=0021317] [Frame Gap Logger] Warning: Frame gap: 167
[f=0021323] [Frame Gap Logger] Warning: Frame gap: 155
[f=0021327] [Frame Gap Logger] Warning: Frame gap: 113
[f=0021329] [Frame Gap Logger] Warning: Frame gap: 102
[f=0021333] [Frame Gap Logger] Warning: Frame gap: 167
[f=0021339] [Frame Gap Logger] Warning: Frame gap: 178
[f=0021342] [Frame Gap Logger] Warning: Frame gap: 120
[f=0021345] Warning: consumeSpeedMult=19.845768 speedFactor=0.708777 lastNumQueuedSimFrames=0 msgProcTimeLeft=220899.625000
[f=0021347] [Frame Gap Logger] Warning: Frame gap: 114
[f=0021349] [Frame Gap Logger] Warning: Frame gap: 156
[f=0021356] [Frame Gap Logger] Warning: Frame gap: 145
[f=0021367] [Frame Gap Logger] Warning: Frame gap: 131
[f=0021371] [Frame Gap Logger] Warning: Frame gap: 164
[f=0021374] Warning: consumeSpeedMult=19.845768 speedFactor=0.708777 lastNumQueuedSimFrames=0 msgProcTimeLeft=148077.328125
[f=0021379] [Frame Gap Logger] Warning: Frame gap: 139
[f=0021385] [Frame Gap Logger] Warning: Frame gap: 111
[f=0021388] [Frame Gap Logger] Warning: Frame gap: 130
[f=0021391] [Frame Gap Logger] Warning: Frame gap: 127
[f=0021396] [Frame Gap Logger] Warning: Frame gap: 135
[f=0021401] [Frame Gap Logger] Warning: Frame gap: 144
[f=0021404] Warning: consumeSpeedMult=18.648350 speedFactor=0.666013 lastNumQueuedSimFrames=0 msgProcTimeLeft=75995.968750
[f=0021405] [Frame Gap Logger] Warning: Frame gap: 140
[f=0021408] [Frame Gap Logger] Warning: Frame gap: 115
[f=0021411] [Frame Gap Logger] Warning: Frame gap: 126
[f=0021414] [Frame Gap Logger] Warning: Frame gap: 108
[f=0021419] [Frame Gap Logger] Warning: Frame gap: 144
[f=0021424] [Frame Gap Logger] Warning: Frame gap: 116
[f=0021429] [Frame Gap Logger] Warning: Frame gap: 177
[f=0021435] Warning: consumeSpeedMult=18.987953 speedFactor=0.678141 lastNumQueuedSimFrames=0 msgProcTimeLeft=3610.332275
[f=0021436] [Frame Gap Logger] Warning: Frame gap: 175
[f=0021462] Warning: consumeSpeedMult=18.987953 speedFactor=0.678141 lastNumQueuedSimFrames=0 msgProcTimeLeft=-160.835876
[f=0021491] Warning: consumeSpeedMult=18.351421 speedFactor=0.655408 lastNumQueuedSimFrames=0 msgProcTimeLeft=-4.079819
[f=0021514] Warning: consumeSpeedMult=23.175713 speedFactor=0.827704 lastNumQueuedSimFrames=0 msgProcTimeLeft=-331.424805
[f=0021540] [Frame Gap Logger] Warning: Frame gap: 103
[f=0021542] Warning: consumeSpeedMult=24.175713 speedFactor=0.827704 lastNumQueuedSimFrames=1 msgProcTimeLeft=499.144958
[f=0021569] Warning: consumeSpeedMult=27.587856 speedFactor=0.913852 lastNumQueuedSimFrames=2 msgProcTimeLeft=445.345276
[f=0021600] Warning: consumeSpeedMult=28.587856 speedFactor=0.913852 lastNumQueuedSimFrames=3 msgProcTimeLeft=-39.648438
[f=0021634] Warning: consumeSpeedMult=26.438105 speedFactor=0.837075 lastNumQueuedSimFrames=3 msgProcTimeLeft=749.434021
[f=0021671] Warning: consumeSpeedMult=23.437172 speedFactor=0.729899 lastNumQueuedSimFrames=3 msgProcTimeLeft=191.258240
[f=0021704] Warning: consumeSpeedMult=23.437172 speedFactor=0.729899 lastNumQueuedSimFrames=3 msgProcTimeLeft=-27.775146
[f=0021732] [Frame Gap Logger] Warning: Frame gap: 169
[f=0021735] [Frame Gap Logger] Warning: Frame gap: 109
[f=0021736] Warning: consumeSpeedMult=20.382963 speedFactor=0.656534 lastNumQueuedSimFrames=2 msgProcTimeLeft=786.630920
[f=0021746] [Frame Gap Logger] Warning: Frame gap: 124
[f=0021759] [Frame Gap Logger] Warning: Frame gap: 129
[f=0021761] [Frame Gap Logger] Warning: Frame gap: 123
[f=0021768] Warning: consumeSpeedMult=17.604887 speedFactor=0.593032 lastNumQueuedSimFrames=1 msgProcTimeLeft=629.598755
[f=0021773] [SpringApp::ShutDown][1]
[f=0021773] [ThreadPool::SetThreadCount][1] #wanted=0 #current=4
[f=0021773] [ThreadPool::SetThreadCount][2] #threads=0
[f=0021773] [SpringApp::ShutDown][2]
[f=0021773] [~CGame][1]
[f=0021773] [~CGame][2]
[f=0021773] [~CGame][3]
[f=0021773] Start gadgetHandler:Shutdown
[f=0021773] Shutdown - ranks api
[f=0021773] Shutdown - ShareControl
[f=0021773] Shutdown - UnitMorph
[f=0021773] Shutdown - DoLine
[f=0021773] Shutdown - LupsNanoSpray
[f=0021773] Shutdown - Puppy Handler
[f=0021773] Shutdown - Terrain Texture Handler
[f=0021773] Shutdown - UnitCloakShield
[f=0021773] End gadgetHandler:Shutdown
[f=0021773] Start gadgetHandler:Shutdown
[f=0021773] Shutdown - Ore mexes!
[f=0021773] Shutdown - UnitMorph
[f=0021773] Shutdown - Animator
[f=0021773] Shutdown - DoLine
[f=0021773] Shutdown - UnitCloakShield
[f=0021773] Shutdown - Lups Cloak FX
[f=0021773] Shutdown - Lups
[f=0021773] End gadgetHandler:Shutdown
[f=0021773] [~CGame][4]
[f=0021773] [~CGame][5]
[f=0021773] [~CGame][6]
[f=0021773] Statistics for RectangleOptimizer: 27%
[f=0021773] Start widgetHandler:Shutdown
[f=0021773] Shutdown - SaveOrderList Complete
[f=0021773] Shutdown - SaveConfigData Complete
[f=0021773] Shutdown Widget - EPIC Menu
[f=0021773] Shutdown Widget - Chili Minimap
[f=0021773] Shutdown Widget - Chili Widget Selector
[f=0021773] Shutdown Widget - Local Team Colors
[f=0021773] Shutdown Widget - HealthBars
[f=0021773] Shutdown Widget - Noises
[f=0021773] Shutdown Widget - Unit Icons
[f=0021773] Shutdown Widget - Team stats
[f=0021773] Shutdown Widget - Chili Chicken Panel
[f=0021773] Shutdown Widget - CameraShake
[f=0021773] Shutdown Widget - Chili Selections & CursorTip
[f=0021773] Shutdown Widget - Context Menu
[f=0021773] Shutdown Widget - Darkening
[f=0021773] Shutdown Widget - Local Widgets Config
[f=0021773] Shutdown Widget - Highlight Geos
[f=0021773] Shutdown Widget - Mex Placement Handler
[f=0021773] Shutdown Widget - MinimapEvents
[f=0021773] Shutdown Widget - Stereo3D
[f=0021773] Shutdown Widget - Chili EndGame Window
[f=0021773] Shutdown Widget - Chili Resource Bars
[f=0021773] Shutdown Widget - Attack AoE
[f=0021773] Shutdown Widget - MessageBoxes
[f=0021773] Shutdown Widget - UnitShapes
[f=0021773] Shutdown Widget - Rank Icons 2
[f=0021773] Shutdown Widget - Selection Send
[f=0021773] Shutdown Widget - Units on Fire
[f=0021773] Shutdown Widget - Chili Chat 2.1
[f=0021773] Shutdown Widget - Chili Deluxe Player List - Alpha 2.02
[f=0021773] Shutdown Widget - Chili Framework
[f=0021773] Shutdown Widget - Chili Core Selector
[f=0021773] Shutdown Widget - Chili Gesture Menu
[f=0021773] Shutdown Widget - Text To Speech Control
[f=0021773] cleanrock DISABLE TTS
[f=0021773] Shutdown Widget - Chili Integral Menu
[f=0021773] Shutdown Widget - Lasso Terraform GUI
[f=0021773] End widgetHandler:Shutdown
[f=0021773] [~CGame][7]
[f=0021773] [~CGame][8]
[f=0021773] [CCollisionHandler] dis-/continuous tests: 55/1759084
[f=0021773] [~CGame][9]
[f=0021773] [~CGame][10]
[f=0021773] [~CPathCache(52x8)] cacheHits=0 hitPercentage=0% numHashColls=0 maxCacheSize=0
[f=0021773] [~CPathCache(52x8)] cacheHits=13092 hitPercentage=31% numHashColls=0 maxCacheSize=74
[f=0021773] [~CPathCache(208x32)] cacheHits=0 hitPercentage=0% numHashColls=0 maxCacheSize=0
[f=0021773] [~CPathCache(208x32)] cacheHits=14159 hitPercentage=19% numHashColls=0 maxCacheSize=201
[f=0021773] Statistics for RectangleOptimizer: 27%
[f=0021773] Statistics for RectangleOptimizer: 27%
[f=0021773] [~CGame][11]
[f=0021773] [~CGame][12]
[f=0021773] [~CGame][13]
[f=0021773] [~CGame][14]
[f=0021773] [~CGame][15]
[f=0021773] [~CGame][16]
[f=0021773] [~CGame][17]
[f=0021773] [SpringApp::ShutDown][3]
[f=0021773] Statistics for UDP connection:
Received: 268865 bytes in 2525 packets (106.481 bytes/package)
Sent: 267903 bytes in 3413 packets (78.4949 bytes/package)
Relative protocol overhead: 0 up, 0.056348 down
0 incoming chunks dropped, 0 outgoing chunks resent

[f=0021773] Writing demo: /home/johanr/.config/spring/demos/20140623_175400_SpeedMetal_97.0.1-81-g05e4f29 HEAD.sdf
[f=0021773] [SpringApp::ShutDown][4]
[f=0021773] [SpringApp::ShutDown][5]
[f=0021773] [SpringApp::ShutDown][6]
[f=0021773] [SpringApp::ShutDown][7]
[LuaSocket] Dumping luasocket rules:
[LuaSocket] TCP_CONNECT ALLOW * -1
[LuaSocket] TCP_LISTEN  ALLOW * -1
[LuaSocket] UDP_CONNECT DENY  94.23.171.72 8681
[LuaSocket] UDP_LISTEN  ALLOW * -1
[SpringApp::ShutDown][8]
[WatchDog::Uninstall][1] hangDetectorThread=0x2cac880
[WatchDog::Uninstall][2]
[WatchDog::Uninstall][3]
[SpringApp::ShutDown][9]
[SpringApp::Run] exitCode=0
    txt file icon infolog_traces.txt (64,326 bytes) 2014-06-23 18:03 +

-Relationships
+Relationships

-Notes

~0013242

Anarchid (reporter)

2014-06-09 20:17

 It seems i can't modify the report, but engine version mentioned is not perfectly correct, game is on 97.0.1-18-gf1dd749.

~0013243

Anarchid (reporter)

2014-06-09 21:03

 Update - does not occur only on linux.

~0013244

Anarchid (reporter)

2014-06-09 21:14

 Another update - also happens for catch-up without rejoining.

~0013245

Anarchid (reporter)

2014-06-10 00:19

 Additionally, it seems that alternating /fullscreen seems to occasionally restore the normal animation behavior.

~0013246

Kloot (developer)

2014-06-10 02:19

Last edited: 2014-06-10 02:19

View 2 revisions

 Since piece animations are uninterpolated, the only? explanation for this would be a non-steady supply of simframes.

If you log the time in millisecs between consecutive frames after rejoining (over a period of 10 seconds or so), what sort of values do you see?

~0013249

Google_Frog (reporter)

2014-06-10 12:09

 I have added a widget to log frame gaps. https://zero-k.googlecode.com/svn/trunk/mods/zk/LuaUI/Widgets/dbg_frame_gap_logger.lua

~0013254

Anarchid (reporter)

2014-06-10 13:04

 infolog with above widget from a rejoining player:
http://pastebin.com/cZZbi63Q

Rejoin is finished at line 1112 [f=0030899] Sortale ENABLE TTS, magnitude of gaps seems to remain as it was during fast-forward.

The widget doesn't seem to log non-gappy frames.

~0013255

Google_Frog (reporter)

2014-06-10 13:43

 It only mentions frame gaps of 100ms or more. Every frame not mentioned is a non-gappy frame.

~0013256

Kloot (developer)

2014-06-10 14:36

Last edited: 2014-06-10 14:40

View 2 revisions

 "magnitude of gaps seems to remain as it was during fast-forward"

That's in line with what I expected.

It means the client catches up too close to the server (even though I added code to prevent this when fixing 3845 / 4171) and doesn't leave enough buffer room to smoothen out network bumps.

~0013269

The_Yak (reporter)

2014-06-11 21:42

 I can reproduce this consistently on ZK and latest engine builds. Is more information required?

~0013271

Kloot (developer)

2014-06-12 02:12

 no, just more time

~0013283

cleanrock (reporter)

2014-06-15 09:17

 Perhaps caused by change to
const unsigned int numQueuedFrames = GetNumQueuedSimFrameMessages(-1u);
which cause lastNumQueuedSimFrames to get much bigger now and since it is only reduced every second will make consumeSpeedMult high for a long time:
lastNumQueuedSimFrames = mix(lastNumQueuedSimFrames * 1.0f, numQueuedFrames * 1.0f, 0.1f);
consumeSpeedMult = GAME_SPEED * gs->speedFactor + lastNumQueuedSimFrames - (2 * gs->speedFactor);

~0013326

cleanrock (reporter)

2014-06-23 18:01

Last edited: 2014-06-23 18:05

View 3 revisions

 I investigated more and this unit jitter can still happen.
msgProcTimeLeft goes very high when GetNumQueuedSimFrameMessages(-1u) is used and decrease very slow when catched up.
https://github.com/spring/spring/commit/05e4f29 seem to reduce risk of msgProcTimeLeft going insane but i think we need to fix this better.
Attached a log with some extra debug traces, catch up happens around line 500.
Also, using UseNetMessageSmoothingBuffer=0 is bad atm, u will most probably get unit jitter after catching up.

~0013340

silentwings (reporter)

2014-06-24 00:35

Last edited: 2014-06-29 13:56

View 5 revisions

 Unit movement, just in a single player game of BA 8.00, after doing /give all and giving all a single move command, is VERY (i.e. unplayably) jerky for me in 97.0.1-23, also -75 and -94, which is all I've tested so far.

97.0.1-20 is smooth for me, just as 96.0 is.

cleanrock suggested changing WTC (-1 or 0) and WTST values (0 or 5) but this seems to have no effect.

Let me know if you can't reproduce this.

~0013369

cleanrock (reporter)

2014-06-27 12:09

 Please test 97.0.1-125-ga0ba15f to see if unit jitter is fixed in multi-player games.
To test locally you can launch a AIvsAI game and connect with an local spec client:
BypassScriptPasswordCheck = 1
spring(.exe) spring://spec1@localhost
(use spec2 if you want to reconnect your spec client)

It will most probably not fix single player jitter since it uses its own net reading strategy.
+Notes

-Issue History
Date Modified Username Field Change
2014-06-09 20:14 Anarchid New Issue
2014-06-09 20:17 Anarchid Note Added: 0013242
2014-06-09 21:03 Anarchid Note Added: 0013243
2014-06-09 21:14 Anarchid Note Added: 0013244
2014-06-10 00:19 Anarchid Note Added: 0013245
2014-06-10 02:19 Kloot Note Added: 0013246
2014-06-10 02:19 Kloot Note Edited: 0013246 View Revisions
2014-06-10 12:09 Google_Frog Note Added: 0013249
2014-06-10 13:04 Anarchid Note Added: 0013254
2014-06-10 13:43 Google_Frog Note Added: 0013255
2014-06-10 14:36 Kloot Note Added: 0013256
2014-06-10 14:40 Kloot Note Edited: 0013256 View Revisions
2014-06-11 21:42 The_Yak Note Added: 0013269
2014-06-12 02:08 abma Target Version => 98.0
2014-06-12 02:12 Kloot Note Added: 0013271
2014-06-15 09:17 cleanrock Note Added: 0013283
2014-06-22 13:47 cleanrock Changeset attached => spring develop 05e4f29f
2014-06-22 13:47 cleanrock Assigned To => cleanrock
2014-06-22 13:47 cleanrock Status new => resolved
2014-06-22 13:47 cleanrock Resolution open => fixed
2014-06-23 18:01 cleanrock Assigned To cleanrock =>
2014-06-23 18:01 cleanrock Note Added: 0013326
2014-06-23 18:01 cleanrock Status resolved => feedback
2014-06-23 18:01 cleanrock Resolution fixed => reopened
2014-06-23 18:01 cleanrock Status feedback => new
2014-06-23 18:03 cleanrock File Added: infolog_traces.txt
2014-06-23 18:04 cleanrock Note Edited: 0013326 View Revisions
2014-06-23 18:05 cleanrock Note Edited: 0013326 View Revisions
2014-06-24 00:35 silentwings Note Added: 0013340
2014-06-24 00:36 silentwings Note Edited: 0013340 View Revisions
2014-06-24 01:42 silentwings Note Edited: 0013340 View Revisions
2014-06-24 01:45 silentwings Note Edited: 0013340 View Revisions
2014-06-27 12:09 cleanrock Note Added: 0013369
2014-06-29 13:56 silentwings Note Edited: 0013340 View Revisions
2014-06-30 13:39 cleanrock Changeset attached => spring develop 73f1b825
2014-06-30 13:39 cleanrock Assigned To => cleanrock
2014-06-30 13:39 cleanrock Status new => resolved
+Issue History