Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250505220010\orcl_j002_10496_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:37489M/63366M, Ph+PgF:44980M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 10496, image: ORACLE.EXE (J002) *** 2025-05-05 22:00:10.214 *** SESSION ID:(225.47641) 2025-05-05 22:00:10.214 *** 2025-05-05 22:00:10.214 Process diagnostic dump for ORACLE.EXE (J002), OS id=10496, pid: 28, proc_ser: 5, sid: 225, sess_ser: 47641 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 10496 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=17 seq_num=18 snap_id=1 wait times: snap=0.178800 sec, exc=0.178800 sec, total=0.178800 sec wait times: max=0.500000 sec, heur=8.108082 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.000009 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=0.510094 sec, exc=0.510094 sec, total=0.510094 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 1: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.500004 sec, exc=0.500004 sec, total=0.500004 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 2: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=14 seq_num=15 snap_id=1 wait times: snap=0.499985 sec, exc=0.499985 sec, total=0.499985 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=13 seq_num=14 snap_id=1 wait times: snap=0.500009 sec, exc=0.500009 sec, total=0.500009 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000007 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.499996 sec, exc=0.499996 sec, total=0.499996 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.504056 sec, exc=0.504056 sec, total=0.504056 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 6: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.500547 sec, exc=0.500547 sec, total=0.500547 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000006 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=9 seq_num=10 snap_id=1 wait times: snap=0.499991 sec, exc=0.499991 sec, total=0.499991 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.500004 sec, exc=0.500004 sec, total=0.500004 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.499986 sec, exc=0.499986 sec, total=0.499986 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000004 sec of elapsed time Sampled Session History of session 225 serial 47641 --------------------------------------------------- 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 --------------------------------------------------- [9 samples, 22:00:02 - 22:00:10] idle wait at each sample [session created at: 22:00:02] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-05 22:00:10.214 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 10496, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-05 21:00:39.847253 :932C4171:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10500 pso_num=28 pso_serial#=254 2025-05-05 21:00:39.847437 :932C4172:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=10500 (legacy spawn) 2025-05-05 21:00:39.853901 :932C4173:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:39.854072 :932C417C:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-05 21:00:39.854887 :932C417D:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 21:00:40.975752 :932C4210:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 21:00:40.965 2025-05-05 21:00:40.975753 :932C4211:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10124 pso_num=28 pso_serial#=255 2025-05-05 21:00:40.975886 :932C4212:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=10124 osp_idx=26 osp_ver=89249 osp_pg=0 (spawn #151984) 2025-05-05 21:00:40.975887 :932C4213:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:00:40.975888 :932C4214:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=93 time=3749618140 2025-05-05 21:00:40.975888 :932C4215:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:00:40.975888 :932C4216:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:00:40.975889 :932C4217:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:00:40.975889 :932C4218:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:00:40.975889 :932C4219:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:00:40.976400 :932C421A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.976441 :932C4220:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 21:00:40.978919 :932C422E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.984099 :932C4236:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.985165 :932C423E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.985710 :932C4246:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.986153 :932C424E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.986581 :932C4256:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.989091 :932C425E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:40.990179 :932C4266:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:41.046606 :932C426E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:41.047481 :932C4276:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:41.047785 :932C427E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:41.047995 :932C4286:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 21:00:41.049729 :932C428E:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 21:05:40.252541 :932CAAF9:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 21:05:40.240 2025-05-05 21:05:40.252543 :932CAAFA:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=7776 pso_num=28 pso_serial#=1 2025-05-05 21:05:40.252681 :932CAAFB:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=7776 osp_idx=26 osp_ver=89250 osp_pg=0 (spawn #151996) 2025-05-05 21:05:40.252682 :932CAAFC:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:05:40.252682 :932CAAFD:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=94 time=3749917406 2025-05-05 21:05:40.252683 :932CAAFE:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:05:40.252683 :932CAAFF:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:05:40.252683 :932CAB00:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:05:40.252684 :932CAB01:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:05:40.252684 :932CAB02:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:05:40.253189 :932CAB03:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 21:05:40.253231 :932CAB09:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 21:05:40.257233 :932CAB22:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.257277 :932CAB23:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.257535 :932CAB24:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.257550 :932CAB25:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.257764 :932CAB26:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.257779 :932CAB27:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.257986 :932CAB28:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.257999 :932CAB29:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.258209 :932CAB2A:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.258222 :932CAB2B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.258430 :932CAB2C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:05:40.258442 :932CAB2D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:05:40.260784 :932CAB2E:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 21:21:42.537754 :932DF045:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 21:21:42.532 2025-05-05 21:21:42.537755 :932DF046:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=9672 pso_num=28 pso_serial#=2 2025-05-05 21:21:42.537886 :932DF047:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=9672 osp_idx=26 osp_ver=89251 osp_pg=0 (spawn #152034) 2025-05-05 21:21:42.537887 :932DF048:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:21:42.537887 :932DF049:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=95 time=3750879703 2025-05-05 21:21:42.537887 :932DF04A:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:21:42.537887 :932DF04B:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:21:42.537888 :932DF04C:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:21:42.537888 :932DF04D:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:21:42.537888 :932DF04E:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:21:42.538447 :932DF04F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 21:21:42.538485 :932DF057:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 21:21:42.545008 :932DF063:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 21:35:44.439554 :932F0980:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 21:35:44.427 2025-05-05 21:35:44.439556 :932F0981:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=9960 pso_num=28 pso_serial#=3 2025-05-05 21:35:44.439689 :932F0982:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=9960 osp_idx=26 osp_ver=89252 osp_pg=0 (spawn #152066) 2025-05-05 21:35:44.439690 :932F0983:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 21:35:44.439690 :932F0984:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=96 time=3751721593 2025-05-05 21:35:44.439690 :932F0985:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 21:35:44.439691 :932F0986:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 21:35:44.439691 :932F0987:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 21:35:44.439692 :932F0988:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 21:35:44.439692 :932F0989:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 21:35:44.440191 :932F098A:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 21:35:44.440230 :932F0990:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 21:35:44.444287 :932F09A9:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.444338 :932F09AA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.444592 :932F09AB:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.444608 :932F09AC:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.444818 :932F09AD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.444832 :932F09AE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.445087 :932F09AF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.445107 :932F09B0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.445329 :932F09B1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.445342 :932F09B2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.445546 :932F09B3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-05 21:35:44.445559 :932F09B4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-05 21:35:44.447788 :932F09B5:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 22:00:00.042026 :9330EEA8:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 22:00:00.033 2025-05-05 22:00:00.042029 :9330EEA9:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11940 pso_num=28 pso_serial#=4 2025-05-05 22:00:00.042170 :9330EEAA:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=11940 osp_idx=26 osp_ver=89253 osp_pg=0 (spawn #152121) 2025-05-05 22:00:00.042170 :9330EEAB:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=3704 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 22:00:00.042171 :9330EEAC:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=97 time=3753177203 2025-05-05 22:00:00.042171 :9330EEAD:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 22:00:00.042172 :9330EEAE:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 22:00:00.042172 :9330EEAF:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 22:00:00.042172 :9330EEB0:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 22:00:00.042174 :9330EEB1:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 22:00:00.042685 :9330EEB2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.042728 :9330EEB9:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksv2.h LINE:1639 ID:ksvpst: run' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:00.042805 :9330EECD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.046689 :9330EEDC:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.047869 :9330EEE4:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.047894 :9330EEE7:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.047933 :9330EEF2:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:00.049771 :9330EEFD:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.049799 :9330EF00:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.049836 :9330EF0B:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:00.050296 :9330EF16:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.052713 :9330EF1E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.058037 :9330EF26:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.063481 :9330EF2E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.064927 :9330EF36:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.067984 :9330EF3E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.069259 :9330EF46:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.072112 :9330EF4E:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.075465 :9330EF56:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.075854 :9330EF65:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.075900 :9330EF68:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-05-05 22:00:00.075912 :9330EF69:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-05-05 22:00:00.077902 :9330EF6F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.077950 :9330EF72:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-05-05 22:00:00.077961 :9330EF73:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-05-05 22:00:00.079799 :9330EF79:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.079836 :9330EF7C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:ktcc.c:879 2025-05-05 22:00:00.079846 :9330EF7D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:ktcc.c:879 2025-05-05 22:00:00.080001 :9330EF83:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.080015 :9330EF86:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:00.080051 :9330EF91:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=18 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:00.081498 :9330EF9C:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-05 22:00:02.043725 :9330F080:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-05 22:00:02.038 2025-05-05 22:00:02.043726 :9330F081:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=10496 pso_num=28 pso_serial#=5 2025-05-05 22:00:02.043853 :9330F082:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=10496 osp_idx=26 osp_ver=89254 osp_pg=0 (spawn #152122) 2025-05-05 22:00:02.043854 :9330F083:db_trace:kso.c@4099:ksonfy(): [10420:28:0] kso: new process: first_req_pid=4308 spawner_pid=3660 sga_crt_ts=x8A8A 2025-05-05 22:00:02.043854 :9330F084:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=98 time=3753179203 2025-05-05 22:00:02.043855 :9330F085:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-05 22:00:02.043855 :9330F086:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-05 22:00:02.043855 :9330F087:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-05 22:00:02.043856 :9330F088:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-05 22:00:02.043856 :9330F089:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-05 22:00:02.044344 :9330F097:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kso2.h LINE:416 ID:ksoreq_reply' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.049699 :9330F0C2:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.049769 :9330F0C5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-05-05 22:00:02.060019 :9330F112:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-05 22:00:02.060638 :9330F11B:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 0ab8110000000000 2025-05-05 22:00:02.062285 :9330F141:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksr2.h LINE:603 ID:ksrpublish' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.062366 :9330F14E:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksr2.h LINE:607 ID:ksrmdone' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.062376 :9330F155:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIRCO [1] with args (1 8397264 1) 2025-05-05 22:00:02.062382 :9330F156:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.062412 :9330F161:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.063115 :9330F16E:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 224414690) 2025-05-05 22:00:02.063119 :9330F16F:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.063145 :9330F17A:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.063152 :9330F187:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (6 65564 1) 2025-05-05 22:00:02.063154 :9330F188:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.063188 :9330F194:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.063192 :9330F19C:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (1 2 65564) 2025-05-05 22:00:02.063194 :9330F1A1:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.063239 :9330F1CE:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.063849 :9330F24A:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksq.h LINE:1877 ID:ksqrcl' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.063869 :9330F25D:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-05 22:00:02.064728 :9330F264:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 0bb8110000000000 2025-05-05 22:00:02.065086 :9330F265:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 224414690) 2025-05-05 22:00:02.065091 :9330F266:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=15 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.065111 :9330F272:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=15 loc='ksa2.h LINE:286 ID:ksasnr' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:02.109941 :9330F387:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-05-05 22:00:02.111655 :9330F388:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=14 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.111718 :9330F38B:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=59 loc='kkj.h LINE:928 ID:jslve_execute' id1=0 id2=0 name= type=0 2025-05-05 22:00:02.111834 :9330F398:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] 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-05 22:00:02.163835 :9330F3B4:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 2025-05-05 22:00:04.017949 :9330F7FA:db_trace:ksl2.c@12699:ksliwat(): [10005:28:225] KSL POST RCVD poster=59 loc='kkj.h LINE:914 ID:kkjpstnp' id1=0 id2=0 name= type=0 fac#=0 facpost=1 ------------------------------------------------------------------------------- Trace Bucket Dump End: default bucket for process 28 (osid: 10496, J002)