Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250531220508\orcl_w000_9500_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:37203M/63366M, Ph+PgF:44064M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 9500, image: ORACLE.EXE (W000) *** 2025-05-31 22:05:08.934 *** SESSION ID:(177.17037) 2025-05-31 22:05:08.934 *** 2025-05-31 22:05:08.934 Process diagnostic dump for ORACLE.EXE (W000), OS id=9500, pid: 22, proc_ser: 131, sid: 177, sess_ser: 17037 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=27 seq_num=28 snap_id=1 wait times: snap=3.462957 sec, exc=3.462957 sec, total=3.462957 sec wait times: max=5.000000 sec, heur=2 min 13 sec wait counts: calls=1 os=1 in_wait=1 iflags=0x5a8 Wait State: fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1 Session Wait History: elapsed time of 0.000025 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=26 seq_num=27 snap_id=1 wait times: snap=5.007245 sec, exc=5.007245 sec, total=5.007245 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=25 seq_num=26 snap_id=1 wait times: snap=5.001291 sec, exc=5.001291 sec, total=5.001291 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000026 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=24 seq_num=25 snap_id=1 wait times: snap=5.004185 sec, exc=5.004185 sec, total=5.004185 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=23 seq_num=24 snap_id=1 wait times: snap=5.014722 sec, exc=5.014722 sec, total=5.014722 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=22 seq_num=23 snap_id=1 wait times: snap=5.010154 sec, exc=5.010154 sec, total=5.010154 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=21 seq_num=22 snap_id=1 wait times: snap=5.009772 sec, exc=5.009772 sec, total=5.009772 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=20 seq_num=21 snap_id=1 wait times: snap=5.003315 sec, exc=5.003315 sec, total=5.003315 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000021 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=19 seq_num=20 snap_id=1 wait times: snap=5.000325 sec, exc=5.000325 sec, total=5.000325 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=18 seq_num=19 snap_id=1 wait times: snap=5.013760 sec, exc=5.013760 sec, total=5.013760 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000031 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=5.006241 sec, exc=5.006241 sec, total=5.006241 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000023 sec of elapsed time Sampled Session History of session 177 serial 17037 --------------------------------------------------- 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 --------------------------------------------------- [121 samples, 22:03:08 - 22:05:08] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-31 22:05:08.934 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 9500, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-31 20:02:29.621828 :9E9292B1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14084 pso_num=22 pso_serial#=115 2025-05-31 20:02:29.621956 :9E9292B2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14084 (legacy spawn) 2025-05-31 20:02:29.628406 :9E9292B3:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-31 20:02:29.628582 :9E9292BC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-31 20:02:29.629412 :9E9292BD:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:02:29.638028 :9E9292C0:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:02:29.622 2025-05-31 20:02:29.638031 :9E9292C1:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15296 pso_num=22 pso_serial#=116 2025-05-31 20:02:29.638165 :9E9292C2:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15296 (legacy spawn) 2025-05-31 20:02:29.644769 :9E9292E5:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-31 20:02:29.644967 :9E9292FC:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-31 20:02:29.645744 :9E92930C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:02:32.874842 :9E92947F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:02:32.861 2025-05-31 20:02:32.874844 :9E929480:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11456 pso_num=22 pso_serial#=117 2025-05-31 20:02:32.874983 :9E929481:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11456 (legacy spawn) 2025-05-31 20:02:32.881428 :9E929482:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-31 20:02:32.881621 :9E929487:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-31 20:02:32.882420 :9E92948C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:02:32.890927 :9E92948F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:02:32.877 2025-05-31 20:02:32.890929 :9E929490:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9112 pso_num=22 pso_serial#=118 2025-05-31 20:02:32.891061 :9E929491:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9112 (legacy spawn) 2025-05-31 20:02:32.897482 :9E929492:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-31 20:02:32.897645 :9E92949B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-31 20:02:32.898449 :9E92949C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:02:37.954690 :9E92963A:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:02:37.946 2025-05-31 20:02:37.954692 :9E92963B:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15252 pso_num=22 pso_serial#=119 2025-05-31 20:02:37.954831 :9E92963C:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=15252 (legacy spawn) 2025-05-31 20:02:37.961257 :9E92963D:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-31 20:02:37.961454 :9E929642:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] 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-31 20:02:37.962278 :9E929647:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:02:38.857176 :9E929690:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:02:38.852 2025-05-31 20:02:38.857177 :9E929691:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=4696 pso_num=22 pso_serial#=120 2025-05-31 20:02:38.857312 :9E929692:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=4696 osp_idx=0 osp_ver=254172 osp_pg=0 (spawn #238883) 2025-05-31 20:02:38.857313 :9E929693:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:02:38.857313 :9E929694:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=71 time=1697517500 2025-05-31 20:02:38.857314 :9E929695:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:02:38.857314 :9E929696:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:02:38.857314 :9E929697:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:02:38.857315 :9E929698:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:02:38.857315 :9E929699:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:02:38.857799 :9E92969A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:02:38.857845 :9E9296A0:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 20:12:39.824497 :9E935F5A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:12:40.141793 :9E935F94:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:12:40.137 2025-05-31 20:12:40.141795 :9E935F95:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15080 pso_num=22 pso_serial#=121 2025-05-31 20:12:40.141931 :9E935F96:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15080 osp_idx=0 osp_ver=254173 osp_pg=0 (spawn #238907) 2025-05-31 20:12:40.141932 :9E935F97:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:12:40.141932 :9E935F98:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=72 time=1698118782 2025-05-31 20:12:40.141933 :9E935F99:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:12:40.141933 :9E935F9A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:12:40.141934 :9E935F9B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:12:40.141935 :9E935F9C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:12:40.141935 :9E935F9D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:12:40.142417 :9E935F9E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:12:40.142460 :9E935FA5:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 20:22:41.099532 :9E942541:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:22:41.385436 :9E942576:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:22:41.380 2025-05-31 20:22:41.385439 :9E942577:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14084 pso_num=22 pso_serial#=122 2025-05-31 20:22:41.385576 :9E942578:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14084 osp_idx=0 osp_ver=254174 osp_pg=0 (spawn #238930) 2025-05-31 20:22:41.385577 :9E942579:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:22:41.385578 :9E94257A:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=73 time=1698720032 2025-05-31 20:22:41.385578 :9E94257B:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:22:41.385579 :9E94257C:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:22:41.385579 :9E94257D:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:22:41.385580 :9E94257E:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:22:41.385580 :9E94257F:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:22:41.386093 :9E942580:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:22:41.386138 :9E942587:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 20:32:42.277336 :9E94E8F8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:32:42.651454 :9E94E949:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:32:42.647 2025-05-31 20:32:42.651456 :9E94E94A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14528 pso_num=22 pso_serial#=123 2025-05-31 20:32:42.651595 :9E94E94B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14528 osp_idx=0 osp_ver=254175 osp_pg=0 (spawn #238952) 2025-05-31 20:32:42.651595 :9E94E94C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:32:42.651595 :9E94E94D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=74 time=1699321297 2025-05-31 20:32:42.651596 :9E94E94E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:32:42.651597 :9E94E94F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:32:42.651597 :9E94E950:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:32:42.651597 :9E94E951:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:32:42.651598 :9E94E952:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:32:42.652075 :9E94E953:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:32:42.652120 :9E94E95B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 20:42:43.724716 :9E95AD31:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:42:44.088814 :9E95AD68:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:42:44.084 2025-05-31 20:42:44.088817 :9E95AD69:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12148 pso_num=22 pso_serial#=124 2025-05-31 20:42:44.088954 :9E95AD6A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12148 osp_idx=0 osp_ver=254176 osp_pg=0 (spawn #238975) 2025-05-31 20:42:44.088955 :9E95AD6B:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:42:44.088955 :9E95AD6C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=75 time=1699922735 2025-05-31 20:42:44.088955 :9E95AD6D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:42:44.088955 :9E95AD6E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:42:44.088956 :9E95AD6F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:42:44.088956 :9E95AD70:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:42:44.088956 :9E95AD71:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:42:44.089441 :9E95AD72:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:42:44.089487 :9E95AD7A:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 20:52:45.114294 :9E967064:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 20:52:45.475721 :9E9670A6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 20:52:45.470 2025-05-31 20:52:45.475723 :9E9670A7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14760 pso_num=22 pso_serial#=125 2025-05-31 20:52:45.475857 :9E9670A8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14760 osp_idx=0 osp_ver=254177 osp_pg=0 (spawn #238998) 2025-05-31 20:52:45.475858 :9E9670A9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 20:52:45.475859 :9E9670AA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=76 time=1700524125 2025-05-31 20:52:45.475859 :9E9670AB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 20:52:45.475860 :9E9670AC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 20:52:45.475860 :9E9670AD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 20:52:45.475860 :9E9670AE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 20:52:45.475860 :9E9670AF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 20:52:45.476337 :9E9670B0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 20:52:45.476382 :9E9670B8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 21:02:46.379461 :9E9735E9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 21:02:46.821789 :9E97361E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 21:02:46.817 2025-05-31 21:02:46.821792 :9E97361F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14796 pso_num=22 pso_serial#=126 2025-05-31 21:02:46.821931 :9E973620:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14796 osp_idx=0 osp_ver=254178 osp_pg=0 (spawn #239022) 2025-05-31 21:02:46.821933 :9E973621:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 21:02:46.821933 :9E973622:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=77 time=1701125469 2025-05-31 21:02:46.821934 :9E973623:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 21:02:46.821935 :9E973624:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 21:02:46.821936 :9E973625:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 21:02:46.821936 :9E973626:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 21:02:46.821936 :9E973627:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 21:02:46.822428 :9E973628:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 21:02:46.822479 :9E973632:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 21:07:51.420252 :9E97A03D:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=16 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-31 21:12:48.237986 :9E980077:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksl2.h LINE:2165 ID:kslpsr' id1=255 id2=0 name=EV type=0 fac#=0 facpost=1 2025-05-31 21:22:49.128877 :9E98C6A1:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 21:22:49.711679 :9E98C6E6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 21:22:49.706 2025-05-31 21:22:49.711681 :9E98C6E7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15024 pso_num=22 pso_serial#=127 2025-05-31 21:22:49.711839 :9E98C6E8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15024 osp_idx=0 osp_ver=254179 osp_pg=0 (spawn #239068) 2025-05-31 21:22:49.711840 :9E98C6E9:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 21:22:49.711840 :9E98C6EA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=78 time=1702328360 2025-05-31 21:22:49.711841 :9E98C6EB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 21:22:49.711841 :9E98C6EC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 21:22:49.711841 :9E98C6ED:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 21:22:49.711842 :9E98C6EE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 21:22:49.711842 :9E98C6EF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 21:22:49.712349 :9E98C6F0:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 21:22:49.712398 :9E98C6F8:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 21:32:50.593647 :9E998A3A:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 21:32:51.129697 :9E998A77:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 21:32:51.125 2025-05-31 21:32:51.129699 :9E998A78:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14592 pso_num=22 pso_serial#=128 2025-05-31 21:32:51.129839 :9E998A79:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14592 osp_idx=0 osp_ver=254180 osp_pg=0 (spawn #239090) 2025-05-31 21:32:51.129840 :9E998A7A:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 21:32:51.129840 :9E998A7B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=79 time=1702929782 2025-05-31 21:32:51.129841 :9E998A7C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 21:32:51.129841 :9E998A7D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 21:32:51.129841 :9E998A7E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 21:32:51.129842 :9E998A7F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 21:32:51.129842 :9E998A80:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 21:32:51.130332 :9E998A81:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 21:32:51.130377 :9E998A88:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 21:42:52.036695 :9E9A5016:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 21:42:52.588387 :9E9A5049:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 21:42:52.584 2025-05-31 21:42:52.588389 :9E9A504A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12308 pso_num=22 pso_serial#=129 2025-05-31 21:42:52.588521 :9E9A504B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12308 osp_idx=0 osp_ver=254181 osp_pg=0 (spawn #239113) 2025-05-31 21:42:52.588522 :9E9A504C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 21:42:52.588522 :9E9A504D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=80 time=1703531235 2025-05-31 21:42:52.588522 :9E9A504E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 21:42:52.588523 :9E9A504F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 21:42:52.588523 :9E9A5050:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 21:42:52.588523 :9E9A5051:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 21:42:52.588523 :9E9A5052:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 21:42:52.589065 :9E9A5053:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 21:42:52.589109 :9E9A505B:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 21:52:53.571213 :9E9B1640:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 21:52:53.904294 :9E9B1680:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 21:52:53.899 2025-05-31 21:52:53.904296 :9E9B1681:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11304 pso_num=22 pso_serial#=130 2025-05-31 21:52:53.904423 :9E9B1682:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11304 osp_idx=0 osp_ver=254182 osp_pg=0 (spawn #239136) 2025-05-31 21:52:53.904424 :9E9B1683:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 21:52:53.904424 :9E9B1684:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=81 time=1704132547 2025-05-31 21:52:53.904425 :9E9B1685:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 21:52:53.904425 :9E9B1686:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 21:52:53.904425 :9E9B1687:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 21:52:53.904426 :9E9B1688:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 21:52:53.904426 :9E9B1689:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 21:52:53.904907 :9E9B168A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 21:52:53.904954 :9E9B1693:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-31 22:02:54.704376 :9E9BDF0D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-31 22:02:55.291789 :9E9BDF49:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-31 22:02:55.287 2025-05-31 22:02:55.291791 :9E9BDF4A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9500 pso_num=22 pso_serial#=131 2025-05-31 22:02:55.291934 :9E9BDF4B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9500 osp_idx=0 osp_ver=254183 osp_pg=0 (spawn #239161) 2025-05-31 22:02:55.291934 :9E9BDF4C:db_trace:kso.c@4099:ksonfy(): [10420:22:0] kso: new process: first_req_pid=1236 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-31 22:02:55.291935 :9E9BDF4D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=82 time=1704733938 2025-05-31 22:02:55.291935 :9E9BDF4E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-31 22:02:55.291936 :9E9BDF4F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-31 22:02:55.291936 :9E9BDF50:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-31 22:02:55.291936 :9E9BDF51:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-31 22:02:55.291937 :9E9BDF52:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-31 22:02:55.292429 :9E9BDF53:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:22:177] KSL POST SENT postee=23 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-31 22:02:55.292476 :9E9BDF59:db_trace:ksl2.c@12699:ksliwat(): [10005:22:177] KSL POST RCVD poster=23 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 22 (osid: 9500, W000)