Archive

Tag Archives: internals

This blogpost is about the Oracle database row or dictionary cache. This is a separate cache that caches database metadata, like database object properties or user properties.

There is surprising little in-depth technical detail about the row cache. To some degree I understand: issues with the row cache are rare.

I noticed a column in V$ROWCACHE called ‘FASTGETS’. Whatever FASTGETS means, in my database it is being used:

SQL> select cache#, type, parameter, gets, fastgets, getmisses from v$rowcache;
    CACHE# TYPE        PARAMETER                              GETS   FASTGETS  GETMISSES
---------- ----------- -------------------------------- ---------- ---------- ----------
         3 PARENT      dc_rollback_segments                   1000          9         12
         1 PARENT      dc_free_extents                           0          0          0
         4 PARENT      dc_used_extents                           0          0          0
         2 PARENT      dc_segments                            4374       7308       2496
         0 PARENT      dc_tablespaces                         1232      14466        178
         5 PARENT      dc_tablespace_quotas                      0          0          0
         6 PARENT      dc_files                                  5          0          5
        10 PARENT      dc_users                                953      13473        196
         8 PARENT      dc_objects                            32545      13682       3769
        17 PARENT      dc_global_oids                          723          0        165
        12 PARENT      dc_constraints                            0          0          0
        13 PARENT      dc_sequences                              9          0          9
        16 PARENT      dc_histogram_defs                     60851          0      19613

If you look at the description of FASTGETS in the documentation (currently the 20c version), it says: ‘Reserved for internal use’. That’s not very helpful.

Luckily, there is a trace event to make Oracle print additional information regarding the row cache: event 10222.

Please mind using events is an unsupported action unless you have explicit blessing from Oracle support to use it. Even then, it should only be set if you are 100% sure you need it, and you should unset it as soon as you can. Also document the exact reason for using it, and evaluate set events during patching and version upgrades.

Using the event, I found that a normal dictionary lookup looks like this:

kqrpre: start hash=6d2c659c mode=S keyIndex=1 dur=CALL opt=FALSE
kqrpre: found cached object po=0x7e5da720 flg=2
kqrmpin : kqrpre: found po Pin po 0x7e5da720 cid=10 flg=2 hash=70b9dd3f
time=3663934334
kqrpre: pinned po=0x7e5da720 flg=2 pso=0x793472c8
kqrpre: done po=0x7e5da720 cid=10 flg=2 eq=0x7e616a20 pso=0x793472c8 dur=CALL
kqrpre: keyIndex=1 hash=70b9dd3f 6d2c659c 0
kqrpre: time=3663934346
kqrpre: returnVal: TRUE
.
kqrprl: eq=0x7e616a20 fpInUse=FALSE
ksedsts()+418<-kqrprl()+1208<-kkdlGetBaseUser()+248<-kzulgt1()+220<-kksLockUserSchema()+125<-kksLoadChild()+1983<-kxsGetRuntimeLock()+2049<-kksfbc()+17007<-kkspsc0()+2222<-kksParseCursor()+123<-opiosq0()+2266<-kpoopr
x()+420<-kpoal8()+838<-opiodr()+1244<-ttcpip()+1239
<-opitsk()+1943<-opiino()+957<-opiodr()+1244<-opidrv()+1091<-sou2o()+191<-opimai_real()+455<-ssthrdmain()+423<-main()+275<-__libc_start_main()+245.

This is a bit cryptic, but this is a row cache parent read (kqrpre) and release (kqrprl), for cache id (cid) 10 (dc_users, see above v$rowcache output), for which the needed entry was found (found cached object). It even contains a short stack format dump of the current location of invocation.

Now see the following lookup:

kqrpre: start hash=70b9dd3f mode=S keyIndex=0 dur=CALL opt=TRUE
kqrpre: optimistic lookup hash=70b9dd3f
kqrpre: KQR_READ_PD_VER: versionAddr=0x628f2a20 version=10
kqrpre: optimistic lookup: success
kqrpre: done po=0x7f651cbb1bf8 cid=10 flg=0 eq=(nil) pso=0x79360288 dur=CALL
kqrpre: keyIndex=0 hash=70b9dd3f 6d2c659c 0
kqrpre: time=3663936115
kqrpre: returnVal: TRUE
.
kqrprl: eq=0x7f651cbb1bf8 fpInUse=TRUE
ksedsts()+418<-kqrprl()+1208<-kkdlGetUserId()+587<-kqlhdlod()+641<-kqlCallback()+120<-kqllod()+667<-kglLoadOnLock()+1107<-kgllkal()+861<-kglLock()+1429<-kglget()+302<-kglgob()+328<-qcdlgbo()+609<-qcdlgob()+982<-qcsfgob()+278<-qcsprfro()+553<-qcsprfro_tree()+380
<-qcsprfro_tree()+150<-qcspafq()+246<-qcspqbDescendents()+281<-qcspqb()+272<-kkmdrv()+192<-opiSem()+1962<-opiDeferredSem()+447<-opitca()+436<-kksFullTypeCheck()+86<-rpiswu2()+583<-kksLoadChild()+7969<-kxsGetRuntimeLock()+2049<-kksfbc()+17007<-kkspsc0()+2222
<-kksParseCursor()+123<-opiosq0()+2266<-kpooprx()+420<-kpoal8()+838<-opiodr()+1244<-ttcpip()+1239<-opitsk()+1943<-opiino()+957<-opiodr()+1244<-opidrv()+1091<-sou2o()+191<-opimai_real()+455<-ssthrdmain()+423<-main()+275<-__libc_start_main()+245.

This is lookup for cid 10 (dc_users) too, but now “optimistic”, as can be seen on line 2. The first line shows “opt=TRUE”, which gives the indication that optimistic reading is probably not done dynamically, but an explicit setting. Could this “optimistic” read be what is shown as FASTGET in v$rowcache?

Let’s look at the actual C functions that are called for such an optimistic row cache read:

> kqrpre1(0xa, 0x7ffc48561380, ...)
| > kqrpre2(0xa, 0x7ffc48561380, ...)
| | > kqrhsh(0x62f471c8, 0x7ffc48561380, ...)
| | | > kgghash(0x7ffc48561380, 0x82, ...)
| | | < kgghash+0x0000000000d0 returns: 0xc34886c9
| | < kqrhsh+0x00000000007d returns: 0xc34886c9
| | > KQR_READ_PD_VER(0x62f471c8, 0x628c7670, ...)
| | < KQR_READ_PD_VER+0x000000000044 returns: 0x4a
| | > kqrFastPoRead(0x62f471c8, 0x7ffc48561380, ...)
| | | > _intel_fast_memcmp(0x7ffc48561380, 0x78fc6834, ...)
| | | < _intel_fast_memcmp+0x000000000053 returns: 0
| | | > kglInstanceIdn(0x7f1bc9f099a0, 0x78fc6800, ...)
| | | <> kglHandleIdn(0x7f1bc9f099a0, 0x7c736fb0, ...)
| | | < kglHandleIdn+0x000000000011 returns: 0x1
| | | > kglPdbInstanceIdn(0x7f1bc9f099a0, 0x7c736fb0, ...)
| | | < kglPdbInstanceIdn+0x000000000024 returns: 0x1
| | < kqrFastPoRead+0x0000000001ac returns: 0x1

Here we see kqrpre1 call kqrpre2, which calls kqrhsh to calculate a hash value to lookup the row cache entry. Then we see KQR_READ_PD_VER being called, which is unique to the optimistic lookup, and then kqrFastPoRead. That seems to be a reasonable definite indication this is doing the FASTGET.

The logical question to ask then is what is the actual difference between a fastget and a (regular) get?

Looking through the function calls of a fastget versus a regular get the thing that strikes me is the absence of concurrency checking and protection gets in the fastget alias optimistic call. A regular row cache get performs:
– obtains the row cache hash bucket mutex
– obtains the row cache parent object mutex
– pins the (row cache entry) memory
– frees the row cache hash bucket mutex
– locks the row cache entry (kqrget)
– frees the row cache parent object mutex

– the row cache data is used (this is the actual purpose of the row cache get)

– obtains the row cache parent object mutex
– unpins the (row cache entry) memory
– frees the row cache parent object mutex
– frees the lock (there is no explicit unlock call, I assume it’s done via the state object)

A fastget does simply not do a lot of the concurrency protection measures, it checks the version of the entry before and after getting the entry, and apparently that’s enough to be sure about the consistency of the row cache entry. It does lock the entry, and releases it after usage. Especially since the number of row cache lookups can easily get very high, this probably saves a lot of CPU cycles.

Looking in the bigger picture, the fastget seems to be done at times when the database executable has fetched the same entry in a regular way earlier, so it’s safe to assume it will still be there, and it’s safe to do it without all the concurrency control around it.

Is there anything you can do about it? Not that I know, this is just a blog to explain something about which there is no documentation.

In case you’re wondering when this appeared in Oracle, the answer is 11.2.0.4. The FASTGETS column appeared in that function, as well as the C function kqrFastPoRead.

There’s also the undocumented parameter “_kqr_optimistic_reads”, which is TRUE in my (Oracle 18) instance.

For the difference between Oracle database versions 12.2.0.1.191015 and 12.2.0.1.200114 this too follows the line of a low amount of differences.

There have been two spare parameters that have been changed to named undocumented parameters, and no data dictionary changes.

parameters unique in version 12.2.0.1.191015 versus 12.2.0.1.200114

NAME
--------------------------------------------------
_fifth_spare_parameter
_one-hundred-and-forty-eighth_spare_parameter

parameters unique in version 12.2.0.1.200114 versus 12.2.0.1.191015

NAME
--------------------------------------------------
_bug29825525_bct_public_dba_buffer_dynresize_delay
_enable_ptime_update_for_sys

On the C function side, there have been a group of AWR functions that have been removed and a group of SGA management functions, among other functions. There functions that have been added are random and diverse.

code symbol names unique in version 12.2.0.1.191015 versus 12.2.0.1.200114

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
R_CR_entropy_resource_init                                   R_CR_entropy_resource_init                                   ??
kcbzdra                                                      (kcbz)dra                                                    kernel cache buffers subroutines for kcb ??
kdmsCreateSampleInvBlkList                                   (kdm)sCreateSampleInvBlkList                                 kernel data in-memory data layer ??
kdmsFillSampleList                                           (kdm)sFillSampleList                                         kernel data in-memory data layer ??
kewmfdms_flush_drmsum                                        (kewm)fdms_flush_drmsum                                      kernel event AWR metrics ??
kewmgaeidct                                                  (kewm)gaeidct                                                kernel event AWR metrics ??
kewmusmdb_update_smdbuf                                      (kewm)usmdb_update_smdbuf                                    kernel event AWR metrics ??
kewramcs_app_map_condbid_str                                 (kewr)amcs_app_map_condbid_str                               kernel event AWR repository ??
kewramvn_append_mdb_vvwname                                  (kewr)amvn_append_mdb_vvwname                                kernel event AWR repository ??
kewrccsq_collect_csql                                        (kewr)ccsq_collect_csql                                      kernel event AWR repository ??
kewrfosp2_fos_mdb_part2                                      (kewrf)osp2_fos_mdb_part2                                    kernel event AWR repository flush ??
kewrfosp3_fos_mdb_part3                                      (kewrf)osp3_fos_mdb_part3                                    kernel event AWR repository flush ??
kewrgcfes_get_cacheid_from_enum_str                          (kewr)gcfes_get_cacheid_from_enum_str                        kernel event AWR repository ??
kewrggd_get_group_descriptor                                 (kewr)ggd_get_group_descriptor                               kernel event AWR repository ??
kewrggf_grp_get_flags                                        (kewr)ggf_grp_get_flags                                      kernel event AWR repository ??
kewrggh_grp_get_handle                                       (kewr)ggh_grp_get_handle                                     kernel event AWR repository ??
kewrggmc_grp_get_member_count                                (kewr)ggmc_grp_get_member_count                              kernel event AWR repository ??
kewrgltn_gen_lrgtest_tab_name                                (kewr)gltn_gen_lrgtest_tab_name                              kernel event AWR repository ??
kewrgvm_grp_valid_member                                     (kewr)gvm_grp_valid_member                                   kernel event AWR repository ??
kewrice_is_cache_enabled                                     (kewr)ice_is_cache_enabled                                   kernel event AWR repository ??
kewrmfp_map_flush_phase                                      (kewr)mfp_map_flush_phase                                    kernel event AWR repository ??
kewrmplvl_map_snap_level                                     (kewr)mplvl_map_snap_level                                   kernel event AWR repository ??
kewrpfbue_pdb_from_buffer_entry                              (kewr)pfbue_pdb_from_buffer_entry                            kernel event AWR repository ??
kewrptsq_prep_topsql                                         (kewr)ptsq_prep_topsql                                       kernel event AWR repository ??
kewrrc_release_cache                                         (kewr)rc_release_cache                                       kernel event AWR repository ??
kewrsaobn_set_all_objnames                                   (kewr)saobn_set_all_objnames                                 kernel event AWR repository ??
kewrsonie_set_object_names_in_entry                          (kewr)sonie_set_object_names_in_entry                        kernel event AWR repository ??
kewrsqlc_sql_iscolored_cb                                    (kewr)sqlc_sql_iscolored_cb                                  kernel event AWR repository ??
kgskltyp                                                     (kgsk)ltyp                                                   kernel generic service resource manager ??
kkeutlCopyAllocatorState                                     (kke)utlCopyAllocatorState                                   kernel compile cost engine ??
kkeutlIsAllocStructureSame                                   (kke)utlIsAllocStructureSame                                 kernel compile cost engine ??
kmgs_check_uninited_comp                                     (kmgs)_check_uninited_comp                                   kernel multi threaded/mman manage (sga) space (?) ??
kmgs_dump_partial_inuse_list_comp                            (kmgs)_dump_partial_inuse_list_comp                          kernel multi threaded/mman manage (sga) space (?) ??
kmgs_dump_quiesce_list                                       (kmgs)_dump_quiesce_list                                     kernel multi threaded/mman manage (sga) space (?) ??
kmgs_dump_resize_summary                                     (kmgs)_dump_resize_summary                                   kernel multi threaded/mman manage (sga) space (?) ??
kmgs_fill_start_sizes                                        (kmgs)_fill_start_sizes                                      kernel multi threaded/mman manage (sga) space (?) ??
kmgs_get_min_cache_grans                                     (kmgs)_get_min_cache_grans                                   kernel multi threaded/mman manage (sga) space (?) ??
kmgs_getgran_from_comp_pg                                    (kmgs)_getgran_from_comp_pg                                  kernel multi threaded/mman manage (sga) space (?) ??
kmgs_init_sgapga_comps                                       (kmgs)_init_sgapga_comps                                     kernel multi threaded/mman manage (sga) space (?) ??
kmgs_nvmksmid_2_kcbpoolid                                    (kmgs)_nvmksmid_2_kcbpoolid                                  kernel multi threaded/mman manage (sga) space (?) ??
kmgs_recv_and_donor_are_caches                               (kmgs)_recv_and_donor_are_caches                             kernel multi threaded/mman manage (sga) space (?) ??
kmgs_shrink_gran                                             (kmgs)_shrink_gran                                           kernel multi threaded/mman manage (sga) space (?) ??
kmgs_update_param_manual_helper                              (kmgs)_update_param_manual_helper                            kernel multi threaded/mman manage (sga) space (?) ??
kmgs_update_resize_summary                                   (kmgs)_update_resize_summary                                 kernel multi threaded/mman manage (sga) space (?) ??
kmgsb_in_range                                               (kmgs)b_in_range                                             kernel multi threaded/mman manage (sga) space (?) ??
kmgsdpgl                                                     (kmgs)dpgl                                                   kernel multi threaded/mman manage (sga) space (?) ??
kmgsset_timestamp                                            (kmgs)set_timestamp                                          kernel multi threaded/mman manage (sga) space (?) ??
krvxgtf                                                      (krvx)gtf                                                    kernel redo recovery extract ??
krvxrte                                                      (krvx)rte                                                    kernel redo recovery extract ??
kslsesftcb_int                                               (ksl)sesftcb_int                                             kernel service  latching and post-wait ??
ksmg_estimate_sgamax                                         (ksm)g_estimate_sgamax                                       kernel service  memory ??
ktcxbFlgPrint                                                (ktc)xbFlgPrint                                              kernel transaction control component ??
kzagetcid                                                    (kza)getcid                                                  kernel security audit  ??
kzekmdcw                                                     (kz)ekmdcw                                                   kernel security ??
qeroiFirstPart                                               (qeroi)FirstPart                                             query execute rowsource extensibel indexing query component ??
qksbgUnderOFE                                                (qksbg)UnderOFE                                              query kernel sql bind (variable) management(?) ??
ri_entcb_cmd_func                                            ri_entcb_cmd_func                                            ??
zt_yield_entropy_source_cb                                   (zt)_yield_entropy_source_cb                                 security encryption ??

code symbol names unique in version 12.2.0.1.200114 versus 12.2.0.1.191015

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
apagwnrn                                                     (apa)gwnrn                                                   SQL Access Path Analysis ??
apagwnrnprd                                                  (apa)gwnrnprd                                                SQL Access Path Analysis ??
apatwnrn                                                     (apa)twnrn                                                   SQL Access Path Analysis ??
kafcpy_one_row                                               (kaf)cpy_one_row                                             kernel access fetch ??
kcbz_eff_bsz                                                 (kcbz)_eff_bsz                                               kernel cache buffers subroutines for kcb ??
kdilm_row_diskcompress_policy_type                           (kdil)m_row_diskcompress_policy_type                         kernel data index load ??
kdsReadAheadSafe                                             (kds)ReadAheadSafe                                           kernel data seek/scan ??
kfdFreeReqs                                                  (kfd)FreeReqs                                                kernel automatic storage management disk ??
kfdp_getNormalFgCnt                                          (kfdp)_getNormalFgCnt                                        kernel automatic storage management disk PST ??
kghunalo                                                     (kgh)unalo                                                   kernel generic heap manager ??
kjcts_syncseq_incident_dump                                  (kjc)ts_syncseq_incident_dump                                kernel lock management communication ??
kkfdIsXlate                                                  (kkfd)IsXlate                                                kernel compile fast dataflow (PQ DFO) ??
kkoRowNumLimit_Int                                           (kko)RowNumLimit_Int                                         kernel compile optimizer ??
kkoWnRowNumLimit                                             (kko)WnRowNumLimit                                           kernel compile optimizer ??
kkoarFreeStats                                               (kkoar)FreeStats                                             kernel compile optimizer automatic (sql) reoptimisation ??
kkqgbpValidPredCB                                            (kkqgbp)ValidPredCB                                          kernel compile query  group by placement ??
kkqoreApplyFKR                                               (kkqore)ApplyFKR                                             kernel compile query  or-expansion ??
kkqstIsOneToOneFunc                                          (kkq)stIsOneToOneFunc                                        kernel compile query  ??
kkquReplSCInMWithRefCB                                       (kkqu)ReplSCInMWithRefCB                                     kernel compile query  subquery unnesting ??
kkqvtOpnInView                                               (kkqvt)OpnInView                                             kernel compile query  vector transformation ??
kokujJsonSerialize                                           (kok)ujJsonSerialize                                         kernel objects kernel side ??
kpdbCheckCommonprofileCbk                                    (kpdb)CheckCommonprofileCbk                                  kernel programmatic interface pluggable database ??
kpdbSyncCreateProfile                                        (kpdbSync)CreateProfile                                      kernel programmatic interface pluggable database DBMS_PDB.KPDBSYNC SYNC_PDB ??
krvfptai_PutTxAuditInfo                                      (krv)fptai_PutTxAuditInfo                                    kernel redo recovery ??
krvtab                                                       (krvt)ab                                                     kernel redo recovery log miner viewer support ??
krvxdsr                                                      (krvx)dsr                                                    kernel redo recovery extract ??
ksmg_estimate_nonimc_sga_size                                (ksm)g_estimate_nonimc_sga_size                              kernel service  memory ??
ktspFetchMeta1                                               (ktsp)FetchMeta1                                             kernel transaction segment management segment pagetable ??
kzekmckdcw                                                   (kz)ekmckdcw                                                 kernel security ??
kzekmckdcw_cbk                                               (kz)ekmckdcw_cbk                                             kernel security ??
opiBindReorderInfo                                           (opi)BindReorderInfo                                         oracle program interface ??
qcpiJsonSerialize                                            (qcpi)JsonSerialize                                          query compile parse interim ??
qcsSqnLegalCB                                                (qcs)SqnLegalCB                                              query compile semantic analysis (parser) ??
qergiSetFirstPartFlag                                        (qergi)SetFirstPartFlag                                      query execute rowsource granule iterator (partitioning? or PX granules?) ??
qeroiFindGranuleIter                                         (qeroi)FindGranuleIter                                       query execute rowsource extensibel indexing query component ??
qesblZero                                                    (qesbl)Zero                                                  query execute services bloom filter ??
qjsnIsDollarOnly                                             (qjsn)IsDollarOnly                                           query json ??
qjsnJsonCreatDom                                             (qjsn)JsonCreatDom                                           query json ??
qjsn_ferrh                                                   (qjsn)_ferrh                                                 query json ??
qkaGetClusteringFactor                                       (qka)GetClusteringFactor                                     query kernel allocation ??
qkaIsRTRIMRequiredForViewCol                                 (qka)IsRTRIMRequiredForViewCol                               query kernel allocation ??
qksopCheckConstOrOptWithBindInAndChains                      (qksop)CheckConstOrOptWithBindInAndChains                    query kernel sql compilter operand processing ??
qksqbCorrToNonParent                                         (qksqb)CorrToNonParent                                       query kernel sql Query compilation for query blocks ??
qksvcCloneHJPred                                             (qksvc)CloneHJPred                                           query kernel sql Virtual Column ??

(disclaimer: I can’t look at the sourcecode, which means I look at the oracle executable with normal, modern tools. This also means that there’s a of stuff that I don’t see, for example if functionality has been added inside an existing function, then that’s totally invisible to me)

This post was created when trying to understand how the Oracle executable works. Specifically the logwriter, which, if it is posted by a process, which is done using semop(), signals that process back using semop() if the logwriter happens to be in post/wait mode, and is not using the ‘scalable logwriter mode’, which means it is not using additional worker processes.

To be more specific, I tried investigating something that is not Oracle specific, but specific to the usage of semaphores on linux with an executable for which you do not have the source code and is not compiled with debugging symbols.

I attached to the process using gdb, and put a break on semop:

$ gdb -p 1000
...
(gdb) break semop
Breakpoint 1 at 0x7fb92b0410c0: file ../sysdeps/unix/syscall-template.S, line 81.
(gdb) c
Continuing.

A word here: you probably will not see “file ../sysdeps/unix/syscall-template.S, line 81.”. This is because I installed the following debuginfo packages:

kernel-uek-debuginfo-4.14.35-1902.9.2.el7uek.x86_64
nss-softokn-debuginfo-3.44.0-5.0.1.el7.x86_64
kernel-uek-debuginfo-common-4.14.35-1902.9.2.el7uek.x86_64
glibc-debuginfo-common-2.17-292.0.1.el7.x86_64
libaio-debuginfo-0.3.109-13.el7.x86_64
numactl-debuginfo-2.0.12-3.el7_7.1.x86_64
glibc-debuginfo-2.17-292.0.1.el7.x86_64

When using Oracle linux (version 7), this is actually really easy, you add the debug info packages repo by adding the file /etc/yum.repos.d/debug.repo, and put this in the file:

[ol7_debuginfo]
name=Oracle Linux 7 debuginfo
baseurl=http://oss.oracle.com/ol7/debuginfo
gpgkey=file:///etc/pki/rpm-gpg/RPM-GPG-KEY-oracle
gpgcheck=1
enabled=1

You now even can use the ‘debuginfo-install’ executable that gdb tells you to do. A word of warning too: this repository is not very closely maintained by oracle (sadly, I blogged about this in the past), so things might be missing. For example, the debuginfo package for the libgcc on my system can not be found by yum. Another issue I encountered, was that when I tried installing the debuginfo package for my kernel, I couldn’t just say debuginfo-install kernel-uek, because that installed the debuginfo package for the latest kernel. So I had to specifically point it to my exact kernel version. When installing the kernel debuginfo package, which is very bulky, another word of warning: the repo (at least for me) is limited to a very low bandwidth, so downloading the file (+200MB) took a long time.

I installed this with the idea to have all system variables, like the ones for semaphores, present, so I could look into them. This turned out not to be the case:

Continuing.

Breakpoint 1, semop () at ../sysdeps/unix/syscall-template.S:81
81	T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
(gdb)

Gdb broke execution because it encountered semop. Now let’s investigate. Because of the pseudo system call handler, we can only indirectly investigate the semop call. But how to know what to investigate? That’s where the manpages come in:

$ man semop
SEMOP(2)                Linux Programmer's Manual                  SEMOP(2)

NAME
       semop, semtimedop - System V semaphore operations

SYNOPSIS
       #include <sys/types.h>
       #include <sys/ipc.h>
       #include <sys/sem.h>

       int semop(int semid, struct sembuf *sops, unsigned nsops);

       int semtimedop(int semid, struct sembuf *sops, unsigned nsops,
                      struct timespec *timeout);

   Feature Test Macro Requirements for glibc (see feature_test_macros(7)):

       semtimedop(): _GNU_SOURCE

So, semop takes 3 arguments, the semid as integer, a struc sembuf that holds the actual operation to be executed and the number of operations in the sembuf.
We still can investigate this, by knowing how the arguments are passed to a function:
– The first argument is in the CPU register $rdi
– The second argument is in the CPU register $rsi
– The third argument is in the CPU register $rdx
Well, let’s look at our session:

(gdb) p $rdi
$1 = 229376
(gdb) p $rsi
$2 = 140721769476432
(gdb) p $rdx
$3 = 1

So, the simple information is available directly, the semid is 229376, and there is 1 operation.
Let’s look at semid 229376 (warning: you have to have access to the semaphore array to be able to see it):

$ ipcs -si 229376

Semaphore Array semid=229376
uid=54321	 gid=54321	 cuid=54321	 cgid=54321
mode=0600, access_perms=0600
nsems = 250
otime = Sun Jan 19 16:36:30 2020
ctime = Sun Jan 19 15:52:22 2020
semnum     value      ncount     zcount     pid
0          1          0          0          3524
1          9065       0          0          3524
2          13900      0          0          3524
3          32766      0          0          3524
4          0          0          0          0
5          0          0          0          0
6          0          1          0          9340
7          0          1          0          9347
8          0          1          0          9356
9          0          0          0          0
10         0          1          0          10146
11         0          1          0          10163
12         0          1          0          30940
13         0          1          0          10189
14         0          1          0          10189
15         0          1          0          0
...and so on...

Okay, so in order to understand what that semop call does, we need to look into the struct.

But this is what gdb says:

(gdb) p $rsi
$4 = 140721769476432

Wait a minute, didn’t the main page say: struct sembuf *sops? That asterisk (‘*’) means it’s a pointer. Let’s try that:

(gdb) p * $rsi
$5 = 65574

Well…not sure what that means…

(gdb) ptype *$rsi
type = int

Ah…it thinks it’s an integer, and displays that… That’s not very helpful.

You can cast (declare a variable to be of a certain type, not the magician type of thing) a variable, so let’s try that:

(gdb) p (struct sembuf *) $rsi
No struct type named sembuf.

Mhhh, despite installing all these debuginfo packages, it turns out the struct definition is not available.

But I really want to know the semaphore information!

I found this gdb feature:

(gdb) help add-symbol-file
Load symbols from FILE, assuming FILE has been dynamically loaded.
Usage: add-symbol-file FILE ADDR [-s <SECT> <SECT_ADDR> -s <SECT> <SECT_ADDR> ...]
ADDR is the starting address of the file's text.
The optional arguments are section-name section-address pairs and
should be specified if the data and bss segments are not contiguous
with the text.  SECT is a section name to be loaded at SECT_ADDR.

So, I can add symbols from a file, provided that file is dynamically loadable. What if I create a mini file with the definition of sembuf? Would that work??

First create a very small c program that only defines a sembuf variable:

$ cat semh.c
#include <sys/sem.h>
struct sembuf mysembuf;

That’s two lines, that really is small, isn’t it?
Then compile it, but do not link it, we only need the object file:

$ gcc -c -g semh.c -o semh.o

(the ‘-c’ switch makes it only compile, not linking)

Now we got an object file semh.o. Let’s try to “side-load” that:

(gdb) add-symbol-file semh.o 0
add symbol table from file "semh.o" at
	.text_addr = 0x0
(y or n) y
Reading symbols from /home/oracle/pin-3.11-97998-g7ecce2dac-gcc-linux/semh.o...done.
(gdb)

(you have to say ‘y’ for it to load the symbol table at address 0x0)

Now let’s try casting again:

(gdb) print (struct sembuf *) $rsi
$3 = (struct sembuf *) 0x7ffc5714f150

And now we can ask gdb to print the casted variable:

(gdb) p *$3
$5 = {sem_num = 38, sem_op = 1, sem_flg = 0}

And that’s because it knows how it looks like:

(gdb) ptype *$3
type = struct sembuf {
    unsigned short sem_num;
    short sem_op;
    short sem_flg;
}

Now this information can be used to find the process the semop call is executed for:

$ ipcs -si 229376 | grep ^38
38         0          1          0          32324

So process 32324.

For the difference between Oracle database versions 18.8 and 18.9 this too follows the line of a low amount of differences.

As always, there are some parameters that have changed from being undocumented spare to being undocumented with a name.

Also, the DBA and CDB table (DBA|CDB)_REGISTRY_BACKPORTS is back again. The disappearance of this table in 18.8 turned out to be a bug. There is a patch for 18.8 if you need this table.

parameters unique in version 18.8 versus 18.9

NAME
--------------------------------------------------
_eighth_spare_parameter
_one-hundred-and-forty-eighth_spare_parameter
_second_spare_parameter

parameters unique in version 18.9 versus 18.8

NAME
--------------------------------------------------
_bug29825525_bct_public_dba_buffer_dynresize_delay
_enable_ptime_update_for_sys
_session_modp_list

dba tables unique to 18.8 versus 18.9

dba tables unique to 18.9 versus 18.8

NAME
----------------------------------------------------------------------------------------------------
DBA_REGISTRY_BACKPORTS

cdb tables unique to 18.8 versus 18.9

cdb tables unique to 18.9 versus 18.8

NAME
----------------------------------------------------------------------------------------------------
CDB_REGISTRY_BACKPORTS

On the C function side, it becomes apparent that this update is truly an update, roughly the number of functions that have gone and appeared are the same. A large portion of the functions that are removed in 18.9 are functions that have to do with AWR, and some other functions dealing with ASM and others.

The functions that have been added seem to be quite diverse,

code symbol names unique in version 18.8 versus 18.9

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
R_CR_entropy_resource_init                                   R_CR_entropy_resource_init                                   ??
kcfis_clear_lob                                              (kcfis)_clear_lob                                            kernel cache file management intelligent storage ??
kds_update_turbo_scan_pivot_statistics                       (kds)_update_turbo_scan_pivot_statistics                     kernel data seek/scan ??
kewramcs_app_map_condbid_str                                 (kewr)amcs_app_map_condbid_str                               kernel event AWR repository ??
kewramvn_append_mdb_vvwname                                  (kewr)amvn_append_mdb_vvwname                                kernel event AWR repository ??
kewraxc_attribute_xcb                                        (kewr)axc_attribute_xcb                                      kernel event AWR repository ??
kewrbtsg_build_topseg                                        (kewr)btsg_build_topseg                                      kernel event AWR repository ??
kewrccsq_collect_csql                                        (kewr)ccsq_collect_csql                                      kernel event AWR repository ??
kewrgcfes_get_cacheid_from_enum_str                          (kewr)gcfes_get_cacheid_from_enum_str                        kernel event AWR repository ??
kewrmplvl_map_snap_level                                     (kewr)mplvl_map_snap_level                                   kernel event AWR repository ??
kewrpfbue_pdb_from_buffer_entry                              (kewr)pfbue_pdb_from_buffer_entry                            kernel event AWR repository ??
kewrptsq_prep_topsql                                         (kewr)ptsq_prep_topsql                                       kernel event AWR repository ??
kewrrdsi_rank_dstat_item                                     (kewr)rdsi_rank_dstat_item                                   kernel event AWR repository ??
kewrrtsq_rank_topsql                                         (kewr)rtsq_rank_topsql                                       kernel event AWR repository ??
kewrsaobn_set_all_objnames                                   (kewr)saobn_set_all_objnames                                 kernel event AWR repository ??
kewrsonie_set_object_names_in_entry                          (kewr)sonie_set_object_names_in_entry                        kernel event AWR repository ??
kewrsqlc_sql_iscolored_cb                                    (kewr)sqlc_sql_iscolored_cb                                  kernel event AWR repository ??
kfatknHsh                                                    (kfa)tknHsh                                                  kernel automatic storage management alias operations ??
kfdDskComputeHashForRow                                      (kfd)DskComputeHashForRow                                    kernel automatic storage management disk ??
kfioSrMsgBuf_ack                                             (kfio)SrMsgBuf_ack                                           kernel automatic storage management translation I/O layer ??
kfkcrRefresh                                                 (kfk)crRefresh                                               kernel automatic storage management KFK ??
kfnFreeKfnpnmMem                                             (kfn)FreeKfnpnmMem                                           kernel automatic storage management networking subsystem ??
kkqtutlSelItemMatches                                        (kkqt)utlSelItemMatches                                      kernel compile query  table ??
kkquIsCorrTransInList                                        (kkqu)IsCorrTransInList                                      kernel compile query  subquery unnesting ??
krvxgtf                                                      (krvx)gtf                                                    kernel redo recovery extract ??
krvxrsr_SkipRedo                                             (krvx)rsr_SkipRedo                                           kernel redo recovery extract ??
ksmg_estimate_sgamax                                         (ksm)g_estimate_sgamax                                       kernel service  memory ??
kzagetcid                                                    (kza)getcid                                                  kernel security audit  ??
lxCharsetIsByteUnique                                        (l)xCharsetIsByteUnique                                      core library functions ??
qeroiFirstPart                                               (qeroi)FirstPart                                             query execute rowsource extensibel indexing query component ??
qkspmTravInit                                                (qkspm)TravInit                                              query kernel sql plan management ??
ri_entcb_cmd_func                                            ri_entcb_cmd_func                                            ??
zt_yield_entropy_source_cb                                   (zt)_yield_entropy_source_cb                                 security encryption ??

code symbol names unique in version 18.9 versus 18.8

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
apagwnrn                                                     (apa)gwnrn                                                   SQL Access Path Analysis ??
apagwnrnprd                                                  (apa)gwnrnprd                                                SQL Access Path Analysis ??
apatwnrn                                                     (apa)twnrn                                                   SQL Access Path Analysis ??
kafcpy_one_row                                               (kaf)cpy_one_row                                             kernel access fetch ??
kcbz_eff_bsz                                                 (kcbz)_eff_bsz                                               kernel cache buffers subroutines for kcb ??
kdilm_row_diskcompress_policy_type                           (kdil)m_row_diskcompress_policy_type                         kernel data index load ??
kdsReadAheadSafe                                             (kds)ReadAheadSafe                                           kernel data seek/scan ??
kewrcc_bind_cb                                               (kewr)cc_bind_cb                                             kernel event AWR repository ??
kewrcc_check_columns                                         (kewr)cc_check_columns                                       kernel event AWR repository ??
kewrcc_fetch_cb                                              (kewr)cc_fetch_cb                                            kernel event AWR repository ??
kfdp_getNormalFgCnt                                          (kfdp)_getNormalFgCnt                                        kernel automatic storage management disk PST ??
kfkIsAFDLoaded                                               (kfk)IsAFDLoaded                                             kernel automatic storage management KFK ??
kgskltyp                                                     (kgsk)ltyp                                                   kernel generic service resource manager ??
kjcts_syncseq_incident_dump                                  (kjc)ts_syncseq_incident_dump                                kernel lock management communication ??
kkoRowNumLimit_Int                                           (kko)RowNumLimit_Int                                         kernel compile optimizer ??
kkoWnRowNumLimit                                             (kko)WnRowNumLimit                                           kernel compile optimizer ??
kkqljpUpdateXplAnn                                           (kkq)ljpUpdateXplAnn                                         kernel compile query  ??
kkqoreAndDriver                                              (kkqore)AndDriver                                            kernel compile query  or-expansion ??
kpcxdrBindReorderInfo                                        (kp)cxdrBindReorderInfo                                      kernel programmatic interface ??
kpdbCheckCommonprofileCbk                                    (kpdb)CheckCommonprofileCbk                                  kernel programmatic interface pluggable database ??
kpdbSyncCreateProfile                                        (kpdbSync)CreateProfile                                      kernel programmatic interface pluggable database DBMS_PDB.KPDBSYNC SYNC_PDB ??
kpossGetEncNonTemplateOverflow                               (kpo)ssGetEncNonTemplateOverflow                             kernel programmatic interface oracle ??
kpossSetEncNonTemplateOverflow                               (kpo)ssSetEncNonTemplateOverflow                             kernel programmatic interface oracle ??
kpossTemplateMatch_                                          (kpo)ssTemplateMatch_                                        kernel programmatic interface oracle ??
kpossTemplateSet                                             (kpo)ssTemplateSet                                           kernel programmatic interface oracle ??
kpussTemplateSend                                            (kpu)ssTemplateSend                                          kernel programmatic interface user ??
kpuxcSessionSignatureRecv                                    (kpuxc)SessionSignatureRecv                                  kernel programmatic interface user db replay? ??
kpuxcSessionTemplateSend                                     (kpuxc)SessionTemplateSend                                   kernel programmatic interface user db replay? ??
kpuxcSessionTemplatesFree                                    (kpuxc)SessionTemplatesFree                                  kernel programmatic interface user db replay? ??
krvxdsr                                                      (krvx)dsr                                                    kernel redo recovery extract ??
ksmg_estimate_nonimc_sga_size                                (ksm)g_estimate_nonimc_sga_size                              kernel service  memory ??
ksp_init_modp_send                                           (ksp)_init_modp_send                                         kernel service  parameter ??
ksp_modp_get_enckeyvals                                      (ksp)_modp_get_enckeyvals                                    kernel service  parameter ??
ksp_modp_get_keyvals                                         (ksp)_modp_get_keyvals                                       kernel service  parameter ??
ksp_modp_set_enckeyvals                                      (ksp)_modp_set_enckeyvals                                    kernel service  parameter ??
ksp_modp_set_keyvals                                         (ksp)_modp_set_keyvals                                       kernel service  parameter ??
ksp_modp_update_sign                                         (ksp)_modp_update_sign                                       kernel service  parameter ??
kspdecbuf                                                    (ksp)decbuf                                                  kernel service  parameter ??
kspencbuf                                                    (ksp)encbuf                                                  kernel service  parameter ??
qergiSetFirstPartFlag                                        (qergi)SetFirstPartFlag                                      query execute rowsource granule iterator (partitioning? or PX granules?) ??
qeroiFindGranuleIter                                         (qeroi)FindGranuleIter                                       query execute rowsource extensibel indexing query component ??
qjsnIsDollarOnly                                             (qjsn)IsDollarOnly                                           query json ??
qjsnJsonSerialize_optim                                      (qjsn)JsonSerialize_optim                                    query json ??
qkaIsRTRIMRequiredForViewCol                                 (qka)IsRTRIMRequiredForViewCol                               query kernel allocation ??
qksopCheckConstOrOptWithBindInAndChains                      (qksop)CheckConstOrOptWithBindInAndChains                    query kernel sql operand processing ??

(disclaimer: I can’t look at the sourcecode, which means I look at the oracle executable with normal, modern tools. This also means that there’s a of stuff that I don’t see, for example if functionality has been added inside an existing function, then that’s totally invisible to me)

As expected, there aren’t any really drastic differences between Oracle database version 19.5 and 19.6. Now that I am doing these series on differences for all the versions every quarter the new release updates are coming out, there is a certain line, and this release does follow that.

As always, there are some parameters that have changed from being undocumented spare to being undocumented with a name. There is one documented parameter that was added: optimizer_session_type, which has gone official from “_optimizer_auto_index_allow”; see bug 29632611.

parameters unique in version 19.5 versus 19.6

NAME
--------------------------------------------------
_fifth_spare_parameter
_one-hundred-and-fifty-fifth_spare_parameter
_one-hundred-and-fifty-fourth_spare_parameter
_one-hundred-and-fifty-sixth_spare_parameter
_optimizer_auto_index_allow
_sixth_spare_parameter

parameters unique in version 19.6 versus 19.5

NAME
--------------------------------------------------
_bug29825525_bct_public_dba_buffer_dynresize_delay
_bug30224950_kjac_direct_path_enabled
_enable_ptime_update_for_sys
_path_prefix_create_dir
_smart_log_threshold_usec
optimizer_session_type

No data dictionary changes have been found.

On the C function side, it becomes apparent that there’s development taking place. For the functions that have been removed, there’s a bunch that deal with ASM (kfd), some with kubs which has to do with big data SQL and some XDB/XML stuff.

There’s way more functions that gotten into the newest release update. There’s a lot of unknowns, ASM, application continuity, lots of big data SQL, JSON, polymorphic table functions, XML, and something that looks like it has to do with SIMD processing (skfSIMD) for which I don’t know what the ‘f’ is there (functions?). There’s also a whole batch of functions starting with ‘rest_nhp’, I yet have to look into these.

code symbol names unique in version 19.5 versus 19.6

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
jskqJobQReadDiskCbk                                          (js)kqJobQReadDiskCbk                                        job scheduing ??
kcbo_incr_doc                                                (kcbo)_incr_doc                                              kernel cache buffers object queue ??
kcfis_clear_lob                                              (kcfis)_clear_lob                                            kernel cache file management intelligent storage ??
kcoclnup602                                                  (kco)clnup602                                                kernel cache operation ??
kewraxc_attribute_xcb                                        (kewr)axc_attribute_xcb                                      kernel event AWR repository ??
kfMaxParityHoles                                             (kf)MaxParityHoles                                           kernel automatic storage management ??
kfdDskComputeHashForRow                                      (kfd)DskComputeHashForRow                                    kernel automatic storage management disk ??
kfdDskTableCbInternal                                        (kfd)DskTableCbInternal                                      kernel automatic storage management disk ??
kfgComputeGrpProp                                            (kfg)ComputeGrpProp                                          kernel automatic storage management diskgroups ??
kfgGrpTableCbInternal                                        (kfg)GrpTableCbInternal                                      kernel automatic storage management diskgroups ??
kgds_dump_callers_sub                                        (kgds)_dump_callers_sub                                      kernel generic vos generic stack trace ??
kgfdDiscoverSubmit                                           (kgfd)DiscoverSubmit                                         kernel generic ASM io subsystem driver ??
kgh_size_sanity_check                                        (kgh)_size_sanity_check                                      kernel generic heap manager ??
kjccspbat                                                    (kjc)cspbat                                                  kernel lock management communication ??
kkeTbRowCPUCost                                              (kke)TbRowCPUCost                                            kernel compile cost engine ??
kkqjePatchCol                                                (kkqj)ePatchCol                                              kernel compile query  join analysis ??
krbbCountThreads                                             (krbb)CountThreads                                           kernel redo backup/restore creation of a backuppiece ??
ksadmb                                                       ksadmb                                                       kernel service  asynchronous messages deallocate message buffer
ksdhng_wdat_rem_dup                                          (ksdhng)_wdat_rem_dup                                        kernel service  debug internal errors hang analyze ??
kubsprqcrio_close                                            (kubsprq)crio_close                                          kernel utility big data sql parquet ??
kubsprqcrio_read                                             (kubsprq)crio_read                                           kernel utility big data sql parquet ??
kubsprqcrio_seek                                             (kubsprq)crio_seek                                           kernel utility big data sql parquet ??
kubsprqioAdvise                                              (kubsprq)ioAdvise                                            kernel utility big data sql parquet ??
kubsprqioClose                                               (kubsprq)ioClose                                             kernel utility big data sql parquet ??
kubsprqioOpen                                                (kubsprq)ioOpen                                              kernel utility big data sql parquet ??
kubsprqioRead                                                (kubsprq)ioRead                                              kernel utility big data sql parquet ??
kzagetcid                                                    (kza)getcid                                                  kernel security audit  ??
qeroiFirstPart                                               (qeroi)FirstPart                                             query execute rowsource extensibel indexing query component ??
qjsnGetBinFromOSON                                           (qjsn)GetBinFromOSON                                         query json ??
qksptfOCIerr                                                 (qksptf)OCIerr                                               query kernel sql polymorphic table functions compilation ??
qmxgniCheckLOBSize                                           (qmx)gniCheckLOBSize                                         query XDB XML Objects ??
qmxgniHasNodeIdOrCSX                                         (qmx)gniHasNodeIdOrCSX                                       query XDB XML Objects ??
qmxgniReturnString                                           (qmx)gniReturnString                                         query XDB XML Objects ??
qmxgniUnderEvent                                             (qmx)gniUnderEvent                                           query XDB XML Objects ??
rwssid_andv                                                  (rws)sid_andv                                                row source ??

code symbol names unique in version 19.6 versus 19.5

NAME                                                         RESOLVE                                                      ANNOTATION
------------------------------------------------------------ ------------------------------------------------------------ --------------------------------------------------------------------------------
CJPathConsumer2D_create                                      CJPathConsumer2D_create                                      ??
CJPathConsumer2D_staticFinalize                              CJPathConsumer2D_staticFinalize                              ??
CJPathConsumer2D_staticInitialize                            CJPathConsumer2D_staticInitialize                            ??
Java_sun_dc_pr_PathStroker_cInitialize2D                     Java_sun_dc_pr_PathStroker_cInitialize2D                     ??
PC2D__cleanup                                                PC2D__cleanup                                                ??
PC2D__enumCoObs                                              PC2D__enumCoObs                                              ??
PC2D_appendCubic                                             PC2D_appendCubic                                             ??
PC2D_appendLine                                              PC2D_appendLine                                              ??
PC2D_appendQuad                                              PC2D_appendQuad                                              ??
PC2D_beginPath                                               PC2D_beginPath                                               ??
PC2D_beginSubpath                                            PC2D_beginSubpath                                            ??
PC2D_className                                               PC2D_className                                               ??
PC2D_closedSubpath                                           PC2D_closedSubpath                                           ??
PC2D_copy                                                    PC2D_copy                                                    ??
PC2D_endPath                                                 PC2D_endPath                                                 ??
PC2D_useProxy                                                PC2D_useProxy                                                ??
crio_close                                                   crio_close                                                   ??
crio_read                                                    crio_read                                                    ??
crio_seek                                                    crio_seek                                                    ??
dbnest_etime_op                                              (dbnest)_etime_op                                            dbnest ??
dcpr_PCClosePath                                             dcpr_PCClosePath                                             ??
dcpr_PCCubicTo                                               dcpr_PCCubicTo                                               ??
dcpr_PCLineTo                                                dcpr_PCLineTo                                                ??
dcpr_PCMoveTo                                                dcpr_PCMoveTo                                                ??
dcpr_PCPathDone                                              dcpr_PCPathDone                                              ??
dcpr_PCQuadTo                                                dcpr_PCQuadTo                                                ??
dmqlDeserLogicalCheck                                        dmqlDeserLogicalCheck                                        ??
dmsarProdDump                                                dmsarProdDump                                                ??
dmsspKroneckerChk                                            dmsspKroneckerChk                                            ??
dmsspProdDump                                                dmsspProdDump                                                ??
dtbfti_find_tobedrp_ix                                       (dtb)fti_find_tobedrp_ix                                     drop table ??
jskqCountClassesUsingService                                 (js)kqCountClassesUsingService                               job scheduing ??
jskqJobQueuePDBReload                                        (js)kqJobQueuePDBReload                                      job scheduing ??
jskqUpdateQueueNextRunTime                                   (js)kqUpdateQueueNextRunTime                                 job scheduing ??
jznDecodeOSON4IMCJMetaD                                      (jzn)DecodeOSON4IMCJMetaD                                    json ??
jznOctDistFnmAllocSz                                         (jzn)OctDistFnmAllocSz                                       json ??
jznoctGetArraySizeI                                          (jzn)octGetArraySizeI                                        json ??
jznoctIsTopScalar                                            (jzn)octIsTopScalar                                          json ??
kciVARCHAR2sz                                                (kci)VARCHAR2sz                                              kernel cache oracle text ??
kcoclnup                                                     (kco)clnup                                                   kernel cache operation ??
kcrfw_alfs_sl_emulate                                        (kcrfw_alfs)_sl_emulate                                      kernel cache recovery file write/broadcast SCN adaptive log file sync ??
kcrfw_alfs_sl_save_redowrite_time                            (kcrfw_alfs)_sl_save_redowrite_time                          kernel cache recovery file write/broadcast SCN adaptive log file sync ??
kcrfw_alfs_sl_update_mode                                    (kcrfw_alfs)_sl_update_mode                                  kernel cache recovery file write/broadcast SCN adaptive log file sync ??
kcrfw_dax_is_smart_log                                       (kcrfw)_dax_is_smart_log                                     kernel cache recovery file write/broadcast SCN ??
kewrcc_bind_cb                                               (kewr)cc_bind_cb                                             kernel event AWR repository ??
kewrcc_check_columns                                         (kewr)cc_check_columns                                       kernel event AWR repository ??
kewrcc_fetch_cb                                              (kewr)cc_fetch_cb                                            kernel event AWR repository ??
kfGetParityFailureMask                                       (kf)GetParityFailureMask                                     kernel automatic storage management ??
kfParityCalP                                                 (kf)ParityCalP                                               kernel automatic storage management ??
kfParityCalP0                                                (kf)ParityCalP0                                              kernel automatic storage management ??
kfParityCalQ                                                 (kf)ParityCalQ                                               kernel automatic storage management ??
kfParityCalQ0                                                (kf)ParityCalQ0                                              kernel automatic storage management ??
kfdBlockContentCheck                                         (kfd)BlockContentCheck                                       kernel automatic storage management disk ??
kfdp_getNormalFgCnt                                          (kfdp)_getNormalFgCnt                                        kernel automatic storage management disk PST ??
kfknodecFreeCb                                               (kfk)nodecFreeCb                                             kernel automatic storage management KFK ??
kfnASMBnRunning                                              (kfn)ASMBnRunning                                            kernel automatic storage management networking subsystem ??
kglLockWaitTime                                              (kglLock)WaitTime                                            kernel generic library cache management library cache lock ??
kgskltyp                                                     (kgsk)ltyp                                                   kernel generic service resource manager ??
kgwsm_reset                                                  (kg)wsm_reset                                                kernel generic ??
kjac_dp_alloc                                                (kjac)_dp_alloc                                              kernel lock management application continuity  ??
kjac_dp_bind_tim                                             (kjac)_dp_bind_tim                                           kernel lock management application continuity  ??
kjac_dp_bind_uin                                             (kjac)_dp_bind_uin                                           kernel lock management application continuity  ??
kjac_dp_comp_bin                                             (kjac)_dp_comp_bin                                           kernel lock management application continuity  ??
kjac_dp_comp_uin                                             (kjac)_dp_comp_uin                                           kernel lock management application continuity  ??
kjac_dp_enabled_cbk                                          (kjac)_dp_enabled_cbk                                        kernel lock management application continuity  ??
kjac_dp_free                                                 (kjac)_dp_free                                               kernel lock management application continuity  ??
kjac_dp_insert_init                                          (kjac)_dp_insert_init                                        kernel lock management application continuity  ??
kjac_dp_md_init                                              (kjac)_dp_md_init                                            kernel lock management application continuity  ??
kjac_dp_open                                                 (kjac)_dp_open                                               kernel lock management application continuity  ??
kjac_dp_recover                                              (kjac)_dp_recover                                            kernel lock management application continuity  ??
kjac_dp_update                                               (kjac)_dp_update                                             kernel lock management application continuity  ??
kjac_dp_update_init                                          (kjac)_dp_update_init                                        kernel lock management application continuity  ??
kjac_dp_update_state                                         (kjac)_dp_update_state                                       kernel lock management application continuity  ??
kjac_dpctx_alloc                                             (kjac)_dpctx_alloc                                           kernel lock management application continuity  ??
kjac_dpctx_free                                              (kjac)_dpctx_free                                            kernel lock management application continuity  ??
kjac_dpinfo_close                                            (kjac)_dpinfo_close                                          kernel lock management application continuity  ??
kjac_dpinfo_open                                             (kjac)_dpinfo_open                                           kernel lock management application continuity  ??
kjac_sql_ltxid_tabid                                         (kjac)_sql_ltxid_tabid                                       kernel lock management application continuity  ??
kjac_sql_materialize_part                                    (kjac)_sql_materialize_part                                  kernel lock management application continuity  ??
kjac_trace_event_cbk                                         (kjac)_trace_event_cbk                                       kernel lock management application continuity  ??
kjfclmdrsc                                                   (kj)fclmdrsc                                                 kernel lock management ??
kjfclmdsgvbi                                                 (kj)fclmdsgvbi                                               kernel lock management ??
kjgcr_GetTopCPU                                              (kj)gcr_GetTopCPU                                            kernel lock management ??
kjgcr_RunSyncTask                                            (kj)gcr_RunSyncTask                                          kernel lock management ??
kjgcr_SlaveReqGetSlot                                        (kj)gcr_SlaveReqGetSlot                                      kernel lock management ??
kkbati_add_tbd_ix                                            (kkb)ati_add_tbd_ix                                          kernel compile table ??
kkbdti_drop_tbd_ix                                           (kkb)dti_drop_tbd_ix                                         kernel compile table ??
kkdlVirtColCB                                                (kkdl)VirtColCB                                              kernel compile dictionary lookup ??
kkoUpdOrdTabWithOrdSubqHints                                 (kko)UpdOrdTabWithOrdSubqHints                               kernel compile optimizer ??
kkqjfCopyFroNoChn                                            (kkqjf)CopyFroNoChn                                          kernel compile query  join analysis join factorization ??
kpdbcCheckRedoApplyNeeded                                    (kpdb)cCheckRedoApplyNeeded                                  kernel programmatic interface pluggable database ??
kpoxcAppContPDBNotify                                        (kpo)xcAppContPDBNotify                                      kernel programmatic interface oracle ??
kpudpParquetInt96                                            (kpudp)ParquetInt96                                          kernel programmatic interface user DPAPI Load ??
ksfqsrfn                                                     (ksfq)srfn                                                   kernel service  functions sequential file io interface ??
kswsLdiToInt                                                 (ksws)LdiToInt                                               kernel service  workgroup services ??
ksws_alb_colocation_tag_cbk                                  (ksws)_alb_colocation_tag_cbk                                kernel service  workgroup services ??
ksws_alb_mark_stale_colocated_sessions                       (ksws)_alb_mark_stale_colocated_sessions                     kernel service  workgroup services ??
ksws_alb_set_session_colocation                              (ksws)_alb_set_session_colocation                            kernel service  workgroup services ??
kubsBUFioAdvise                                              (kubs)BUFioAdvise                                            kernel utility big data sql ??
kubsBUFioClose                                               (kubs)BUFioClose                                             kernel utility big data sql ??
kubsBUFioOpen                                                (kubs)BUFioOpen                                              kernel utility big data sql ??
kubsBUFioRead                                                (kubs)BUFioRead                                              kernel utility big data sql ??
kubsCRioODM_close                                            (kubs)CRioODM_close                                          kernel utility big data sql ??
kubsCRioODM_finish                                           (kubs)CRioODM_finish                                         kernel utility big data sql ??
kubsCRioODM_finishHelper                                     (kubs)CRioODM_finishHelper                                   kernel utility big data sql ??
kubsCRioODM_init                                             (kubs)CRioODM_init                                           kernel utility big data sql ??
kubsCRioODM_initHelper                                       (kubs)CRioODM_initHelper                                     kernel utility big data sql ??
kubsCRioODM_opcsetupgp                                       (kubs)CRioODM_opcsetupgp                                     kernel utility big data sql ??
kubsCRioODM_openHelper                                       (kubs)CRioODM_openHelper                                     kernel utility big data sql ??
kubsCRioODM_read                                             (kubs)CRioODM_read                                           kernel utility big data sql ??
kubsCRioODM_readHelper                                       (kubs)CRioODM_readHelper                                     kernel utility big data sql ??
kubsCRioREST_allocNextFromDSArray                            (kubs)CRioREST_allocNextFromDSArray                          kernel utility big data sql ??
kubsCRioREST_close                                           (kubs)CRioREST_close                                         kernel utility big data sql ??
kubsCRioREST_finish                                          (kubs)CRioREST_finish                                        kernel utility big data sql ??
kubsCRioREST_httpInit                                        (kubs)CRioREST_httpInit                                      kernel utility big data sql ??
kubsCRioREST_httpRequest                                     (kubs)CRioREST_httpRequest                                   kernel utility big data sql ??
kubsCRioREST_id                                              (kubs)CRioREST_id                                            kernel utility big data sql ??
kubsCRioREST_id_add                                          (kubs)CRioREST_id_add                                        kernel utility big data sql ??
kubsCRioREST_init                                            (kubs)CRioREST_init                                          kernel utility big data sql ??
kubsCRioREST_read                                            (kubs)CRioREST_read                                          kernel utility big data sql ??
kubsCRioREST_validate_url                                    (kubs)CRioREST_validate_url                                  kernel utility big data sql ??
kubsCRioSPescape                                             (kubs)CRioSPescape                                           kernel utility big data sql ??
kubsCRioURLencode                                            (kubs)CRioURLencode                                          kernel utility big data sql ??
kubsCRio_get_cell_wallet_path                                (kubs)CRio_get_cell_wallet_path                              kernel utility big data sql ??
kubsCRio_get_rdbms_wallet_path                               (kubs)CRio_get_rdbms_wallet_path                             kernel utility big data sql ??
kubsavroGetDecimalTpeProp                                    (kubsavro)GetDecimalTpeProp                                  kernel utility big data sql avro ??
kubsprqGetBoolProp                                           (kubsprq)GetBoolProp                                         kernel utility big data sql parquet ??
kubsprqtGetData                                              (kubsprq)tGetData                                            kernel utility big data sql parquet ??
kubsprqtGetDataByte                                          (kubsprq)tGetDataByte                                        kernel utility big data sql parquet ??
kubsprqtRead                                                 (kubsprq)tRead                                               kernel utility big data sql parquet ??
kubsprqtReadVarint                                           (kubsprq)tReadVarint                                         kernel utility big data sql parquet ??
kubsprquReadZVarint                                          (kubsprq)uReadZVarint                                        kernel utility big data sql parquet ??
kubsxGetConfigList                                           (kubs)xGetConfigList                                         kernel utility big data sql ??
kubsxiGetLocalCreds                                          (kubs)xiGetLocalCreds                                        kernel utility big data sql ??
kubsxiGetNextCell                                            (kubs)xiGetNextCell                                          kernel utility big data sql ??
kupaxisosf                                                   (kup)axisosf                                                 kernel utility datapump ??
kwqaexgcur                                                   (kwqa)exgcur                                                 kernel advanced queuing  administration ??
kwqaexgcurobc                                                (kwqa)exgcurobc                                              kernel advanced queuing  administration ??
kxes_sqlcomp_check_1                                         (kx)es_sqlcomp_check_1                                       kernel execution ??
kxes_sqlcomp_check_macro                                     (kx)es_sqlcomp_check_macro                                   kernel execution ??
kzvCheckGrantInRoot_cbk                                      (kz)vCheckGrantInRoot_cbk                                    kernel security ??
kzvGrantedCommonlyInRoot                                     (kz)vGrantedCommonlyInRoot                                   kernel security ??
ntt_pptlv                                                    (ntt)_pptlv                                                  network transport (drivers) tcp/ip ??
odm_apg                                                      (odm)_apg                                                    oracle disk manager ??
odm_fpg                                                      (odm)_fpg                                                    oracle disk manager ??
odm_get_creds                                                (odm)_get_creds                                              oracle disk manager ??
odm_get_proxy                                                (odm)_get_proxy                                              oracle disk manager ??
odm_oua                                                      (odm)_oua                                                    oracle disk manager ??
odm_pec                                                      (odm)_pec                                                    oracle disk manager ??
odm_printf                                                   (odm)_printf                                                 oracle disk manager ??
odm_wrf                                                      (odm)_wrf                                                    oracle disk manager ??
ph2osfm_setup_function_metadata                              (ph2)osfm_setup_function_metadata                            PLSQL phase 2 (semantic analyzer) ??
ph2scs_semantic_checks_for_sqm                               (ph2)scs_semantic_checks_for_sqm                             PLSQL phase 2 (semantic analyzer) ??
qctoj_obadi4DateTimeStuff                                    (qcto)j_obadi4DateTimeStuff                                  query compile type check operations operators ??
qergiSetFirstPartFlag                                        (qergi)SetFirstPartFlag                                      query execute rowsource granule iterator (partitioning? or PX granules?) ??
qeroiFindGranuleIter                                         (qeroi)FindGranuleIter                                       query execute rowsource extensibel indexing query component ??
qertrcGetEncMaxLen                                           (qer)trcGetEncMaxLen                                         query execute rowsource ??
qerupFindChiHC                                               (qerup)FindChiHC                                             query execute rowsource update ??
qerupUpdStatsCbk                                             (qerup)UpdStatsCbk                                           query execute rowsource update ??
qerxjConvertToBinaryNumber                                   (qerxj)ConvertToBinaryNumber                                 query execute rowsource json ??
qerxjConvertToInterval                                       (qerxj)ConvertToInterval                                     query execute rowsource json ??
qjsnJSON_DML_OptimOccurred                                   (qjsn)JSON_DML_OptimOccurred                                 query json ??
qjsnOKToApplySkipCpOSONOptim                                 (qjsn)OKToApplySkipCpOSONOptim                               query json ??
qjsnRetBinaryNumber                                          (qjsn)RetBinaryNumber                                        query json ??
qjsnRetInterval                                              (qjsn)RetInterval                                            query json ??
qjsn_can_skip_cpy_oson_bytes                                 (qjsn)_can_skip_cpy_oson_bytes                               query json ??
qjsn_can_skip_is_json_validation                             (qjsn)_can_skip_is_json_validation                           query json ??
qjsngGetBinFromOSON                                          (qjsn)gGetBinFromOSON                                        query json ??
qjsngRaiseSQLError                                           (qjsn)gRaiseSQLError                                         query json ??
qjsngStringToDateDty3                                        (qjsn)gStringToDateDty3                                      query json ??
qjsnlobCheckLobPatch                                         (qjsn)lobCheckLobPatch                                       query json ??
qkaIsRTRIMRequiredForViewCol                                 (qka)IsRTRIMRequiredForViewCol                               query kernel allocation ??
qksopCheckConstOrOptWithBindInAndChains                      (qksop)CheckConstOrOptWithBindInAndChains                    query kernel sql compilter operand processing ??
qksopFindQbByName                                            (qksop)FindQbByName                                          query kernel sql operand processing ??
qksopSplitPreds                                              (qksop)SplitPreds                                            query kernel sql operand processing ??
qksopVisitPredsInt                                           (qksop)VisitPredsInt                                         query kernel sql operand processing ??
qksopVisitPredsPostOrder                                     (qksop)VisitPredsPostOrder                                   query kernel sql compilter operand processing ??
qksptfContainNestedScalar                                    (qksptf)ContainNestedScalar                                  query kernel sql polymorphic table functions compilation ??
qksptfDescribePTF                                            (qksptf)DescribePTF                                          query kernel sql polymorphic table functions compilation ??
qksptfOCIerr_                                                (qksptf)OCIerr_                                              query kernel sql polymorphic table functions compilation ??
qksptfSQM_Check_Errors                                       (qksptf)SQM_Check_Errors                                     query kernel sql polymorphic table functions compilation ??
qksptfSQM_CleanupTDOs                                        (qksptf)SQM_CleanupTDOs                                      query kernel sql polymorphic table functions compilation ??
qksptfSQM_Describe                                           (qksptf)SQM_Describe                                         query kernel sql polymorphic table functions compilation ??
qksptfSQM_ExpRepl_                                           (qksptf)SQM_ExpRepl_                                         query kernel sql polymorphic table functions compilation ??
qksptfSQM_GetTxt                                             (qksptf)SQM_GetTxt                                           query kernel sql polymorphic table functions compilation ??
qksptfSQM_Init                                               (qksptf)SQM_Init                                             query kernel sql polymorphic table functions compilation ??
qksptfSQM_Laz_                                               (qksptf)SQM_Laz_                                             query kernel sql polymorphic table functions compilation ??
qksptfSQM_Model_Check                                        (qksptf)SQM_Model_Check                                      query kernel sql polymorphic table functions compilation ??
qksptfSQM_Parse                                              (qksptf)SQM_Parse                                            query kernel sql polymorphic table functions compilation ??
qksptfSQM_Parse_errors                                       (qksptf)SQM_Parse_errors                                     query kernel sql polymorphic table functions compilation ??
qksptfSQM_PstPrc                                             (qksptf)SQM_PstPrc                                           query kernel sql polymorphic table functions compilation ??
qksptfSQM_PstPrc1_                                           (qksptf)SQM_PstPrc1_                                         query kernel sql polymorphic table functions compilation ??
qksptfSQM_QbcRelExp_                                         (qksptf)SQM_QbcRelExp_                                       query kernel sql polymorphic table functions compilation ??
qksptfSQM_RplExpA                                            (qksptf)SQM_RplExpA                                          query kernel sql polymorphic table functions compilation ??
qksptfSQM_RplExpB                                            (qksptf)SQM_RplExpB                                          query kernel sql polymorphic table functions compilation ??
qksptfSQM_SetIQB_                                            (qksptf)SQM_SetIQB_                                          query kernel sql polymorphic table functions compilation ??
qksptfSQM_SetSQM_                                            (qksptf)SQM_SetSQM_                                          query kernel sql polymorphic table functions compilation ??
qksptfSQM_Template                                           (qksptf)SQM_Template                                         query kernel sql polymorphic table functions compilation ??
qksptfSQM_rm_vqb                                             (qksptf)SQM_rm_vqb                                           query kernel sql polymorphic table functions compilation ??
qksptfSubExprContainScalar                                   (qksptf)SubExprContainScalar                                 query kernel sql polymorphic table functions compilation ??
qmxtigCheckLOBSize                                           (qmxt)igCheckLOBSize                                         query XDB XML Objects XML ??
qmxtigCreXMLImgFromLob                                       (qmxt)igCreXMLImgFromLob                                     query XDB XML Objects XML ??
qmxtigGetXMLImgInfo                                          (qmxt)igGetXMLImgInfo                                        query XDB XML Objects XML ??
qmxtigImgNdsCnv                                              (qmxt)igImgNdsCnv                                            query XDB XML Objects XML ??
qmxtigReturnString                                           (qmxt)igReturnString                                         query XDB XML Objects XML ??
qmxtigUnderEvent                                             (qmxt)igUnderEvent                                           query XDB XML Objects XML ??
qmxtigUpdateReplayChecksum                                   (qmxt)igUpdateReplayChecksum                                 query XDB XML Objects XML ??
qmxtigValidateXmlImage                                       (qmxt)igValidateXmlImage                                     query XDB XML Objects XML ??
qmxtigValidateXmlImgBody                                     (qmxt)igValidateXmlImgBody                                   query XDB XML Objects XML ??
qmxtigValidateXmlImgHdr                                      (qmxt)igValidateXmlImgHdr                                    query XDB XML Objects XML ??
qxxqGetCredentials                                           (qx)xqGetCredentials                                         query query execution ??
qxxqGetProxy                                                 (qx)xqGetProxy                                               query query execution ??
qxxqGetSSLWallet                                             (qx)xqGetSSLWallet                                           query query execution ??
rest_nhpavail                                                rest_nhpavail                                                ??
rest_nhpconnect                                              rest_nhpconnect                                              ??
rest_nhpdisconnect                                           rest_nhpdisconnect                                           ??
rest_nhpflush                                                rest_nhpflush                                                ??
rest_nhpfree                                                 rest_nhpfree                                                 ??
rest_nhpmalloc                                               rest_nhpmalloc                                               ??
rest_nhprealloc                                              rest_nhprealloc                                              ??
rest_nhprecv                                                 rest_nhprecv                                                 ??
rest_nhprequestauth                                          rest_nhprequestauth                                          ??
rest_nhpsend                                                 rest_nhpsend                                                 ??
rest_nhptrace                                                rest_nhptrace                                                ??
rest_nhpwalletauth                                           rest_nhpwalletauth                                           ??
rwssecondtop                                                 (rws)secondtop                                               row source ??
setJPathConsumer2D                                           setJPathConsumer2D                                           ??
skfParityGDiv                                                (sk)fParityGDiv                                              operating system dependent kernel ??
skfParityGMul                                                (sk)fParityGMul                                              operating system dependent kernel ??
skfSIMDAvail                                                 (sk)fSIMDAvail                                               operating system dependent kernel ??
skfSIMDCalP                                                  (sk)fSIMDCalP                                                operating system dependent kernel ??
skfSIMDCalP0                                                 (sk)fSIMDCalP0                                               operating system dependent kernel ??
skfSIMDCalQ                                                  (sk)fSIMDCalQ                                                operating system dependent kernel ??
skfSIMDCalQ0                                                 (sk)fSIMDCalQ0                                               operating system dependent kernel ??
skfSIMDMultiplicationLookupTable                             (sk)fSIMDMultiplicationLookupTable                           operating system dependent kernel ??
skfSIMDRecoverOneDataFromQ                                   (sk)fSIMDRecoverOneDataFromQ                                 operating system dependent kernel ??
skfSIMDRecoverTwoDataFromPQ                                  (sk)fSIMDRecoverTwoDataFromPQ                                operating system dependent kernel ??

(disclaimer: I can’t look at the sourcecode, which means I look at the oracle executable with normal, modern tools. This also means that there’s a of stuff that I don’t see, for example if functionality has been added inside an existing function, then that’s totally invisible to me)

This post is about how to use gdb, which is a debugger, so very simplistically put an aid for looking at C programs, as a profiler. I use gdb quite a lot for profiling because it’s the easiest way for profiling for me.

Lots of people which I know use other tools like perf, systemtap and dtrace for the same purpose and that’s fine. Each tools has its own advantages and disadvantages. One disadvantage of gdb is that it’s using ptrace to attach to a process, which makes it dead slow from a machine perspective, because everything it then does goes via another process, which is the debugger. That is how the debugger works.

Also lots of people use gdb like I do, and use basic functionality, which is breaking at functions, which makes it possible to find out the sequence of how functions are called, generating backtraces (stack traces) to understand the stack and maybe looking at functions arguments.

But there is more that you can do. Way more actually. These examples use the gdb that comes with RHEL7/OL7 via yum.

You can break conditionally at a function, which means that a break will be executed only if the condition is met. For example:

break sltrgatime64 if $caller_is("ksbabs")

This only breaks at a function called sltrgatime64 if it is called from a function that is called ksbabs.

But for what I wanted to do and investigate, I didn’t only want to do “something” when the sltrgatime64 function was called from ksbabs, I wanted be able to distinguish the two times this was called as the first one and the second one.

I knew that the “first time” was actually right after a function with the name of “dbktFlush” was called. So here’s what I did:

set $status = -1

break dbktFlush if $caller_is("ksbabs")
commands
 silent
 set $status = 0
 c
end

break sltrgatime64 if $caller_is("ksbabs")
commands
 silent
 if $status == 0
   set $status = 1
   printf "first invocation\n"
   c
 end
 if $status == 1
  set $status = 2
  printf "second invocation\n"
  c
 end
 if $status > 1
  printf "error. third or more invocations\n"
 end
end

This is much more advanced than using a single command, but I think for anyone who is able to program a few languages is reasonably simple to understand.

There’s two breaks, and both are conditional, the function from which the function to break on must be ksbabs.
In the break of dbktFlush the (convenience) variable $status is set to 0, indicating the the first invocation for the other break.

In the second break, there are 3 if statements. The first one picks up the variable $status set to 0, indicating the first invocation and then sets it to 1 for the second invocation and the second if picks up the second invocation indicated by the variable $status set to 1 and sets it to 2, so if I didn’t look carefully and there are more invocations of sltrgatime64, I will get notified.

If breaks would be activated when the second call to sltrgatime64 was executed, it would not come across dbktFlush, and thus the $status variable would (still) be set to -1, and the break would skip all ifs.

Of course this is a very specific case, you should tailor it for your own needs. However, this was the actual investigation I done to investigate the function of the above sltrgatime64 calls.

In fact, I gone a little deeper and wanted to understand what the timing of of these two reads of the wall clock time did. For that, I used the python interface in gdb, for which the support seems to be compiled in in the rpm based version.

You can use python, and use variables in python that remain state between gdb interactions. I used a dead simple interaction; calling time.time() to time the invocation of the sltrgatime64 executed right after dbktFlush was called:

python import time
python var_time=time.time()

break dbktFlush if $caller_is("ksbabs")
commands
 silent
 set $status = 0
 c
end

break sltrgatime64 if $caller_is("ksbabs")
commands
 silent
 if $status == 0
   set $status = 1
   python print time.time()-var_time
   python var_time=time.time()
   c
  else
   c
 end
end

If you set single logwriter to true and execute this against the logwriter, you will see that the logwriter tries to keep a 3 second pace by adjusting the sleep time on semtimedop().

My actual goal was to try to find out what is exactly timed for the message ‘Warning: log write elapsed time ????ms, size ?KB’ in the logwriter trace file, which Nenad Noveljic proved is not only about the actual IO time.

To be honest, I done it clumsy by going backward measuring all the calls that measured wall clock time and should have put a break on write and look at the backtrace. When I executed a backtrace of the write call that wrote the trace file entry, I could see this line was written in kcrfw_postprocess_write().

This is the gdb script with the timing:

python import time

break skgstmGetEpochTs if $caller_is("kcrfw_redo_write_driver")
commands
 silent
 python var_time=time.time()
 c
end

break kcrfw_do_write
 commands
 silent
 print $rip
 c
end

break skgstmGetEpochTs if $caller_is("kcrfw_postprocess_write")
commands
 silent
 shell sleep 1
 python print time.time()-var_time
 c
end

What does gdb script does, is always set the python variable var_time, which includes the idle cycles of the logwriter. If it goes into the function kcrfw_do_write it actually is going to write. That is also when potentially the line “Warning: log write elapsed time 1024ms, size 0KB” could be produced.
when the function skgstmGetEpochTs is called in the function kcrfw_postprocess_write, it executes a sleep for 1 second, and then prints the current time minus the time obtained when kcrfw_redo_write_driver was entered.

What this proofs, is that the timing for the log write time elapsed time warning is done from the start of the kcrfw_redo_write_driver function. That means that everything that the logwriter needs to do, excluding the the last bit of what the logwriter performs, posting the foregrounds, is timed, including dealing with the internal structures that keep track of the redo strands and the latching of it.

The Oracle database log writer is the process that fundamentally influences database change performance. Under normal circumstances the log writer must persist the changes made to the blocks before the actual change is committed. Therefore, it’s vitally important to understand what the log writer is exactly doing. This is widely known by the Oracle database community.

The traditional method for looking at log writer performance is looking at the wait event ‘log file parallel write’ and the CPU time, and comparing that to the ‘log file sync’ alias “commit wait time”. If ‘log file parallel write’ and ‘log file sync’ roughly match, a commit is waiting on the log writer IO latency, if it isn’t then it’s unclear, and things get vague.

Now we get to the gist of this blogpost: since Oracle 12, there are additional statistics in V$SESSTAT and v$SYSSTAT that describe where the log writer spending it’s time on. However, and sadly, these are not documented by Oracle. The statistics are:

– redo write gather time
– redo write schedule time
– redo write finish time
– redo write time (usec)
– redo write total time

Probably ‘redo write time (usec)’ doesn’t belong to these statistics because the timing is as good as the same as ‘redo write finish time’. Also the statistic ‘redo write time (usec)’ is updated by ‘kcrfw_postprocess_write’ right after the main writing function (kcrfw_do_write), whilst the other redo write timing statistics are updated/made visible by ksu_dispatch_tac outside of the actual writing functions, at the approximate rate of every 3 seconds.

All these statistics contain cumulative timing figure in microseconds (usec).

All these timings start at the start of the function kcrfw_redo_write_driver. This is the main function that handles all the redo writing, including investigating the fixed area structure (kcrfs_) and the shared pool structures (made visible using X$KCRFSTRAND) to see if there are changes.

1. redo write gather time.
This times reading the structures that control allocation of the redo structures, validating foreground processes are done writing the change vectors and applying these to the blocks, updating the LWN SCN. Part of this also happens when there is nothing to write, but then the time is not added to this statistic, only if it found something to write.

2. redo write schedule time.
This includes the time of 1, but now it found something to write, entered the writing function (kcrfw_do_write), and updated the ksfd IO related structures for writing.

3. redo write finish time.
This includes the time of 1 and 2, but this additionally times all the IO related functions for writing the changes it found in the public redo strands, as indicated by the shared pool and fixed area structures.

4. redo write time (usec).
This probably is not part of this group of statistics, but it works in exactly the same way: it’s a cumulative figure, it counts time since the start of the kcrfw_redo_write_driver and includes a tiny bit more code, it times until it has left the kcrfw_do_write function and enters the kcrfw_postprocess_write function.

5. redo write total time.
This includes the time of 1, 2 and 3, but additionally times the kcrfw_post function, which performs the signalling of the foreground processes that have committed and wait for a semop() signal.

This means that the Oracle database since Oracle 12 provides the timing information to see where the log writer is spending it’s time on. This can prevent a lot of guesswork.

%d bloggers like this: