Using the Client Log File
From Multiverse
| Using the Multiverse Client |
|
Install & Run • Supported Graphics Cards • Release Notes • Client FAQ • Troubleshooting • Connecting to a World • Client Metering • Using the Client Log File • Debugging Client Errors |
| Reference |
|
Command Line Syntax • World Settings File • Patcher Page Reference • Client Logging |
The Multiverse client creates a detailed log file that can help with debugging client problems. It contains a wealth of data on what the client has done, and what errors or problems it has encountered. For general information on the Client logging system, see Client Logging.
Contents |
The log file
The Client log files are plain text files saved to the user's "My Documents" folder, generally C:\Documents and Settings\username\My Documents\Multiverse World Browser on Windows XP and C:\Users\username\Documents\Multiverse World Browser on Windows Vista. The full log file is MultiverseClient.log; it can be quite large, with potentially thousands of lines.
By default, the Client also creates several other log files that are subsets of this file; see Client Logging for details.
Format
The format of most of the lines is consistent, for example:
INFO [2007-12-18 17:13:12,391] Axiom Total System Memory Size: 1022MB ... DEBUG [2007-12-18 17:14:38,563] MessageDispatcher Handling message: NewObject ...
Each line provides this information (from left to right):
- Log level of the item
- Timestamp
- Module providing the information
- The log information
Error stack traces
When the Client encounters an error, it provides a full stack trace; for example:
ERROR [2007-12-18 17:14:42,094] Exception System.Threading.ThreadStateException: ActiveX control '8856f961-340a-11d0-a96b-00c04fd705a2' cannot be instantiated because the current thread is not in a single-threaded apartment. at System.Windows.Forms.WebBrowserBase..ctor(String clsidString) at System.Windows.Forms.WebBrowser..ctor() at Multiverse.Movie.Codecs.Browser.CreateBrowser() at Multiverse.Movie.Codecs.Browser..ctor() at Multiverse.Movie.Codecs.BrowserMovie.Initialize(String n, String p, String t) at Multiverse.Movie.Codecs.BrowserCodec.DoMovieLoad(String name, String url, String textureName) at Multiverse.Movie.Codecs.BrowserCodec.LoadFile(String name, String file, String textureName) at Multiverse.Movie.D3DMovieTexture.Load() at Axiom.Core.TextureManager.Load(String name, TextureType type, Int32 numMipMaps, Single gamma, Boolean isAlpha) at Axiom.Core.TextureManager.Load(String name, TextureType type) at Axiom.Graphics.TextureUnitState.Load()
Structure of the log file
The trace file provides a detailed record of all the actions the client performs as it starts up. Since the client starts up with the same sequence of steps each time, you can learn to read the log file and see how far the client has gone before it encounters an error. For example, if the server you are connecting to is not running or is somehow unreachable, you will see an error early on when the client tries to first connect.
What follows is a general breakdown of a typical log file, showing the steps the client takes as it starts up. For each of these steps, an excerpt from a log file is shown for reference. Once you understand the different parts of the log file, it will be easier for you to analyze how far the client has proceeded, and help you find out where error messages may occur.
At the beginning of the log file is information as the client starts up and loads various libraries and modules into memory...
Initialization
The beginning of the log file provides basic information on the Client environment, such as command-line arguments, version number, and operating system version.
INFO [2007-12-18 17:13:05,641] MultiverseClient Client command line arguments: --development INFO [2007-12-18 17:13:05,672] MultiverseClient Checking if restart required INFO [2007-12-18 17:13:05,750] MultiverseClient Client version up to date: 1.1.2894.20955 INFO [2007-12-18 17:13:05,782] Client Starting up client; client version number is 1.1.2894.20948 INFO [2007-12-18 17:13:05,813] Axiom *********Axiom 3D Engine Log ************* Copyright Copyright Š Axiom and RealmForge Development Team 2003-2005 Version: 0.7.0.20931 Operating System: Microsoft Windows NT 5.1.2600 Service Pack 2 .Net Framework: 2.0.50727.832 INFO [2007-12-18 17:13:05,813] Axiom *-*-* Axiom Intializing ...
Master server connection
Next, if connecting to an online server, the client connects to the Multiverse master server. If for some reason your machine has no Internet connection, you will see an error at this point as the master server will be unreachable.
INFO [2008-01-02 16:14:57,359] Network Information Connecting to master tcp server INFO [2008-01-02 16:14:57,359] NetworkHelper IP Address for master.kothuria.com: '64.13.140.178' INFO [2008-01-02 16:14:57,359] Network Information Connecting to login server at 64.13.140.178:9005 INFO [2008-01-02 16:14:57,375] Network Information Login Result: System.Byte[], Success INFO [2008-01-02 16:14:57,375] LoginHelper Login return: Success INFO [2008-01-02 16:14:57,375] Network Information Connecting to master rdp server INFO [2008-01-02 16:14:57,375] Network Information Connecting to rdp world server at master.kothuria.com:9010 INFO [2008-01-02 16:14:57,375] NetworkHelper IP Address for master.kothuria.com: '64.13.140.178' INFO [2008-01-02 16:14:57,390] RdpMessageHandler Setting up RdpClient with localPort = 5310 INFO [2008-01-02 16:14:57,406] Rdp Connection Created connection to: 64.13.140.178:9010 DEBUG [2008-01-02 16:14:57,422] RdpConnection OnSegmentArrival: 01/02/2008 16:14:57 - packet True:True:False:False:False - 9 datalen: 0 seq: 1 ack: 0 500:4000:True INFO [2008-01-02 16:14:57,422] Network Information Sending world resolve message DEBUG [2008-01-02 16:14:57,422] RdpConnection SendPacket: 01/02/2008 16:14:57 - packet False:True:False:False:False - 6 datalen: 12 seq: 1 ack: 1 DEBUG [2008-01-02 16:14:57,437] RdpConnection OnSegmentArrival: 01/02/2008 16:14:57 - packet False:True:False:False:False - 6 datalen: 0 seq: 2 ack: 1 DEBUG [2008-01-02 16:14:57,437] RdpConnection OnSegmentArrival: 01/02/2008 16:14:57 - packet False:True:False:False:False - 6 datalen: 129 seq: 2 ack: 1 DEBUG [2008-01-02 16:14:57,453] RdpConnection Queued packet 2 : 2 DEBUG [2008-01-02 16:14:57,453] RdpConnection Receive called for packet 2 INFO [2008-01-02 16:14:57,531] Network Information Found entry for world 'foo' INFO [2008-01-02 16:14:57,531] Network Information World resolve message status: Success INFO [2008-01-02 16:14:57,531] Network Information WorldServerEntry: WorldName: foo Hostname: foo.multiverse.net Port: 5040 PatcherUrl: http://update.multiverse.net/foo/patcher.html UpdateUrl: http://update.multiverse.net/foo/ ...
Asset download
Once the client has information on the world to be loaded, it creates an asset repository folder for the game if none exists, then downloads any updated assets or assets it does not have. If the asset repository URL is incorrect or not accessible, then you may see an error at this point. Note that if you start the client while another copy of the client is already running, you may get a file access error at this point.
When it downloads assets from an asset repository, the Client creates the media_patcher.log file containing a log of files it downloads. For example:
Updating Media ... State Changed: UpdatingFiles Removed file: Textures/nyts_paramount_diffuse.dds Removed file: Skeletons/rocketbox_m_mediumpoly.skeleton Downloading File: Textures/loadscreen.dds ... Downloaded File: Textures/loadscreen.dds (524416/524416 bytes) Modified file: Textures/loadscreen.dds ...
The Client will not create this file if it is using a local asset repository.
Rendering enginer setup
After assets are confirmed to be up to date, the client begins setting up the rendering engine...
[10/14/07 10:17:20.468] MultiverseClient.exe Information: 0 : Device constructed with presentation parameters: MultiSampleQuality: 0 PresentationInterval: Immediate FullScreenRefreshRateInHz: 0 PresentFlag: None AutoDepthStencilFormat: D24S8 EnableAutoDepthStencil: True Windowed: True ...
more libraries are loaded...
[10/14/07 10:17:30.968] MultiverseClient.exe Information: 0 : refAssembly.FullName: System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089 [10/14/07 10:17:31.156] MultiverseClient.exe Information: 0 : refAssembly.FullName: mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089 [10/14/07 10:17:31.328] MultiverseClient.exe Information: 0 : refAssembly.FullName: Multiverse.Interface, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null ...
Display loadscreen
and the client loads and displays the loading screen image.
[10/14/07 10:17:32.734] D3D9 : Loading 2D Texture, image name : 'loadscreen.dds' with 5 mip map levels [10/14/07 10:17:33.421] Creating viewport rendering from camera 'camera.player', relative dimensions L:0,T:0,W:1,H:1, Z-Order:100 [10/14/07 10:17:33.421] Viewport for camera 'camera.player' - actual dimensions L:0,T:0,W:1024,H:768 ...
Script execution
The client executes several startup Python scripts. This is the first point where you may see an error message if you have an error of some kind in your Python code. Common types of errors you will see here are syntax errors in the Python code, or “not found” errors that reference missing or incorrectly referenced functions or libraries.
[10/14/07 10:17:34.015] MultiverseClient.exe Information: 0 : API Script Path: ../Scripts/ [10/14/07 10:17:34.015] MultiverseClient.exe Information: 0 : World Script Path: ../Worlds/UCF_PHYSICS//Scripts/ [10/14/07 10:17:34.031] MultiverseClient.exe Information: 0 : Running module file 'C:\Program Files\Multiverse Client/Scripts/ClientAPI.py' in module 'ClientAPI' [10/14/07 10:17:37.546] ClientAPI.py loaded [10/14/07 10:17:37.546] MultiverseClient.exe Information: 0 : Ran script file 'C:\Program Files\Multiverse Client/Scripts/ClientAPI.py' in module 'ClientAPI' [10/14/07 10:17:37.546] MultiverseClient.exe Information: 0 : Executing script file '../Worlds/UCF_PHYSICS/\Scripts\Startup.py' [10/14/07 10:17:38.656] Registering EffectAttackEffect [10/14/07 10:17:38.875] Registering EffectPlayAnimation [10/14/07 10:17:38.875] Startup.py loaded [10/14/07 10:17:38.875] MultiverseClient.exe Information: 0 : Ran script file '../Worlds/UCF_PHYSICS/\Scripts\Startup.py' in module '' [10/14/07 10:17:38.906] MultiverseClient.exe Information: 0 : Client setup complete: 10/14/2007 10:17:38 ...
Connect to world server
When all of the startup scripts have been run, the client connects to and begins to exchange data with the game server. This is another point where you may see errors. If the server's port is being blocked by your local network connection or firewall you may see an error here. Another really common and simple error is if the server is not actually running, you will get a connection failure. Don't always assume the problem is with the client!
[10/14/07 10:17:38.984] Released connection: Multiverse.Network.Rdp.RdpConnection [10/14/07 10:17:39.015] Connecting to world login manager at retrolabs.dyndns.org:5040 [10/14/07 10:17:39.015] MultiverseClient.exe Information: 0 : authToken: ////cQ== [10/14/07 10:17:39.015] MultiverseClient.exe Information: 0 : Connecting to tcp world server at retrolabs.dyndns.org:5040 [10/14/07 10:17:39.015] MultiverseClient.exe Information: 0 : IP Address for retrolabs.dyndns.org: '72.188.167.50' [10/14/07 10:17:39.015] Connecting to login server at 72.188.167.50:5040 [10/14/07 10:17:39.328] MultiverseClient.exe Information: 0 : Wrote message to tcp world server [10/14/07 10:17:42.703] MultiverseClient.exe Information: 0 : WorldTcpMessageFactory got message type: CharacterResponse [10/14/07 10:17:42.750] MultiverseClient.exe Information: 0 : Read message from tcp world server ...
When a server connection is established, the client begins creating the character creation and selection screen. Since Python code is involved with creating this screen, this is another place where you may see Python errors or possibly missing asset errors if you are trying to place an asset in the creation screen that does not exist.
[10/14/07 10:17:45.468] MultiverseClient.exe Information: 0 : debug: got pdata response [10/14/07 10:17:45.609] Upgraded LOD of 258 subPages [10/14/07 10:17:45.750] D3D9 : Loading 2D Texture, image name : 'splatting_sand.dds' with 5 mip map levels [10/14/07 10:17:45.875] D3D9 : Loading 2D Texture, image name : 'splatting_grass.dds' with 5 mip map levels [10/14/07 10:17:46.000] D3D9 : Loading 2D Texture, image name : 'splatting_rock.dds' with 5 mip map levels [10/14/07 10:17:46.093] D3D9 : Loading 2D Texture, image name : 'splatting_snow.dds' with 5 mip map levels [10/14/07 10:17:46.296] MultiverseClient.exe Information: 0 : Created normal texture PageShadeMask [10/14/07 10:17:46.296] MultiverseClient.exe Information: 0 : Texture: PageShadeMask: Loading 1 faces(PF_A8,256x256x1) [10/14/07 10:17:46.843] Preparing entity for entity.0.0 ...
Load user interface
Next up, the client begins loading up all of the user interface definitions which are used in the character creation and selection screens. If you have XML errors or Python errors in your user interface definition, you will see errors here.
[10/14/07 10:17:49.468] MultiverseClient.exe Information: 0 : Executing script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\Library.py' [10/14/07 10:17:49.750] MultiverseClient.exe Information: 0 : Ran script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\Library.py' in module '' [10/14/07 10:17:49.765] MultiverseClient.exe Information: 0 : Loading interface module from startup.toc [10/14/07 10:17:49.859] MultiverseClient.exe Information: 0 : Added frame: MasterFont [10/14/07 10:17:49.875] MultiverseClient.exe Information: 0 : Added frame: NormalFont [10/14/07 10:17:49.875] MultiverseClient.exe Information: 0 : Added frame: SmallFont [10/14/07 10:17:49.875] MultiverseClient.exe Information: 0 : Added frame: FrameNameFont [10/14/07 10:17:49.875] MultiverseClient.exe Information: 0 : Added frame: ChatFont ...
After this screen, there will be quite a bit of output from the character selection or creation process. Once this is complete, the client will actually log into the game server with the selected character. This is also another point where networking or server problems can cause error messages to show up in the trace.
[10/14/07 10:18:01.750] Connecting to world login manager at retrolabs.dyndns.org:5040 [10/14/07 10:18:01.750] MultiverseClient.exe Information: 0 : authToken: ////cQ== [10/14/07 10:18:01.750] MultiverseClient.exe Information: 0 : Connecting to tcp world server at retrolabs.dyndns.org:5040 ...
Once connected, the client begins to load up the game world, and then loads up all of the user interface XML used by the game. Besides Python errors, this part of the trace file shown above is where you may also see XML errors. Here is an excerpt from the trace file where it begins to load up the user interface definitions.
[10/14/07 10:18:10.875] MultiverseClient.exe Information: 0 : Executing script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\Library.py' [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Ran script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\Library.py' in module '' [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Loading interface module from basic.toc [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Added frame: MasterFont [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Added frame: NormalFont [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Added frame: SmallFont [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Added frame: FrameNameFont [10/14/07 10:18:11.015] MultiverseClient.exe Information: 0 : Added frame: ChatFont ...
Run UI scripts
Once the XML is completely loaded, the client then reads in all Python scripts that have been referenced in the XML files. The point when the XML parsing ends and the Python loading begins looks like this in the trace file...
[10/14/07 10:18:11.578] MultiverseClient.exe Information: 0 : End Xml Ui Prepare: 137387281 [10/14/07 10:18:11.578] MultiverseClient.exe Information: 0 : Begin CompileCode: 137387281 [10/14/07 10:18:11.578] MultiverseClient.exe Information: 0 : Executing script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\MvChat.py' [10/14/07 10:18:11.593] MultiverseClient.exe Information: 0 : Ran script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\MvChat.py' in module '' [10/14/07 10:18:11.593] MultiverseClient.exe Information: 0 : Executing script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\MvStatus.py' [10/14/07 10:18:11.625] MultiverseClient.exe Information: 0 : Ran script file '../Worlds/UCF_PHYSICS/\Interface\FrameXML\MvStatus.py' in module '' ...
You can see how there are two messages displayed for each Python script loaded. First is an “Executing script file” message indicating that the given Python file is being loaded. If the script file is successfully loaded and has no errors, you then will see a “Ran script file” message. If there is an error in the Python file, it will show up after the “Executing script file” message.
Once all scripts have been loaded, the following line appears in the trace file...
[10/14/07 10:18:12.250] MultiverseClient.exe Information: 0 : End CompileCode: 137387953
Enter world
At this point, the client has completed initialization of the game, and will begin to load the world and the player actually begins to play. Depending on how long the client runs, the amount of information in the trace file can vary greatly. The more one plays, the more lines that will be added to the trace file.
