persistentstorage/sql/SRC/Server/SqlSrvResourceProfiler.cpp
branchRCL_3
changeset 11 211563e4b919
parent 0 08ec8eefde2f
child 14 04ec7606545c
equal deleted inserted replaced
10:31a8f755b7fe 11:211563e4b919
     1 // Copyright (c) 2008-2009 Nokia Corporation and/or its subsidiary(-ies).
     1 // Copyright (c) 2008-2010 Nokia Corporation and/or its subsidiary(-ies).
     2 // All rights reserved.
     2 // All rights reserved.
     3 // This component and the accompanying materials are made available
     3 // This component and the accompanying materials are made available
     4 // under the terms of "Eclipse Public License v1.0"
     4 // under the terms of "Eclipse Public License v1.0"
     5 // which accompanies this distribution, and is available
     5 // which accompanies this distribution, and is available
     6 // at the URL "http://www.eclipse.org/legal/epl-v10.html".
     6 // at the URL "http://www.eclipse.org/legal/epl-v10.html".
    58 @internalComponent
    58 @internalComponent
    59 */
    59 */
    60 static TBool TheSqlSrvProfilerSqlTraceEnabled = EFalse;
    60 static TBool TheSqlSrvProfilerSqlTraceEnabled = EFalse;
    61 
    61 
    62 /**
    62 /**
    63 When the SQL server boots, TheSqlSrvStartTime will be initialized with the current time then. 
       
    64 @internalComponent
       
    65 */
       
    66 TTime TheSqlSrvStartTime = 0;
       
    67 
       
    68 /**
       
    69 When KSqlSrvProfilerDbName is with non-zero length, then only traces coming from database identified by
    63 When KSqlSrvProfilerDbName is with non-zero length, then only traces coming from database identified by
    70 KSqlSrvProfilerDbName name are printed out. 
    64 KSqlSrvProfilerDbName name are printed out. 
    71 @internalComponent
    65 @internalComponent
    72 */
    66 */
    73 //_LIT(KSqlSrvProfilerDbName, "default_avacon.dbSQL");
    67 //_LIT(KSqlSrvProfilerDbName, "default_avacon.dbSQL");
    77 //File "read", "write", "sync" and "set size" counters, incremented inside the OS porting layer.
    71 //File "read", "write", "sync" and "set size" counters, incremented inside the OS porting layer.
    78 TInt TheSqlSrvProfilerFileRead = 0;
    72 TInt TheSqlSrvProfilerFileRead = 0;
    79 TInt TheSqlSrvProfilerFileWrite = 0;
    73 TInt TheSqlSrvProfilerFileWrite = 0;
    80 TInt TheSqlSrvProfilerFileSync = 0;
    74 TInt TheSqlSrvProfilerFileSync = 0;
    81 TInt TheSqlSrvProfilerFileSetSize = 0;
    75 TInt TheSqlSrvProfilerFileSetSize = 0;
    82 
       
    83 static TInt TheSqlSrvProfilerFileRead1 = 0;
       
    84 static TInt TheSqlSrvProfilerFileWrite1 = 0;
       
    85 static TInt TheSqlSrvProfilerFileSync1 = 0;
       
    86 static TInt TheSqlSrvProfilerFileSetSize1 = 0;
       
    87 
    76 
    88 //Set it to true if you want traces to be stored into a file.
    77 //Set it to true if you want traces to be stored into a file.
    89 static TBool TheSqlSrvProfilerTraceToFile = EFalse;
    78 static TBool TheSqlSrvProfilerTraceToFile = EFalse;
    90 
    79 
    91 //"Prepared" and "Executed" SQL statement counters
    80 //"Prepared" and "Executed" SQL statement counters
   625     const TInt KMicroSecIn1Sec = 1000000;
   614     const TInt KMicroSecIn1Sec = 1000000;
   626     TInt32 us = (diffTicks * KMicroSecIn1Sec) / freq;
   615     TInt32 us = (diffTicks * KMicroSecIn1Sec) / freq;
   627     return us;
   616     return us;
   628     }
   617     }
   629 
   618 
   630 //Calculates the time since the SQL server boot in microseconds.
   619 //Calculates the time since the first time this function has been called.
   631 static TInt64 SqlTimeFromStartUs()
   620 static TInt64 SqlTimeFromStartUs()
   632     {
   621     {
       
   622     struct TStartTime
       
   623         {
       
   624         inline TStartTime()
       
   625             {
       
   626             iTime.UniversalTime();
       
   627             }
       
   628         TTime iTime;
       
   629         };
       
   630     static TStartTime startTime;
   633     TTime time;
   631     TTime time;
   634     time.UniversalTime();
   632     time.UniversalTime();
   635     TTimeIntervalMicroSeconds us = time.MicroSecondsFrom(TheSqlSrvStartTime);
   633     TTimeIntervalMicroSeconds us = time.MicroSecondsFrom(startTime.iTime);
   636     if(us.Int64() < 0)
   634     const TInt64 KMaxDiff = 999999999999LL;//999999999999 is the max number that can be printed out using %12ld format spec
   637         {
   635     if(us.Int64() < 0 || us.Int64() >= KMaxDiff)
   638         TheSqlSrvStartTime = time;
   636         {
       
   637         startTime.iTime = time;
   639         us = 0;
   638         us = 0;
   640         }
   639         }
   641     return us.Int64();
   640     return us.Int64();
   642     }
   641     }
   643 
   642 
   644 
   643 
   645 //Tracing data buffer
   644 //Tracing data buffer
   646 const TInt KSqlSrvProfilePrnBufSize = 230;
   645 const TInt KSqlSrvProfilePrnBufSize = 300;
   647 static TBuf<KSqlSrvProfilePrnBufSize> TheSqlSrvProfileTraceBuf;
   646 static TBuf<KSqlSrvProfilePrnBufSize> TheSqlSrvProfileTraceBuf;
   648 static TBuf8<KSqlSrvProfilePrnBufSize> TheSqlSrvProfileTraceBuf8;
   647 static TBuf8<KSqlSrvProfilePrnBufSize> TheSqlSrvProfileTraceBuf8;
   649 
   648 
   650 static RFs TheSqlSrvTraceFs;
   649 static RFs TheSqlSrvTraceFs;
   651 static RFile TheTheSqlSrvTraceFile;
   650 static RFile TheTheSqlSrvTraceFile;
   661         {
   660         {
   662         prevTimeDiff = timeDiff;
   661         prevTimeDiff = timeDiff;
   663         TTime time;
   662         TTime time;
   664         time.UniversalTime();
   663         time.UniversalTime();
   665         TDateTime dt = time.DateTime();
   664         TDateTime dt = time.DateTime();
   666         TheSqlSrvProfileTraceBuf8.Format(_L8("%08X¬%012ld¬TME¬%02d:%02d:%02d.%06d¬Prep8=%08d¬Prep16=%08d¬Ex8=%08d¬Ex16=%08d"),
   665         TheSqlSrvProfileTraceBuf8.Format(_L8("% 8X¬%012ld¬TME¬%02d:%02d:%02d:%06d¬Prep8=%08d¬Prep16=%08d¬Ex8=%08d¬Ex16=%08d"),
   667                 0, timeDiff, dt.Hour(), dt.Minute(), dt.Second(), dt.MicroSecond(),
   666                 0, timeDiff, dt.Hour(), dt.Minute(), dt.Second(), dt.MicroSecond(),
   668                 TheSqlSrvProfilerPreparedCnt8, TheSqlSrvProfilerPreparedCnt16, 
   667                 TheSqlSrvProfilerPreparedCnt8, TheSqlSrvProfilerPreparedCnt16, 
   669                 TheSqlSrvProfilerExecutedCnt8, TheSqlSrvProfilerExecutedCnt16);
   668                 TheSqlSrvProfilerExecutedCnt8, TheSqlSrvProfilerExecutedCnt16);
   670         if(TheSqlSrvProfilerTraceToFile)
   669         if(TheSqlSrvProfilerTraceToFile)
   671             {
   670             {
   714 //Called at the beginning of CSqlSrvSession::ServiceL().
   713 //Called at the beginning of CSqlSrvSession::ServiceL().
   715 void SqlIpcStart(TUint& aIpcCounter, TUint32& aStartTicks, TUint aDbHandle)
   714 void SqlIpcStart(TUint& aIpcCounter, TUint32& aStartTicks, TUint aDbHandle)
   716     {
   715     {
   717     if(TheSqlSrvProfilerTraceEnabled)
   716     if(TheSqlSrvProfilerTraceEnabled)
   718         {
   717         {
       
   718         TheSqlSrvProfilerFileRead = TheSqlSrvProfilerFileWrite = TheSqlSrvProfilerFileSync = TheSqlSrvProfilerFileSetSize = 0;
   719         if(TheSqlSrvProfilerTraceLevel == 0)
   719         if(TheSqlSrvProfilerTraceLevel == 0)
   720             {
   720             {
   721             return;
   721             return;
   722             }
   722             }
   723         if(KSqlSrvProfilerDbName().Length() > 0 && (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   723         if(KSqlSrvProfilerDbName().Length() > 0 && (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   724             {
   724             {
   725             return;
   725             return;
   726             }
   726             }
   727         ++aIpcCounter;
   727         ++aIpcCounter;
   728         TheSqlSrvProfilerFileRead1 = TheSqlSrvProfilerFileRead;
       
   729         TheSqlSrvProfilerFileWrite1 = TheSqlSrvProfilerFileWrite;
       
   730         TheSqlSrvProfilerFileSync1 = TheSqlSrvProfilerFileSync;
       
   731         TheSqlSrvProfilerFileSetSize1 = TheSqlSrvProfilerFileSetSize;
       
   732         aStartTicks = User::FastCounter();
   728         aStartTicks = User::FastCounter();
   733         }
   729         }
   734     }
   730     }
   735 
   731 
   736 //Called at the end of CSqlSrvSession::ServiceL().
   732 //Called at the end of CSqlSrvSession::ServiceL().
   760             ttlExecTime = aIpcTraceData[ipcCallIdx].iExecutionTime;
   756             ttlExecTime = aIpcTraceData[ipcCallIdx].iExecutionTime;
   761             count = ++aIpcTraceData[ipcCallIdx].iCount;
   757             count = ++aIpcTraceData[ipcCallIdx].iCount;
   762             }
   758             }
   763         if(ipcCallIdx >= 0  || (ipcCallIdx == KErrNotFound && TheSqlSrvProfilerTraceLevel == 2))
   759         if(ipcCallIdx >= 0  || (ipcCallIdx == KErrNotFound && TheSqlSrvProfilerTraceLevel == 2))
   764             {
   760             {
   765             TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬IPC¬%08u¬%20.20S¬%012ld¬%010d¬%08d¬%04d¬%04d¬%04d¬%04d¬rc=%d"),  
   761             TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬IPC¬%08u¬%20.20S¬%012ld¬%010d¬%08d¬%04d¬%04d¬%04d¬%04d¬rc=%d"),  
   766                     aDbHandle, 
   762                     aDbHandle, 
   767                     timeFromStart,
   763                     timeFromStart,
   768                     aIpcCounter,
   764                     aIpcCounter,
   769                     &ipcCallName, 
   765                     &ipcCallName, 
   770                     ttlExecTime, 
   766                     ttlExecTime, 
   771                     executionTime,
   767                     executionTime,
   772                     count,
   768                     count,
   773                     TheSqlSrvProfilerFileRead - TheSqlSrvProfilerFileRead1,
   769                     TheSqlSrvProfilerFileRead,
   774                     TheSqlSrvProfilerFileWrite - TheSqlSrvProfilerFileWrite1,
   770                     TheSqlSrvProfilerFileWrite,
   775                     TheSqlSrvProfilerFileSync - TheSqlSrvProfilerFileSync1,
   771                     TheSqlSrvProfilerFileSync,
   776                     TheSqlSrvProfilerFileSetSize - TheSqlSrvProfilerFileSetSize1,
   772                     TheSqlSrvProfilerFileSetSize,
   777                     aRetCode);
   773                     aRetCode);
   778             SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   774             SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   779             }
   775             }
   780         }
   776         }
   781     }
   777     }
   790             return;
   786             return;
   791             }
   787             }
   792         TPtrC ipcCallName;
   788         TPtrC ipcCallName;
   793         (void)SqlIpcTraceIdxAndName(aFuncCode, ipcCallName); 
   789         (void)SqlIpcTraceIdxAndName(aFuncCode, ipcCallName); 
   794         TInt64 timeFromStart = SqlTimeFromStartUs();
   790         TInt64 timeFromStart = SqlTimeFromStartUs();
   795         TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬ERR¬%08u¬%20.20S¬err=%d"), 
   791         TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬ERR¬%08u¬%20.20S¬err=%d"), 
   796                 aDbHandle, 
   792                 aDbHandle, 
   797                 timeFromStart,
   793                 timeFromStart,
   798                 aIpcCounter,
   794                 aIpcCounter,
   799                 &ipcCallName,
   795                 &ipcCallName,
   800                 aError);
   796                 aError);
   825         _LIT(KPrepare,  "Prepare16");
   821         _LIT(KPrepare,  "Prepare16");
   826         _LIT(KExec,     "Exec16");
   822         _LIT(KExec,     "Exec16");
   827         _LIT(KEmptyStr,  "");
   823         _LIT(KEmptyStr,  "");
   828         if(pos == 0)
   824         if(pos == 0)
   829             {
   825             {
   830             line.Format(_L("%08X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, aPrepare ? &KPrepare : &KExec);
   826             line.Format(_L("% 8X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, aPrepare ? &KPrepare : &KExec);
   831             }
   827             }
   832         else
   828         else
   833             {
   829             {
   834             if(!TheSqlSrvProfilerTraceToFile)
   830             if(!TheSqlSrvProfilerTraceToFile)
   835                 {
   831                 {
   836                 line.Format(_L("%08X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, &KEmptyStr);
   832                 line.Format(_L("% 8X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, &KEmptyStr);
   837                 }
   833                 }
   838             }
   834             }
   839         TInt l = Min(len, (line.MaxLength() - line.Length()));
   835         TInt l = Min(len, (line.MaxLength() - line.Length()));
   840         TPtrC ptr(aSql.Ptr() + pos, l);
   836         TPtrC ptr(aSql.Ptr() + pos, l);
   841         pos += l;
   837         pos += l;
   870         _LIT(KPrepare,   "Prepare8");
   866         _LIT(KPrepare,   "Prepare8");
   871         _LIT(KExec,      "Exec8");
   867         _LIT(KExec,      "Exec8");
   872         _LIT(KEmptyStr,  "");
   868         _LIT(KEmptyStr,  "");
   873         if(pos == 0)
   869         if(pos == 0)
   874             {
   870             {
   875             line.Format(_L("%08X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, aPrepare ? &KPrepare : &KExec);
   871             line.Format(_L("% 8X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, aPrepare ? &KPrepare : &KExec);
   876             }
   872             }
   877         else
   873         else
   878             {
   874             {
   879             if(!TheSqlSrvProfilerTraceToFile)
   875             if(!TheSqlSrvProfilerTraceToFile)
   880                 {
   876                 {
   881                 line.Format(_L("%08X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, &KEmptyStr);
   877                 line.Format(_L("% 8X¬%012ld¬SQL¬%12.12S¬"), aDbHandle, timeFromStart, &KEmptyStr);
   882                 }
   878                 }
   883             }
   879             }
   884         TInt l = Min(len, (line.MaxLength() - line.Length()));
   880         TInt l = Min(len, (line.MaxLength() - line.Length()));
   885         TPtrC8 ptr(aSql.Ptr() + pos, l);
   881         TPtrC8 ptr(aSql.Ptr() + pos, l);
   886         pos += l;
   882         pos += l;
   906         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   902         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   907             {
   903             {
   908             return;
   904             return;
   909             }
   905             }
   910         TInt64 timeFromStart = SqlTimeFromStartUs();
   906         TInt64 timeFromStart = SqlTimeFromStartUs();
   911         TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬CRE¬%S"), 
   907         TheSqlSrvProfileTraceBuf.Format(_L("% 08X¬%012ld¬CRE¬%S"), 
   912                 aDbHandle, 
   908                 aDbHandle, 
   913                 timeFromStart,
   909                 timeFromStart,
   914                 &aDbName);
   910                 &aDbName);
   915         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   911         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   916         }
   912         }
   928         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   924         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   929             {
   925             {
   930             return;
   926             return;
   931             }
   927             }
   932         TInt64 timeFromStart = SqlTimeFromStartUs();
   928         TInt64 timeFromStart = SqlTimeFromStartUs();
   933         TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬OPN¬%S"), 
   929         TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬OPN¬%S"), 
   934                 aDbHandle, 
   930                 aDbHandle, 
   935                 timeFromStart,
   931                 timeFromStart,
   936                 &aDbName);
   932                 &aDbName);
   937         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   933         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   938         }
   934         }
   946         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   942         if(KSqlSrvProfilerDbName().Length() > 0 &&  (aDbHandle == 0 || TheSqlSrvProfilerHandle != aDbHandle))
   947             {
   943             {
   948             return;
   944             return;
   949             }
   945             }
   950         TInt64 timeFromStart = SqlTimeFromStartUs();
   946         TInt64 timeFromStart = SqlTimeFromStartUs();
   951         TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬CSE"),  
   947         TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬CSE"),  
   952                 aDbHandle, 
   948                 aDbHandle, 
   953                 timeFromStart);
   949                 timeFromStart);
   954         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   950         SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   955         if(aDbHandle == TheSqlSrvProfilerHandle)
   951         if(aDbHandle == TheSqlSrvProfilerHandle)
   956             {
   952             {
   988             TheSqlSrvTraceFs.Close();
   984             TheSqlSrvTraceFs.Close();
   989             TheSqlSrvProfilerTraceToFile = EFalse;
   985             TheSqlSrvProfilerTraceToFile = EFalse;
   990             RDebug::Print(_L("SQL trace file creation failed with err=%d"), err);
   986             RDebug::Print(_L("SQL trace file creation failed with err=%d"), err);
   991             }
   987             }
   992         }
   988         }
   993     TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬SRV¬START"), 0, timeFromStart); 
   989     TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬SRV¬START"), 0, timeFromStart); 
   994     SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   990     SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   995     }
   991     }
   996 
   992 
   997 //Prints a trace when the SQL server stops
   993 //Prints a trace when the SQL server stops
   998 void SqlPrintServerStop()
   994 void SqlPrintServerStop()
   999     {
   995     {
  1000     TInt64 timeFromStart = SqlTimeFromStartUs();
   996     TInt64 timeFromStart = SqlTimeFromStartUs();
  1001     TheSqlSrvProfileTraceBuf.Format(_L("%08X¬%012ld¬SRV¬STOP"), 0, timeFromStart); 
   997     TheSqlSrvProfileTraceBuf.Format(_L("% 8X¬%012ld¬SRV¬STOP"), 0, timeFromStart); 
  1002     SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
   998     SqlSrvProfilePrintf(ESqlSrvProfilerNonSqlTrace);
  1003     if(TheSqlSrvProfilerTraceToFile)
   999     if(TheSqlSrvProfilerTraceToFile)
  1004         {
  1000         {
  1005         TheTheSqlSrvTraceFile.Close();
  1001         TheTheSqlSrvTraceFile.Close();
  1006         TheSqlSrvTraceFs.Close();
  1002         TheSqlSrvTraceFs.Close();