Browse Source

Some non-significant fix in trace analysis script used in profiling.

PYADPT-55
Edouard Tisserant 9 years ago
parent
commit
677b5cfc03
  1. 86
      test/profiling/results.txt
  2. 23
      test/profiling/trace_analysis.py

86
test/profiling/results.txt

@ -1,32 +1,3 @@
_gpgme_engine_reset 110  110   0.00 0.00
vdbeRecordDecodeInt 243  243   0.00 0.00
_gpgme_engine_set_colon_line_handler 121  121   0.00 0.00
keylist_colon_handler 1046  1046  0.00 0.00
_gpgme_engine_set_locale 246  246   0.00 0.00
_gpgme_engine_set_status_handler 123  123   0.00 0.00
resolveP2Values 46  46   0.00 0.00
_gpgme_engine_op_encrypt_sign 1  1   0.00 0.00
sqlite3GetToken 138  138   0.00 0.00
yy_destructor 184  184   0.00 0.00
sqlite3VXPrintf 25  25   0.00 0.00
_gpgme_engine_op_export 1  1   0.00 0.00
gpg_io_event 319  319   0.00 0.00
yy_reduce 207  207   0.00 0.00
gpgme_get_protocol 13  13   0.00 0.00
unixFileControl 72  72   0.00 0.00
mime_encode_message 1  1   0.00 0.00
_gpgme_engine_set_io_cbs 123  123   0.00 0.00
_gpgme_passphrase_status_handler 10  10   0.00 0.00
_gpgme_engine_set_pinentry_mode 123  123   0.00 0.00
_gpgme_engine_op_keylist 121  121   0.00 0.00
sqlite3VdbeSerialGet 650  650   0.00 0.00
sqlite3VdbeExec 232  232   0.00 0.00
gpgme_ctx_set_engine_info 13  13   0.00 0.00
gpgme_set_protocol 13  13   0.00 0.00
_gpgme_decode_c_string 161  161   0.00 0.00
get_gpgconf_item 123  123   0.00 0.00
_gpgme_engine_io_event 319  319   0.00 0.00
gpgme_result_unref 123  123   0.00 0.00
gpgme_key_release 1  0   0.00 0.00
computeJD 1  0   0.00 0.00
decodeFlags 1  0   0.00 0.00
@ -140,6 +111,7 @@ sqlite3BtreeNext 47  0   0.00 0.00
sqlite3DeleteTable 46  0   0.00 0.00
sqlite3BtreeFirst 1  0   0.00 0.00
_gpgme_engine_info_release 13  0   0.00 0.00
_gpgme_passphrase_status_handler 10  0   0.00 0.00
sqlite3AuthCheck 46  0   0.00 0.00
storeLastErrno 48  0   0.00 0.00
sqlite3PcacheClearSyncFlags 24  0   0.00 0.00
@ -182,6 +154,7 @@ callFinaliser 116  0   0.00 0.00
sqlite3PagerFilename 116  0   0.00 0.00
clearAllSharedCacheTableLocks 116  0   0.00 0.00
gpgme_key_unref 16  0   0.00 0.00
yy_destructor 184  0   0.00 0.00
_gpgme_get_basename 123  0   0.00 0.00
free_stringlist 26  0   0.00 0.00
_gpgme_engine_info_copy 13  0   0.00 0.00
@ -225,6 +198,7 @@ sqlite3BtreeLockTable 255  0   0.00 0.00
fileHasMoved 24  0   0.00 0.00
pager_cksum 235  0   0.00 0.00
sqlite3BtreeSchemaLocked 46  0   0.00 0.00
sqlite3VXPrintf 25  0   0.00 0.00
gpgme_data_write 32  0   0.00 0.00
yy_pop_parser_stack 184  0   0.00 0.00
sqlite3_context_db_handle 301  0   0.00 0.00
@ -243,7 +217,7 @@ sqlite3_aggregate_context 68  0   0.00 0.00
gpgme_new 13  0   0.00 0.00
_gpgme_map_pk_algo 323  0   0.00 0.00
btreeParseCellPtr 373  0   0.00 0.00
_gpgme_ath_read 420  0   0.00 1.04
_gpgme_ath_read 420  0   0.00 0.00
sqlite3BitvecTestNotNull 423  0   0.00 0.00
btreePageFromDbPage 117  0   0.00 0.00
btreeParseCellPtrIndex 347  0   0.00 0.00
@ -253,6 +227,7 @@ sqlite3_vsnprintf 25  0   0.00 0.00
_gpgme_key_add_subkey 322  0   0.00 0.00
sqlite3BtreeGetFilename 116  0   0.00 0.00
sqlite3VdbeRewind 418  0   0.00 0.00
unixFileControl 72  0   0.00 0.00
pager_write_changecounter 48  0   0.00 0.00
sqlite3VdbeLeave 464  0   0.00 0.00
gpg_set_locale 246  0   0.00 0.00
@ -265,9 +240,11 @@ sqlite3VdbeSerialTypeLen 592  0   0.00 0.00
sqlite3_snprintf 25  0   0.00 0.00
sqlite3PagerWalCallback 141  0   0.00 0.00
sqlite3BtreeCursorHintFlags 556  0   0.00 0.00
vdbeRecordDecodeInt 243  0   0.00 0.00
fetchPayload 554  0   0.00 0.00
pcacheManageDirtyList 587  0   0.00 0.00
_gpgme_wait_private_event_cb 442  0   0.00 0.00
_gpgme_engine_set_io_cbs 123  0   0.00 0.00
seekAndRead 141  0   0.00 0.00
closeUnixFile 24  0   0.00 0.00
sqlite3ValueBytes 625  0   0.00 0.00
@ -281,6 +258,7 @@ _gpgme_getenv 246  0   0.00 0.00
allocateSpace 211  0   0.00 0.00
pthreadMutexAlloc 632  0   0.00 0.00
sqlite3VdbeFindCompare 532  0   0.00 0.00
resolveP2Values 46  0   0.00 0.00
btreePagecount 556  0   0.00 0.00
sqlite3BtreeCursorHasMoved 625  0   0.00 0.00
sqlite3OsDeviceCharacteristics 164  0   0.00 0.00
@ -302,6 +280,7 @@ sqlite3PagerBegin 24  0   0.00 0.00
sqlite3VdbeChangeEncoding 698  0   0.00 0.00
sqlite3PcacheFetchFinish 697  0   0.00 0.00
sqlite3VdbeMakeReady 46  0   0.00 0.00
_gpgme_decode_c_string 161  0   0.00 0.00
sqlite3Put4byte 734  0   0.00 0.00
sqlite3VdbeTransferError 232  0   0.00 0.00
sqlite3PcacheMakeDirty 235  0   0.00 0.00
@ -335,6 +314,7 @@ fillInCell 211  0   0.00 0.00
sqlite3StatusHighwater 1159  0   0.00 0.00
btreeCursor 556  0   0.00 0.00
_gpgme_key_append_name 161  0   0.00 0.00
get_gpgconf_item 123  0   0.00 0.00
columnMallocFailure 183  0   0.00 0.00
sqlite3Error 1049  0   0.00 0.00
sqlite3BtreeKeyFetch 323  0   0.00 0.00
@ -344,6 +324,7 @@ sqlite3_column_text 69  0   0.00 0.00
Cleanup 418  0   0.00 0.00
sqlite3PagerExclusiveLock 48  0   0.00 0.00
sqlite3DbRealloc 46  0   0.00 0.00
_gpgme_engine_set_pinentry_mode 123  0   0.00 0.00
sqlite3ParserAlloc 46  0   0.00 0.00
sqlite3VdbeRecordCompare 173  0   0.00 0.00
out2Prerelease 1419  0   0.00 0.00
@ -366,6 +347,7 @@ sqlite3OsFileSize 348  0   0.00 0.00
sqlite3BtreeClearCursor 556  0   0.00 0.00
writeJournalHdr 24  0   0.00 0.00
sqlite3BtreeSavepoint 47  0   0.00 0.00
gpgme_result_unref 123  0   0.00 0.00
sqlite3VdbeCreate 46  0   0.00 0.00
growOpArray 46  0   0.00 0.00
sqlite3BitvecDestroy 211  0   0.00 0.00
@ -425,7 +407,7 @@ sqlite3PcacheRelease 696  0   0.00 0.00
btreeGetPage 116  0   0.00 0.00
sqlite3DbMallocZero 92  0   0.00 0.00
unixEnterMutex 304  0   0.00 0.00
sqlite3MemSize 2944  0   0.00 0.01
sqlite3MemSize 2944  0   0.00 0.00
sqlite3OsAccess 232  0   0.00 0.00
close_notify_handler 494  0   0.00 0.00
sqlite3VdbeDelete 46  0   0.00 0.00
@ -439,11 +421,11 @@ vdbeMemClear 162  0   0.00 0.00
pcache1FetchNoMutex 696  0   0.00 0.00
sqlite3OsDelete 24  0   0.00 0.00
_gpgme_io_pipe 260  0   0.00 0.00
pthreadMutexLeave 3922  0   0.00 0.01
pthreadMutexLeave 3922  0   0.00 0.00
gpg_release 123  0   0.00 0.00
_add_arg 2853  0   0.00 0.10
_gpgme_ath_mutex_lock 1847  0   0.00 0.01
pthreadMutexEnter 3922  0   0.00 0.01
_add_arg 2853  0   0.00 0.00
_gpgme_ath_mutex_lock 1847  0   0.00 0.00
pthreadMutexEnter 3922  0   0.00 0.00
handleDeferredMoveto 138  0   0.00 0.00
posixUnlock 140  0   0.00 0.00
vdbeMemAddTerminator 139  0   0.00 0.00
@ -453,6 +435,7 @@ sqlite3BtreeCursor 556  0   0.00 0.00
btreeMoveto 117  0   0.00 0.00
sqlite3VdbeFinalize 46  0   0.00 0.00
sqlite3GetVdbe 92  0   0.00 0.00
_gpgme_engine_set_locale 246  0   0.00 0.00
unixUnlock 140  0   0.00 0.00
sqlite3DbMallocSize 1300  0   0.00 0.00
posixOpen 48  0   0.00 0.00
@ -504,10 +487,12 @@ unixWrite 988  0   0.01 0.00
btreeEndTransaction 116  0   0.01 0.00
sqlite3_mutex_leave 3922  0   0.01 0.01
unlockBtreeIfUnused 672  0   0.01 0.00
gpg_io_event 319  0   0.01 0.00
sqlite3_mutex_enter 3922  0   0.01 0.01
replaceFunc 162  0   0.01 0.00
sqlite3_bind_text 328  0   0.01 0.00
getAndInitPage 556  0   0.01 0.00
_gpgme_engine_io_event 319  0   0.01 0.00
upperFunc 139  0   0.01 0.00
sqlite3OsWrite 988  0   0.01 0.00
sqlite3RunParser 46  0   0.01 0.00
@ -519,20 +504,21 @@ sqlite3BtreeCloseCursor 556  0   0.02 0.00
sqlite3Prepare 46  0   0.02 0.00
releasePageNotNull 672  0   0.02 0.00
sqlite3VdbeFreeCursor 556  0   0.02 0.00
mallocWithAlarm 1159  0   0.02 0.00
mallocWithAlarm 1159  0   0.02 0.01
sqlite3DbFree 2619  0   0.02 0.00
sqlite3LockAndPrepare 46  0   0.02 0.00
sqlite3_prepare_v2 46  0   0.02 0.00
dbMallocRawFinish 718  0   0.02 0.00
_gpgme_debug 18241  0   0.02 6.46
_gpgme_io_close 520  0   0.02 0.00
_gpgme_debug 18241  0   0.02 0.02
_gpgme_io_close 520  0   0.02 0.01
releaseMemArray 651  0   0.02 0.00
sqlite3BtreeCommitPhaseTwo 116  0   0.02 0.00
lockBtree 116  0   0.02 0.00
sqlite3DbMallocRawNN 1464  0   0.02 0.00
sqlite3BtreeMovetoUnpacked 856  0   0.02 0.00
yy_reduce 207  0   0.02 0.00
sqlite3DbMallocRaw 1370  0   0.02 0.00
sqlite3_free 2458  0   0.02 0.00
sqlite3_free 2458  0   0.02 0.01
sqlite3BtreeBeginTrans 186  0   0.02 0.00
sqlite3VdbeMemClearAndResize 768  0   0.02 0.00
pager_write 235  0   0.02 0.00
@ -544,6 +530,7 @@ sqlite3VdbeMemGrow 1254  0   0.03 0.00
syncJournal 24  0   0.03 0.00
full_fsync 96  0   0.03 0.03
closeAllCursors 559  0   0.03 0.00
sqlite3GetToken 138  0   0.03 0.00
unixSync 72  0   0.03 0.00
sqlite3OsSync 72  0   0.03 0.00
colon_line_handler 242  0   0.03 0.00
@ -551,16 +538,21 @@ sqlite3VdbeReset 418  0   0.03 0.00
sqlite3_reset 372  0   0.04 0.00
sqlite3PagerCommitPhaseOne 24  0   0.04 0.00
sqlite3BtreeCommitPhaseOne 116  0   0.04 0.00
sqlite3VdbeSerialGet 650  0   0.05 0.00
get_identity 23  0   0.05 0.00
blacklist_is_listed 68  0   0.06 0.00
_gpgme_run_io_cb 420  0   0.06 0.00
_gpgme_engine_op_export 1  0   0.06 0.00
export_start 1  0   0.06 0.00
gpgme_op_export 1  0   0.06 0.00
vdbeCommit 116  0   0.07 0.00
_gpgme_engine_op_encrypt_sign 1  0   0.07 0.00
encrypt_sign_start 1  0   0.07 0.00
keylist_colon_handler 1046  0   0.08 0.01
sqlite3_exec 46  0   0.08 0.00
sqlite3VdbeHalt 559  0   0.10 0.00
gpg_new 123  0   0.11 0.00
_gpgme_engine_reset 110  0   0.10 0.00
gpg_new 123  0   0.11 0.10
_gpgme_engine_new 123  0   0.11 0.00
_gpgme_op_reset 123  0   0.12 0.00
pgp_export_keydata 1  0   0.23 0.00
@ -572,6 +564,7 @@ key_expired 1  0   0.23 0.00
pgp_key_revoked 1  0   0.24 0.00
key_revoked 1  0   0.24 0.00
set_identity 23  0   0.25 0.00
sqlite3VdbeExec 232  0   0.26 0.01
sqlite3Step 232  0   0.26 0.00
sqlite3_step 232  0   0.26 0.00
pgp_contains_priv_key 1  0   0.43 0.00
@ -581,27 +574,34 @@ find_single_key 2  0   0.48 0.00
_myself 1  0   0.93 0.00
myself 1  0   0.93 0.00
gpgme_op_encrypt_sign 1  0   1.03 0.00
_gpgme_io_read 420  0   1.05 0.00
_gpgme_io_read 420  0   1.05 1.04
_gpgme_get_program_version 13  0   1.95 0.00
_gpgme_set_engine_info 13  0   1.95 0.00
_gpgme_ath_waitpid 136  0   2.70 2.70
gpgme_ctx_set_engine_info 13  0   5.14 0.00
gpgme_set_protocol 13  0   5.14 0.00
gpgme_get_protocol 13  0   5.14 0.00
gpgme_get_key 13  0   5.14 0.00
_pgp_search_keys 22  0   5.15 0.00
pgp_find_keys 22  0   5.15 0.00
find_keys 22  0   5.15 0.00
pgp_encrypt_and_sign 1  0   5.73 0.00
encrypt_and_sign 1  0   5.73 0.00
mime_encode_message 1  0   5.73 0.00
encrypt_PGP_MIME 1  0   5.73 0.00
_gpgme_engine_op_keylist 121  0   8.13 0.00
_gpgme_engine_set_colon_line_handler 121  0   8.14 0.00
start 123  0   8.25 0.00
gpgme_op_keylist_start 121  0   8.26 0.00
_gpgme_io_spawn 136  0   9.15 0.00
_gpgme_engine_set_status_handler 123  0   8.27 0.00
_gpgme_io_spawn 136  0   9.15 6.43
_get_comm_type 11  0   12.81 0.00
elect_pubkey 22  0   19.97 0.00
pgp_get_key_rating 84  0   20.04 0.00
get_key_rating 84  0   20.04 0.00
gpgme_op_keylist_next 196  0   20.60 0.00
_gpgme_ath_select 736  0   21.65 21.65
_gpgme_io_select 771  0   21.67 0.00
_gpgme_io_select 771  0   21.67 0.01
_gpgme_wait_on_condition 178  0   21.72 0.00
update_identity 22  0   25.52 0.00
encrypt_message 1  0   32.41 0.00

23
test/profiling/trace_analysis.py

@ -1,8 +1,8 @@
import sys
first = True
funcs = {}
prevfs = [0,0,0,[0]]
prevtime = 0
stack=[]
for line in sys.stdin:
if first:
@ -17,13 +17,26 @@ for line in sys.stdin:
entry = point == "entry"
fs = funcs.setdefault(func,[0,0,0,[]])
if entry:
prevfs[2] = prevfs[2] + time - prevtime
if len(stack) > 0:
prevfunc, prevfs = stack[-1]
prevfs[2] = prevfs[2] + time - prevtime
fs[0] = fs[0] + 1
fs[3].append(time)
stack.append((func,fs))
else:
prevfs[2] = prevfs[2] + time - prevtime
while len(stack) > 0 :
prevfunc, prevfs=stack.pop()
if func != prevfunc:
print(prevfunc, ": NO RETURN, unwinded in", func, file=sys.stderr)
prevfs[2] = prevfs[2] + time - prevtime
prevtime = time #don't add to all unwinded calls
prevfs[1] = prevfs[1] + time - prevfs[3].pop()
else:
break
fs[2] = fs[2] + time - prevtime
fs[1] = fs[1] + time - fs[3].pop()
prevfs = fs
prevtime = time
#print(_cpu, _id, func,point, time)
@ -31,6 +44,6 @@ for line in sys.stdin:
for func in sorted(funcs.items(), key=lambda fs: fs[1][1]):
name,(count, totaltime, insidetime, entries) = func
print("{:<40} {:<6} {:<4} {:>6.2f} {:>6.2f}".format( name, count, len(entries), totaltime/1000000000, insidetime/1000000000))
print("{:<40} {:<6} {:<4} {:>6.2f} {:>6.2f}".format( name, count, totaltime/1000000000, insidetime/1000000000))

Loading…
Cancel
Save