1 /*

     2 * Copyright (c) 2006 Nokia Corporation and/or its subsidiary(-ies).

     3 * All rights reserved.

     4 * This component and the accompanying materials are made available

     5 * under the terms of "Eclipse Public License v1.0"

     6 * which accompanies this distribution, and is available

     7 * at the URL "http://www.eclipse.org/legal/epl-v10.html".

     8 *

     9 * Initial Contributors:

    10 * Nokia Corporation - initial contribution.

    11 *

    12 * Contributors:

    13 *

    14 * Description:   Debug logging utility

    15 *

    16 */

    17 

    18 

    19 /**

    20 * INSTRUCTIONS

    21 *

    22 * To enable logging, add MACROs in the mmp for individual options:

    23 * This enables debug logging and the undertaker watchdog.

    24 * MACRO CATALOGS_BUILD_CONFIG_DEBUG

    25 *

    26 * Define this to direct debug output to external logger app (must be started before starting Catalogs).

    27 * Only has effect if CATALOGS_BUILD_CONFIG_DEBUG is defined.

    28 * MACRO CATALOGS_BUILD_CONFIG_DEBUG_EXT_LOGGER

    29 *

    30 * Define this to write debug output to a file using file logger (slow)

    31 * Only has effect if CATALOGS_BUILD_CONFIG_DEBUG is defined.

    32 * MACRO CATALOGS_BUILD_CONFIG_DEBUG_FILE_LOGGER

    33 *

    34 * Define this to send Catalogs debug print output to system debug log (RDebug)

    35 * Only has effect if CATALOGS_BUILD_CONFIG_DEBUG is defined.

    36 * MACRO CATALOGS_BUILD_CONFIG_DEBUG_RDEBUG

    37 *

    38 * This enables the heap checker utility, needs CATALOGS_BUILD_CONFIG_DEBUG.

    39 * Note that on ARMV5 build the heap checker is never enabled.

    40 * MACRO CATALOGS_BUILD_CONFIG_HEAP_CHECKER

    41 *

    42 * Enable method in/out logging

    43 * MACRO CATALOGS_LOG_TRACE

    44 *

    45 * Enable general logging (dltrace etc matcros)

    46 * MACRO CATALOGS_LOG_DEBUG

    47 *

    48 * Enable DASSERT macro

    49 * MACRO CATALOGS_DEBUG_ASSERTS

    50 *

    51 * This first version will create normal a normal file log.

    52 * Create dir "c:\Logs\Catalogs". Log file "debug.log" will be created there, if the 

    53 * directory exists.

    54 *

    55 * For each cpp file, include "catalogsdebug.h". 

    56 * For each MMP, include "ncddebug_20019119.lib".

    57 * For each executable, place DLINIT macro in entry code before using any debug prints, and

    58 * DLUNINIT macro in exit code after last debug prints have been made.

    59 * 

    60 * NOTE: DO NOT USE CATALOGS_FILEID. Causes trouble in branch management.

    61 * To log Perforce file and version information, do this for each cpp file:

    62 * #undef CATALOGS_FILEID

    63 * #define CATALOGS_FILEID "$Id$"

    64 * P4 will replace this with "//depot/path/file.txt#3" during the next submit.

    65 * If this define is not done, only file name is logged.

    66 * NOTE! $Id$ is only replaced if the corresponding file has keyword expansion enabled,

    67 * this can be changed by right clicking a file in the changelist and selecting 

    68 * "Change file type...".

    69 *

    70 * Logging is done using macros. Each macro automatically log the following information:

    71 * - source file name and revision (from P4), or filename if not available

    72 * - function name

    73 * - line number

    74 *

    75 * Note the double parentheses in the macros.

    76 *

    77 * Use DLTRACEIN macro to log function entry, and DLTRACEOUT to log function exit. 

    78 * DLTRACE can be used to log entries to some important parts of the code.

    79 * Example:

    80 * DLTRACEIN((_L("Input parameter aParam=%d"),aParam));

    81 * DLTRACE((_L("Branch taken")));

    82 * DLTRACEOUT((_L("Output=%d"),result));

    83 *

    84 * DLINFO can be used to log generic info:

    85 * DLINFO((_L("Parsing created an element with name %S"),&elementName));

    86 *

    87 * DLERROR can be used to log errors:

    88 * DLERROR((_L("Error while processing data error=%d, message=%S"),errorCode,&errorMessage));

    89 *

    90 * DLWARNING is used to log warnings.

    91 *

    92 * The macros support both 16-bit and 8-bit descriptors.

    93 * 8-bit format:

    94 * DLERROR(("this is a 8-bit string: %S",&K8BitString));

    95 *

    96 * NOTE! It's important to choose the right variant depending

    97 * on the %S parameter type you want to print.

    98 *

    99 * DLERRORDUMP and DLINFODUMP can be used to output hex data to the log file.

   100 *

   101 * DASSERT should be used for asserts.

   102 */

   103 

   104 

   105 #ifndef CATALOGSDEBUG_H

   106 #define CATALOGSDEBUG_H

   107 

   108 #include <e32std.h>

   109 #include <flogger.h>

   110 #include <e32msgqueue.h>

   111 

   112 #ifdef CATALOGS_BUILD_CONFIG_DEBUG

   113 // This could be overridden by each source file:

   114 //#undef CATALOGS_FILEID

   115 #define CATALOGS_FILEID __FILE__

   116 #define CATALOGS_FUNCNAME __PRETTY_FUNCTION__

   117 

   118 // panic with <filename>, <lineno>

   119 // Filename is formatted so that extension (.cpp) is dropped, and 16

   120 // rightmost characters are used. This maximises information about where problem occured.

   121 // (the code is inside if statements is in one line because otherwise doesn't compile on codewarrior)

   122 #define DEBUG_PANIC { \

   123     const TInt KPanicSize = 16; \

   124     TPtrC8 fname((const TUint8 *)CATALOGS_FILEID); \

   125     TBuf<KPanicSize> panic; \

   126     TInt dotPos = fname.LocateReverse('.'); \

   127     if ( dotPos == KErrNotFound ) { panic.Copy(fname.Right(KPanicSize)); } \

   128     else \

   129         { \

   130         TInt start = dotPos - KPanicSize; \

   131         /* we have to clip from start, panicsize=4 -> "c:\something\test.cpp" -> "test" */ \

   132         if ( start >= 0 ) { panic.Copy( fname.Mid( start, KPanicSize ) ); } \

   133         else \

   134             { /* no clipping from the start needed */ \

   135             panic.Copy( fname.Left( KPanicSize ) ); \

   136             } \

   137         }  \

   138     User::Panic( panic, __LINE__ ); }

   139 

   140 #define DLINIT { \

   141     TRAPD( err, RCatalogsDebugHeap::InstallL() ); \

   142     if( err != KErrNone ) DEBUG_PANIC; }

   143 #define DLUNINIT RCatalogsDebugHeap::Uninstall();

   144 #else

   145 #define DLINIT

   146 #define DLUNINIT

   147 #endif  // CATALOGS_BUILD_CONFIG_DEBUG

   148 

   149 // For now, enable all debug utilities disabled by default

   150 //#define CATALOGS_LOG_TRACE

   151 //#define CATALOGS_LOG_DEBUG

   152 //#define CATALOGS_DEBUG_ASSERTS

   153 

   154 #ifdef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

   155 #define CATALOGS_DEBUG_CHECKS

   156 #endif  // CATALOGS_BUILD_CONFIG_HEAP_CHECKER

   157 

   158 // Define to enable debug logger GUI

   159 //#define CATALOGS_EXT_LOGGER

   160 

   161 

   162 

   163 #if defined (CATALOGS_BUILD_CONFIG_DEBUG) && defined (CATALOGS_LOG_TRACE)

   164 #   define DLTRACE( x )     { TCatalogsDebug debug( TCatalogsDebug::ETrace,    CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print x; }

   165 #   define DLTRACEIN( x )   TCatalogsLocalExitTrace __traceIn( CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); { TCatalogsDebug debug( TCatalogsDebug::ETraceIn, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print x; }

   166 #   define DLTRACEOUT( x )  { TCatalogsDebug debug( TCatalogsDebug::ETraceOut, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID, User::FastCounter()-__traceIn.iEntryTime ); debug.Print x; __traceIn.Disable(); }

   167 #   undef TRAP_INSTRUMENTATION_LEAVE

   168 #   define TRAP_INSTRUMENTATION_LEAVE( x ) { TCatalogsDebug debug( TCatalogsDebug::ETrace, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print(_L("Leave code=%d"), x); }

   169 #else

   170 #   define DLTRACE( x )

   171 #   define DLTRACEIN( x )

   172 #   define DLTRACEOUT( x )

   173 #endif  // CATALOGS_BUILD_CONFIG_DEBUG && CATALOGS_LOG_TRACE

   174 

   175 #if defined (CATALOGS_BUILD_CONFIG_DEBUG) && defined (CATALOGS_LOG_DEBUG)

   176 #   define DLERROR( x )     { TCatalogsDebug debug( TCatalogsDebug::EError, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print x; }

   177 #   define DLWARNING( x )   { (void)__traceIn; TCatalogsDebug debug( TCatalogsDebug::EWarning, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print x; }

   178 #   define DLINFO( x )      { (void)__traceIn; TCatalogsDebug debug( TCatalogsDebug::EInfo,  CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print x; }

   179 #   define DLERRORDUMP( ptr, size, clip ) { (void)__traceIn; TCatalogsDebug debug( TCatalogsDebug::EError, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.DumpData( ptr, size, clip ); }

   180 #   define DLINFODUMP( ptr, size, clip )  { (void)__traceIn; TCatalogsDebug debug( TCatalogsDebug::EInfo,  CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.DumpData( ptr, size, clip ); }

   181 #else

   182 #   define DLERROR( x )

   183 #   define DLWARNING( x )

   184 #   define DLINFO( x )

   185 #   define DLERRORDUMP( ptr, size, clip )

   186 #   define DLINFODUMP( ptr, size, clip )

   187 #endif  // CATALOGS_BUILD_CONFIG_DEBUG && CATALOGS_LOG_DEBUG

   188 

   189 #if defined (CATALOGS_BUILD_CONFIG_DEBUG) && defined (CATALOGS_DEBUG_ASSERTS)

   190 #   define DASSERT( x ) if(!(x)) { DLERROR(("ASSERTION FAILED")); DEBUG_PANIC; }

   191 #else

   192 #   define DASSERT( x )

   193 #endif

   194 

   195 #if defined (CATALOGS_BUILD_CONFIG_DEBUG) && defined (CATALOGS_DEBUG_CHECKS)

   196   #define DCHECK_CSTACK TCatalogsLocalCleanupStackWatcher __cleanupStackWatcher;

   197   #define DCHECK_HEAP TCatalogsLocalDebugHeapActivator __debugHeapActivator;

   198   #define DCHECK \

   199     TCatalogsLocalCleanupStackWatcher __cleanupStackWatcher; \

   200     TCatalogsLocalDebugHeapActivator __debugHeapActivator;

   201 #else

   202   #define DCHECK_CSTACK

   203   #define DCHECK_HEAP

   204   #define DCHECK

   205 #endif // CATALOGS_BUILD_CONFIG_DEBUG && CATALOGS_DEBUG_CHECKS

   206 

   207 

   208 #if defined (CATALOGS_BUILD_CONFIG_DEBUG) && defined (CATALOGS_PROFILING)

   209 #   if defined(COMPONENT_CATALOGSSERVEREXE)

   210 #       define DPROFILING_BEGIN( x ) TTime x; x.HomeTime(); static TInt64 total = 0

   211 #       define DPROFILING_END( x ) { TTime now2; \

   212                     now2.HomeTime(); \

   213                     TInt64 time1 = now2.MicroSecondsFrom( x ).Int64();\

   214                     total = total + time1; \

   215                     TCatalogsDebug debug( TCatalogsDebug::ETrace, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print( "%Ld ms, total: %Ld ms", (time1 / 1000 ), (total / 1000) ); }

   216 #   else // Non-server code

   217 #       define DPROFILING_BEGIN( x ) TTime x; x.HomeTime()

   218 #       define DPROFILING_END( x ) { TTime now2; \

   219                     now2.HomeTime(); \

   220                     TInt64 time1 = now2.MicroSecondsFrom( x ).Int64();\

   221                     TCatalogsDebug debug( TCatalogsDebug::ETrace, CATALOGS_FUNCNAME, __LINE__, CATALOGS_FILEID ); debug.Print( "%Ld ms", (time1 / 1000 ) ); }

   222 #   endif

   223 #else

   224 #   define DPROFILING_BEGIN( x )

   225 #   define DPROFILING_END( x )

   226 #endif

   227 

   228 

   229 // Helpers for reference count checking

   230 #if defined (CATALOGS_BUILD_CONFIG_DEBUG)

   231 

   232     #define DREFCOUNT_IS( objectPtr, value ) { if ( objectPtr ) { (objectPtr)->AddRef(); TInt count = (objectPtr)->Release(); DASSERT( count == value ); } }

   233     

   234     #define DREFCOUNT_EVAL( objectPtr, expression ) { if ( objectPtr ) { (objectPtr)->AddRef(); TInt count = (objectPtr)->Release(); DASSERT( count expression ); } }            

   235 

   236 #else

   237 

   238     #define DREFCOUNT_IS( objectPtr, value )

   239     #define DREFCOUNT_EVAL( objectPtr, expression )

   240 

   241 #endif

   242 

   243 

   244 /**

   245  * Function-local exit tracer. When instantiated as a local variable at start of a scope (e.g. function)

   246  * makes a debug print when the scope is left (either normally or through a leave)

   247  *

   248  * @note Cannot be used in scopes that leave item(s) on cleanup stack, such as an LC function.

   249  * @note Can be used in nested scopes.

   250  */

   251 class TCatalogsLocalExitTrace

   252     {

   253 public:

   254     IMPORT_C TCatalogsLocalExitTrace( const char* aFunctionName, TInt aLine, const char* aFileId );

   255     IMPORT_C ~TCatalogsLocalExitTrace();

   256     IMPORT_C void Disable();

   257 

   258     const char* iFunctionName;

   259     TInt iLine;

   260     const char* iFileId;   

   261     TBool iDisabled;

   262     TUint32 iEntryTime;

   263     };

   264 

   265 /**

   266  * Function-local cleanup stack watcher. When instantiated as a local variable at start of a scope (e.g. function),

   267  * tracks cleanupstack balance; will cause E32USER-CBase 90 panic if cleanupstack in the beginning and end of the scope

   268  * doesn't match (one or more items have been left on cleanup stack or popped out).

   269  *

   270  * @note Cannot be used in scopes that are supposed to leave item(s) on cleanup stack, such as an LC function.

   271  * @note Can be used in nested scopes.

   272  */

   273 class TCatalogsLocalCleanupStackWatcher

   274     {

   275 public:

   276     IMPORT_C TCatalogsLocalCleanupStackWatcher();

   277     IMPORT_C ~TCatalogsLocalCleanupStackWatcher();

   278     TBool iPopped;

   279     };

   280 

   281 /**

   282  * Function-local debug heap activator. When instantiated as a local variable at start of a scope (e.g. function)

   283  * makes sure debug heap is active only within the scope.

   284  *

   285  * @note Cannot be used in scopes that leave item(s) on cleanup stack, such as an LC function.

   286  * @note Can be used in nested scopes.

   287  */

   288 class TCatalogsLocalDebugHeapActivator

   289     {

   290 public:

   291     IMPORT_C TCatalogsLocalDebugHeapActivator();

   292     IMPORT_C ~TCatalogsLocalDebugHeapActivator();

   293     TBool iPopped;

   294     TBool iActive;

   295     };

   296 

   297 

   298 // Big enough formatting buffer. If the format parameters exceeds this, a panic occurs!

   299 const TInt KCatalogsDebugBufferSize = 1024*80;

   300 

   301 /**

   302 * Debug utility class. 

   303 */

   304 class TCatalogsDebug

   305     {

   306 public:

   307     /**

   308     * Debug log event types

   309     */

   310     enum TType

   311         {

   312         ETrace,

   313         ETraceIn,

   314         ETraceOut,

   315         EError,

   316         EWarning,

   317         EInfo,

   318         ETraceLeave

   319         };

   320     

   321     enum

   322         {

   323         EOutputRDebug = 1,

   324         EOutputFileLogger = 2,

   325         EOutputExtLogger = 4

   326         };

   327         

   328     enum

   329         {

   330         EBuildOutput = 0

   331 #ifdef CATALOGS_BUILD_CONFIG_DEBUG_RDEBUG

   332         | EOutputRDebug

   333 #endif

   334 #ifdef CATALOGS_BUILD_CONFIG_DEBUG_FILE_LOGGER

   335         | EOutputFileLogger

   336 #endif

   337 #ifdef CATALOGS_BUILD_CONFIG_DEBUG_EXT_LOGGER

   338         | EOutputExtLogger

   339 #endif

   340         };

   341         

   342     /**

   343     * Constructor, sets generic information for the print.

   344     * @param aType

   345     * @param aFunction Function name

   346     * @param aLine Source code line

   347     * @param aFileId File identification

   348     */

   349     IMPORT_C TCatalogsDebug( 

   350         TType aType, 

   351         const char* aFunction, 

   352         TInt aLine, 

   353         const char* aFileId,

   354         TUint aDeltaTime = 0,

   355         TInt aOutput = EBuildOutput

   356         );

   357     

   358     /**

   359     * Print formatted data to the log, 16-bit descriptors.

   360     * @param aFmt Format string

   361     */

   362     IMPORT_C void Print( TRefByValue<const TDesC16> aFmt, ... );

   363 

   364     /**

   365     * Print formatted data to the log, 8-bit descriptors.

   366     * @param aFmt Format string

   367     */

   368     IMPORT_C void Print( const char* aFmt, ... );

   369 

   370     /**

   371     * Print hex data to the log.

   372     * @param aData Data pointer

   373     * @param aSize 

   374     * @param aClipToSize 

   375     */

   376     IMPORT_C void DumpData( const TAny* aData, TInt aSize, TInt aClipToSize );

   377 

   378 private:

   379     void PrintGeneral( TPtr8 aPrintBuf );

   380     void FileWrite( const TDesC8& aPrintBuf );

   381 

   382 private:

   383 

   384     TType       iType;

   385     const char* iFunction;

   386     TInt        iLine;

   387     const char* iFileId;

   388     TUint       iDeltaTime;

   389     TInt        iOutput;

   390     };

   391 

   392 /**

   393  * Debug heap implementation. Holds "global" data for debug printing, and has

   394  * utilities for finding memory leaks.

   395  */

   396 class RCatalogsDebugHeap : public RHeap

   397     {

   398 public:

   399 

   400     IMPORT_C static void InstallL( TBool aEnabled = 

   401 #ifdef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

   402         ETrue );

   403 #else

   404         EFalse );

   405 #endif    

   406     IMPORT_C static void Uninstall();

   407     IMPORT_C static TBool Activate( TBool aActive );

   408 

   409     void ChunkOutput( const TDesC8& aBuffer, TUint aDeltaTime );

   410     TBool IsEnabled( TCatalogsDebug::TType aPrintType );

   411 

   412 public: // from RHeap

   413 

   414     TAny* Alloc( TInt aSize );

   415     void Free( TAny* aPtr );

   416     TAny* ReAlloc(TAny* aPtr, TInt aSize, TInt aMode=0);

   417     TInt AllocLen(const TAny* aCell) const;

   418     TInt Compress();

   419     void Reset();

   420     TInt AllocSize(TInt& aTotalAllocSize) const;

   421     TInt Available(TInt& aBiggestBlock) const;

   422     TInt DebugFunction(TInt aFunc, TAny* a1=NULL, TAny* a2=NULL);

   423 

   424     TAny* operator new( TUint aSize );

   425     void operator delete( TAny* aPtr );

   426 

   427 protected: // from RHeap

   428     TInt Extension_(TUint aExtensionId, TAny*& a0, TAny* a1);

   429 

   430     RCatalogsDebugHeap( RHeap& aBaseHeap, TBool aEnabled );

   431     ~RCatalogsDebugHeap();

   432 

   433 private:

   434 

   435     RHeap&  iBaseHeap;

   436     TInt    iAllocCounter; // running counter for allocs

   437     

   438     struct TAllocInfo

   439         {

   440         TAny*   iAllocPtr;

   441         TInt    iAllocSize;

   442         TInt    iAllocNum;

   443         };

   444 

   445     RArray< TAllocInfo > iAllocInfo;

   446     TBool               iEnabled;

   447     TBool               iActive;

   448 

   449     // Debug chunk logging

   450     void InitExtLogger();

   451 

   452     TInt    iChunkIndex;    // current chunk index

   453     RChunk  iChunk[2];

   454     RSemaphore iChunkWriteSemaphore;

   455     RMutex  iMutex;

   456     RMsgQueue<TInt> iMsgQueue;

   457     

   458     TUint   iFastCounterFrequency;

   459     };

   460 

   461 #endif // CATALOGSDEBUG_H