Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250507220009\orcl_w000_11720_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:37415M/63366M, Ph+PgF:44830M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 11720, image: ORACLE.EXE (W000) *** 2025-05-07 22:00:09.109 *** SESSION ID:(177.52871) 2025-05-07 22:00:09.109 *** 2025-05-07 22:00:09.109 Process diagnostic dump for ORACLE.EXE (W000), OS id=11720, pid: 22, proc_ser: 23, sid: 177, sess_ser: 52871 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=54 seq_num=55 snap_id=1 wait times: snap=0.927695 sec, exc=0.927695 sec, total=0.927695 sec wait times: max=5.000000 sec, heur=4 min 26 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.000030 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=53 seq_num=54 snap_id=1 wait times: snap=5.011112 sec, exc=5.011112 sec, total=5.011112 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000032 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=52 seq_num=53 snap_id=1 wait times: snap=5.001260 sec, exc=5.001260 sec, total=5.001260 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=51 seq_num=52 snap_id=1 wait times: snap=5.014778 sec, exc=5.014778 sec, total=5.014778 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=50 seq_num=51 snap_id=1 wait times: snap=5.004606 sec, exc=5.004606 sec, total=5.004606 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000033 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=49 seq_num=50 snap_id=1 wait times: snap=5.014705 sec, exc=5.014705 sec, total=5.014705 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000039 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=48 seq_num=49 snap_id=1 wait times: snap=5.007171 sec, exc=5.007171 sec, total=5.007171 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000082 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=47 seq_num=48 snap_id=1 wait times: snap=5.001405 sec, exc=5.001405 sec, total=5.001405 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=46 seq_num=47 snap_id=1 wait times: snap=5.010439 sec, exc=5.010439 sec, total=5.010439 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=45 seq_num=46 snap_id=1 wait times: snap=5.011853 sec, exc=5.011853 sec, total=5.011853 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000037 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=44 seq_num=45 snap_id=1 wait times: snap=5.004600 sec, exc=5.004600 sec, total=5.004600 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000036 sec of elapsed time Sampled Session History of session 177 serial 52871 --------------------------------------------------- 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, 21:58:09 - 22:00:09] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-07 22:00:09.109 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 11720, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-07 19:45:25.184780 :94073A86:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 19:45:25.184780 :94073A87:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 19:45:25.184781 :94073A88:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 19:45:25.185277 :94073A89: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-07 19:45:25.185323 :94073A91: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-07 19:55:26.148812 :940802C2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 19:55:26.528394 :94080321:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 19:55:26.523 2025-05-07 19:55:26.528397 :94080322:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=6572 pso_num=22 pso_serial#=8 2025-05-07 19:55:26.528571 :94080323:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=6572 osp_idx=0 osp_ver=163718 osp_pg=0 (spawn #158599) 2025-05-07 19:55:26.528572 :94080324: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-07 19:55:26.528573 :94080325:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=35 time=3918503687 2025-05-07 19:55:26.528573 :94080326:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 19:55:26.528574 :94080327:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 19:55:26.528574 :94080328:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 19:55:26.528574 :94080329:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 19:55:26.528575 :9408032A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 19:55:26.529067 :9408032B: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-07 19:55:26.529114 :94080335: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-07 20:05:27.414471 :9408CE72:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 20:05:27.747334 :9408CEAB:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 20:05:27.742 2025-05-07 20:05:27.747336 :9408CEAC:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9240 pso_num=22 pso_serial#=9 2025-05-07 20:05:27.747472 :9408CEAD:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9240 osp_idx=0 osp_ver=163719 osp_pg=0 (spawn #158625) 2025-05-07 20:05:27.747473 :9408CEAE: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-07 20:05:27.747473 :9408CEAF:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=36 time=3919104906 2025-05-07 20:05:27.747474 :9408CEB0:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 20:05:27.747474 :9408CEB1:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 20:05:27.747474 :9408CEB2:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 20:05:27.747475 :9408CEB3:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 20:05:27.747475 :9408CEB4:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 20:05:27.747980 :9408CEB5: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-07 20:05:27.748028 :9408CEBF: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-07 20:15:28.672401 :9409A197:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 20:15:29.067713 :9409A1DC:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 20:15:29.063 2025-05-07 20:15:29.067715 :9409A1DD:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=8032 pso_num=22 pso_serial#=10 2025-05-07 20:15:29.067845 :9409A1DE:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=8032 osp_idx=0 osp_ver=163720 osp_pg=0 (spawn #158648) 2025-05-07 20:15:29.067846 :9409A1DF: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-07 20:15:29.067846 :9409A1E0:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=37 time=3919706234 2025-05-07 20:15:29.067846 :9409A1E1:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 20:15:29.067847 :9409A1E2:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 20:15:29.067847 :9409A1E3:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 20:15:29.067847 :9409A1E4:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 20:15:29.067848 :9409A1E5:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 20:15:29.068335 :9409A1E6: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-07 20:15:29.068384 :9409A1F0: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-07 20:25:29.981914 :940A6B8D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 20:25:30.408470 :940A6BE6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 20:25:30.404 2025-05-07 20:25:30.408472 :940A6BE7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9836 pso_num=22 pso_serial#=11 2025-05-07 20:25:30.408606 :940A6BE8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9836 osp_idx=0 osp_ver=163721 osp_pg=0 (spawn #158672) 2025-05-07 20:25:30.408606 :940A6BE9: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-07 20:25:30.408606 :940A6BEA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=38 time=3920307578 2025-05-07 20:25:30.408607 :940A6BEB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 20:25:30.408607 :940A6BEC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 20:25:30.408607 :940A6BED:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 20:25:30.408608 :940A6BEE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 20:25:30.408608 :940A6BEF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 20:25:30.409093 :940A6BF0: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-07 20:25:30.409139 :940A6BF9: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-07 20:35:31.231922 :940B3656:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 20:35:31.705413 :940B36A3:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 20:35:31.700 2025-05-07 20:35:31.705415 :940B36A4:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11592 pso_num=22 pso_serial#=12 2025-05-07 20:35:31.705553 :940B36A5:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11592 osp_idx=0 osp_ver=163722 osp_pg=0 (spawn #158695) 2025-05-07 20:35:31.705554 :940B36A6: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-07 20:35:31.705554 :940B36A7:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=39 time=3920908875 2025-05-07 20:35:31.705554 :940B36A8:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 20:35:31.705555 :940B36A9:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 20:35:31.705555 :940B36AA:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 20:35:31.705555 :940B36AB:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 20:35:31.705556 :940B36AC:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 20:35:31.706054 :940B36AD: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-07 20:35:31.706112 :940B36B3: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-07 20:37:45.339153 :940B63A3: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-07 20:45:33.134260 :940C011B: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-07 20:55:34.056932 :940CCB29:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 20:55:34.498996 :940CCB77:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 20:55:34.494 2025-05-07 20:55:34.498998 :940CCB78:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12188 pso_num=22 pso_serial#=13 2025-05-07 20:55:34.499131 :940CCB79:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12188 osp_idx=0 osp_ver=163723 osp_pg=0 (spawn #158739) 2025-05-07 20:55:34.499131 :940CCB7A: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-07 20:55:34.499132 :940CCB7B:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=40 time=3922111671 2025-05-07 20:55:34.499132 :940CCB7C:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 20:55:34.499132 :940CCB7D:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 20:55:34.499133 :940CCB7E:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 20:55:34.499133 :940CCB7F:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 20:55:34.499134 :940CCB80:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 20:55:34.499618 :940CCB81: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-07 20:55:34.499661 :940CCB8B: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-07 21:05:35.380813 :940D9C3D:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:05:35.628147 :940D9C5F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:05:35.615 2025-05-07 21:05:35.628149 :940D9C60:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11396 pso_num=22 pso_serial#=14 2025-05-07 21:05:35.628291 :940D9C61:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11396 (legacy spawn) 2025-05-07 21:05:35.634701 :940D9C62: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-07 21:05:35.634889 :940D9C6B: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-07 21:05:35.635692 :940D9C6C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:05:35.644188 :940D9C6F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:05:35.631 2025-05-07 21:05:35.644191 :940D9C70:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7736 pso_num=22 pso_serial#=15 2025-05-07 21:05:35.644326 :940D9C71:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=7736 (legacy spawn) 2025-05-07 21:05:35.650809 :940D9C72: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-07 21:05:35.650968 :940D9C7B: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-07 21:05:35.651765 :940D9C7C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:05:35.979315 :940D9CB5:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:05:35.975 2025-05-07 21:05:35.979317 :940D9CB6:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=5020 pso_num=22 pso_serial#=16 2025-05-07 21:05:35.979457 :940D9CB7:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=5020 osp_idx=0 osp_ver=163726 osp_pg=0 (spawn #158765) 2025-05-07 21:05:35.979458 :940D9CB8: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-07 21:05:35.979458 :940D9CB9:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=41 time=3922713140 2025-05-07 21:05:35.979458 :940D9CBA:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:05:35.979459 :940D9CBB:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:05:35.979459 :940D9CBC:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:05:35.979459 :940D9CBD:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:05:35.979460 :940D9CBE:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:05:35.979955 :940D9CBF: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-07 21:05:35.980000 :940D9CC8: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-07 21:15:36.817306 :940E6A4F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:15:37.300821 :940E6A9E:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:15:37.296 2025-05-07 21:15:37.300823 :940E6A9F:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10000 pso_num=22 pso_serial#=17 2025-05-07 21:15:37.300954 :940E6AA0:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10000 osp_idx=0 osp_ver=163727 osp_pg=0 (spawn #158788) 2025-05-07 21:15:37.300954 :940E6AA1: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-07 21:15:37.300955 :940E6AA2:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=42 time=3923314468 2025-05-07 21:15:37.300955 :940E6AA3:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:15:37.300956 :940E6AA4:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:15:37.300956 :940E6AA5:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:15:37.300956 :940E6AA6:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:15:37.300956 :940E6AA7:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:15:37.301503 :940E6AA8: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-07 21:15:37.301550 :940E6AB0: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-07 21:25:38.189848 :940F3464:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:25:38.604070 :940F347F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:25:38.596 2025-05-07 21:25:38.604072 :940F3480:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9240 pso_num=22 pso_serial#=18 2025-05-07 21:25:38.604209 :940F3481:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9240 (legacy spawn) 2025-05-07 21:25:38.610580 :940F3482: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-07 21:25:38.610756 :940F348A: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-07 21:25:38.611555 :940F348C:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:25:38.741364 :940F34C7:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:25:38.737 2025-05-07 21:25:38.741365 :940F34C8:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11272 pso_num=22 pso_serial#=19 2025-05-07 21:25:38.741503 :940F34C9:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11272 osp_idx=0 osp_ver=163729 osp_pg=0 (spawn #158812) 2025-05-07 21:25:38.741504 :940F34CA: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-07 21:25:38.741505 :940F34CB:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=43 time=3923915906 2025-05-07 21:25:38.741505 :940F34CC:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:25:38.741506 :940F34CD:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:25:38.741506 :940F34CE:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:25:38.741506 :940F34CF:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:25:38.741507 :940F34D0:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:25:38.742025 :940F34D1: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-07 21:25:38.742066 :940F34D8: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-07 21:35:39.669954 :940FFF30:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:35:40.222564 :940FFF91:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:35:40.217 2025-05-07 21:35:40.222566 :940FFF92:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11940 pso_num=22 pso_serial#=20 2025-05-07 21:35:40.222699 :940FFF93:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11940 osp_idx=0 osp_ver=163730 osp_pg=0 (spawn #158835) 2025-05-07 21:35:40.222700 :940FFF94: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-07 21:35:40.222701 :940FFF95:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=44 time=3924517390 2025-05-07 21:35:40.222701 :940FFF96:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:35:40.222701 :940FFF97:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:35:40.222702 :940FFF98:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:35:40.222702 :940FFF99:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:35:40.222702 :940FFF9A:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:35:40.223181 :940FFF9B: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-07 21:35:40.223235 :940FFFA2: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-07 21:45:41.071606 :9410C8C6:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:45:41.638743 :9410C92D:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:45:41.634 2025-05-07 21:45:41.638745 :9410C92E:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10208 pso_num=22 pso_serial#=21 2025-05-07 21:45:41.638878 :9410C92F:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10208 osp_idx=0 osp_ver=163731 osp_pg=0 (spawn #158858) 2025-05-07 21:45:41.638879 :9410C930: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-07 21:45:41.638880 :9410C931:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=45 time=3925118812 2025-05-07 21:45:41.638880 :9410C932:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:45:41.638880 :9410C933:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:45:41.638881 :9410C934:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:45:41.638881 :9410C935:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:45:41.638883 :9410C936:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:45:41.639408 :9410C937: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-07 21:45:41.639452 :9410C93F: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-07 21:55:42.413252 :9411930F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:55:42.749336 :94119332:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:55:42.741 2025-05-07 21:55:42.749338 :94119333:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9868 pso_num=22 pso_serial#=22 2025-05-07 21:55:42.749469 :94119334:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=9868 (legacy spawn) 2025-05-07 21:55:42.755816 :94119335: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-07 21:55:42.755990 :9411933D: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-07 21:55:42.756811 :9411933F:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-07 21:55:42.886597 :94119379:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-07 21:55:42.881 2025-05-07 21:55:42.886600 :9411937A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11720 pso_num=22 pso_serial#=23 2025-05-07 21:55:42.886735 :9411937B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=11720 osp_idx=0 osp_ver=163733 osp_pg=0 (spawn #158880) 2025-05-07 21:55:42.886736 :9411937C: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-07 21:55:42.886736 :9411937D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=46 time=3925720046 2025-05-07 21:55:42.886737 :9411937E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-07 21:55:42.886737 :9411937F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-07 21:55:42.886738 :94119380:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-07 21:55:42.886738 :94119381:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-07 21:55:42.886738 :94119382:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-07 21:55:42.887223 :94119383: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-07 21:55:42.887279 :9411938D: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: 11720, W000)