On 22 Jan 2004, at 14:14, Andres Kroonmaa <andre@online.ee> wrote:
> Also, regarding indirect hints, it crossed my mind that you could try
> check out state of *xprof_Timers array. Profiling probes are reset every
> second by event, thus probes that have stop timestamp zero mean active
> probes. If you can deduce from core all active profiling probes, you
> can hopefully narrow down area of sourcecode considerably. Infact with
> stop timestamps you can even deduce most recent history of probes.
This works with 3.0 only. But for fun, I tried to extract latest probe
trace from a core I had. After some scripting, you'd get something like
this, which is intact even when stack is completely smashed.
delta cputick timestamp probe event,
0 18692823504052420 -> "eventRun", 243932
242332 18692823504294752 -> "PROF_OVERHEAD", 76
76 18692823504294828 <- "PROF_OVERHEAD", 76
1524 18692823504296352 <- "eventRun", 243932
134970544 18692823639266896 -> "comm_open", 536692
536692 18692823639803588 <- "comm_open", 536692
2208052 18692823642011640 -> "comm_connect_addr", 8728
8728 18692823642020368 <- "comm_connect_addr", 8728
7376176 18692823649396544 -> "comm_close", 147972
147972 18692823649544516 <- "comm_close", 147972
2258476 18692823651802992 -> "xcalloc", 2544
112 18692823651803104 -> "calloc", 1488
1488 18692823651804592 <- "calloc", 1488
944 18692823651805536 <- "xcalloc", 2544
215392 18692823652020928 -> "xstrndup", 2304
2304 18692823652023232 <- "xstrndup", 2304
461896 18692823652485128 -> "storeGet", 3172
3172 18692823652488300 <- "storeGet", 3172
1362392 18692823653850692 -> "comm_check_incoming", 4496
4496 18692823653855188 <- "comm_check_incoming", 4496
408248 18692823654263436 -> "storeRelease", 26392
21336 18692823654284772 -> "xxfree", 176
176 18692823654284948 <- "xxfree", 176
4880 18692823654289828 <- "storeRelease", 26392
12712 18692823654302540 <- "commHandleWrite", -1
196 18692823654302736 <- "comm_write_handler", -1
14244 18692823654316980 -> "CommWriteCallbackData_callCallback", 12452
12452 18692823654329432 <- "CommWriteCallbackData_callCallback", 12452
6904888 18692823661234320 -> "comm_read_handler", 59892
59892 18692823661294212 <- "comm_read_handler", 59892
1952 18692823661296164 <- "comm_handle_ready_fd", -1
3064 18692823661299228 -> "storeDirCallback", 4356
4356 18692823661303584 <- "storeDirCallback", 4356
572 18692823661304156 -> "comm_calliocallback", 1131988
396 18692823661304552 -> "CommReadCallbackData_callCallback", 724972
920 18692823661305472 -> "HttpStateData_readReply", 723560
5880 18692823661311352 -> "HttpStateData_processReplyData", 716056
1536 18692823661312888 -> "StoreEntry_write", 561880
352 18692823661313240 -> "storeGetMemSpace", 404
404 18692823661313644 <- "storeGetMemSpace", 404
464 18692823661314108 -> "MemObject_write", 560244
1932 18692823661316040 -> "mem_hdr_write", 12648
12648 18692823661328688 <- "mem_hdr_write", 12648
184 18692823661328872 -> "storeWriteComplete", 545296
495536 18692823661824408 -> "aclCheckFast", 92
92 18692823661824500 <- "aclCheckFast", 92
8512 18692823661833012 -> "aclMatchAclList", 5012
5012 18692823661838024 <- "aclMatchAclList", 5012
36144 18692823661874168 <- "storeWriteComplete", 545296
184 18692823661874352 <- "MemObject_write", 560244
416 18692823661874768 <- "StoreEntry_write", 561880
8776 18692823661883544 -> "xcountws", 88
88 18692823661883632 <- "xcountws", 88
13416 18692823661897048 -> "hash_lookup", 1160
1160 18692823661898208 <- "hash_lookup", 1160
2344 18692823661900552 -> "xstrdup", 1584
1584 18692823661902136 <- "xstrdup", 1584
280 18692823661902416 -> "memPoolAlloc", 572
572 18692823661902988 <- "memPoolAlloc", 572
8252 18692823661911240 -> "xstrncpy", 716
716 18692823661911956 <- "xstrncpy", 716
115452 18692823662027408 <- "HttpStateData_processReplyData", 716056
1624 18692823662029032 <- "HttpStateData_readReply", 723560
492 18692823662029524 <- "CommReadCallbackData_callCallback", 724972
406620 18692823662436144 <- "comm_calliocallback", 1131988
4972 18692823662441116 -> "comm_poll_prep_pfds", 28912
28912 18692823662470028 <- "comm_poll_prep_pfds", 28912
524 18692823662470552 -> "comm_poll_normal", 23752
23752 18692823662494304 <- "comm_poll_normal", 23752
0 18692823662494304 -> "PROF_UNACCOUNTED", 20448
20448 18692823662514752 <- "PROF_UNACCOUNTED", 20448
0 18692823662514752 -> "comm_handle_ready_fd", -1
3008 18692823662517760 -> "comm_write_handler", -1
480 18692823662518240 -> "commHandleWrite", -1
41224 18692823662559464 -> "memPoolFree", 1440
1440 18692823662560904 <- "memPoolFree", 1440
20072 18692823662580976 -> "storeClient_kickReads", 2000
2000 18692823662582976 <- "storeClient_kickReads", 2000
276991484 18692823939574460 -> "xmalloc", 872
84 18692823939574544 -> "malloc", 484
484 18692823939575028 <- "malloc", 484
304 18692823939575332 <- "xmalloc", 872
107152 18692823939682484 -> "xfree", 1192
1192 18692823939683676 <- "xfree", 1192
Of course, its not exactly exec trace, as each probe has only its latest
invocation saved, but it can give you a clue as to in what part of code
the crash happens.
------------------------------------
Andres Kroonmaa <andre@online.ee>
CTO, Microlink Data AS
Tel: 6501 731, Fax: 6501 725
Pärnu mnt. 158, Tallinn
11317 Estonia
Received on Fri Jan 23 2004 - 04:26:31 MST
This archive was generated by hypermail pre-2.1.9 : Sat Jan 31 2004 - 12:00:10 MST