Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250530081630\orcl_w000_9028_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:37243M/63366M, Ph+PgF:44158M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 22 Windows thread id: 9028, image: ORACLE.EXE (W000) *** 2025-05-30 08:16:30.728 *** SESSION ID:(177.3917) 2025-05-30 08:16:30.728 *** 2025-05-30 08:16:30.728 Process diagnostic dump for ORACLE.EXE (W000), OS id=9028, pid: 22, proc_ser: 210, sid: 177, sess_ser: 3917 ------------------------------------------------------------------------------- current sql: Current Wait Stack: 0: waiting for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=104 seq_num=105 snap_id=1 wait times: snap=0.849839 sec, exc=0.849839 sec, total=0.849839 sec wait times: max=5.000000 sec, heur=8 min 36 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.000035 sec since current wait 0: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=103 seq_num=104 snap_id=1 wait times: snap=5.004646 sec, exc=5.004646 sec, total=5.004646 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 1: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=102 seq_num=103 snap_id=1 wait times: snap=5.014716 sec, exc=5.014716 sec, total=5.014716 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 2: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=101 seq_num=102 snap_id=1 wait times: snap=5.005139 sec, exc=5.005139 sec, total=5.005139 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000025 sec of elapsed time 3: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=100 seq_num=101 snap_id=1 wait times: snap=5.014560 sec, exc=5.014560 sec, total=5.014560 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 4: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=99 seq_num=100 snap_id=1 wait times: snap=5.009318 sec, exc=5.009318 sec, total=5.009318 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 5: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=98 seq_num=99 snap_id=1 wait times: snap=5.004639 sec, exc=5.004639 sec, total=5.004639 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000028 sec of elapsed time 6: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=97 seq_num=98 snap_id=1 wait times: snap=5.004612 sec, exc=5.004612 sec, total=5.004612 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000027 sec of elapsed time 7: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=96 seq_num=97 snap_id=1 wait times: snap=5.009201 sec, exc=5.009201 sec, total=5.009201 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000020 sec of elapsed time 8: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=95 seq_num=96 snap_id=1 wait times: snap=5.010149 sec, exc=5.010149 sec, total=5.010149 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time 9: waited for 'Space Manager: slave idle wait' Slave ID=0x0, =0x0, =0x0 wait_id=94 seq_num=95 snap_id=1 wait times: snap=5.001777 sec, exc=5.001777 sec, total=5.001777 sec wait times: max=5.000000 sec wait counts: calls=1 os=1 occurred after 0.000024 sec of elapsed time Sampled Session History of session 177 serial 3917 --------------------------------------------------- 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, 08:14:30 - 08:16:30] idle wait at each sample ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-30 08:16:30.728 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 22 (osid: 9028, W000) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-30 05:57:35.905196 :9DE05219:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 05:57:36.206786 :9DE05250:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 05:57:36.202 2025-05-30 05:57:36.206788 :9DE05251:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14656 pso_num=22 pso_serial#=196 2025-05-30 05:57:36.206923 :9DE05252:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14656 osp_idx=0 osp_ver=248638 osp_pg=0 (spawn #233578) 2025-05-30 05:57:36.206923 :9DE05253: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-30 05:57:36.206924 :9DE05254:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=69 time=1560416985 2025-05-30 05:57:36.206924 :9DE05255:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 05:57:36.206925 :9DE05256:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 05:57:36.206925 :9DE05257:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 05:57:36.206925 :9DE05258:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 05:57:36.206926 :9DE05259:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 05:57:36.207422 :9DE0525A: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-30 05:57:36.207474 :9DE05262: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-30 06:07:37.099761 :9DE122A2:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 06:07:37.448191 :9DE122E6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 06:07:37.443 2025-05-30 06:07:37.448192 :9DE122E7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=10716 pso_num=22 pso_serial#=197 2025-05-30 06:07:37.448326 :9DE122E8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=10716 osp_idx=0 osp_ver=248639 osp_pg=0 (spawn #233604) 2025-05-30 06:07:37.448327 :9DE122E9: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-30 06:07:37.448327 :9DE122EA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=70 time=1561018219 2025-05-30 06:07:37.448327 :9DE122EB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 06:07:37.448328 :9DE122EC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 06:07:37.448328 :9DE122ED:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 06:07:37.448328 :9DE122EE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 06:07:37.448329 :9DE122EF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 06:07:37.448818 :9DE122F0: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-30 06:07:37.448871 :9DE122F7: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-30 06:17:38.438354 :9DE1EDB4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 06:17:38.786784 :9DE1EDEF:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 06:17:38.782 2025-05-30 06:17:38.786787 :9DE1EDF0:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12400 pso_num=22 pso_serial#=198 2025-05-30 06:17:38.786921 :9DE1EDF1:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12400 osp_idx=0 osp_ver=248640 osp_pg=0 (spawn #233627) 2025-05-30 06:17:38.786922 :9DE1EDF2: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-30 06:17:38.786923 :9DE1EDF3:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=71 time=1561619563 2025-05-30 06:17:38.786924 :9DE1EDF4:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 06:17:38.786924 :9DE1EDF5:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 06:17:38.786925 :9DE1EDF6:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 06:17:38.786925 :9DE1EDF7:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 06:17:38.786926 :9DE1EDF8:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 06:17:38.787489 :9DE1EDF9: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-30 06:17:38.787537 :9DE1EE01: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-30 06:27:39.721809 :9DE2B5F4:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 06:27:40.117154 :9DE2B644:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 06:27:40.112 2025-05-30 06:27:40.117155 :9DE2B645:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14440 pso_num=22 pso_serial#=199 2025-05-30 06:27:40.117292 :9DE2B646:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14440 osp_idx=0 osp_ver=248641 osp_pg=0 (spawn #233649) 2025-05-30 06:27:40.117293 :9DE2B647: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-30 06:27:40.117293 :9DE2B648:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=72 time=1562220891 2025-05-30 06:27:40.117294 :9DE2B649:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 06:27:40.117294 :9DE2B64A:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 06:27:40.117294 :9DE2B64B:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 06:27:40.117295 :9DE2B64C:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 06:27:40.117295 :9DE2B64D:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 06:27:40.117780 :9DE2B64E: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-30 06:27:40.117842 :9DE2B658: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-30 06:28:25.219018 :9DE2C585:db_trace:ksl2.c@2477:kslwtbctx(): [10005:22:177] KSL WAIT BEG [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-05-30 06:28:25.219046 :9DE2C58C:db_trace:ksl2.c@2611:kslwtectx(): [10005:22:177] KSL WAIT END [latch free] 136537728/0x8236680 259/0x103 0/0x0 wait_id=10 seq_num=11 snap_id=1 2025-05-30 06:28:25.219048 :9DE2C58D:db_trace:ksl2.c@2619:kslwtectx(): [10005:22:177] KSL WAIT END wait times (usecs) - snap=27, exc=27, tot=27 2025-05-30 06:29:45.977410 :9DE2E022: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-30 06:37:41.371958 :9DE37DF1: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-30 06:47:42.293777 :9DE445DF:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 06:47:42.673443 :9DE44628:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 06:47:42.668 2025-05-30 06:47:42.673445 :9DE44629:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15040 pso_num=22 pso_serial#=200 2025-05-30 06:47:42.673577 :9DE4462A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15040 osp_idx=0 osp_ver=248642 osp_pg=0 (spawn #233695) 2025-05-30 06:47:42.673578 :9DE4462B: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-30 06:47:42.673578 :9DE4462C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=73 time=1563423438 2025-05-30 06:47:42.673578 :9DE4462D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 06:47:42.673579 :9DE4462E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 06:47:42.673579 :9DE4462F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 06:47:42.673579 :9DE44630:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 06:47:42.673580 :9DE44631:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 06:47:42.674069 :9DE44632: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-30 06:47:42.674115 :9DE44639: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-30 06:57:43.606097 :9DE50D5B:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 06:57:44.032673 :9DE50D90:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 06:57:44.028 2025-05-30 06:57:44.032676 :9DE50D91:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=7888 pso_num=22 pso_serial#=201 2025-05-30 06:57:44.032812 :9DE50D92:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=7888 osp_idx=0 osp_ver=248643 osp_pg=0 (spawn #233717) 2025-05-30 06:57:44.032812 :9DE50D93: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-30 06:57:44.032813 :9DE50D94:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=74 time=1564024797 2025-05-30 06:57:44.032813 :9DE50D95:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 06:57:44.032814 :9DE50D96:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 06:57:44.032814 :9DE50D97:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 06:57:44.032814 :9DE50D98:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 06:57:44.032815 :9DE50D99:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 06:57:44.033315 :9DE50D9A: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-30 06:57:44.033363 :9DE50DA1: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-30 07:07:44.896107 :9DE5E036:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:07:45.022734 :9DE5E039:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:07:45.021 2025-05-30 07:07:45.022736 :9DE5E03A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14400 pso_num=22 pso_serial#=202 2025-05-30 07:07:45.022870 :9DE5E03B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=14400 (legacy spawn) 2025-05-30 07:07:45.029223 :9DE5E03C: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-30 07:07:45.029402 :9DE5E041: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-30 07:07:45.030195 :9DE5E046:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:07:45.038850 :9DE5E049:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:07:45.036 2025-05-30 07:07:45.038852 :9DE5E04A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=11816 pso_num=22 pso_serial#=203 2025-05-30 07:07:45.038991 :9DE5E04B:db_trace:kso.c@4070:ksonfy(): [10420:22:0] kso: new process: pid=11816 (legacy spawn) 2025-05-30 07:07:45.045397 :9DE5E04C: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-30 07:07:45.045427 :9DE5E04F: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-30 07:07:45.045573 :9DE5E052: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-30 07:07:45.046356 :9DE5E062:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:07:45.463224 :9DE5E0A6:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:07:45.458 2025-05-30 07:07:45.463226 :9DE5E0A7:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=2404 pso_num=22 pso_serial#=204 2025-05-30 07:07:45.463371 :9DE5E0A8:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=2404 osp_idx=0 osp_ver=248646 osp_pg=0 (spawn #233743) 2025-05-30 07:07:45.463372 :9DE5E0A9: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-30 07:07:45.463373 :9DE5E0AA:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=75 time=1564626235 2025-05-30 07:07:45.463373 :9DE5E0AB:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:07:45.463374 :9DE5E0AC:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:07:45.463374 :9DE5E0AD:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:07:45.463375 :9DE5E0AE:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:07:45.463375 :9DE5E0AF:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:07:45.463903 :9DE5E0B0: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-30 07:07:45.463946 :9DE5E0B7: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-30 07:17:46.359950 :9DE6A7D3:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:17:46.895961 :9DE6A808:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:17:46.891 2025-05-30 07:17:46.895963 :9DE6A809:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14048 pso_num=22 pso_serial#=205 2025-05-30 07:17:46.896148 :9DE6A80A:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14048 osp_idx=0 osp_ver=248647 osp_pg=0 (spawn #233766) 2025-05-30 07:17:46.896148 :9DE6A80B: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-30 07:17:46.896149 :9DE6A80C:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=76 time=1565227672 2025-05-30 07:17:46.896149 :9DE6A80D:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:17:46.896150 :9DE6A80E:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:17:46.896150 :9DE6A80F:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:17:46.896150 :9DE6A810:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:17:46.896150 :9DE6A811:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:17:46.896647 :9DE6A812: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-30 07:17:46.896696 :9DE6A819: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-30 07:27:47.908356 :9DE76FA9:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:27:48.303731 :9DE76FE2:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:27:48.299 2025-05-30 07:27:48.303734 :9DE76FE3:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=14792 pso_num=22 pso_serial#=206 2025-05-30 07:27:48.303875 :9DE76FE4:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=14792 osp_idx=0 osp_ver=248648 osp_pg=0 (spawn #233788) 2025-05-30 07:27:48.303876 :9DE76FE5: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-30 07:27:48.303877 :9DE76FE6:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=77 time=1565829079 2025-05-30 07:27:48.303877 :9DE76FE7:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:27:48.303877 :9DE76FE8:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:27:48.303878 :9DE76FE9:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:27:48.303878 :9DE76FEA:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:27:48.303878 :9DE76FEB:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:27:48.304378 :9DE76FEC: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-30 07:27:48.304431 :9DE76FF3: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-30 07:37:49.217336 :9DE83825:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:37:49.659515 :9DE83869:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:37:49.654 2025-05-30 07:37:49.659516 :9DE8386A:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=13204 pso_num=22 pso_serial#=207 2025-05-30 07:37:49.659656 :9DE8386B:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=13204 osp_idx=0 osp_ver=248649 osp_pg=0 (spawn #233811) 2025-05-30 07:37:49.659657 :9DE8386C: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-30 07:37:49.659657 :9DE8386D:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=78 time=1566430422 2025-05-30 07:37:49.659657 :9DE8386E:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:37:49.659657 :9DE8386F:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:37:49.659658 :9DE83870:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:37:49.659658 :9DE83871:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:37:49.659658 :9DE83872:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:37:49.660177 :9DE83873: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-30 07:37:49.660228 :9DE8387A: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-30 07:47:50.645930 :9DE900EB:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:47:51.135109 :9DE90123:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:47:51.130 2025-05-30 07:47:51.135112 :9DE90124:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=12328 pso_num=22 pso_serial#=208 2025-05-30 07:47:51.135248 :9DE90125:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=12328 osp_idx=0 osp_ver=248650 osp_pg=0 (spawn #233834) 2025-05-30 07:47:51.135249 :9DE90126: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-30 07:47:51.135250 :9DE90127:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=79 time=1567031907 2025-05-30 07:47:51.135250 :9DE90128:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:47:51.135251 :9DE90129:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:47:51.135251 :9DE9012A:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:47:51.135251 :9DE9012B:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:47:51.135252 :9DE9012C:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:47:51.135762 :9DE9012D: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-30 07:47:51.135806 :9DE90135: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-30 07:57:51.973871 :9DE9C8C8:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 07:57:52.681558 :9DE9C90F:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 07:57:52.677 2025-05-30 07:57:52.681560 :9DE9C910:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=15204 pso_num=22 pso_serial#=209 2025-05-30 07:57:52.681693 :9DE9C911:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=15204 osp_idx=0 osp_ver=248651 osp_pg=0 (spawn #233856) 2025-05-30 07:57:52.681694 :9DE9C912: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-30 07:57:52.681694 :9DE9C913:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=80 time=1567633454 2025-05-30 07:57:52.681695 :9DE9C914:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 07:57:52.681695 :9DE9C915:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 07:57:52.681695 :9DE9C916:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 07:57:52.681696 :9DE9C917:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 07:57:52.681696 :9DE9C918:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 07:57:52.682189 :9DE9C919: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-30 07:57:52.682235 :9DE9C920: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-30 08:07:53.590309 :9DEA9B66:db_trace:kst.c@698:kstpsodel(): [10280:22:0] kst: process state object about to be deleted 2025-05-30 08:07:54.058309 :9DEA9BAD:db_trace:kst.c@673:kstipg(): [10280:22:0] kst: process state object created on 05-30 08:07:54.053 2025-05-30 08:07:54.058312 :9DEA9BAE:db_trace:kst.c@679:kstipg(): [10280:22:0] kst: process info: ospid=9028 pso_num=22 pso_serial#=210 2025-05-30 08:07:54.058454 :9DEA9BAF:db_trace:kso.c@4093:ksonfy(): [10420:22:0] kso: new process: pid=9028 osp_idx=0 osp_ver=248652 osp_pg=0 (spawn #233882) 2025-05-30 08:07:54.058454 :9DEA9BB0: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-30 08:07:54.058455 :9DEA9BB1:db_trace:kso.c@4103:ksonfy(): [10420:22:0] kso: new process: pso_index=22 reservation=81 time=1568234829 2025-05-30 08:07:54.058455 :9DEA9BB2:db_trace:kso.c@4109:ksonfy(): [10420:22:0] kso: spawn diagnostics: queue time=0 secs 2025-05-30 08:07:54.058455 :9DEA9BB3:db_trace:kso.c@4111:ksonfy(): [10420:22:0] kso: spawn diagnostics: fork time=0 secs 2025-05-30 08:07:54.058456 :9DEA9BB4:db_trace:kso.c@4113:ksonfy(): [10420:22:0] kso: spawn diagnostics: exec time=0 secs 2025-05-30 08:07:54.058456 :9DEA9BB5:db_trace:kso.c@4115:ksonfy(): [10420:22:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-30 08:07:54.058456 :9DEA9BB6:db_trace:kso.c@4117:ksonfy(): [10420:22:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-30 08:07:54.058943 :9DEA9BB7: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-30 08:07:54.058993 :9DEA9BBF: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: 9028, W000)