====== AllPeers Logging System ====== To summary what is the logging for is very simple: when something happens we have to know why. Therefor every very internal event that happens in AllPeers is logged into files. These files can be found in active profile directory and its sub-directory allpeers/log. By default there is at most 20 log files and each is at most 2MB of size. See "How To Use The AllPeers Logging Framework?" chapter to understand the format. ==== Why AllPeers Has Its Own Logging Framework? ==== Logging provided by NSPR API is heavy to use, has no simple ability to log into file. Console logging to "error console" used as XPCOM component has huge overhead and not all abilities we need. Goal of AllPeers logging is to provide very simple way to write useful informations to a single log file without large overhead. Its API concept is to provide user-friendly and simple-to-use API for logging that motivates user/programmer to create useful and full logging output. It is mainly designed to work inside component method bodies. How to use it in normal code is described in chapter Extended Usage of AllPeers Logging Framework. It also overrides the NS_ENSURE_TRUE and NS_ENSURE_SUCCESS macros. When some of these checks fails error is logged into the file. See next chapter for example of the output. Framework its self have to be initiated. It is automatically done by our core service ''apLogStartup'' that tells the global logging instance to log into a subdirectory located in the current Firefox profile directory. Exactly it can be found for example in C:\Documents and Settings\Administrator\Application Data\Mozilla\Firefox\Profiles\902bv284.default\allpeers\log\ under Windows OS. ==== How To Use The AllPeers Logging Framework? ==== To include the framework to your C or C++ file simply include one header: #include "apLogging.h" Then you have to define a name of your module: #define AP_LOG_MODULE_SCREENNAME "myloggingmodule" When this is done, you can simply use following macros inside of your code to put lines into the log file. Examples: NS_IMETHODIMP apMyClass::MyMethod() { AP_LOG1("Hallo world! It is %llu time", PR_Now()); return NS_OK; } The ''1'' in AP_LOG1 is the number of parameters you will pass for format. AP_LOG0 means that you will not pass any parameters. We use NSPR PR_snprintf function to formating the string which conforms with printf standards. This example code outputs following line into the log file: **''02-09 18:22:56 00006588 F myloggingmodule:054342ac |Hallo world! It is 89234758275892 time| apMyClass.cpp(123) UI''** ^ Value ^ Meaning ^ | ''**02-09**'' | month-date | | ''**18:22:56**'' | GMT (world global) time set on the machine | | ''**00006588**'' | time in milliseconds from start of the logging framework | | ''**F**'' | means the level of severity that is in particular described later in chapter Severity Levels | | ''**myloggingmodule**'' | the name of the module - the string you define in AP_LOG_MODULE_SCREENNAME | | ''**054342ac**'' | physical address of the component, value of ''this'' pointer; ''this'' pointer is QIed for nsISupports to always display the same value of the pointer in case of multiple inheritance; then you can grep or use other filters for parsing or filtering the log file | | ''**Hallo world! It is 89234758275892 time**'' | the user's formated message | | ''**apMyClass.cpp(123)**'' | the name of the C/C++ file and the line number where the log macro has been used | | ''**UI**'' | the name of the thread; allpeers standardly names the main UI thread as "UI"; how to name your own thread see Extended Usage of AllPeers Logging Framework chapter | ==== Logging of Error and Warning ==== There are two other standard macros to be used for logging: AP_LOGWARNn and AP_LOGERRORn. ''n'' means the number of parameter. These macros has exactly same usage as at the AP_LOGn macros. Warning and error logs produce this output: ''02-28 16:14:45 00002776 S tcp:00c8f018 |@WARN: Cannot start listen socket on port 443| apTcpStartup.cpp(352) UI'' and ''02-28 10:48:01 00611813 S core:05f08ed0 |@ERROR: NS_ENSURE_SUCCESS(rv) failed, result is 0x80070057| apCoreStartup.cpp(320) allpeers.networkcontext.socket'' Notice key words @ERROR and @WARN that are prepended to a message. Error messages are displayed always, independently on level of severity. See Severity Levels chapter. ==== Assertions Logging ==== Use AP_LOGASSERTn(condition, format string, ...) macro for that. Same as error logging AP_LOGERRORn but in debug mode check the condition. If it is false PR_ASSERT is used to break the process. In release mode only the error message is displayed. ===== Extended Usage of AllPeers Logging Framework ===== Following chapters describes only few extended features of the framework. See log/public/apLogging.h file for detailed overview of all functionality. ==== How To Use AllPeers Loggin Framework Outside Component Code? Have compilation problems with logging? ==== Key is redefinition of AP_LOG_THIS_KEY macro. This macro standardly QIs this pointer for nsISupports interfaces and displays the value to the log file. You can do it like this: #define AP_LOG_MODULE_SCREENNAME "mymodule" #define AP_LOG_THIS_KEY(result) (result) = myPointer Then used in following code void myFunction(MyClass myPointer, MyParam param) { AP_LOG0("My Message"); } will automatically take the value of myPointer and put it after name of the module like in this example: ''mymodule:0f84ea94''. ==== How To Correctly Put Other Component's Pointer to Format String? ==== If you wish to log other pointers in the formated string and those pointers are pointers to mozilla components implementing nsISupports use following code: AP_LOG1("Using my component %08p", AP_LogKey(myComponentPointer)); AP_LogKey helper function QIs the component for nsISupports to ensure that in every log message will be the correct value of a pointer displayed. Then you can grep of filter the log file using this pointer value and can be sure that you do not miss any log line. === AP_LOG_JOINT(some_object) === This produce e.g: "networkcontext:047bdd34 |@JOINT: mListener=05020e48| apConnectionManager.cpp(174)" to see that instance of apConnectionManager with address 047bdd34 holds reference to some listener object with address 05020e48. Useful to look up path in asynchronous algorithms and when searching memory leaks. === AP_LOG_SPLIT(some_object) === This is invert to the previous: "networkcontext:047bdd34 |@SPLIT: mListener=05020e48| apConnectionManager.cpp(220)", informs about release of the listener, i.e. apConnectionManager with address 047bdd34 no more holds reference to a listener object with address 05020e48. === AP_LOG_LINK_DISPOSE() === Put this exclusively into the destructor body. This simply log that the object was released from memory: "networkcontext:047bdd34, |@DISPOSE| apConnectionManager.cpp(160)" tell that instance of apConnectionManager with address 047bdd34 has been released from memory. ==== How To Give a Name My Own Thread? ==== Simply on this thread use function ''AP_LogNameThread("mythread");''. When logging macros are called on that thread the name will be appended at the end of the log line. If the thread has not a name defined NSPR thread id number is displayed instead of name. ===== Severity Levels ===== There are four severity level defined and are liken to human body. To change default level of your module's severity, redefine macro AP_LOG_MODULE_SEVERITY as in the following example: #undef AP_LOG_MODULE_SEVERITY #define AP_LOG_MODULE_SEVERITY AP_LOG_SEVERITY_SKIN Then all AP_LOGn and AP_LOGWARNn macros will output at this severity. If you wish to change severity of only particular log outputs use following macros, similar to AP_LOGn macro: AP_LOGn_WITH_SEVERITY(AP_LOG_SEVERITY_XXXX, "message format", ...); ==== #define AP_LOG_SEVERITY_MARROW 0 ==== Parts of code that do not have to be logged at all by default. These parts of code would be too much annoying to be logged and are well known as 100% working. Logging is then useless unless serious trouble occurs and we need to have really deep logging. Use this for e.g. info about socket polling, event posting that occurs too often and is always the same and simple. ==== #define AP_LOG_SEVERITY_BONE 1 ==== Parts of code that are already debugged and considered as working and do not have to be logged during normal use of the application but are usefull for internal testing and debbugging (inside of the company). With that, also these bone logs would output too much lines of log we want to avoid of during normal use of the application. These logs are usefull during replications of problems that external people report. Bone logs are used for code that have to be 99% working when leaving the company. This should be used for already debugged and almost error free helper classes and code that is used often but always on different data. Examples: background processor runner, smux and ssl core events, events inside of the download/uplaod protocols. ==== #define AP_LOG_SEVERITY_FLESH 2 ==== Parts of code that have to be debugged to preventially watch for possible problems this is standard severity for using application by external people (betatesters) These logs MUST be very well concepted and be enaught to provide information related to problems that are well known and have to be fixed. Also have to be engaged to prevent problems in the future. Most important is to use it in code that is new or that has some major changes. Remeber, when betatesters report a problem we have just this level of severity, nothing more. Examples: database, sql processing, mfp stuff, chat stuff, main events from sharing processes, source excahnge, xml packet exchange, connection processes (top level like "I am attapting to connect peer at IP:port" + "Attempt to connect failed/succeeded"). Just take care of some load of the log framework to avoid to much output on this level - put there just what you neccessarily need, nothing more. ==== #define AP_LOG_SEVERITY_SKIN 3 ==== Parts of top level code that will be logged (visible) always. This level of severity has also all ERROR logs - errors are displayed always, therefor add error only where the event logged is really an error. ==== How To Setup Severity At Runtime? ==== apLogStartup service that initialize the global logging instance reads also command line parameters. These are available: ^ Option ^ Meaning ^ | -aplogsuppress | suppresses logging to a file either a screen | | -aplogscreen | enables output of logging to screen (disabled by deafult) | | -aplogseverity marrow | enables the deepest debug logging, not recomended, waste disk space, eats CPU | | -aplogseverity bone | enables deep debug logging, may slow application a little bit down | | -aplogseverity flesh | enables standard debug logging | | -aplogseverity skin | enables only top level logging | | -aplogmodule name | enables log of a specified module, this option may be passed mupltiple times | | -aplogfilelimit number | changes the limit number of log files, default is 20 | Also there is option to set the limit number in preferences, add following line to prefs.js file as an example: user_pref("allpeers.logfilelimit", 1000); ===== Note for testers ===== Please, use only FLESH level when testing - this is default, so - do not take care of it, let AllPeers run unchanged as a ordinary external user would do. This is good feedback for us to see, if FLESH level logs are well concept and provide enaught information for us. If not, we have to overwrite them or ask you to switch to bone logging (ask me or anybody else how to do it) and try to reproduce the problem. For all except testers: please, use BONE level, especially those who test nightly builds.