|
Veteran Member
Join Date: Aug 2015
Location: Dreams, zz
|
01-13-2016
, 18:33
[TUT] How to use an efficient debug system, which does not overload the final code
|
#1
|
[Tutorial]
How to use an efficient debug system,
which do not overload your final code
Contents' Table
Introduction | go to top
Recently when developing plugins, was found a way to do a debug system that you do not need to delete after you configure it. This means that, if in the future you need to re-use you debug system, you do not need to re-create it, because it was never deleted. And was never deleted because you do not need to delete it, it is invisible to you final code and the Amx Mod X compiler itself, but not for its preprocessor.
First, here are some links to you get inside to what means to debug code, or debugging: - Debug code
- Debugging
- Good programming habits
- [TUT] Code Styling & Good Programming Habits
- [INFO] Pawn compiler constants
- PAWN Pre-Processor - Introduction - Part 1/7
- [HOW TO] Debug your plugins
- [TUT] Compiling errors
- Boston University - Debugging
- Scripting Help (Suggested) Posting Guidelines
- How to be a zero-bug programmer?
- C preprocessor
- How to fix bugs, step by step
- Finding Bugs in your Projects
- A Gentle Introduction to Programming
- Known Runtime/Compiler PAWN Bugs
Points | go to top
- This debugging system is controlled by a preprocessor directive called 'IS_DEBUG_ENABLED'. This is how we declare it to our needs:
Code:
/** This is to view internal program data while execution. See the function 'debugMesssageLogger(...)'
* and the variable 'g_debug_level' for more information. Default value: 0 - which is disabled.
*/
#define IS_DEBUG_ENABLED 1
- Once we declare it with the value 1, the preprocessor will understand that the debug system is active, then it will allow our Amx Mod X compiler to see our debugging code, i.e., compile it to our final binary file '.amxx'. But if the directive 'IS_DEBUG_ENABLED' is declared with the value 0, the preprocessor will understand that the debug system is inactive, then it will not allow our Amx Mod X compiler to see its code, i.e., compile it to our final binary file '.amxx'.
Now we define what will be our debug logger, that is controlled by our directive 'IS_DEBUG_ENABLED':
Code:
#if IS_DEBUG_ENABLED > 0
#define DEBUG_LOGGER(%1) debugMesssageLogger( %1 );
/**
* ( 0 ) 0 disabled all debug.
* ( 1 ) 1 displays basic debug messages.
*/
new g_debug_level = 1;
#else
#define DEBUG_LOGGER(%1)
#endif
- If the preprocessor directive 'IS_DEBUG_ENABLED' is declared as '1', i.e., active, we define that the preprocessor function DEBUG_LOGGER is to be recognized as our real debugger function 'debugMesssageLogger'. But if it is disabled, all debug functions at our code, will be recognized by the compiler as just a simple empty statement, which means that is like they never existed. See:
- The choice for allow semicolons on Macros
Now let us see the printer function 'debugMesssageLogger', mentioned above, with outputs the debug messages to the console:
Code:
#define LONG_STRING 256
/**
* Write debug messages to server's console accordantly to the global variable g_debug_level.
*
* @param mode the debug mode level, see the variable 'g_debug_level' for the levels.
* @param message[] the text formatting rules to display.
* @param any the variable number of formatting parameters.
*/
stock debugMesssageLogger( mode, message[], any: ... )
{
if( mode & g_debug_level )
{
static formated_message[ LONG_STRING ];
vformat( formated_message, charsmax( formated_message ), message, 3 );
server_print( "%s", formated_message );
client_print( 0, print_console, "%s", formated_message );
}
}
Gathering Everthing | go to top
So, gathering every thing mentioned until now, we get all we need to build are debug system. He it is the full code:
Code:
#include <amxmodx>
#include <amxmisc>
#define LONG_STRING 256
/** This is to view internal program data while execution. See the function 'debugMesssageLogger(...)'
* and the variable 'g_debug_level' for more information. Default value: 0 - which is disabled.
*/
#define IS_DEBUG_ENABLED 1
#if IS_DEBUG_ENABLED > 0
#define DEBUG_LOGGER(%1) debugMesssageLogger( %1 );
/**
* ( 0 ) 0 disabled all debug.
* ( 1 ) 1 displays basic debug messages.
* ( 10 ) 2 displays leaving functions messages.
* ( 100 ) 4 displays do_debug() messages.
* ( 111 ) 7 displays all debug levels.
*/
new g_debug_level = 7;
/**
* Write debug messages to server's console accordantly to the global variable g_debug_level.
*
* @param mode the debug mode level, see the variable 'g_debug_level' for the levels.
* @param message[] the text formatting rules to display.
* @param any the variable number of formatting parameters.
*/
stock debugMesssageLogger( mode, message[], any: ... )
{
if( mode & g_debug_level )
{
static formated_message[ LONG_STRING ];
vformat( formated_message, charsmax( formated_message ), message, 3 );
server_print( "%s", formated_message );
client_print( 0, print_console, "%s", formated_message );
}
}
#else
#define DEBUG_LOGGER(%1)
#endif
/*
* Called just after server activation.
*/
public plugin_init()
{
DEBUG_LOGGER( 1, "^n^nI am ENTERING on plugin_init()" )
register_plugin( "Cool Plugin", "1.0", "Addons zz" );
register_concmd( "amx_next", "do_debug" );
do_debug();
DEBUG_LOGGER( 2, "I am LEAVING on plugin_init()^n" )
}
public do_debug()
{
new hour;
new minute;
new second;
time( hour, minute, second );
DEBUG_LOGGER( 3, "^nI am doing debug, the current time is: %d:%d:%d^n", \
hour, minute, second )
}
This would out put this at the server/client console:
Code:
I am ENTERING on plugin_init()
I am doing debug, the current time is: 19:55:12
I am LEAVING on plugin_init()
Examples | go to top- This function below integrates the mapchooser Galileo:
Code:
stock client_print_color_internal( player_id, message[], any: ... )
{
new formated_message[ COLOR_MESSAGE ];
if( g_is_color_chat_supported )
{
#if AMXX_VERSION_NUM < 183
if( player_id )
{
vformat( formated_message, charsmax( formated_message ), message, 3 );
DEBUG_LOGGER( 64, "( in ) Player_Id: %d, Chat printed: %s", player_id, formated_message )
PRINT_COLORED_MESSAGE( player_id, formated_message )
}
else
{
new players_array[ 32 ];
new players_number;
get_players( players_array, players_number, "ch" );
// Figure out if at least 1 player is connected
// so we don't execute useless code
if( !players_number )
{
DEBUG_LOGGER( 64, "!players_number. players_number = %d", players_number )
return;
}
new player_id;
new string_index;
new argument_index;
new multi_lingual_constants_number;
new params_number = numargs();
new Array:multi_lingual_indexes_array = ArrayCreate();
DEBUG_LOGGER( 64, "players_number: %d, params_number: %d", players_number, params_number )
if( params_number >= 4 ) // ML can be used
{
for( argument_index = 2; argument_index < params_number; argument_index++ )
{
DEBUG_LOGGER( 64, "argument_index: %d, getarg(argument_index): %d / %s", \
argument_index, getarg( argument_index ), getarg( argument_index ) )
// retrieve original param value and check if it's LANG_PLAYER value
if( getarg( argument_index ) == LANG_PLAYER )
{
string_index = 0;
// as LANG_PLAYER == -1, check if next param string is a registered language translation
while( ( formated_message[ string_index ] =
getarg( argument_index + 1, string_index++ ) ) )
{
}
formated_message[ string_index ] = 0;
DEBUG_LOGGER( 64, "Player_Id: %d, formated_message: %s, \
GetLangTransKey( formated_message ) != TransKey_Bad: %d", \
player_id, formated_message, \
GetLangTransKey( formated_message ) != TransKey_Bad )
DEBUG_LOGGER( 64, "(multi_lingual_constants_number: %d, string_index: %d", \
multi_lingual_constants_number, string_index )
if( GetLangTransKey( formated_message ) != TransKey_Bad )
{
// Store that argument as LANG_PLAYER so we can alter it later
ArrayPushCell( multi_lingual_indexes_array, argument_index++ );
// Update ML array, so we'll know 1st if ML is used,
// 2nd how many arguments we have to change
multi_lingual_constants_number++;
}
DEBUG_LOGGER( 64, "argument_index (after ArrayPushCell): %d", argument_index )
}
}
}
DEBUG_LOGGER( 64, "(multi_lingual_constants_number: %d", multi_lingual_constants_number )
for( --players_number; players_number >= 0; players_number-- )
{
player_id = players_array[ players_number ];
if( multi_lingual_constants_number )
{
for( argument_index = 0; argument_index < multi_lingual_constants_number; argument_index++ )
{
// Set all LANG_PLAYER args to player index ( = player_id )
// so we can format the text for that specific player
setarg( ArrayGetCell( multi_lingual_indexes_array, argument_index ), _, player_id );
DEBUG_LOGGER( 64, "(argument_index: %d, player_id: %d, \
ArrayGetCell( multi_lingual_indexes_array, argument_index ): %d", \
argument_index, player_id, \
ArrayGetCell( multi_lingual_indexes_array, argument_index ) )
}
vformat( formated_message, charsmax( formated_message ), message, 3 );
}
DEBUG_LOGGER( 64, "( in ) Player_Id: %d, Chat printed: %s", player_id, formated_message )
PRINT_COLORED_MESSAGE( player_id, formated_message )
}
ArrayDestroy( multi_lingual_indexes_array );
}
#else
vformat( formated_message, charsmax( formated_message ), message, 3 );
DEBUG_LOGGER( 64, "( in ) Player_Id: %d, Chat printed: %s", player_id, formated_message )
client_print_color( player_id, print_team_default, formated_message );
#endif
}
else
{
vformat( formated_message, charsmax( formated_message ), message, 3 );
DEBUG_LOGGER( 64, "( in ) Player_Id: %d, Chat printed: %s", player_id, formated_message )
REMOVE_COLOR_TAGS( formated_message )
client_print( player_id, print_chat, formated_message );
}
DEBUG_LOGGER( 64, "( out ) Player_Id: %d, Chat printed: %s", player_id, formated_message )
}
Here is the output example:
Code:
players_number: 1, params_number: 4
argument_index: 2, getarg(argument_index): -1 /
Player_Id: 0, formated_message: GAL_CHANGE_TIMEEXPIRED, GetLangTransKey( formated_message ) != TransKey_Bad = 1
(multi_lingual_constants_number: 0, string_index: 23
argument_index: 3
(multi_lingual_constants_number: 1
(argument_index: 0, player_id: 4, ArrayGetCell( multi_lingual_indexes_array, argument_index ): 2
( in ) Player_Id: 4, Chat printed: O Limite de Tempo expirou.
( out ) Player_Id: 0, Chat printed: O Limite de Tempo expirou.
At that code you can see the use of the 'DEBUG_LOGGER' directive. Here below are the currently active debug levels at that plugin (here you can see its whole code):
Code:
#if IS_DEBUG_ENABLED > 0
#define DEBUG_LOGGER(%1) debugMesssageLogger( %1 );
/**
* ( 0 ) 0 disabled all debug.
* ( 1 ) 1 displays basic debug messages.
* ( 10 ) 2 displays players disconnect, total number, multiple time limits changes and restores.
* ( 100 ) 4 displays maps events, choices, votes, nominations, and the calls to 'map_populateList'.
* ( ... ) 8 displays vote_loadChoices( ) and actions at vote_startDirector.
* ( ... ) 16 displays messages related to RunOff voting.
* ( ... ) 32 displays messages related to the rounds end map voting.
* ( ... ) 64 displays messages related 'client_print_color_internal'.
* ( ... ) 128 execute the test units and print their out put results.
* ( 11111111 ) 255 displays all debug logs levels at server console.
*/
new g_debug_level 251
#else
#define DEBUG_LOGGER(%1)
#endif
- One tip, is that you some times need to print something that is really big and do not fit to any debug levels you already have, or you do not want to create a debug level just for it. So you declare is as debug level 1 to see it, a during the time you need, and when you do not need it anymore, change its level to 0. That level means that it will never be showed at any level, just when you go to it, and change it to an accept level as 1. For exemple, when was needed to know if all my maps was being loaded and how are they being loaded from the map directory, at the moment the nomination menu was showed. Hence, to do that was just created a debug logger with level 1 while it was needed it, and later, it was placed it to the level 0, because there are a lot of maps at the map directory, and as each one of them are being printed in one line, have it enabled at any debug level is annoying. This is the code:
Code:
stock nomination_menu( player_id )
{
// assume there'll be more than one match ( because we're lazy ) and starting building the match menu
if( g_nominationMatchesMenu[ player_id ] )
{
menu_destroy( g_nominationMatchesMenu[ player_id ] );
}
g_nominationMatchesMenu[ player_id ] = menu_create( "Nominate Map", "nomination_handleMatchChoice" );
// gather all maps that match the nomination
new mapIdx;
new info[ 1 ];
new choice[ 64 ];
new nominationMap[ 32 ];
new disabledReason[ 16 ];
for( mapIdx = 0; mapIdx < g_nominationMapCnt; mapIdx++ )
{
ArrayGetString( g_nominationMap, mapIdx, nominationMap, charsmax( nominationMap ) );
info[ 0 ] = mapIdx;
// in most cases, the map will be available for selection, so assume that's the case here
disabledReason[ 0 ] = '^0';
if( nomination_getPlayer( mapIdx ) ) // disable if the map has already been nominated
{
formatex( disabledReason, charsmax( disabledReason ), "%L", player_id,
"GAL_MATCH_NOMINATED" );
}
else if( map_isTooRecent( nominationMap ) ) // disable if the map is too recent
{
formatex( disabledReason, charsmax( disabledReason ), "%L", player_id,
"GAL_MATCH_TOORECENT" );
}
else if( equal( g_currentMap, nominationMap ) ) // disable if the map is the current map
{
formatex( disabledReason, charsmax( disabledReason ), "%L", player_id,
"GAL_MATCH_CURRENTMAP" );
}
formatex( choice, charsmax( choice ), "%s %s", nominationMap, disabledReason );
menu_additem( g_nominationMatchesMenu[ player_id ], choice, info,
( disabledReason[ 0 ] == '^0' ? 0 : ( 1 << 26 ) ) );
DEBUG_LOGGER( 0, "( nomination_menu ) choice: %s, info[0]: %d", choice, info[ 0 ] )
}
menu_display( player_id, g_nominationMatchesMenu[ player_id ] );
}
Here is the output example, when the debug level other than 0, i.e., is activated:
Code:
( nomination_menu ) choice: !!!sex_movie , info[0]: 0
( nomination_menu ) choice: !!water_iceworld , info[0]: 1
( nomination_menu ) choice: !!_STTZ_!! , info[0]: 2
( nomination_menu ) choice: !!~sex_movie , info[0]: 3
( nomination_menu ) choice: !3 , info[0]: 4
( nomination_menu ) choice: !vip_truck , info[0]: 5
...
...
...
( nomination_menu ) choice: zm_toxic_house2 , info[0]: 802
( nomination_menu ) choice: zm_uknow , info[0]: 803
( nomination_menu ) choice: zm_uknow_last_hope , info[0]: 804
( nomination_menu ) choice: zm_umbrella_v1 , info[0]: 805
( nomination_menu ) choice: zm_zombattack , info[0]: 806
( nomination_menu ) choice: zm_zombies , info[0]: 807
( cmd_say ) equali( arg1, 'nom', 3 ): 1, equali( arg1[ strlen( arg1 ) - 4 ], 'menu' ): 1
[V]iper*S| Addons zz : nomenu
L 01/11/2016 - 16:38:32: "[V]iper*S| Addons zz<1><STEAM_ID_LAN><CT>" say "nomenu"
- You can also protect a whole code block, then sometimes just the 'DEBUG_LOGGER' directives are not enough. This is an example using the IS_DEBUG_ENABLED protection:
Code:
/**
* Loads the config file "voting_list.ini" and all mods stored there.
*/
public load_votingList()
{
new currentLine [ LONG_STRING ];
new currentLine_splited [ SHORT_STRING ];
new mod_name [ SHORT_STRING ];
new mod_shortName_string[ SHORT_STRING ];
new unusedLast_string [ SHORT_STRING ];
new votingList_filePointer = fopen( g_votingList_filePath, "rt" );
while( !feof( votingList_filePointer ) )
{
fgets( votingList_filePointer, currentLine, charsmax( currentLine ) );
trim( currentLine );
// skip commentaries while reading file
if( !currentLine[ 0 ]
|| currentLine[ 0 ] == ';'
|| ( currentLine[ 0 ] == '/'
&& currentLine[ 1 ] == '/' ) )
{
continue;
}
if( currentLine[ 0 ] == '[' )
{
g_modCounter++
// remove line delimiters [ and ]
replace_all( currentLine, charsmax( currentLine ), "[", "" );
replace_all( currentLine, charsmax( currentLine ), "]", "" );
// broke the current config line, in modname ( mod_name ), modtag ( mod_shortName_string )
strtok( currentLine, mod_name, charsmax( mod_name ), currentLine_splited, charsmax( currentLine_splited ), ':', 0 );
strtok( currentLine_splited, mod_shortName_string, charsmax( mod_shortName_string ), unusedLast_string,
charsmax( unusedLast_string ), ':', 0 );
// stores at memory the modname and the modShortName
formatex( g_mod_names[ g_modCounter ], sizeof( g_mod_names[] ) - 1, "%s", mod_name );
formatex( g_mod_shortNames[ g_modCounter ], sizeof( g_mod_shortNames[] ) - 1, "%s", mod_shortName_string );
DEBUG_LOGGER( 1, "[AMX MOD Loaded] %d - %s", g_modCounter - 2, g_mod_names[ g_modCounter ] )
#if IS_DEBUG_ENABLED > 0
if( g_debug_level & 2 )
{
new mapcycle_filePath [ SHORT_STRING ];
new config_filePath [ SHORT_STRING ];
new plugin_filePath [ SHORT_STRING ];
new message_filePath [ SHORT_STRING ];
new messageResource_filePath[ SHORT_STRING ];
new lateConfig_filePath [ SHORT_STRING ];
mapcycle_pathCoder( mod_shortName_string, mapcycle_filePath, charsmax( mapcycle_filePath ) );
config_pathCoder( mod_shortName_string, config_filePath, charsmax( config_filePath ) );
plugin_pathCoder( mod_shortName_string, plugin_filePath, charsmax( plugin_filePath ) );
message_pathCoder( mod_shortName_string, message_filePath, charsmax( message_filePath ) );
messageResource_pathCoder( mod_shortName_string, messageResource_filePath,
charsmax( messageResource_filePath ) );
lateConfig_pathCoder( mod_shortName_string, lateConfig_filePath, charsmax( lateConfig_filePath ) );
server_print( "[AMX MOD Loaded] %s", mod_shortName_string );
server_print( "[AMX MOD Loaded] %s", mapcycle_filePath );
server_print( "[AMX MOD Loaded] %s", plugin_filePath );
server_print( "[AMX MOD Loaded] %s", config_filePath );
server_print( "[AMX MOD Loaded] %s", message_filePath );
server_print( "[AMX MOD Loaded] %s", lateConfig_filePath );
server_print( "[AMX MOD Loaded] %s^n", messageResource_filePath );
}
#endif
}
}
fclose( votingList_filePointer )
}
Here is the output example:
Code:
[AMX MOD Loaded] 1 - CS-DM (DeathMatch)
[AMX MOD Loaded] csdm
[AMX MOD Loaded] mapcycles/csdm.txt
[AMX MOD Loaded] addons/amxmodx/configs/multimod/plugins/csdm.ini
[AMX MOD Loaded] addons/amxmodx/configs/multimod/cfg/csdm.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/msg/csdm.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/latecfg/csdm.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/csdm.cfg
...
...
...
[AMX MOD Loaded] 13 - Zombie Mod with AmmoPacks
[AMX MOD Loaded] zp50Ammo
[AMX MOD Loaded] mapcycles/zp50Ammo.txt
[AMX MOD Loaded] addons/amxmodx/configs/multimod/plugins/zp50Ammo.ini
[AMX MOD Loaded] addons/amxmodx/configs/multimod/cfg/zp50Ammo.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/msg/zp50Ammo.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/latecfg/zp50Ammo.cfg
[AMX MOD Loaded] addons/amxmodx/configs/multimod/zp50Ammo.cfg
Final Results | go to top
Now, let show that the ' DEBUG_LOGGER' directives are really working and doing the job to keep the final compiled binary '.amxx' clean of debug statements. Here is a table containing at a relation between the mapchooser Galileo with its ' IS_DEBUG_ENABLED' directive activated, and deactivated.
Compilations data comparisons at the Amx Mod X "1.8.3-dev+4964"
Code:
Plugin name: IS_DEBUG_ENABLED 0 IS_DEBUG_ENABLED 1 Diferences
Header size: 3.532 bytes 3.860 bytes + 328 bytes
Code size: 70.936 bytes 87.104 bytes +16.168 bytes
Data size: 42.680 bytes 67.996 bytes +25.316 bytes
Stack/heap size: 16.384 bytes 16.384 bytes +0.0 bytes
Total requirements: 133.532 bytes 175.344 bytes +41.812 bytes
Compilation Time: 0,47 sec 0,55 sec
Source data
Here you can find plugins filled with this debugging system, for more examples: - https://github.com/addonszz/Galileo/blob/develop/scripting/galileo.sma
- https://github.com/addonszz/Multi-Mod_Manager/blob/develop/scripting/multimod_manager.sma
Credits | go to top
- Craxor: You can't define a macross with '//'
__________________
Last edited by addons_zz; 05-27-2017 at 10:37.
Reason: Added new tutorial
|
|
Linear Mode
