DEV: D2TM Logging (tool)

stefanhendriks · August 5, 2009

This thread should be about the d2tm log:

- how to make the log better

- how to make it easier to understand and easier to read by tools (like the D2TMLogViewer tool).

Currently, the log is like this (snippet)

0| REINFORCE: Starting from cell 511, going to cell 637
0| REINFORCE: Starting from cell 7, going to cell 72
0| upgrading tech tree
0| REINFORCE: Starting from cell 32, going to cell 97
0| [sCENARIO] -> REINFORCEMENTS
0| [0] Reinforcement: Controller = 3, House 4, Time 12, Type = 3
0| [sCENARIO] -> REINFORCEMENTS
0| [1] Reinforcement: Controller = 2, House 3, Time 12, Type = 9

This is roughly:

(the <time> does not even work, i noticed lately).

This is a bit too general. So perhaps this would be a better way to start logging things:

Where time is:

HH:MM:SS

Level is:

TRACE

WARN

ERROR

FATAL

component could be:

UNITS

STRUCTURES

INI

GAME

SIDEBAR

Event could be:

"Loading file bla.ini"

"Attacking"

etc

Message is optional , is additional information

outcome is basically:

SUCCESS, FAILED, BUSY (?), NONE? (when none required?)

player If applicable, the player id.

Example log line:

I can imagine that the log tool would be able to show this in a friendly way, where you could filter on several pieces of the log line.

Any feedback?

stefanhendriks · August 5, 2009

An update;

I have introduced a new logger class. This handles the format as in the first post described. It is *still open* for debate.

Please have a look at the source code (see cLog*.*).

Here is a snippet of how the new log file looks like (the old log lines are still printed, they always have 'default' values, like level WARN, etc).

-------------------
DUNE II - The Maker
-------------------
-------------------
Version information
-------------------
22:08:01|INFO|SETUP|Initializing|Version 0.4.2, Compiled at Aug 5 2009 , 22:06:57
22:08:01|INFO|SETUP|Initializing|Windowed mode
-------
Allegro
-------
22:08:01|INFO|ALLEGRO|Allegro init succes|Allegro 4.2.2, MinGW32
22:08:01|WARN|NONE||install_timer()|NONE
22:08:01|WARN|NONE||alfont_init()|NONE
22:08:01|WARN|NONE||install_keyboard()|NONE
22:08:01|WARN|NONE||install_mouse()|NONE
22:08:01|WARN|NONE||setting up timer functions / locking functions & memory|NONE
22:08:01|WARN|NONE||Timers installed|NONE
22:08:01|WARN|NONE||Window title set: [Dune II - The Maker [0.4.2] - (by Stefan Hendriks)]|NONE
22:08:01|WARN|NONE||DESKTOP: Found desktop color depth. Will switch to 32 bit.|NONE
22:08:01|WARN|NONE||Loading font data|NONE
22:08:01|WARN|NONE||Display 'switch to background' mode set|NONE
22:08:01|WARN|NONE||Initializing sound|NONE
22:08:01|WARN|NONE||Succes with 32 reserved voices.|NONE
22:08:01|WARN|NONE||Memory bitmap created: bmp_screen|NONE
22:08:01|WARN|NONE||Memory bitmap created: bmp_throttle|NONE
22:08:01|WARN|NONE||Memory bitmap created: bmp_winlose|NONE
22:08:01|WARN|NONE||Memory bitmap created: bmp_fadeout|NONE
22:08:01|WARN|NONE||Color conversion method set|NONE
22:08:01|WARN|NONE||MOUSE: Mouse speed set|NONE
22:08:01|WARN|NONE||
----|NONE
22:08:01|WARN|NONE||GAME |NONE
22:08:01|WARN|NONE||----|NONE
22:08:02|WARN|NONE||Datafile hooked: gfxdata.dat|NONE
22:08:02|WARN|NONE||Datafile hooked: gfxaudio.dat|NONE
22:08:02|WARN|NONE||Datafile hooked: gfxinter.dat|NONE
22:08:02|WARN|NONE||Datafile hooked: gfxworld.dat|NONE
22:08:02|WARN|NONE||Datafile hooked: gfxmentat.dat|NONE
22:08:02|WARN|NONE||MP3MUS.DAT not found, using MIDI to play music|NONE
22:08:02|WARN|NONE||Seed is 1249502882|NONE
22:08:02|WARN|NONE||Installing: PLAYERS|NONE
22:08:02|WARN|NONE||Installing: HOUSES|NONE
22:08:02|WARN|NONE||Installing: STRUCTURES|NONE
22:08:02|WARN|NONE||Installing: BULLET TYPES|NONE
22:08:02|WARN|NONE||Installing: UNITS|NONE
22:08:02|WARN|NONE||Installing: WORLD|NONE
22:08:02|WARN|NONE||[GAME.INI] Opening file|NONE
22:08:02|WARN|NONE||Opening game settings from : game.ini|NONE
22:08:02|WARN|NONE||[GAME.INI] -> [uNITS]|NONE
22:08:02|WARN|NONE||[GAME.INI] -> [sTRUCTURES]|NONE
22:08:02|WARN|NONE||[GAME.INI] Done|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/2PL_Sand_Pit.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/3PL_Three_Of_A_Kind.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/3PL_Waging_War_On_Arrakis.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/4PL_Clover.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/4PL_He_Who_Controls_The_Spice.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/4PL_Mountains.ini|NONE
22:08:03|WARN|NONE||Loading skirmish map: skirmish/4PL_Symmetric_Four.ini|NONE
22:08:08|WARN|NONE||LOAD SCENE: data/scenes/plord.dat|NONE
22:08:08|WARN|NONE||[bRIEFING] Opening file|NONE
22:08:08|WARN|NONE||campaign/briefings/mentato.ini|NONE
22:08:08|WARN|NONE||[bRIEFING] File opened|NONE
22:08:08|WARN|NONE||MENTAT: sentences prepared|NONE
22:08:09|WARN|NONE||[sCENARIO] 'campaign/maps/sceno001.ini' (Mission 1)|NONE
22:08:09|WARN|NONE||[sCENARIO] Opening file|NONE
22:08:09|WARN|NONE||LOAD SCENE: data/scenes/harvest.dat|NONE
22:08:09|WARN|NONE||[sCENARIO] -> [MAP] Seed=|NONE
22:08:09|WARN|NONE||Generating seed map with seed 1498.|NONE
22:08:09|WARN|NONE||Seedmap generated|NONE
22:08:09|WARN|NONE||Seedmap converted into D2TM map.|NONE
22:08:09|WARN|NONE||upgrading tech tree|NONE
22:08:09|WARN|NONE||getHouseFromChar could not determine what house type '' is. Returning -1; this will probably cause problems.|NONE
22:08:09|WARN|NONE||WARNING: Identifying house/controller of structure (typo?)|NONE
22:08:09|WARN|NONE|||NONE
22:08:09|WARN|NONE||Could not find structure:|NONE
22:08:09|WARN|NONE|||NONE
22:08:09|WARN|NONE||WARNING: Identifying house/controller of structure (typo?)|NONE
22:08:09|WARN|NONE||[sCENARIO] Done reading|NONE
22:08:09|WARN|NONE||[bRIEFING] Opening file|NONE
22:08:09|WARN|NONE||campaign/briefings/mentato.ini|NONE
22:08:09|WARN|NONE||[bRIEFING] File opened|NONE
22:08:09|WARN|NONE||MENTAT: sentences prepared|NONE
22:08:11|WARN|NONE||[uNIT[7]: Soldier - House 3, iCell = 2209, iGoal = 2209 ] 'Attacking UNIT ID 5, STRUC ID -1, ATTACKCLL -1, GoalCell 1953'|NONE
22:08:11|WARN|NONE||[uNIT[8]: Raider Trike - House 3, iCell = 2207, iGoal = 2207 ] 'Attacking UNIT ID 5, STRUC ID -1, ATTACKCLL -1, GoalCell 1953'|NONE
22:08:11|WARN|NONE||[uNIT[7]: Soldier - House 3, iCell = 2209, iGoal = 1953 ] 'No pathindex & no nextcell, resetting unit'|NONE
22:08:11|WARN|NONE||CREATE_PATH: Found the goal cell, succes, bailing out|NONE
22:08:11|WARN|NONE||[uNIT[7]: Soldier - House 3, iCell = 2209, iGoal = 1953 ] 'Create path ... result = 0'|NONE
22:08:11|WARN|NONE||[uNIT[8]: Raider Trike - House 3, iCell = 2207, iGoal = 1953 ] 'No pathindex & no nextcell, resetting unit'|NONE
22:08:11|WARN|NONE||CREATE_PATH: Found the goal cell, succes, bailing out|NONE
22:08:11|WARN|NONE||[uNIT[8]: Raider Trike - House 3, iCell = 2207, iGoal = 1953 ] 'Create path ... result = 0'|NONE
22:08:12|WARN|NONE||SHOULD CALCULATE NEW PATH|NONE
22:08:12|WARN|NONE||[uNIT[5]: Soldier - House 1, iCell = 1953, iGoal = 1953 ] 'Attacking UNIT ID 8, STRUC ID -1, ATTACKCLL -1, GoalCell 2081'|NONE
22:08:12|WARN|NONE||[uNIT[5]: Soldier - House 1, iCell = 1953, iGoal = 2081 ] 'Attacking UNIT ID 8, STRUC ID -1, ATTACKCLL -1, GoalCell 2081'|NONE
22:08:12|WARN|NONE||[uNIT[5]: Soldier - House 1, iCell = 1953, iGoal = 2081 ] 'No pathindex & no nextcell, resetting unit'|NONE
22:08:12|WARN|NONE||CREATE_PATH: Found the goal cell, succes, bailing out|NONE
22:08:12|WARN|NONE||[uNIT[5]: Soldier - House 1, iCell = 1953, iGoal = 2081 ] 'Create path ... result = 0'|NONE
22:08:13|WARN|NONE||CREATE_PATH: Found the goal cell, succes, bailing out|NONE
22:08:13|WARN|NONE||[uNIT[7]: Soldier - House 3, iCell = 2145, iGoal = 1953 ] 'Create path ... result = 0'|NONE
22:08:13|WARN|NONE||[uNIT[5]: Soldier - House 1, iCell = 1953, iGoal = 2081 ] 'Attacking UNIT ID 8, STRUC ID -1, ATTACKCLL -1, GoalCell 2081'|NONE
22:08:13|WARN|NONE||--------|NONE
22:08:13|WARN|NONE||SHUTDOWN|NONE
22:08:13|WARN|NONE||--------|NONE
22:08:13|WARN|NONE||Allegro FONT library shut down.|NONE
22:08:13|WARN|NONE||Allegro MP3 library shut down.|NONE

I still need to apply the logger class, but you'll get the idea. (also, it is not completely finished, but it basically works already)

Additions to above:

- the player id and outcome are not obliged. They can be left out.

I really like lines like this:

22:08:01|INFO|SETUP|Initializing|Version 0.4.2, Compiled at Aug 5 2009 , 22:06:57
22:08:01|INFO|SETUP|Initializing|Windowed mode

The first line tells me basically that I am running version 0.4.2 , compiled today and it is initializing. And that the message

is for informative purposes.

Rene · August 5, 2009

Making a strict format for the logging would be nice, it's why the tool is currently only showing unit information. To parse everything was just way too hard. Actually, if you would make the timestamp work, the tool would stop working. ATM, its looking for lines starting with 0| [uNIT[ :-[

About the format you propose: it looks OK, only it would be useful to log the current and target cells. This combined with the map information and timestamp would make it possible to create a time line based viewer, showing the actual location of units and their targets at the 'current' time. Although it would be quite useful to debug the game, it will require a log entry for almost every action the player or AI takes, and that might be quite a big amount of work.

Anyway, it is a good idea to split the different fields with one specific symbol, this makes parsing the log a LOT easier.

What would be a possibility is to make a different meaning for each field for each type of message. For example, sidebar information doesn't need a 'current' and 'target' cell, and to make these fields 'null' fields wouldn't be very elegant.

Some thoughts on the format you already described:

Time field - I think it's better to make this one just one unit, ms for example. A HH:MM:SS format would make it more susceptible to errors, both for reading as well as writing. The tool could show these ms as a HH:MM:SS time to make it easier to understand, but the logfile should stick to a single value IMO.

Level Field - One thing I like about the Logger class in Java is the way the different levels are handled. There are a few constants named just like the ones you described, only these are stored as integer values, for example LEVEL_CRITICAL = 1000;

You could create similar constants in the game, and for the logger tool it is possible to show only messages with an higher or equal value to 'x'. This makes it very easy to create additional levels later in case it is needed.

Component field - Looks fine, can't think of any possible improvement.

Event Field - One of your examples is "Loading file bla.ini". I think it's better to keep this field very strict. So in this case, it would only say "Loading File". The message field would contain the message "File = blabla.ini". This makes placing the different entry's in different categories easier.

The other fields would contain information specific about the Component and Event fields. What I can think of at the moment is:

Components:

UNIT(might be more elegant to call it unit instead of units - one entry is about only one unit. Not too important though)

STRUCURE

INI

GAME

GUI (A bit broader than sidebar. Would in a later version also mean in-game options etc?)

SYSTEM

Game is mostly about game information, like player wins etc, can't think up much more ATM but I'm sure there are more game related messages.

System is more about the 'technical' side of the game, like failed assertions and stuff like that.

For UNIT, there are the following events:

CREATED

DESTROYED (has been killed)

DESTROYS (killed something else)

MOVE

ATTACK

HIT

HITS

SHOOTS

HARVEST (not sure if this one is needed, should take a look at how harvesting is implemented)

DEPLOY (For harvester, this is return to refinery? If not, that should have a event too.)

VETERANCY

REPAIR (not sure if this one is needed)

These events need the following field:

CREATED: cell

DESTROYED: cell, destroyer id

DESTROYS: victim id :P, experience amount

MOVE: cell, target cell

ATTACK: target id

HIT: health, 'damage dealt by' id(?), amount(?), projectile id(?)

HITS: target ID

SHOOTS: projectile id, target id

HARVEST: spice cell

DEPLOY: nothing, I think

VETERANCY: new veterancy level, new stats(?)

REPAIR: repair facility id

For Structure, there are these events:

CREATED

CREATES (A unit or building has been completed)

CREATE (Ordered to start creating something, not sure if this one is needed)

DESTROYED

DESTROYS

UPGRADE

ORDER (for Starport)

REPAIR (for repair facility)

REPAIRING (repairing itself)

These events need the following field:

CREATED: cell

CREATES: creation id

CREATE: time(until completion), cost, type

DESTROYED: destroyer id

DESTROYS: victim id

UPGRADE: cost, level, time

ORDER: not sure: ordered units, total cost, cost per unit type, what would be useful?

REPAIR: unit id, percentage, cost

REPAIRING: percentage, cost

I'm not sure what kind of events, let alone fields, the other components need. I think it's best you think them up as you go.

Well, this is already one hell of a post, let me know if you have any thoughts on it :)

EDIT: While I was writing this post, you posted your second message so some stuff in this post doesn't take your second post in account. The logger already looks pretty neat though.

Rene · August 6, 2009

No matter what the final file format is going to be like, these logs are going to contain a huge load of information, and huge loads of information always need a rather complex GUI to visualize this data. Before I start working on complex GUI's, I always make a quick sketch first. So, as I'm not the only one who's going to use this tool it might be best to share these sketches here to see if someone has some ideas for improvement or additional functions.

Here's a link to the first sketch.

Now, before anyone gets his hopes up... Here are two BIG disappointments:

1 - The program will NOT contain my beautiful handwriting. It will use a standard font instead.

2 - All lines in the program will be straight. No nice curves.

http://www.xyzw.nl/GUI_Design_0001.jpg

In the Filter section you can select what kind of data you want to see: Level, Component, House and Event type.

The Filter Results will be a list with everything that gets trough the filters. Much like the left list in the current program. Once you select an 'entity' in this list, all the log messages concerning this entity will be shown in the Raw Selection Entry's section, much like the right list in the current program. The Timeline View and Timeline filters are entity-specific implementations: A GUI component needs a completely different Timeline Viewer than a unit for example. For the filter selection for an unit you can think of stuff like 'do not show move events'. Then there is the Minimap Viewer. This gives a approximation of the battlefield at the time selected in the Timeline Viewer. Approximated, because the log will not contain every cell a unit moves. It think it should only contain 'now commanded to move to...' messages and 'arrived at...' messages. So, the minimap will not be able to track the exact unit locations. Instead, I think it is best to make the unit instantly move to his move target as soon as the timeline passes the 'arrived at...' message. Interpolating between start and end positions might cause confusion, as units don't always move in a straight line. I think the Minimap filter section is self-explanatory.

About the timeline viewer: Here is an (simple) example for what I had in mind as the timeline for an unit:

#include the same disappointments :P

http://www.xyzw.nl/GUI_Design_0002.jpg

The upper track contains all the move commands, the middle track all the attack commands, and the lower one contains all the other messages. Clicking on one of the message boxes will select the corresponding entry in the list with entry's, and vica-versa. This might be useful because the log entry's will probably contain more information about the selected event.

If someone knows some improvements, or a completely other concept, please let me know.

stefanhendriks · August 6, 2009

stefanhendriks · August 6, 2009

Here's a link to the first sketch.
Now, before anyone gets his hopes up... Here are two BIG disappointments:
1 - The program will NOT contain my beautiful handwriting. It will use a standard font instead.
2 - All lines in the program will be straight. No nice curves.
http://www.xyzw.nl/GUI_Design_0001.jpg

I would not care less about these curves and hand writing ;) But I do think it looks great! The only thing I wonder about is: Do you have that

much time to create it?

In the Filter section you can select what kind of data you want to see: Level, Component, House and Event type.
The Filter Results will be a list with everything that gets trough the filters. Much like the left list in the current program. Once you select an 'entity' in this list, all the log messages concerning this entity will be shown in the Raw Selection Entry's section, much like the right list in the current program. The Timeline View and Timeline filters are entity-specific implementations: A GUI component needs a completely different Timeline Viewer than a unit for example. For the filter selection for an unit you can think of stuff like 'do not show move events'. Then there is the Minimap Viewer. This gives a approximation of the battlefield at the time selected in the Timeline Viewer. Approximated, because the log will not contain every cell a unit moves. It think it should only contain 'now commanded to move to...' messages and 'arrived at...' messages. So, the minimap will not be able to track the exact unit locations. Instead, I think it is best to make the unit instantly move to his move target as soon as the timeline passes the 'arrived at...' message. Interpolating between start and end positions might cause confusion, as units don't always move in a straight line. I think the Minimap filter section is self-explanatory.
About the timeline viewer: Here is an (simple) example for what I had in mind as the timeline for an unit:
#include the same disappointments Tongue
http://www.xyzw.nl/GUI_Design_0002.jpg
The upper track contains all the move commands, the middle track all the attack commands, and the lower one contains all the other messages. Clicking on one of the message boxes will select the corresponding entry in the list with entry's, and vica-versa. This might be useful because the log entry's will probably contain more information about the selected event.
If someone knows some improvements, or a completely other concept, please let me know.

Actually I cannot add anything to this. If it is possible to make it this visual, it would be very cool to see how the battle 'evolves'. Also

if possible, it would be great to see how a specific unit would 'evolve' in the game (what did it do, think, etc).

Also, thought of another component: COMP_PATHFINDER

:)

Rene · August 6, 2009

I would not care less about these curves and hand writing ;) But I do think it looks great! The only thing I wonder about is: Do you have that
much time to create it?

Time won't be a big problem: I'm still some lazy student ATM, so I see it as a nice exercise :P

Actually I cannot add anything to this. If it is possible to make it this visual, it would be very cool to see how the battle 'evolves'. Also
if possible, it would be great to see how a specific unit would 'evolve' in the game (what did it do, think, etc).

The 'what did it do' should be visualized by the timeline viewer. But to make its state for the selected time easier to see, maybe add a panel next to the timeline viewer showing its complete 'current' state, like position, health, etc?

Also, thought of another component: COMP_PATHFINDER

That should make it, among other things, possible to to track the precise unit movements. Would be cool :)

would just run normally and use log level "error" as default? (or perhaps even FATAL?)
but using:
d2tm.exe -loglevel INFO
would make it log everything.

Sounds good. But I'm not sure what to use as a default level. The idea is to be able to get useful information out of the default log files, as it isn't always possible to recreate a bug.

Makes sense to mee. I think the GAME component is a bit to abstract. Anything is a game component in the end Wink But perhaps you can make it more concrete?
Apart from GAME and SYSTEM, i think they are ok. Hint: You could look at the enums.h file (latest revision) to have an idea what components i have identified so
far. I believe even "GAME" is in there too, just in case, i'm curious what you think about them.

The components look good so far. What I had in mind for SYSTEM has become more specific, which is good. By these I mean the ALLEGRO, SETUP and components like these.

What I was thinking to put under the GAME category is information about a battle that doesn't apply to only one player, maybe like 'player x wins'. I'm not sure what can be put in this category, and it's always important to make sure things don't get overcomplicated. So maybe it isn't needed. If it is, GAMEPLAY might be a better name?

Anyway, if the goal is really to have such an accurate logging system, the game needs to log more. And that's something I think I can help with, if you think it will take too much of your time ;)

I will make a prototype GUI later today, I first got some more earthly business to attend to...

stefanhendriks · August 6, 2009

Sounds great.

I wish I had so much time as you ;) (lazy student and all).

You're always welcome to make changes to the code; if i think it goes to a direction not my liking, i'll probably contact you (or anyone for that matter) to discuss it.

I have never really reverted code so don't worry that I will simply kill all the code you submit ;)

that should make it, among other things, possible to to track the precise unit movements. Would be cool Smiley

I am not sure about that; because that would require for you to have a string of cells (comma seperated?) to know what the 'path' is. It is not impossible of course.

But I'm not sure what to use as a default level

Actually, from a user perspective; there should be as little to no logging information. Only for those who really want to test it the logging should be turned 'on'.

The components look good so far. What I had in mind for SYSTEM has become more specific, which is good. By these I mean the ALLEGRO, SETUP and components like these.
What I was thinking to put under the GAME category is information about a battle that doesn't apply to only one player, maybe like 'player x wins'. I'm not sure what can be put in this category, and it's always important to make sure things don't get overcomplicated. So maybe it isn't needed. If it is, GAMEPLAY might be a better name?
Anyway, if the goal is really to have such an accurate logging system, the game needs to log more. And that's something I think I can help with, if you think it will take too much of your time.

About the components, I see. Yes i'd rather see them more concrete. :)

About time, you see my first sentences.

I will make a prototype GUI later today, I first got some more earthly business to attend to...

Great; ah real life. Yes i almost forget what it is all about ;)

(nah kidding) ;)

Rene · August 6, 2009

I am not sure about that; because that would require for you to have a string of cells (comma seperated?) to know what the 'path' is. It is not impossible of course.

Yeah, it would make the log files awfully big. The most important question is: Is it really needed? Let's just keep it out until we have an answer to that question, it's always possible to add it later.

Actually, from a user perspective; there should be as little to no logging information. Only for those who really want to test it the logging should be turned 'on'.

Agreed, but ATM, D2TM is still under construction. Isn't anyone playing the game some kind of tester? The problem is, say someone is playing the game, and notices something odd. Take the 'AI and turrets not shooting' issue in the 'Demo 4 released' thread for example. If the player was running the game in 'normal' mode, almost no logging information would be generated. So maybe it's better to generate a medium amount of logging information by default, at least until a version 1.0 comes out.

Great; ah real life. Yes i almost forget what it is all about ;)

Hehe, yeah. Well, the problem was I ran out of coffee, so I really had to go buy some new :P

Anyway, here's the GUI so far. Nothing has been implemented yet. I'm going to design it first, as this tool is going to be quite complex I guess.

http://www.xyzw.nl/GUI_Design_Prev.png

stefanhendriks · August 6, 2009

The tool will be more complex then any tool y ou have created (for d2tm) so far.

I could imagine you want to integrate some functionality. Like, when you want to draw the map, how are you going to get that info? Do you want a serialized map as well in the log?

Agreed, but ATM, D2TM is still under construction. Isn't anyone playing the game some kind of tester? The problem is, say someone is playing the game, and notices something odd. Take the 'AI and turrets not shooting' issue in the 'Demo 4 released' thread for example. If the player was running the game in 'normal' mode, almost no logging information would be generated. So maybe it's better to generate a medium amount of logging information by default, at least until a version 1.0 comes out.

Sounds good to me. Lets say the mechanism will be built, but the default logging level will be set to the lowest threshold possible, so everything will be logged :)

Rene · August 6, 2009

I could imagine you want to integrate some functionality. Like, when you want to draw the map, how are you going to get that info? Do you want a serialized map as well in the log?

Yeah, that's probably the best solution.

About the log file you showed in your second post, is it possible to make every 'non-log' line, like the lines at the beginning:

-------------------

DUNE II - The Maker

-------------------

start with, say, // so you would get

//-------------------

//DUNE II - The Maker

//-------------------

It makes the parser cleaner. Maybe by adding a logComment() function to your logger, that automatically prepends the //?

Anyway, I've been designing the tool a bit, and started programming a few things. The tool makes use of a class I called the FilterList. A FilterList contains an ArrayList containing objects implementing the Filterable interface. This interface has a public boolean passesFilter(Filter f) method, to allow the user to ask the list to get a 'Filtered List', a List only containing the objects that pass the filter. The Filter class currently supports the following criteria:

- Timestamp (min <= timestamp <= max)

- Level

- Component

- Event

- House (if supported by Component)

Any ideas for more useful criteria?

In the following paragraph, I will use the terms Entity and Entry. Just to make clear: by Entity I mean everything in the left list, for example a unit, a structure, or the allegro messages. By entry I mean everything in the right list: all the lines in the log concerning a single entity.

While designing and programming the application, I noticed the following things:

- the existence of two fields depends on the component: House and ID. Not all components need these, and there will never be a case where 'some' events need these fields. It's an all-or-nothing scenario :P

- The previous point implies that Components do not need to be instantiated for every Entry, or even every Entity. There are a few different components, but the entities sharing the same type of Component can safely share the same instance: house and id are stored in the entity object, if the Component requires this.

- Events however, need a new instance for every entry. This is because every event type has other types of fields, and these fields hold different data each entry.

Based on these observations (yay, let's use lots of expensive words!), I think it might be best to change the line format a bit:

The Message field is before the Event field to make parsing easier and code cleaner, else the location of the Message field would depend on the number of fields the Event requires. Same reason for the Outcome field. Let me know what you think of it.

It might be easier to put a document on the repository describing the format, I'll do that tomorrow. Right now, I'm going to relax a little, my brain feels like it's melting :P

stefanhendriks · August 6, 2009

I had my mental breakdown this afternoon; but anyway.

Basically I think you can have several 'line parsers' for every kind of Component and its Event.

Creating comment lines is not hard to do.

I will submit some new code tonight. I hope the format is a bit better then. If not, please let me know. I intend to focus on the (unfinished refactored) sidebar the coming days.

stefanhendriks · August 6, 2009

New code comitted.

Do note, that the outcome field is not nescesary. But, they will be always there for certain components. SO your parser should not be having any trouble with that :)

Example of how the log file looks like now:

-------------------
Dune II - The Maker
-------------------
-------------------
Version information
-------------------
9|INFO|VERSION|Version 0.4.2, Compiled at Aug 6 2009 , 22:05:54|Initializing
9|INFO|SETUP|Windowed mode|Initializing
-------
Allegro
-------
161|INFO|ALLEGRO|Allegro 4.2.2, MinGW32|SUCCESS|Allegro init
162|INFO|ALLEGRO|install_timer()|SUCCESS|Initializing timer functions
162|INFO|ALLEGRO|alfont_init()|SUCCESS|Initializing ALFONT
177|INFO|ALLEGRO|install_keyboard()|SUCCESS|Initializing Allegro Keyboard
179|INFO|ALLEGRO|install_mouse()|SUCCESS|Initializing Allegro Mouse
180|INFO|ALLEGRO|LOCK_VARIABLE/LOCK_FUNCTION|SUCCESS|Set up timer related variables
180|INFO|ALLEGRO||SUCCESS|Set up window title
181|WARN|NONE|DESKTOP: Found desktop color depth. Will switch to 32 bit.|Default log message (CHANGEME)
285|WARN|NONE|Loading font data|Default log message (CHANGEME)
297|WARN|NONE|Display 'switch to background' mode set|Default log message (CHANGEME)
297|WARN|NONE|Initializing sound|Default log message (CHANGEME)
554|WARN|NONE|Succes with 32 reserved voices.|Default log message (CHANGEME)
555|WARN|NONE|Memory bitmap created: bmp_screen|Default log message (CHANGEME)
556|WARN|NONE|Memory bitmap created: bmp_throttle|Default log message (CHANGEME)
557|WARN|NONE|Memory bitmap created: bmp_winlose|Default log message (CHANGEME)
557|WARN|NONE|Memory bitmap created: bmp_fadeout|Default log message (CHANGEME)
557|WARN|NONE|Color conversion method set|Default log message (CHANGEME)
557|WARN|NONE|MOUSE: Mouse speed set|Default log message (CHANGEME)
558|WARN|NONE|
----|Default log message (CHANGEME)
558|WARN|NONE|GAME |Default log message (CHANGEME)
558|WARN|NONE|----|Default log message (CHANGEME)
745|WARN|NONE|Datafile hooked: gfxdata.dat|Default log message (CHANGEME)
787|WARN|NONE|Datafile hooked: gfxaudio.dat|Default log message (CHANGEME)
961|WARN|NONE|Datafile hooked: gfxinter.dat|Default log message (CHANGEME)
1006|WARN|NONE|Datafile hooked: gfxworld.dat|Default log message (CHANGEME)
1114|WARN|NONE|Datafile hooked: gfxmentat.dat|Default log message (CHANGEME)
1115|WARN|NONE|MP3MUS.DAT not found, using MIDI to play music|Default log message (CHANGEME)
1115|WARN|NONE|Seed is 1249589322|Default log message (CHANGEME)
1116|WARN|NONE|Installing: PLAYERS|Default log message (CHANGEME)
1116|WARN|NONE|Installing: HOUSES|Default log message (CHANGEME)
1117|WARN|NONE|Installing: STRUCTURES|Default log message (CHANGEME)
1117|WARN|NONE|Installing: BULLET TYPES|Default log message (CHANGEME)
1117|WARN|NONE|Installing: UNITS|Default log message (CHANGEME)
1118|WARN|NONE|Installing: WORLD|Default log message (CHANGEME)
1118|WARN|NONE|[GAME.INI] Opening file|Default log message (CHANGEME)
1119|WARN|NONE|Opening game settings from : game.ini|Default log message (CHANGEME)
1120|WARN|NONE|[GAME.INI] -> [uNITS]|Default log message (CHANGEME)
1121|WARN|NONE|[GAME.INI] -> [sTRUCTURES]|Default log message (CHANGEME)
1122|WARN|NONE|[GAME.INI] Done|Default log message (CHANGEME)
2924|WARN|NONE|LOAD SCENE: data/scenes/platr.dat|Default log message (CHANGEME)
3053|WARN|NONE|[bRIEFING] Opening file|Default log message (CHANGEME)
3054|WARN|NONE|campaign/briefings/mentata.ini|Default log message (CHANGEME)
3058|WARN|NONE|[bRIEFING] File opened|Default log message (CHANGEME)
3059|WARN|NONE|MENTAT: sentences prepared|Default log message (CHANGEME)
4142|WARN|NONE|[sCENARIO] 'campaign/maps/scena001.ini' (Mission 1)|Default log message (CHANGEME)
4143|WARN|NONE|[sCENARIO] Opening file|Default log message (CHANGEME)
4176|WARN|NONE|LOAD SCENE: data/scenes/harvest.dat|Default log message (CHANGEME)
4177|WARN|NONE|[sCENARIO] -> [MAP] Field=|Default log message (CHANGEME)
4177|WARN|NONE|[sCENARIO] -> [MAP] Bloom=|Default log message (CHANGEME)
4177|WARN|NONE|[sCENARIO] -> [MAP] Seed=|Default log message (CHANGEME)
4178|WARN|NONE|Generating seed map with seed 353.|Default log message (CHANGEME)
4178|WARN|NONE|Seedmap generated|Default log message (CHANGEME)
4179|WARN|NONE|Seedmap converted into D2TM map.|Default log message (CHANGEME)
4183|WARN|NONE|upgrading tech tree|Default log message (CHANGEME)
4185|WARN|NONE|[sCENARIO] Done reading|Default log message (CHANGEME)
4186|WARN|NONE|[bRIEFING] Opening file|Default log message (CHANGEME)
4186|WARN|NONE|campaign/briefings/mentata.ini|Default log message (CHANGEME)
4189|WARN|NONE|[bRIEFING] File opened|Default log message (CHANGEME)
4189|WARN|NONE|MENTAT: sentences prepared|Default log message (CHANGEME)
7798|WARN|NONE|[uNIT[2]: Soldier - House 2, iCell = 1439, iGoal = 1439 ] 'ORDERED TO MOVE'|Default log message (CHANGEME)
7799|WARN|NONE|Soldier|Default log message (CHANGEME)
7799|WARN|NONE|[uNIT[4]: Trike - House 2, iCell = 1501, iGoal = 1501 ] 'ORDERED TO MOVE'|Default log message (CHANGEME)
7799|WARN|NONE|Trike|Default log message (CHANGEME)
7799|WARN|NONE|[uNIT[5]: Soldier - House 2, iCell = 1569, iGoal = 1569 ] 'ORDERED TO MOVE'|Default log message (CHANGEME)
7799|WARN|NONE|Soldier|Default log message (CHANGEME)
7800|WARN|NONE|[uNIT[6]: Soldier - House 2, iCell = 1697, iGoal = 1697 ] 'ORDERED TO MOVE'|Default log message (CHANGEME)
7800|WARN|NONE|Soldier|Default log message (CHANGEME)
7800|WARN|NONE|[uNIT[8]: Trike - House 2, iCell = 1824, iGoal = 1824 ] 'ORDERED TO MOVE'|Default log message (CHANGEME)
7800|WARN|NONE|Trike|Default log message (CHANGEME)
7803|WARN|NONE|[uNIT[2]: Soldier - House 2, iCell = 1439, iGoal = 1315 ] 'No pathindex & no nextcell, resetting unit'|Default log message (CHANGEME)
7803|WARN|NONE|CREATE_PATH: Found the goal cell, succes, bailing out|Default log message (CHANGEME)
7804|WARN|NONE|[uNIT[2]: Soldier - House 2, iCell = 1439, iGoal = 1315 ] 'Create path ... result = 0'|Default log message (CHANGEME)
7804|WARN|NONE|[uNIT[4]: Trike - House 2, iCell = 1501, iGoal = 1315 ] 'No pathindex & no nextcell, resetting unit'|Default log message (CHANGEME)
7804|WARN|NONE|CREATE_PATH: Found the goal cell, succes, bailing out|Default log message (CHANGEME)
7805|WARN|NONE|[uNIT[4]: Trike - House 2, iCell = 1501, iGoal = 1315 ] 'Create path ... result = 0'|Default log message (CHANGEME)
7805|WARN|NONE|[uNIT[5]: Soldier - House 2, iCell = 1569, iGoal = 1315 ] 'No pathindex & no nextcell, resetting unit'|Default log message (CHANGEME)
7805|WARN|NONE|CREATE_PATH: Found the goal cell, succes, bailing out|Default log message (CHANGEME)
7805|WARN|NONE|[uNIT[5]: Soldier - House 2, iCell = 1569, iGoal = 1315 ] 'Create path ... result = 0'|Default log message (CHANGEME)
7805|WARN|NONE|[uNIT[6]: Soldier - House 2, iCell = 1697, iGoal = 1315 ] 'No pathindex & no nextcell, resetting unit'|Default log message (CHANGEME)
7806|WARN|NONE|CREATE_PATH: Found the goal cell, succes, bailing out|Default log message (CHANGEME)
7806|WARN|NONE|[uNIT[6]: Soldier - House 2, iCell = 1697, iGoal = 1315 ] 'Create path ... result = 0'|Default log message (CHANGEME)
7806|WARN|NONE|[uNIT[8]: Trike - House 2, iCell = 1824, iGoal = 1315 ] 'No pathindex & no nextcell, resetting unit'|Default log message (CHANGEME)
7806|WARN|NONE|CREATE_PATH: Found the goal cell, succes, bailing out|Default log message (CHANGEME)
7806|WARN|NONE|[uNIT[8]: Trike - House 2, iCell = 1824, iGoal = 1315 ] 'Create path ... result = 0'|Default log message (CHANGEME)
8754|WARN|NONE|--------|Default log message (CHANGEME)
8754|WARN|NONE|SHUTDOWN|Default log message (CHANGEME)
8755|WARN|NONE|--------|Default log message (CHANGEME)
8755|WARN|NONE|Allegro FONT library shut down.|Default log message (CHANGEME)
8755|WARN|NONE|Allegro MP3 library shut down.|Default log message (CHANGEME)
8832|WARN|NONE|Allegro shut down.|Default log message (CHANGEME)
8833|WARN|NONE|Thanks for playing.|Default log message (CHANGEME)

As you can see, changes as requested, where miliseconds are shown (from the first moment the game is started!). And using the format you suggested.

Rene · August 7, 2009

Looks great! I'll start working on the parser right away.

stefanhendriks · August 8, 2009

Looks great! I'll start working on the parser right away.

How's it going?

Rene · August 8, 2009

Still working on the parser, I think it will be able to parse some basic files later today. I have to go to work in a few hours, so I hope it will work before then.

stefanhendriks · August 8, 2009

I'm not really 'waiting' for it. So there is no presure or whatever. But I was just interested if things where going as expected (because of the complexity).

I am busy with some other things now. I've also introduced another component:

COMP_SKIRMISHSETUP

stefanhendriks · August 8, 2009

I've made a little change; where the HOUSE ID comes, i will print there the house name.

Like this:

5906|TRACE|SKIRMISHSETUP|ORDOS|0|Wants 10 amount of units; amount created 10|NONE|Creating units
5909|TRACE|SKIRMISHSETUP|HARKONNEN|1|Wants 1 amount of units; amount created 1|NONE|Creating units

Rene · August 8, 2009

I've made a little change; where the HOUSE ID comes, i will print there the house name.

Are you sure? It would make it impossible to filter between different players if two players use the same house. Maybe include both an ID and house name?

Anyway, I just came back from work and did some tests with the parser, just to notice real fast it didn't work. I've made a workaround for the problem now, but it had a real strange cause, maybe you're interested in it:

To get the different fields, I first read the complete line, and then use the 'split' method in the String class. This returns an array of Strings, split according to the specified String. But for some reason, it can't handle "|" as argument. In that case, it returns an array of strings, with every character as a separate String. To fix this, I first replace all the "|" characters with "[|]", and then split using the "[|]" as regex. Now, everything is working properly, and soon the program should be usable. Not finished or anything near that, but it should be able to read files and show them in the lists. Also, the filters will work.

But the first thing to do now is to make that darned document describing the standard, now I am using a combination of this thread and your source to look up all components, events, etc. Not a perfect solution :P

I hope to put it in the repo later tonight.

stefanhendriks · August 8, 2009

Are you sure? It would make it impossible to filter between different players if two players use the same house. Maybe include both an ID and house name?

The combination player id and house would make it unique, so it should be easy to filter?

In fact, i'm mostly interested in a specific player.

Anyway, I just ... <snip>

The reason why split with | does not work, is that the split method takes a regex as argument. See http://www.regular-expressions.info/reference.html (search for | or 'pipe')

Probably split("[|]") works because the [ ] force to match on | as a character.

I am not entirely sure about the latter, because i h*te regex and am not really into them.

Rene · August 8, 2009

Ah, that makes sense. Never heard of regular expressions before. :-[, I just thought they meant 'any expression' by it. Using the link you provided I changed the parser a bit to use "|" as regex instead of replacing something. Works like a charm now and the code got a bit cleaner. Thanks :)

stefanhendriks · August 8, 2009

No problem :)

I've checked in some code with new sidebar functionality. But it is not working yet, so please excuse the bugs introduced ;)

Rene · August 9, 2009

Made a start on the document describing the standard, and put it in the repository. I'll write more of it tomorrow, but I've had enough writing for today :P

One question about the Components enum:

What are the INIT and SETUP Components exactly for?

Will take a look at the new code tomorrow ;)

stefanhendriks · August 9, 2009

What are the INIT and SETUP Components exactly for?

In the game, i have an INIT method and a SETUP method. The setup method basically sets up the game (so is called only once). But actually I am using there COMP_ALLEGRO and such, so I wonder if the COMP_SETUP is needed.

The INIT method is called on every initialization of the 'game' (ie a new map to play).

Rene · August 11, 2009

I'm sorry for my inactivity the past few days, this real life thingy kept me busy ;)

Made some progress today on the document, it's almost completed. It describes all the stuff discussed in this thread, and a bit more. I'm afraid I've got a request for another change: since the Message and Outcome fields depend on the Event, could they be after the Event? It would make for cleaner code, and should help to prevent bugs: if these fields are before the event field, three fields need to be checked to get the event. But if the message field contains text similar to an event name, it could cause strange things happen.

Also, I've been looking at your new code today, first thing to notice was the addition of the build queue. Now that's a nice addition :)

Sign In

DEV: D2TM Logging (tool)

Recommended Posts

stefanhendriks

stefanhendriks

Rene

Rene

stefanhendriks

stefanhendriks

Rene

stefanhendriks

Rene

stefanhendriks

Rene

stefanhendriks

stefanhendriks

Rene

stefanhendriks

Rene

stefanhendriks

stefanhendriks

Rene

stefanhendriks

Rene

stefanhendriks

Rene

stefanhendriks

Rene

Join the conversation

Activity

Important Information