Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250511082603\orcl_m002_10752_bucket.trc Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options Windows NT Version V6.2 CPU : 32 - type 8664, 16 Physical Cores Process Affinity : 0x0x0000000000000000 Memory (Avail/Total): Ph:37480M/63366M, Ph+PgF:44816M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 29 Windows thread id: 10752, image: ORACLE.EXE (M002) *** 2025-05-11 08:26:03.176 *** SESSION ID:(233.21479) 2025-05-11 08:26:03.176 *** 2025-05-11 08:26:03.176 Process diagnostic dump for ORACLE.EXE (M002), OS id=10752, pid: 29, proc_ser: 7, sid: 233, sess_ser: 21479 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'db file sequential read' file#=0x2, block#=0x6c02, blocks=0x1 wait_id=1669 seq_num=1670 snap_id=1 wait times: snap=0.003566 sec, exc=0.003566 sec, total=0.003566 sec wait times: max=infinite, heur=0.003566 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a0 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000350 sec since current wait 0: waited for 'db file sequential read' file#=0x2, block#=0x6c4a, blocks=0x1 wait_id=1668 seq_num=1669 snap_id=1 wait times: snap=0.005958 sec, exc=0.005958 sec, total=0.005958 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000173 sec of elapsed time 1: waited for 'db file sequential read' file#=0x2, block#=0x6baa, blocks=0x1 wait_id=1667 seq_num=1668 snap_id=1 wait times: snap=0.000277 sec, exc=0.000277 sec, total=0.000277 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000347 sec of elapsed time 2: waited for 'db file sequential read' file#=0x2, block#=0x6b9a, blocks=0x1 wait_id=1666 seq_num=1667 snap_id=1 wait times: snap=0.006424 sec, exc=0.006424 sec, total=0.006424 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000338 sec of elapsed time 3: waited for 'db file sequential read' file#=0x2, block#=0x6b8a, blocks=0x1 wait_id=1665 seq_num=1666 snap_id=1 wait times: snap=0.005171 sec, exc=0.005171 sec, total=0.005171 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000310 sec of elapsed time 4: waited for 'db file sequential read' file#=0x2, block#=0x62fa, blocks=0x1 wait_id=1664 seq_num=1665 snap_id=1 wait times: snap=0.002087 sec, exc=0.002087 sec, total=0.002087 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000146 sec of elapsed time 5: waited for 'db file sequential read' file#=0x2, block#=0x62ea, blocks=0x1 wait_id=1663 seq_num=1664 snap_id=1 wait times: snap=0.000266 sec, exc=0.000266 sec, total=0.000266 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000338 sec of elapsed time 6: waited for 'db file sequential read' file#=0x2, block#=0x62da, blocks=0x1 wait_id=1662 seq_num=1663 snap_id=1 wait times: snap=0.004621 sec, exc=0.004621 sec, total=0.004621 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000205 sec of elapsed time 7: waited for 'db file sequential read' file#=0x2, block#=0x62b2, blocks=0x1 wait_id=1661 seq_num=1662 snap_id=1 wait times: snap=0.001167 sec, exc=0.001167 sec, total=0.001167 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000146 sec of elapsed time 8: waited for 'db file sequential read' file#=0x2, block#=0x5b62, blocks=0x1 wait_id=1660 seq_num=1661 snap_id=1 wait times: snap=0.000125 sec, exc=0.000125 sec, total=0.000125 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000318 sec of elapsed time 9: waited for 'db file sequential read' file#=0x2, block#=0x5b3a, blocks=0x1 wait_id=1659 seq_num=1660 snap_id=1 wait times: snap=0.002996 sec, exc=0.002996 sec, total=0.002996 sec wait times: max=infinite wait counts: calls=0 os=0 occurred after 0.000356 sec of elapsed time Sampled Session History of session 233 serial 21479 --------------------------------------------------- The sampled session history is constructed by sampling the target session every 1 second. The sampling process captures at each sample if the session is in a non-idle wait, an idle wait, or not in a wait. If the session is in a non-idle wait then one interval is shown for all the samples the session was in the same non-idle wait. If the session is in an idle wait or not in a wait for consecutive samples then one interval is shown for all the consecutive samples. Though we display these consecutive samples in a single interval the session may NOT be continuously idle or not in a wait (the sampling process does not know). The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [1 sample, 08:26:02] waited for 'enq: TC - contention', seq_num: 1210 p1: 'name|mode'=0x54430006 p2: 'checkpoint ID'=0x1001d p3: '0'=0x0 time_waited: >= 0 sec (still in wait) [1 sample, 08:26:01] idle wait at each sample [session created at: 08:26:02] --------------------------------------------------- Sampled Session History Summary: longest_non_idle_wait: 'enq: TC - contention' [1 sample, 08:26:02 ] time_waited: >= 0 sec (still in wait) --------------------------------------------------- ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-11 08:26:03.176 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 29 (osid: 10752, M002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-11 07:01:01.060865 :958D1D60:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 07:01:01.061348 :958D1D61:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.061391 :958D1D67:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 07:01:01.068833 :958D1D75:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.069919 :958D1D7D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.070494 :958D1D85:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.071026 :958D1D8D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.071489 :958D1D95:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.074219 :958D1D9D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.075378 :958D1DA5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.125078 :958D1DAD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.125990 :958D1DB5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.126231 :958D1DBD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.126476 :958D1DC5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 07:01:01.128240 :958D1DCD:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 07:03:00.007140 :958D4661:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 07:02:59.995 2025-05-11 07:03:00.007141 :958D4662:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12788 pso_num=29 pso_serial#=253 2025-05-11 07:03:00.007280 :958D4663:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12788 osp_idx=27 osp_ver=10707 osp_pg=0 (spawn #170355) 2025-05-11 07:03:00.007281 :958D4664:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 07:03:00.007281 :958D4665:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=249 time=4217757171 2025-05-11 07:03:00.007282 :958D4666:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 07:03:00.007283 :958D4667:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 07:03:00.007283 :958D4668:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 07:03:00.007284 :958D4669:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 07:03:00.007284 :958D466A:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 07:03:00.007869 :958D466B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 07:03:00.007919 :958D4671:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 07:03:00.016491 :958D4686:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 07:23:03.041482 :958ED793:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 07:23:03.029 2025-05-11 07:23:03.041485 :958ED794:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12148 pso_num=29 pso_serial#=254 2025-05-11 07:23:03.041618 :958ED795:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12148 osp_idx=27 osp_ver=10708 osp_pg=0 (spawn #170401) 2025-05-11 07:23:03.041619 :958ED796:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 07:23:03.041621 :958ED797:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=250 time=4218960203 2025-05-11 07:23:03.041622 :958ED798:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 07:23:03.041622 :958ED799:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 07:23:03.041622 :958ED79A:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 07:23:03.041623 :958ED79B:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 07:23:03.041623 :958ED79C:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 07:23:03.042111 :958ED79D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 07:23:03.042151 :958ED7A3:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 07:23:03.046269 :958ED7CC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.046310 :958ED7CD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.046678 :958ED7CE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.046699 :958ED7CF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.046913 :958ED7D0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.046927 :958ED7D1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.047140 :958ED7D2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.047154 :958ED7D3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.047368 :958ED7D4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.047381 :958ED7D5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.047591 :958ED7D6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:23:03.047604 :958ED7D7:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:23:03.049858 :958ED7D8:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 07:53:07.035706 :95912204:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 07:53:07.033 2025-05-11 07:53:07.035707 :95912205:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12788 pso_num=29 pso_serial#=255 2025-05-11 07:53:07.035837 :95912206:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12788 osp_idx=27 osp_ver=10709 osp_pg=0 (spawn #170469) 2025-05-11 07:53:07.035838 :95912207:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 07:53:07.035838 :95912208:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=251 time=4220764203 2025-05-11 07:53:07.035839 :95912209:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 07:53:07.035839 :9591220A:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 07:53:07.035839 :9591220B:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 07:53:07.035840 :9591220C:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 07:53:07.035840 :9591220D:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 07:53:07.036385 :9591220E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 07:53:07.036429 :95912214:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 07:53:07.040490 :9591222D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.040536 :9591222E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.040796 :9591222F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.040813 :95912230:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.041032 :95912231:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.041045 :95912232:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.041257 :95912233:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.041270 :95912234:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.041480 :95912235:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.041492 :95912236:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.041696 :95912237:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 07:53:07.041710 :95912238:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 07:53:07.044191 :95912239:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:00:09.415524 :9591AC19:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:00:09.410 2025-05-11 08:00:09.415527 :9591AC1A:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=9580 pso_num=29 pso_serial#=1 2025-05-11 08:00:09.415669 :9591AC1B:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=9580 osp_idx=27 osp_ver=10710 osp_pg=0 (spawn #170486) 2025-05-11 08:00:09.415669 :9591AC1C:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 08:00:09.415669 :9591AC1D:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=252 time=4221186562 2025-05-11 08:00:09.415670 :9591AC1E:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 08:00:09.415670 :9591AC1F:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 08:00:09.415670 :9591AC20:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 08:00:09.415671 :9591AC21:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 08:00:09.415671 :9591AC22:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 08:00:09.416186 :9591AC23:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.416234 :9591AC29:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 08:00:09.424119 :9591AC37:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.425225 :9591AC3F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.425776 :9591AC47:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.426320 :9591AC4F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.426768 :9591AC57:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.429193 :9591AC5F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.430362 :9591AC67:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.480378 :9591AC7F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.481819 :9591AC87:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.482682 :9591AC8F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.482925 :9591AC97:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.483163 :9591AC9F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:00:09.485019 :9591ACA7:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:03:08.417956 :9591E75C:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:03:08.406 2025-05-11 08:03:08.417957 :9591E75D:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=13176 pso_num=29 pso_serial#=2 2025-05-11 08:03:08.418104 :9591E75E:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=13176 osp_idx=27 osp_ver=10711 osp_pg=0 (spawn #170496) 2025-05-11 08:03:08.418105 :9591E75F:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 08:03:08.418106 :9591E760:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=253 time=4221365578 2025-05-11 08:03:08.418106 :9591E761:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 08:03:08.418106 :9591E762:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 08:03:08.418107 :9591E763:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 08:03:08.418107 :9591E764:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 08:03:08.418107 :9591E765:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 08:03:08.418687 :9591E766:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 08:03:08.418755 :9591E76C:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 08:03:08.427362 :9591E790:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:23:10.920511 :95937526:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:23:10.908 2025-05-11 08:23:10.920513 :95937527:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=11924 pso_num=29 pso_serial#=3 2025-05-11 08:23:10.920687 :95937528:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=11924 osp_idx=27 osp_ver=10712 osp_pg=0 (spawn #170542) 2025-05-11 08:23:10.920687 :95937529:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 08:23:10.920688 :9593752A:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=254 time=4222568078 2025-05-11 08:23:10.920688 :9593752B:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 08:23:10.920689 :9593752C:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 08:23:10.920690 :9593752D:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 08:23:10.920690 :9593752E:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 08:23:10.920691 :9593752F:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 08:23:10.921255 :95937530:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 08:23:10.921307 :95937536:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 08:23:10.925391 :9593754F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.925446 :95937550:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.925710 :95937551:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.925726 :95937552:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.925941 :95937553:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.925955 :95937554:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.926160 :95937555:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.926172 :95937556:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.926377 :95937557:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.926390 :95937558:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.926590 :95937559:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpus:kelt.c:517 2025-05-11 08:23:10.926602 :9593755A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:29:233] atxpop:kelt.c:517 2025-05-11 08:23:10.928906 :9593755B:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:25:59.319086 :9593E4C7:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:25:59.306 2025-05-11 08:25:59.319088 :9593E4C8:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=7952 pso_num=29 pso_serial#=4 2025-05-11 08:25:59.319221 :9593E4C9:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=7952 (legacy spawn) 2025-05-11 08:25:59.325600 :9593E4CA:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:25:59.326020 :9593E4D3:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-11 08:25:59.326852 :9593E4D4:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:25:59.335508 :9593E4D9:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:25:59.322 2025-05-11 08:25:59.335510 :9593E4DA:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12236 pso_num=29 pso_serial#=5 2025-05-11 08:25:59.335643 :9593E4DB:db_trace:kso.c@4070:ksonfy(): [10420:29:0] kso: new process: pid=12236 (legacy spawn) 2025-05-11 08:25:59.342015 :9593E4DC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-11 08:25:59.342332 :9593E4E5:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=14 loc='ksl2.h LINE:2165 ID:kslpsr' id1=134 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-11 08:25:59.343147 :9593E4E6:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:25:59.985410 :9593E630:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:25:59.978 2025-05-11 08:25:59.985413 :9593E631:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=12944 pso_num=29 pso_serial#=6 2025-05-11 08:25:59.985579 :9593E632:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=12944 osp_idx=27 osp_ver=10715 osp_pg=0 (spawn #170550) 2025-05-11 08:25:59.985580 :9593E633:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 08:25:59.985580 :9593E634:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=255 time=4222737156 2025-05-11 08:25:59.985580 :9593E635:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 08:25:59.985581 :9593E636:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 08:25:59.985581 :9593E637:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 08:25:59.985582 :9593E638:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 08:25:59.985582 :9593E639:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 08:25:59.986475 :9593E63A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 08:25:59.986523 :9593E640:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-11 08:26:00.099680 :9593E7EF:db_trace:kst.c@698:kstpsodel(): [10280:29:0] kst: process state object about to be deleted 2025-05-11 08:26:02.169791 :9593E885:db_trace:kst.c@673:kstipg(): [10280:29:0] kst: process state object created on 05-11 08:26:02.160 2025-05-11 08:26:02.169793 :9593E886:db_trace:kst.c@679:kstipg(): [10280:29:0] kst: process info: ospid=10752 pso_num=29 pso_serial#=7 2025-05-11 08:26:02.169919 :9593E887:db_trace:kso.c@4093:ksonfy(): [10420:29:0] kso: new process: pid=10752 osp_idx=27 osp_ver=10716 osp_pg=0 (spawn #170552) 2025-05-11 08:26:02.169920 :9593E888:db_trace:kso.c@4099:ksonfy(): [10420:29:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-11 08:26:02.169920 :9593E889:db_trace:kso.c@4103:ksonfy(): [10420:29:0] kso: new process: pso_index=29 reservation=0 time=4222739328 2025-05-11 08:26:02.169920 :9593E88A:db_trace:kso.c@4109:ksonfy(): [10420:29:0] kso: spawn diagnostics: queue time=0 secs 2025-05-11 08:26:02.169921 :9593E88B:db_trace:kso.c@4111:ksonfy(): [10420:29:0] kso: spawn diagnostics: fork time=0 secs 2025-05-11 08:26:02.169921 :9593E88C:db_trace:kso.c@4113:ksonfy(): [10420:29:0] kso: spawn diagnostics: exec time=0 secs 2025-05-11 08:26:02.169921 :9593E88D:db_trace:kso.c@4115:ksonfy(): [10420:29:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-11 08:26:02.169922 :9593E88E:db_trace:kso.c@4117:ksonfy(): [10420:29:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-11 08:26:02.170476 :9593E88F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:29:233] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-11 08:26:02.170524 :9593E895:db_trace:ksl2.c@12699:ksliwat(): [10005:29:233] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 29 (osid: 10752, M002)