Trace file d:\app\administrator\diag\rdbms\orcl\orcl\trace\cdmp_20250519220008\orcl_j002_7452_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:37363M/63366M, Ph+PgF:44525M/72582M Instance name: orcl Redo thread mounted by this instance: 1 Oracle process number: 28 Windows thread id: 7452, image: ORACLE.EXE (J002) *** 2025-05-19 22:00:08.188 *** SESSION ID:(225.63645) 2025-05-19 22:00:08.188 *** 2025-05-19 22:00:08.188 Process diagnostic dump for ORACLE.EXE (J002), OS id=7452, pid: 28, proc_ser: 186, sid: 225, sess_ser: 63645 ------------------------------------------------------------------------------- current sql: client details: O/S info: user: SYSTEM, term: WIN-3PIMCL4OH3L, ospid: 7452 machine: WIN-3PIMCL4OH3L program: ORACLE.EXE (J002) Current Wait Stack: 0: waiting for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=16 seq_num=17 snap_id=1 wait times: snap=0.111441 sec, exc=0.111441 sec, total=0.111441 sec wait times: max=0.500000 sec, heur=7.655508 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.000008 sec since current wait 0: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=15 seq_num=16 snap_id=1 wait times: snap=0.499993 sec, exc=0.499993 sec, total=0.499993 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=14 seq_num=15 snap_id=1 wait times: snap=0.500002 sec, exc=0.500002 sec, total=0.500002 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=13 seq_num=14 snap_id=1 wait times: snap=0.502619 sec, exc=0.502619 sec, total=0.502619 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000010 sec of elapsed time 3: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=12 seq_num=13 snap_id=1 wait times: snap=0.506367 sec, exc=0.506367 sec, total=0.506367 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 4: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=11 seq_num=12 snap_id=1 wait times: snap=0.499939 sec, exc=0.499939 sec, total=0.499939 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000017 sec of elapsed time 5: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=10 seq_num=11 snap_id=1 wait times: snap=0.500040 sec, exc=0.500040 sec, total=0.500040 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=9 seq_num=10 snap_id=1 wait times: snap=0.500003 sec, exc=0.500003 sec, total=0.500003 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000009 sec of elapsed time 7: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=8 seq_num=9 snap_id=1 wait times: snap=0.499998 sec, exc=0.499998 sec, total=0.499998 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000011 sec of elapsed time 8: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=7 seq_num=8 snap_id=1 wait times: snap=0.504575 sec, exc=0.504575 sec, total=0.504575 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000012 sec of elapsed time 9: waited for 'jobq slave wait' =0x0, =0x0, =0x0 wait_id=6 seq_num=7 snap_id=1 wait times: snap=0.500001 sec, exc=0.500001 sec, total=0.500001 sec wait times: max=0.500000 sec wait counts: calls=1 os=1 occurred after 0.000008 sec of elapsed time Sampled Session History of session 225 serial 63645 --------------------------------------------------- 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 --------------------------------------------------- [8 samples, 22:00:00 - 22:00:08] idle wait at each sample [session created at: 22:00:00] ------------------------------------------------------------------------------- Process diagnostic dump actual duration=0.000000 sec (max dump time=30.000000 sec) *** 2025-05-19 22:00:08.188 ------------------------------------------------------------------------------- Trace Bucket Dump Begin: default bucket for process 28 (osid: 7452, J002) TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA ------------------------------------------------------------------------------- 2025-05-19 12:53:50.804007 :993097DD:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 12:53:50.804024 :993097DE:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 12:53:50.804234 :993097DF:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 12:53:50.804248 :993097E0:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 12:53:50.804451 :993097E1:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 12:53:50.804463 :993097E2:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 12:53:50.804674 :993097E3:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 12:53:50.804687 :993097E4:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 12:53:50.804887 :993097E5:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 12:53:50.804901 :993097E6:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 12:53:50.807468 :993097E7:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 13:00:53.085679 :993125E5:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 13:00:53.075 2025-05-19 13:00:53.085681 :993125E6:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11580 pso_num=28 pso_serial#=176 2025-05-19 13:00:53.085812 :993125E7:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=11580 osp_idx=26 osp_ver=129970 osp_pg=0 (spawn #197930) 2025-05-19 13:00:53.085813 :993125E8: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-19 13:00:53.085813 :993125E9:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=28 time=635462954 2025-05-19 13:00:53.085813 :993125EA:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-19 13:00:53.085814 :993125EB:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-19 13:00:53.085814 :993125EC:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-19 13:00:53.085814 :993125ED:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-19 13:00:53.085815 :993125EE:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-19 13:00:53.086319 :993125EF: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-19 13:00:53.086363 :993125F5: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-19 13:00:53.093975 :99312603: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-19 13:00:53.095065 :9931260B: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-19 13:00:53.095623 :99312613: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-19 13:00:53.096076 :9931261B: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-19 13:00:53.096571 :99312623: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-19 13:00:53.098992 :9931262B: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-19 13:00:53.100058 :99312633: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-19 13:00:53.149155 :9931263B: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-19 13:00:53.150104 :99312643: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-19 13:00:53.150344 :9931264B: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-19 13:00:53.150560 :99312653: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-19 13:00:53.152302 :9931265B:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 13:03:52.107952 :99316508:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 13:03:52.096 2025-05-19 13:03:52.107953 :99316509:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13600 pso_num=28 pso_serial#=177 2025-05-19 13:03:52.108086 :9931650A:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=13600 osp_idx=26 osp_ver=129971 osp_pg=0 (spawn #197939) 2025-05-19 13:03:52.108087 :9931650B: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-19 13:03:52.108088 :9931650C:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=29 time=635641969 2025-05-19 13:03:52.108088 :9931650D:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-19 13:03:52.108089 :9931650E:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-19 13:03:52.108089 :9931650F:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-19 13:03:52.108090 :99316510:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-19 13:03:52.108090 :99316511:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-19 13:03:52.108660 :99316512: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-19 13:03:52.108706 :99316518: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-19 13:03:52.117138 :9931652D:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 13:23:54.876575 :9932FA42:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 13:23:54.864 2025-05-19 13:23:54.876577 :9932FA43:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13420 pso_num=28 pso_serial#=178 2025-05-19 13:23:54.876710 :9932FA44:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=13420 osp_idx=26 osp_ver=129972 osp_pg=0 (spawn #197985) 2025-05-19 13:23:54.876711 :9932FA45: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-19 13:23:54.876711 :9932FA46:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=30 time=636844735 2025-05-19 13:23:54.876712 :9932FA47:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-19 13:23:54.876712 :9932FA48:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-19 13:23:54.876713 :9932FA49:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-19 13:23:54.876713 :9932FA4A:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-19 13:23:54.876713 :9932FA4B:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-19 13:23:54.877208 :9932FA4C: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-19 13:23:54.877255 :9932FA52: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-19 13:23:54.881331 :9932FA6B:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.881378 :9932FA6C:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.881641 :9932FA6D:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.881658 :9932FA6E:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.881876 :9932FA6F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.881891 :9932FA70:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.882105 :9932FA71:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.882118 :9932FA72:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.882326 :9932FA73:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.882338 :9932FA74:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.882538 :9932FA75:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:kelt.c:517 2025-05-19 13:23:54.882551 :9932FA76:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:kelt.c:517 2025-05-19 13:23:54.884901 :9932FA77:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:09.105932 :993F5110:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:09.097 2025-05-19 16:00:09.105933 :993F5111:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=9780 pso_num=28 pso_serial#=179 2025-05-19 16:00:09.106078 :993F5112:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=9780 (legacy spawn) 2025-05-19 16:00:09.112949 :993F5113: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-19 16:00:09.113131 :993F511B: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-19 16:00:09.113885 :993F511D:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:11.890323 :993F520C:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:11.883 2025-05-19 16:00:11.890324 :993F520D:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=6572 pso_num=28 pso_serial#=180 2025-05-19 16:00:11.890463 :993F520E:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=6572 (legacy spawn) 2025-05-19 16:00:11.896894 :993F520F: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-19 16:00:11.897027 :993F5214: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-19 16:00:11.897708 :993F5218:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:16.249293 :993F53C5:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:16.242 2025-05-19 16:00:16.249294 :993F53C6:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=11708 pso_num=28 pso_serial#=181 2025-05-19 16:00:16.249440 :993F53C7:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=11708 osp_idx=26 osp_ver=129975 osp_pg=0 (spawn #198344) 2025-05-19 16:00:16.249441 :993F53C8: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-19 16:00:16.249441 :993F53C9:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=31 time=646226110 2025-05-19 16:00:16.249442 :993F53CA:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-19 16:00:16.249442 :993F53CB:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-19 16:00:16.249442 :993F53CC:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-19 16:00:16.249442 :993F53CD:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-19 16:00:16.249443 :993F53CE:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-19 16:00:16.249965 :993F53CF: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-19 16:00:16.250006 :993F53D6: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-19 16:00:16.254421 :993F53E8: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-19 16:00:16.278639 :993F53F0: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-19 16:00:16.294243 :993F53F8: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-19 16:00:16.314666 :993F5400: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-19 16:00:16.317900 :993F5408: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-19 16:00:16.321283 :993F5410: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-19 16:00:16.324734 :993F5418: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-19 16:00:16.325654 :993F5420: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-19 16:00:17.194469 :993F547A: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-19 16:00:17.218016 :993F5482: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-19 16:00:17.218330 :993F548A: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-19 16:00:17.218647 :993F5492: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-19 16:00:17.218668 :993F5495:db_trace:ksl2.c@14083:ksl_update_post_stats(): [10005:28:225] KSL POST SENT postee=18 loc='ksa2.h LINE:282 ID:ksasnd' id1=0 id2=0 name= type=0 2025-05-19 16:00:17.218735 :993F54A5: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-19 16:00:17.220774 :993F54AF:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:22.344243 :993F56B6:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:22.344 2025-05-19 16:00:22.344244 :993F56B7:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=13908 pso_num=28 pso_serial#=182 2025-05-19 16:00:22.344390 :993F56B8:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=13908 (legacy spawn) 2025-05-19 16:00:22.350822 :993F56B9: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-19 16:00:22.350970 :993F56BE: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-19 16:00:22.351662 :993F56C3:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:22.359350 :993F56C6:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:22.344 2025-05-19 16:00:22.359351 :993F56C7:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=7340 pso_num=28 pso_serial#=183 2025-05-19 16:00:22.359486 :993F56C8:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=7340 (legacy spawn) 2025-05-19 16:00:22.376838 :993F56C9: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-19 16:00:22.376965 :993F56D2: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-19 16:00:22.377603 :993F56D3:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:25.439707 :993F57C4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:25.427 2025-05-19 16:00:25.439708 :993F57C5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=580 pso_num=28 pso_serial#=184 2025-05-19 16:00:25.439846 :993F57C6:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=580 (legacy spawn) 2025-05-19 16:00:25.446019 :993F57C7: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-19 16:00:25.446168 :993F57CC: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-19 16:00:25.446817 :993F57D1:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 16:00:25.454313 :993F57D4:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 16:00:25.442 2025-05-19 16:00:25.454314 :993F57D5:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=12828 pso_num=28 pso_serial#=185 2025-05-19 16:00:25.454448 :993F57D6:db_trace:kso.c@4070:ksonfy(): [10420:28:0] kso: new process: pid=12828 (legacy spawn) 2025-05-19 16:00:25.460155 :993F57D7: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-19 16:00:25.460268 :993F57E0: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-19 16:00:25.460882 :993F57E1:db_trace:kst.c@698:kstpsodel(): [10280:28:0] kst: process state object about to be deleted 2025-05-19 22:00:00.446745 :995BCEFA:db_trace:kst.c@673:kstipg(): [10280:28:0] kst: process state object created on 05-19 22:00:00.446 2025-05-19 22:00:00.446746 :995BCEFB:db_trace:kst.c@679:kstipg(): [10280:28:0] kst: process info: ospid=7452 pso_num=28 pso_serial#=186 2025-05-19 22:00:00.446887 :995BCEFD:db_trace:kso.c@4093:ksonfy(): [10420:28:0] kso: new process: pid=7452 osp_idx=26 osp_ver=129980 osp_pg=0 (spawn #199176) 2025-05-19 22:00:00.446888 :995BCEFE: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-19 22:00:00.446888 :995BCEFF:db_trace:kso.c@4103:ksonfy(): [10420:28:0] kso: new process: pso_index=28 reservation=32 time=667810297 2025-05-19 22:00:00.446889 :995BCF00:db_trace:kso.c@4109:ksonfy(): [10420:28:0] kso: spawn diagnostics: queue time=0 secs 2025-05-19 22:00:00.446890 :995BCF01:db_trace:kso.c@4111:ksonfy(): [10420:28:0] kso: spawn diagnostics: fork time=0 secs 2025-05-19 22:00:00.446890 :995BCF02:db_trace:kso.c@4113:ksonfy(): [10420:28:0] kso: spawn diagnostics: exec time=0 secs 2025-05-19 22:00:00.446891 :995BCF03:db_trace:kso.c@4115:ksonfy(): [10420:28:0] kso: spawn diagnostics: pre dbkc time=0 secs 2025-05-19 22:00:00.446892 :995BCF04:db_trace:kso.c@4117:ksonfy(): [10420:28:0] kso: spawn diagnostics: post dbkc time=0 secs 2025-05-19 22:00:00.447378 :995BCF0D: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-19 22:00:00.452348 :995BCF2C: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-19 22:00:00.452389 :995BCF2F:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpus:jslv.c:9203 2025-05-19 22:00:00.460902 :995BCF92:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-19 22:00:00.461492 :995BCF93:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 e6d3110000000000 2025-05-19 22:00:00.463225 :995BCF94: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-19 22:00:00.463293 :995BCFA1: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-19 22:00:00.463301 :995BCFA8: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-19 22:00:00.463307 :995BCFA9: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-19 22:00:00.463333 :995BCFB3: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-19 22:00:00.464263 :995BCFD4:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCICKP [2] with args (4 0 225801324) 2025-05-19 22:00:00.464268 :995BCFD5: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-19 22:00:00.464292 :995BCFE1: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-19 22:00:00.464300 :995BCFED: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-19 22:00:00.464303 :995BCFEE: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-19 22:00:00.464329 :995BCFFA: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-19 22:00:00.464332 :995BD003: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-19 22:00:00.464335 :995BD007: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-19 22:00:00.464380 :995BD027: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-19 22:00:00.465370 :995BD0D8: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-19 22:00:00.465390 :995BD0DB:KFNU:kfn.c@2200:kfnPrepareASM(): kfnPrepareASM force=0 state_kfnsg=0x7 2025-05-19 22:00:00.466263 :995BD0EE:db_trace:kcc.c@13684:kccwbp(): [10021:28:225:1] 0115000000000000 0115000000000000 e7d3110000000000 2025-05-19 22:00:00.466637 :995BD0F8:db_trace:ksb.c@6610:ksbcic_int(): [10254:28:225] KSBCIC: (USER) starting cic on opcode KSBCIBBS [20] with args (2 0 225801324) 2025-05-19 22:00:00.466643 :995BD0F9: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-19 22:00:00.466669 :995BD103: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-19 22:00:00.531598 :995BD1FA:db_trace:ktc.c@8711:ktcAutoTxnTrace(): [10441:28:225] atxpop:jslv.c:9203 2025-05-19 22:00:00.532330 :995BD1FB: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-19 22:00:00.533881 :995BD203: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-19 22:00:00.533941 :995BD206: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-19 22:00:00.534041 :995BD213: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-19 22:00:00.555814 :995BD237: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: 7452, J002)