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:   Implementation of debug logging utilities

    15 *

    16 */

    17 

    18 

    19 #ifndef __WINS__

    20 #   ifdef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

    21 #       undef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

    22 #       warning "Automatically disabling heap checker in ARMV5 build!"

    23 #   endif

    24 #   ifdef CATALOGS_BUILD_CONFIG_DEBUG

    25 #       warning "Debug logging on in ARM5 build"!

    26 #   endif

    27 #endif

    28 

    29 #ifdef __WINS__

    30 #   ifdef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

    31 #      warning "Heap checker available!"

    32 #   endif

    33 #endif

    34 

    35 // Enable this to get alternative XML output

    36 //#define CATALOGS_DEBUG_XML

    37 

    38 // Quick method to disable debug functions:

    39 // #undef CATALOGS_BUILD_CONFIG_DEBUG

    40 // #undef CATALOGS_BUILD_CONFIG_HEAP_CHECKER

    41 // #undef CATALOGS_EXT_LOGGER

    42 

    43 #include <flogger.h>

    44 #include <e32msgqueue.h>

    45 #include <e32property.h>

    46 #include <hal.h>

    47 

    48 #include "catalogsdebug.h"

    49 #include "e32debug.h"

    50 

    51 #ifndef __WINS__

    52 extern "C" TUint32 GetStackPointer();

    53 #endif

    54 

    55 //#define _DDPRINT( x ) RDebug::Printf x

    56 #define _DDPRINT( x )

    57 

    58 // Logger includes from ../../debuglogger/inc/

    59 #include "catalogsdebugdefs.h"

    60 #include "catalogslogger.hrh"

    61 

    62 #undef CATALOGS_FILEID

    63 #define CATALOGS_FILEID "$Id: //depot/nf-catalogs/impl/catalogs/engine/src/catalogsdebug.cpp#43 $"

    64 

    65 #ifdef CATALOGS_DEBUG_XML

    66 _LIT8( KCatalogsError,   "error" );

    67 _LIT8( KCatalogsWarning, "warning" );

    68 _LIT8( KCatalogsInfo, "info" );

    69 _LIT8( KCatalogsTraceIn, "func" );

    70 _LIT8( KCatalogsTraceOut, "out" );

    71 _LIT8( KCatalogsTraceLeave, "leave" );

    72 _LIT8( KCatalogsTrace, "trace" );

    73 _LIT8( KLogDir, "Catalogs" );

    74 _LIT8( KLogName, "debug.log" );

    75 #else

    76 _LIT8( KCatalogsError,   "ERROR" );

    77 _LIT8( KCatalogsWarning, "WARNING" );

    78 _LIT8( KCatalogsInfo, "INFO" );

    79 _LIT8( KCatalogsTraceIn, "-->" );

    80 _LIT8( KCatalogsTraceOut, "<--" );

    81 _LIT8( KCatalogsTraceLeave, "<--LEAVE" );

    82 _LIT8( KCatalogsTrace, "@" );

    83 _LIT8( KCatalogsSeparator, "\t" );

    84 _LIT( KLogDir, "Catalogs" );

    85 _LIT( KLogName, "debug.log" );

    86 #endif

    87 

    88 const TInt KLineLength = 120;

    89 

    90 #ifdef CATALOGS_BUILD_CONFIG_DEBUG

    91 static void Append( const char* aText, TDes16& aDestination )

    92     {

    93     TPtrC8 ptr( reinterpret_cast<const TUint8*>( aText ) );

    94     for ( TInt i = 0; i < ptr.Length(); i++ )

    95         {

    96         aDestination.Append( ptr[i] );

    97         }

    98     }

    99 #endif

   100 

   101 #ifndef CATALOGS_DEBUG_XML

   102 static void Append( TPtrC8 aText, TDes8& aDestination, TInt aLength = 60 )

   103     {

   104     for ( TInt i = 0; i < aLength; i++ )

   105         {

   106         if ( i < aText.Length() )

   107             {

   108             aDestination.Append( aText[i] );

   109             }

   110         else

   111             {

   112             aDestination.Append( '.' );

   113             }

   114         }

   115     }

   116 #else

   117 static void Append( TPtrC8 aText, TDes16& aDestination )

   118     {

   119     TInt len = aText.Length();

   120     for ( TInt i = 0; i < len; i++ )

   121         {

   122         aDestination.Append( aText[i] );

   123         }

   124     }

   125 

   126 const TDesC8& TypeTag( TCatalogsDebug::TType aType )

   127     {

   128     switch ( aType )

   129         {

   130         case TCatalogsDebug::EInfo:

   131             return KCatalogsInfo;

   132             break;

   133 

   134         case TCatalogsDebug::EError:

   135             return KCatalogsError;

   136             break;

   137 

   138         case TCatalogsDebug::EWarning:

   139             return KCatalogsWarning;

   140             break;

   141 

   142         case TCatalogsDebug::ETrace:

   143             return KCatalogsTrace;

   144             break;

   145 

   146         case TCatalogsDebug::ETraceIn:

   147             return KCatalogsTraceIn;

   148             break;

   149 

   150         case TCatalogsDebug::ETraceOut:

   151             return KCatalogsTraceOut;

   152             break;

   153             

   154         case TCatalogsDebug::ETraceLeave:

   155             return KDebugLoggerTraceLeave;

   156             break;            

   157 

   158         default:

   159             DASSERT( EFalse );

   160             break;

   161         }

   162 

   163     return KNullDesC(); // for compiler

   164     }

   165 

   166 #endif

   167 

   168 EXPORT_C TCatalogsDebug::TCatalogsDebug(

   169     TType aType,

   170     const char* aFunction,

   171     TInt aLine,

   172     const char* aFileId,

   173     TUint aDeltaTime,

   174     TInt aOutput )

   175         : iType( aType ), iFunction( aFunction ), iLine( aLine ), iFileId( aFileId ), 

   176           iDeltaTime( aDeltaTime ), iOutput( aOutput )

   177     {}

   178 

   179 inline RCatalogsDebugHeap* DebugHeap()

   180     {

   181     return static_cast< RCatalogsDebugHeap* >( &User::Heap() );

   182     }

   183 

   184 void TCatalogsDebug::PrintGeneral( TPtr8 aPrintBuf )

   185     {

   186 #ifdef CATALOGS_DEBUG_XML

   187 

   188     // Insert start tag beginning.

   189     aPrintBuf.AppendFormat( "<%S name=\"", &TypeTag( iType ) );

   190         

   191     // Process the function string. Assume __PRETTY_FUNCTION__ -style string

   192     TPtrC8 func( reinterpret_cast<const TUint8*>( iFunction ) );

   193     // drop params

   194     func.Set( func.Left( func.Locate( '(' ) ) );

   195     // drop return value (if specified)

   196     TInt nameStart = func.LocateReverse( ' ' );

   197     if ( nameStart != KErrNotFound )

   198         {

   199         func.Set( func.Mid( nameStart+1 ) );

   200         }

   201 

   202     // Insert method name

   203     aPrintBuf.Append( func );

   204     aPrintBuf.Append( "\" file=\"" );

   205 

   206     // Insert file name

   207     aPrintBuf.Append( TDesC8( iFileId ) );

   208 

   209     // Insert the rest of the attributes

   210     RThread thread;

   211     TInt totalAllocSize = 0;

   212     User::AllocSize( totalAllocSize );

   213     aPrintBuf.AppendFormat( "\" line=\"%d\" thread=\"%x%x\" alloc=\"%d\">",

   214         iLine, (TUint32)(thread.Id().Id()>>32), (TUint32)thread.Id().Id(), totalAllocSize>>10 );

   215     

   216 #else   // CATALOGS_DEBUG_XML

   217 

   218     // Insert current thread id.

   219     RThread thread;

   220     aPrintBuf.AppendNum( thread.Id().Id(), EHex );

   221     aPrintBuf.Append( ' ' );

   222 

   223     // Process the function string. Assume __PRETTY_FUNCTION__ -style string

   224     TPtrC8 ptr( reinterpret_cast<const TUint8*>( iFunction ) );

   225     // drop params

   226     ptr.Set( ptr.Left( ptr.Locate( '(' ) ) );

   227     // drop return value (if specified)

   228     TInt nameStart = ptr.LocateReverse( ' ' );

   229     if ( nameStart != KErrNotFound )

   230         {

   231 //        aPrintBuf.Append( ptr.Mid( nameStart+1 ) );

   232         Append( ptr.Mid( nameStart+1 ), aPrintBuf );

   233         }

   234     else

   235         {

   236 //        aPrintBuf.Append( ptr );

   237         Append( ptr, aPrintBuf );

   238         }

   239     aPrintBuf.Append( KCatalogsSeparator );

   240     aPrintBuf.AppendNum( iLine );

   241     aPrintBuf.Append( KCatalogsSeparator );

   242 

   243     TInt totalAllocSize = 0;

   244     User::AllocSize( totalAllocSize );

   245     aPrintBuf.Append( 'M' );

   246     aPrintBuf.AppendNum( totalAllocSize>>10 );

   247 

   248     TThreadStackInfo stackInfo;

   249     TInt err = thread.StackInfo( stackInfo );

   250     if( err == KErrNone )

   251         {

   252 #ifdef __WINS__        

   253         volatile TInt32 currentSp=0;

   254         __asm { mov currentSp, esp }

   255 #else

   256         TInt32 currentSp = GetStackPointer();

   257 #endif        

   258 //         TInt remainingStack = currentSp - (TInt)stackInfo.iLimit;

   259         TInt remainingStack = (TInt)stackInfo.iBase - currentSp;

   260         aPrintBuf.Append( '/' );

   261         if( remainingStack > 1023 )

   262             {

   263             aPrintBuf.AppendNum( remainingStack >> 10 );

   264             aPrintBuf.Append( 'k' );

   265             }

   266         else

   267             {

   268             aPrintBuf.AppendNum( remainingStack );

   269             }

   270         }

   271 

   272     aPrintBuf.Append( KCatalogsSeparator );

   273 

   274     switch ( iType )

   275         {

   276         case EError:

   277             aPrintBuf.Append( KCatalogsError );

   278             break;

   279 

   280         case EWarning:

   281             aPrintBuf.Append( KCatalogsWarning );

   282             break;

   283 

   284         case ETrace:

   285             aPrintBuf.Append( KCatalogsTrace );

   286             break;

   287 

   288         case ETraceIn:

   289             aPrintBuf.Append( KCatalogsTraceIn );

   290             break;

   291 

   292         case ETraceOut:

   293             aPrintBuf.Append( KCatalogsTraceOut );

   294             break;            

   295 

   296         case ETraceLeave:

   297         	aPrintBuf.Append( KCatalogsTraceLeave );

   298             break;            

   299 

   300         case EInfo:

   301             aPrintBuf.Append( KCatalogsInfo );

   302             break;

   303 

   304         default:

   305             break;

   306         }

   307         

   308 #endif // CATALOGS_DEBUG_XML

   309     }

   310 

   311 

   312 void TCatalogsDebug::FileWrite( const TDesC8& aPrintBuf )

   313     {

   314     TLex8 lex( aPrintBuf );

   315     TInt length = KLineLength;

   316     lex.Mark();

   317     while ( ! lex.Eos() )

   318         {

   319         while ( length-- > 0 && ! lex.Eos() )

   320             {

   321             lex.Inc();

   322             }

   323         length = KLineLength;

   324         TPtrC8 line( lex.MarkedToken() );

   325         lex.Mark();

   326         RFileLogger::Write( KLogDir, KLogName, EFileLoggingModeAppend, line );

   327         }

   328     }

   329 

   330 EXPORT_C void TCatalogsDebug::Print( TRefByValue<const TDesC16> aFmt, ... )

   331     {

   332     VA_LIST list;

   333     VA_START( list, aFmt );

   334 

   335     if( iOutput & EOutputExtLogger )

   336         if( !DebugHeap()->IsEnabled( iType ) ) return;

   337 

   338     // Disable debug heap (if installed) to prevent infinite recursion.

   339     TBool debugHeapActive = RCatalogsDebugHeap::Activate( EFalse );

   340 

   341     HBufC8* buffer = HBufC8::New( KCatalogsDebugBufferSize );

   342     if ( buffer == NULL ) goto exit1;

   343 

   344     PrintGeneral( buffer->Des() );

   345     

   346     HBufC* buffer16 = HBufC::New( KCatalogsDebugBufferSize );

   347     if ( buffer16 == NULL ) goto exit2;

   348     buffer16->Des().AppendFormatList( aFmt, list );

   349 

   350     HBufC8* buffer16to8 = HBufC8::New( buffer16->Length() );

   351     if ( buffer16to8 == NULL ) goto exit3;

   352     buffer16to8->Des().Copy( *buffer16 );

   353 

   354 #ifndef CATALOGS_DEBUG_XML

   355     buffer->Des().Append( KCatalogsSeparator );

   356 

   357     buffer->Des().Append( *buffer16to8 );

   358 #else

   359     TInt formatPos = buffer->Length();

   360     buffer->Des().Append( *buffer16to8 );

   361     // replace xml-evil chars with ¤

   362     TPtr8 formattedText = buffer->Des().MidTPtr( formatPos );

   363     TInt pos;

   364 

   365     while( (pos = formattedText.Locate( '<' )) != KErrNotFound )

   366         {

   367         formattedText[pos] = '¤';

   368         }

   369     while( (pos = formattedText.Locate( '>' )) != KErrNotFound )

   370         {

   371         formattedText[pos] = '¤';

   372         }

   373     while( (pos = formattedText.Locate( '&' )) != KErrNotFound )

   374         {

   375         formattedText[pos] = '¤';

   376         }

   377     

   378 #endif

   379 

   380 #ifdef CATALOGS_DEBUG_XML

   381     // In tag is not closed until after out

   382     if( iType != ETraceIn )

   383         {

   384         // close the tag

   385         buffer->Des().AppendFormat( "</%S>", &TypeTag( iType ) );

   386         if( iType == ETraceOut || iType == ETraceLeave )

   387             {

   388             buffer->Des().AppendFormat( "</%S>", &KCatalogsTraceIn() );

   389             }

   390         }

   391 #endif

   392 

   393     if( iOutput & EOutputRDebug )

   394         RDebug::Printf( (char*)buffer->Des().PtrZ() );

   395 

   396     if( iOutput & EOutputExtLogger )

   397         DebugHeap()->ChunkOutput( *buffer, iDeltaTime );

   398 

   399     if( iOutput & EOutputFileLogger )

   400         FileWrite( *buffer );

   401 

   402     delete buffer16to8;

   403 exit3:

   404     delete buffer16;

   405 exit2:

   406     delete buffer;

   407 exit1:

   408 

   409     RCatalogsDebugHeap::Activate( debugHeapActive );

   410     }

   411 

   412 

   413 EXPORT_C void TCatalogsDebug::Print( const char* aFmt, ... )

   414     {

   415     VA_LIST list;

   416     VA_START( list, aFmt );

   417 

   418     if( iOutput & EOutputExtLogger )

   419         {

   420         if( !DebugHeap()->IsEnabled( iType ) ) return;

   421         }

   422 

   423     // Disable debug heap (if installed) to prevent infinite recursion.

   424     TBool debugHeapActive = RCatalogsDebugHeap::Activate( EFalse );

   425 

   426     HBufC8* buffer = HBufC8::New( KCatalogsDebugBufferSize );

   427     if ( buffer == NULL ) return;

   428 

   429     PrintGeneral( buffer->Des() );

   430 #ifndef CATALOGS_DEBUG_XML

   431     buffer->Des().Append( KCatalogsSeparator );

   432     buffer->Des().AppendFormatList( TPtrC8( ( const TUint8* )aFmt ), list );

   433 #else

   434     TInt formatPos = buffer->Length();

   435     buffer->Des().AppendFormatList( TPtrC8( ( const TUint8* )aFmt ), list );

   436 

   437     // replace xml-evil chars with ¤

   438     TPtr8 formattedText = buffer->Des().MidTPtr( formatPos );

   439     TInt pos;

   440     while( (pos = formattedText.Locate( '<' )) != KErrNotFound )

   441         {

   442         formattedText[pos] = '¤';

   443         }

   444     while( (pos = formattedText.Locate( '>' )) != KErrNotFound )

   445         {

   446         formattedText[pos] = '¤';

   447         }

   448     while( (pos = formattedText.Locate( '&' )) != KErrNotFound )

   449         {

   450         formattedText[pos] = '¤';

   451         }

   452 

   453     // In tag is not closed until after out

   454     if( iType != ETraceIn )

   455         {

   456         // close the tag

   457         buffer->Des().AppendFormat( "</%S>", &TypeTag( iType ) );

   458         if( iType == ETraceOut || iType == ETraceLeave )

   459             {

   460             buffer->Des().AppendFormat( "</%S>", &KCatalogsTraceIn() );

   461             }

   462         }

   463 #endif

   464 

   465     if( iOutput & EOutputRDebug )

   466         RDebug::Printf( (char*)buffer->Des().PtrZ() );

   467 

   468     if( iOutput & EOutputExtLogger )

   469         DebugHeap()->ChunkOutput( *buffer, iDeltaTime );

   470 

   471     if( iOutput & EOutputFileLogger )

   472         FileWrite( *buffer );

   473 

   474     delete buffer;

   475 

   476     RCatalogsDebugHeap::Activate( debugHeapActive );

   477     }

   478 

   479 

   480 EXPORT_C void TCatalogsDebug::DumpData( const TAny* aData, TInt aSize, TInt aClipToSize )

   481     {

   482     TInt size = aSize;

   483 

   484     Print( "dump: %d bytes total", aSize );

   485 

   486     TUint8* data = ( TUint8* )aData;

   487 

   488     while ( size > 0 )

   489         {

   490         // Cut dumps of > aClipToSize from the middle.

   491         if ( ( aSize-size > aClipToSize/2 ) && ( size > aClipToSize/2 ) )

   492             {

   493             TInt clipAmount = ( ( aSize - aClipToSize ) / 8 + 1 ) * 8;

   494 

   495             Print( "... %d bytes of data clipped ...", clipAmount );

   496 

   497             size -= clipAmount;

   498             data += clipAmount;

   499             continue;

   500             }

   501 

   502         switch ( size )

   503             {

   504             case 1:

   505                 Print( "%04x: %02x", aSize-size,

   506                        ( TInt )data[0] );

   507                 break;

   508 

   509             case 2:

   510                 Print( "%04x: %02x %02x", aSize-size,

   511                        ( TInt )data[0], ( TInt )data[1] );

   512                 break;

   513 

   514             case 3:

   515                 Print( "%04x: %02x %02x %02x", aSize-size,

   516                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2] );

   517                 break;

   518 

   519             case 4:

   520                 Print( "%04x: %02x %02x %02x %02x", aSize-size,

   521                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2],

   522                        ( TInt )data[3] );

   523                 break;

   524 

   525             case 5:

   526                 Print( "%04x: %02x %02x %02x %02x %02x", aSize-size,

   527                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2],

   528                        ( TInt )data[3], ( TInt )data[4] );

   529                 break;

   530 

   531             case 6:

   532                 Print( "%04x: %02x %02x %02x %02x %02x %02x", aSize-size,

   533                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2],

   534                        ( TInt )data[3], ( TInt )data[4], ( TInt )data[5] );

   535                 break;

   536 

   537             case 7:

   538                 Print( "%04x: %02x %02x %02x %02x %02x %02x %02x", aSize-size,

   539                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2],

   540                        ( TInt )data[3], ( TInt )data[4], ( TInt )data[5],

   541                        ( TInt )data[6] );

   542                 break;

   543 

   544             default:    // 8 or more

   545                 Print( "%04x: %02x %02x %02x %02x %02x %02x %02x %02x", aSize-size,

   546                        ( TInt )data[0], ( TInt )data[1], ( TInt )data[2],

   547                        ( TInt )data[3], ( TInt )data[4], ( TInt )data[5],

   548                        ( TInt )data[6], ( TInt )data[7] );

   549                 break;

   550             }

   551 

   552         size -= 8;

   553         data += 8;

   554         }

   555     }

   556 

   557 

   558 TBool RCatalogsDebugHeap::IsEnabled( TCatalogsDebug::TType aPrintType )

   559     {

   560     if( iChunkIndex == -1 ) return EFalse;

   561     TCatalogsDebugChunkHeader* header = (TCatalogsDebugChunkHeader*)iChunk[iChunkIndex].Base();

   562 

   563     switch( aPrintType )

   564         {

   565         case TCatalogsDebug::EError:

   566             return header->iFlags & ECatalogsDebugFlagEnableError;

   567 

   568         case TCatalogsDebug::EWarning:

   569             return header->iFlags & ECatalogsDebugFlagEnableWarning;

   570 

   571         case TCatalogsDebug::EInfo:

   572             return header->iFlags & ECatalogsDebugFlagEnableInfo;

   573 

   574         case TCatalogsDebug::ETrace:

   575         case TCatalogsDebug::ETraceIn:

   576         case TCatalogsDebug::ETraceOut:

   577         case TCatalogsDebug::ETraceLeave:

   578             return header->iFlags & ECatalogsDebugFlagEnableTrace;

   579         }

   580     return EFalse;

   581     }

   582 

   583 void RCatalogsDebugHeap::ChunkOutput( const TDesC8& aBuffer, TUint aDeltaTime )

   584 {

   585     if( iChunkIndex == -1 )

   586         return; // not initialized ok; debuglogger app propably not running

   587 

   588     // Get access to output.

   589     iMutex.Wait();

   590 

   591     // Read the output chunk header.

   592     TCatalogsDebugChunkHeader* header = (TCatalogsDebugChunkHeader*)iChunk[iChunkIndex].Base();

   593     if( header->iFlags & ECatalogsDebugFlagFlushChunk )

   594     {

   595     _DDPRINT(( "DPRN: Debug chunk %d -> %d, flushed by someone else", iChunkIndex, iChunkIndex ^ 1 ));

   596 

   597         // Chunk flushed, need to switch.

   598         iChunkIndex ^= 1;   // toggle 0/1

   599     

   600         header = (TCatalogsDebugChunkHeader*)iChunk[iChunkIndex].Base();

   601     }

   602     

   603     if( header->iFlags & ECatalogsDebugFlagFlushChunk )

   604     {

   605         // Horror error

   606         DASSERT( EFalse );

   607     }

   608     

   609     // Now we have exclusive access to writable chunk.

   610     

   611     // Generate time stamp.

   612 

   613     TUint32 fastCounter = User::FastCounter();

   614 /*

   615     TBuf8< 14 > timeStamp;  // HH:mm:ss.ss

   616     TUint32 hours = fastCounter / (fastCounterFrequency*60*60);

   617     fastCounter -= hours * (fastCounterFrequency*60*60);

   618     TUint32 minutes = fastCounter / (fastCounterFrequency*60);

   619     fastCounter -= minutes * (fastCounterFrequency*60);

   620     TUint32 seconds = fastCounter / fastCounterFrequency;

   621     fastCounter -= seconds * fastCounterFrequency;

   622     TUint32 secondParts = fastCounter / (fastCounterFrequency / 100 );

   623     

   624     timeStamp.Format( "%02d:%02d:%02d.%02d", hours, minutes, seconds, secondParts );

   625 */

   626 

   627     TBuf8< 32 > timeStamp;

   628     TUint32 seconds = fastCounter / iFastCounterFrequency;

   629     TUint32 secondParts = (fastCounter % iFastCounterFrequency) * 1000 / iFastCounterFrequency;

   630     if( aDeltaTime != 0 )

   631         {

   632         TUint32 dseconds = aDeltaTime / iFastCounterFrequency;

   633         TUint32 dsecondParts = (aDeltaTime % iFastCounterFrequency) * 10000 / iFastCounterFrequency;

   634         timeStamp.Format( _L8("%u.%03u %u.%04u\t"), seconds, secondParts, dseconds, dsecondParts );

   635         }

   636     else

   637         {

   638         timeStamp.Format( _L8("%u.%03u       \t"), seconds, secondParts );

   639         }

   640     

   641 //    aPrintBuf.AppendNum( User::FastCounter() );

   642     

   643     TInt spaceRemaining = KCatalogsDebugChunkSize - sizeof( TCatalogsDebugChunkHeader) - header->iOffset;

   644     if( spaceRemaining < (timeStamp.Size() + aBuffer.Size() + KCatalogsDebugLineSeparator().Size() ) )

   645     {

   646         _DDPRINT(( "DPRN: Debug chunk %d -> %d, full, flushing", iChunkIndex, iChunkIndex ^ 1 ));

   647 

   648         // Not enough space for writing the entry to current chunk, need to flush it.

   649         header->iFlags |= ECatalogsDebugFlagFlushChunk;

   650         iMsgQueue.Send( iChunkIndex );

   651         

   652         // Switch to the other chunk, not letting other threads get in between

   653         iChunkIndex ^= 1;   // toggle 0/1

   654         

   655         // Get access to the new chunk. Will block if the block is still being processed by ext-logger.

   656         // The semaphore will be signalled by ext-logger after the chunk has been processed.

   657         _DDPRINT(( "DPRN: Debug chunk write semaphore wait" ));

   658         iChunkWriteSemaphore.Wait();

   659         _DDPRINT(( "DPRN: Debug chunk write semaphore wait done" ));

   660 

   661         // Initialize the new chunk.

   662         header = (TCatalogsDebugChunkHeader*)iChunk[iChunkIndex].Base();

   663         header->iFlags &= ~ECatalogsDebugFlagFlushChunk;

   664         header->iOffset = 0;

   665     }

   666     

   667     // Copy the output buffer to output chunk.

   668     TUint8* ptr = (TUint8*)(header+1) + header->iOffset;

   669     Mem::Copy( ptr, timeStamp.Ptr(), timeStamp.Size() );

   670     ptr += timeStamp.Size();

   671     Mem::Copy( ptr, aBuffer.Ptr(), aBuffer.Size() );

   672     ptr += aBuffer.Size();

   673     Mem::Copy( ptr, KCatalogsDebugLineSeparator().Ptr(), KCatalogsDebugLineSeparator().Size() );

   674  

   675     // Update the output chunk header.

   676     header->iOffset += timeStamp.Size() + aBuffer.Size() + KCatalogsDebugLineSeparator().Size();

   677 

   678     // Release output for others.

   679     iMutex.Signal(); 

   680 }

   681 

   682 void RCatalogsDebugHeap::InitExtLogger()

   683 {

   684     TInt err = iChunk[0].OpenGlobal( KCatalogsDebugChunk1Name, EFalse );

   685     if( err != KErrNone ) return;

   686 

   687     err = iChunk[1].OpenGlobal( KCatalogsDebugChunk2Name, EFalse );

   688     if( err != KErrNone ) return;

   689     

   690     err = iMutex.OpenGlobal( KCatalogsDebugMutexName );

   691     if( err != KErrNone ) return;

   692 

   693     err = iChunkWriteSemaphore.OpenGlobal( KCatalogsDebugChunkWriteSemaphoreName );

   694     if( err != KErrNone ) return;

   695 

   696     err = iMsgQueue.OpenGlobal( KCatalogsDebugMsgQueueName );

   697     if( err != KErrNone ) return;

   698 

   699     TInt freq = 0;

   700     err = HAL::Get( HALData::EFastCounterFrequency, freq );

   701     DASSERT( freq >= 0 );

   702     iFastCounterFrequency = (TUint)freq;

   703     if( err != KErrNone ) return;

   704 

   705     // Init ok, start with chunk 0.

   706     iChunkIndex = 0;

   707     }

   708 

   709 EXPORT_C void RCatalogsDebugHeap::InstallL( TBool aEnabled )

   710     {

   711 //    DLTRACEIN( ( "" ) );

   712     RHeap* oldHeap = &User::Heap();

   713 //    DLINFO( ( "Previous heap at %08x", oldHeap ) );

   714     RCatalogsDebugHeap* heap = new RCatalogsDebugHeap( *oldHeap, aEnabled );

   715     heap->InitExtLogger();

   716 //    DLINFO( ( "Created debug heap at %08x, switching", heap ) );

   717     User::SwitchHeap( heap );

   718 //    DLTRACEOUT( ( "" ) );

   719     }

   720 

   721 EXPORT_C TBool RCatalogsDebugHeap::Activate( TBool aActive )

   722     {

   723     // Need some clever way to check that User::Heap() really is our heap.

   724     RCatalogsDebugHeap* heap = static_cast< RCatalogsDebugHeap* >( &User::Heap() );

   725     TBool result = heap->iActive;

   726     heap->iActive = aActive;

   727     return result;

   728     }

   729 

   730 RCatalogsDebugHeap::RCatalogsDebugHeap( RHeap& aBaseHeap, TBool aEnabled )

   731     : iBaseHeap( aBaseHeap ), iAllocCounter( 0 ), iAllocInfo( 1024 /*list granularity*/ ), 

   732     iEnabled( aEnabled ), iActive( EFalse ), iChunkIndex( -1 )

   733     {

   734     }

   735 

   736 RCatalogsDebugHeap::~RCatalogsDebugHeap()

   737     {

   738     iAllocInfo.Reset();

   739     iChunk[0].Close();

   740     iChunk[1].Close();

   741     iChunkWriteSemaphore.Close();

   742     iMutex.Close();

   743     iMsgQueue.Close();

   744     }

   745 

   746 TAny* RCatalogsDebugHeap::operator new( TUint aSize )

   747     {

   748     return User::Heap().Alloc( aSize );

   749     }

   750 

   751 void RCatalogsDebugHeap::operator delete( TAny* aPtr )

   752     {

   753     User::Heap().Free( aPtr );

   754     }

   755 

   756 EXPORT_C void RCatalogsDebugHeap::Uninstall()

   757     {

   758     RCatalogsDebugHeap* heap = static_cast< RCatalogsDebugHeap* >( &User::Heap() );

   759 

   760     if( heap->iEnabled )

   761         {

   762         if( heap->iAllocInfo.Count() > 0 )

   763             {

   764         

   765             DLTRACEIN( ( "" ) );

   766             DLINFO( ( "Debug heap at %08x", heap ) );

   767         

   768             DLINFO( ( "%d entries in alloc info list", heap->iAllocInfo.Count() ) );

   769         

   770             for ( TInt i=0; i<heap->iAllocInfo.Count(); i++ )

   771                 {

   772                 TAllocInfo& info = heap->iAllocInfo[i];

   773                 DLERROR( ( "ALLOC #%d: memory leak %d bytes at %08x:", info.iAllocNum, info.iAllocSize, info.iAllocPtr ) );

   774                 const TInt KMaxText = 64;

   775                 TPtrC8 text( reinterpret_cast<unsigned char*>( info.iAllocPtr ),

   776                              info.iAllocSize <= KMaxText ? info.iAllocSize : KMaxText );

   777                 DLERROR( ( "text: %S", &text ) );

   778                 DLERRORDUMP( info.iAllocPtr, info.iAllocSize, 1024 );

   779                 }

   780             }

   781         }

   782 

   783     RHeap* oldHeap = &heap->iBaseHeap;

   784 //    DLINFO( ( "Switching back to previous heap %08x", oldHeap ) );

   785     User::SwitchHeap( oldHeap );

   786 

   787     delete heap;

   788 

   789 //    DLTRACEOUT( ( "" ) );

   790     }

   791 

   792 TAny* RCatalogsDebugHeap::Alloc( TInt aSize )

   793     {

   794     TAny* result = iBaseHeap.Alloc( aSize );

   795 

   796     if ( iEnabled && iActive )

   797         {

   798         DLTRACEIN(("aSize=%d", aSize));

   799         iAllocCounter++;

   800         DLINFO( ( "ALLOC #%d: allocated %d bytes at %08x", iAllocCounter, aSize, result ) );

   801 

   802         TAllocInfo info;

   803         info.iAllocPtr = result;

   804         info.iAllocSize = aSize;

   805         info.iAllocNum = iAllocCounter;

   806  

   807         iActive = EFalse;   // deactivate temporarily to prevent internal alloc recording

   808         TInt err = iAllocInfo.Append( info );

   809         iActive = ETrue;

   810 

   811         if ( err != KErrNone )

   812             {

   813             DLERROR( ( "ALLOC ERROR appending alloc info" ) );

   814             }

   815         DLTRACEOUT(("%08x", result));

   816         }

   817 

   818     return result;

   819     }

   820 

   821 void RCatalogsDebugHeap::Free( TAny* aPtr )

   822     {

   823     iBaseHeap.Free( aPtr );

   824 

   825     if( iEnabled && iActive )

   826         {

   827         DLTRACEIN(("aPtr=%08x", aPtr));

   828         for ( TInt i=0; i<iAllocInfo.Count(); i++ )

   829             {

   830             TAllocInfo& info = iAllocInfo[i];

   831             if ( info.iAllocPtr == aPtr )

   832                 {

   833                 DLINFO( ( "ALLOC #%d: freed %d bytes at %08x", info.iAllocNum, info.iAllocSize, aPtr ) );

   834                 iAllocInfo.Remove( i );

   835                 return;

   836                 }

   837             }

   838         }

   839     }

   840 

   841 TAny* RCatalogsDebugHeap::ReAlloc( TAny* aPtr, TInt aSize, TInt aMode )

   842     {

   843     TAny* result = iBaseHeap.ReAlloc( aPtr, aSize, aMode );

   844 

   845     if( iEnabled )

   846         {

   847         for ( TInt i=0; i<iAllocInfo.Count(); i++ )

   848             {

   849             TAllocInfo& info = iAllocInfo[i];

   850             if ( info.iAllocPtr == aPtr )

   851                 {

   852                 DLTRACEIN(("aPtr=%08x, aSize=%d, aMode=%d", aPtr, aSize, aMode));

   853                 DLINFO( ( "ALLOC #%d: realloc %d bytes at %08x to %d bytes at %08x",

   854                           info.iAllocNum, info.iAllocSize, aPtr, aSize, result ) );

   855                 info.iAllocSize = aSize;

   856                 info.iAllocPtr = result;

   857                 return result;

   858                 }

   859             }

   860         }

   861     return result;

   862     }

   863 

   864 TInt RCatalogsDebugHeap::AllocLen( const TAny* aCell ) const

   865     {

   866     return iBaseHeap.AllocLen( aCell );

   867     }

   868 

   869 TInt RCatalogsDebugHeap::Compress()

   870     {

   871     return iBaseHeap.Compress();

   872     }

   873 

   874 void RCatalogsDebugHeap::Reset()

   875     {

   876     DLTRACEIN((""));

   877     iBaseHeap.Reset();

   878     DLINFO( ( "ALLOC: heap reset!" ) );

   879     iAllocInfo.Reset();

   880     }

   881 

   882 TInt RCatalogsDebugHeap::AllocSize( TInt& aTotalAllocSize ) const

   883     {

   884     return iBaseHeap.AllocSize( aTotalAllocSize );

   885     }

   886 

   887 TInt RCatalogsDebugHeap::Available( TInt& aBiggestBlock ) const

   888     {

   889     return iBaseHeap.Available( aBiggestBlock );

   890     }

   891 

   892 TInt RCatalogsDebugHeap::DebugFunction( TInt aFunc, TAny* a1, TAny* a2 )

   893     {

   894     return iBaseHeap.DebugFunction( aFunc, a1, a2 );

   895     }

   896 

   897 TInt RCatalogsDebugHeap::Extension_( TUint /*aExtensionId*/, TAny*& /*a0*/, TAny* /*a1*/ )

   898     {

   899     DLTRACEIN((""));

   900     DASSERT( EFalse );

   901     return 0;

   902     }

   903 

   904 static void CleanupWatcherPop( TAny* aArg )

   905     {

   906     TCatalogsLocalCleanupStackWatcher* watcher = static_cast< TCatalogsLocalCleanupStackWatcher* >( aArg );

   907     watcher->iPopped = ETrue;

   908     }

   909 

   910 EXPORT_C TCatalogsLocalCleanupStackWatcher::TCatalogsLocalCleanupStackWatcher()

   911         : iPopped( EFalse )

   912     {

   913     CleanupDeletePushL( ( TAny* )NULL );  // use NULL pointer as a marker

   914     CleanupStack::PushL( TCleanupItem( CleanupWatcherPop, ( TAny* )this ) );

   915     }

   916 

   917 EXPORT_C TCatalogsLocalCleanupStackWatcher::~TCatalogsLocalCleanupStackWatcher()

   918     {

   919     if ( !iPopped )

   920         {

   921         CleanupStack::PopAndDestroy();

   922         CleanupStack::Pop( ( TAny* )NULL ); // check for NULL marker at this position

   923         }

   924     }

   925 

   926 static void DebugHeapRestore( TAny* aArg )

   927     {

   928     TCatalogsLocalDebugHeapActivator* activator = static_cast< TCatalogsLocalDebugHeapActivator* >( aArg );

   929     RCatalogsDebugHeap::Activate( activator->iActive );

   930     activator->iPopped = ETrue;

   931     }

   932 

   933 EXPORT_C TCatalogsLocalDebugHeapActivator::TCatalogsLocalDebugHeapActivator()

   934     : iPopped( EFalse )

   935     {

   936     // Activate debug heap.

   937     iActive = RCatalogsDebugHeap::Activate( ETrue );

   938 

   939     // Push cleanup item for restoring the previous debug heap enable status.

   940     CleanupStack::PushL( TCleanupItem( DebugHeapRestore, ( TAny* )this ) );

   941     }

   942 

   943 EXPORT_C TCatalogsLocalDebugHeapActivator::~TCatalogsLocalDebugHeapActivator()

   944     {

   945     if ( !iPopped )

   946         {

   947         // Restore debug heap previous enable status.

   948         RCatalogsDebugHeap::Activate( iActive );

   949         CleanupStack::Pop();

   950         }

   951     }

   952 

   953 EXPORT_C TCatalogsLocalExitTrace::TCatalogsLocalExitTrace( const char* aFunctionName, TInt aLine, const char* aFileId )

   954     : iFunctionName( aFunctionName ), iLine( aLine ), iFileId( aFileId ), iDisabled( EFalse )

   955     {

   956     iEntryTime = User::FastCounter();

   957     }

   958 

   959 EXPORT_C TCatalogsLocalExitTrace::~TCatalogsLocalExitTrace()

   960     {

   961     if ( std::uncaught_exception() )

   962     	{

   963     	TCatalogsDebug debug( TCatalogsDebug::ETraceLeave, iFunctionName, iLine, iFileId, User::FastCounter()-iEntryTime );

   964         debug.Print( "" );

   965     	}

   966     else if  ( !iDisabled )

   967         {

   968         TCatalogsDebug debug( TCatalogsDebug::ETraceOut, iFunctionName, iLine, iFileId, User::FastCounter()-iEntryTime );

   969         debug.Print( "" );

   970         }

   971     }

   972 

   973 EXPORT_C void TCatalogsLocalExitTrace::Disable()

   974     {

   975     iDisabled = ETrue;

   976     }