Top 60 Oracle Blogs

Recent comments

Oakies Blog Aggregator

Loading a Flat File from OCI Object Storage into an Autonomous Database. Part 1. Upload to Object Storage

This blog is the first in a series of three that looks at transferring a file to Oracle Cloud Infrastructure (OCI) Object Storage, and then reading it into the database with an external table or copying it into a regular table.

Last year I wrote a blog titled Reading the Active Session History Compressed Export File in eDB360/SQLd360 as an External Table.  I set myself the challenge of doing the same thing with an Autonomous database.  I would imagine that these are commonly used Oracle Cloud operations, yet I found the documentation was spread over a number of places, and it took me a while to get it right. So, I hope you find this series helpful.

Install OCI

I could just upload my data file through the browser directly into an object storage bucket, but I don't want to copy it to a Windows desktop.  That is not a good option for very large files.  Instead, I am going to install the OCI Command Line Interface onto the Linux VM where my data file resides (see OCI CLI Quickstart Guide).
I am installing this into the oracle user on a Linux VM where the Oracle database has previously been installed, so I just accepted all the defaults.
#eeeeee; line-height: 95%; width: 95%;">bash -c "$(curl -L"

Set up Token-Based Authentication for OCI

I couldn't get the instructions for generating a token without a browser to work.  Instead, installed OCI on a Windows machine and generated a token there and transferred it to my Linux VM (see Token-based Authentication for the CLI).

#eeeeee; line-height: 95%; width: 95%;">C:\Users\david.kurtz>oci session authenticate
Enter a region (e.g. ap-mumbai-1, ap-seoul-1, ap-sydney-1, ap-tokyo-1, ca-toronto-1, eu-frankfurt-1, eu-zurich-1, sa-saopaulo-1, uk-london-1, us-ashburn-1, us-gov-ashburn-1, us-gov-chicago-1, us-gov-phoenix-1, us-langley-1, us-luke-1, us-phoenix-1): uk-london-1
Please switch to newly opened browser window to log in!
Completed browser authentication process!
Config written to: C:\Users\david.kurtz\.oci\config

Try out your newly created session credentials with the following example command:

oci iam region list --config-file C:\Users\david.kurtz\.oci\config --profile DEFAULT --auth security_token

If I run the suggested example command, I get this response with the list of OCI regions.

#eeeeee; line-height: 95%; width: 95%;">{
"data": [

"key": "LHR",
"name": "uk-london-1"


Export OCI Profile

Now I can export the profile to a zip file

#eeeeee; line-height: 95%; width: 95%;">C:\Users\david.kurtz>oci session export --profile DEFAULT --output-file DEFAULT
File already exists, do you want to overwrite it? [y/N]: y
Exporting profile: DEFAULT from config file: C:\Users\david.kurtz\.oci\config
Export file written to: C:\Users\david.kurtz\

Import OCI Profile

I can transfer this zip file to my Linux VM and import it.

#eeeeee; line-height: 95%; width: 95%;">[oracle@oracle-database .oci]$ oci session import --session-archive ./ --force
Config already contains a profile with the same name as the archived profile: DEFAULT. Provide an alternative name for the imported profile: myprofile
Imported profile myprofile written to: /home/oracle/.oci/config

Try out your newly imported session credentials with the following example command:

oci iam region list --config-file /home/oracle/.oci/config --profile myprofile --auth security_token

I can test it by again getting the list of OCI regions.

Upload a File

I have created a bucket on OCI.

I could upload a file through the OCI web interface, but I want to use a command-line from my Linux VM

#eeeeee; line-height: 95%; width: 95%;">[oracle@oracle-database ~]$ oci os object put --bucket-name bucket-20200505-1552 --file /media/sf_temp/dba_hist_active_sess_history.txt.gz --disable-parallel-uploads --config-file /home/oracle/.oci/config --profile myprofile --auth security_token
Upload ID: 1ad452f7-ab49-a24b-2fe9-f55f565cdf40
Split file into 2 parts for upload.
Uploading object [####################################] 100%
"etag": "66681c40-4e11-4b73-baf9-cc1e4c3ebd5f",
"last-modified": "Wed, 06 May 2020 15:17:03 GMT",
"opc-multipart-md5": "MFdfU7vGZlJ5Mb4nopxtpw==-2"

I can see the file in the bucket via the web interface, and I can see that the size and the MD5 checksum are both correct.

In the next post, I will explain how to read the file from Object Storage using an External Table.

Order By

This is a brief note with an odd history – and the history is more significant than the note.

While searching my library for an example of an odd costing effect for the “order by” clause I discovered a script that looked as if I’d written for in 2008 to demonstrate a redundant sort operation appearing in an execution plan; and then I discovered a second script written for in 2014 demonstrating a variant of the same thing (presumably because I’d not found the original script in 2014) and the second script referenced a MOS bug number


Whenever I “discover” an old bug test I tend to re-run it to check whether or not the bug has been fixed.  So that’s what I did, and found that the anomaly was still present in The really odd thing, though, was that the bug note no longer existed – and even after I’d done a few searches involving the text in the description I couldn’t manage to find it!

For the record, here’s the original 2008 script (with a couple of minor edits)

rem     Script:         order_by_anomaly.sql
rem     Author:         Jonathan Lewis
rem     Dated:          June 2008
rem     Purpose:        
rem     Last tested 
rem           Still sorting

set linesize 180
set pagesize 60

create table test 
select  * 
from    all_objects 
where   rownum <= 10000 -- >  comment to avoid wordpress format issue

alter table test modify object_name not null;
create index i_test_1 on test(object_name);

analyze table test compute statistics;

set serveroutput off
alter session set statistics_level = all;

select  * 
from    (select * from test order by object_name) 
        rownum < 11 -- > comment to avoid wordpress format issue

select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));

select  * 
from    (select /*+ index(test) */ * from test order by object_name,rowid) 
        rownum < 11 -- > comment to avoid wordpress format issue

select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));

alter session set statistics_level = typical;
set serveroutput on

Yes, that is an analyze command – it’s a pretty old script and I must have been a bit lazy about writing it. (Or, possibly, it’s a script from an Oracle-l or Oracle forum posting and I hadn’t re-engineered it.)

I’ve run two queries – the first uses an inline view to impose an order on some data and then selects the first 10 rows. The second query does nearly the same thing but adds an extra column to the “order by” clause – except it’s not a real column it’s the rowid pseudo-column. Conveniently there’s an index on the table that is a perfect match for the “order by” clause and it’s on a non-null column so the optimizer can walk the index in order and stop after 10 rows.

Adding the rowid to the “order by” clause shouldn’t make any difference to the plan as the index Oracle is using is a single column non-unique index, which means that the internal representation makes it a two-column index where the rowid is (quite literally) stored as the second column. But here are the two execution plans:

| Id  | Operation                     | Name     | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
|   0 | SELECT STATEMENT              |          |      1 |        |     10 |00:00:00.01 |       7 |
|*  1 |  COUNT STOPKEY                |          |      1 |        |     10 |00:00:00.01 |       7 |
|   2 |   VIEW                        |          |      1 |     10 |     10 |00:00:00.01 |       7 |
|   3 |    TABLE ACCESS BY INDEX ROWID| TEST     |      1 |  10000 |     10 |00:00:00.01 |       7 |
|   4 |     INDEX FULL SCAN           | I_TEST_1 |      1 |     10 |     10 |00:00:00.01 |       3 |

Predicate Information (identified by operation id):
   1 - filter(ROWNUM<11)

| Id  | Operation                              | Name     | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
|   0 | SELECT STATEMENT                       |          |      1 |        |     10 |00:00:00.01 |    4717 |       |       |          |
|*  1 |  COUNT STOPKEY                         |          |      1 |        |     10 |00:00:00.01 |    4717 |       |       |          |
|   2 |   VIEW                                 |          |      1 |  10000 |     10 |00:00:00.01 |    4717 |       |       |          |
|*  3 |    SORT ORDER BY STOPKEY               |          |      1 |  10000 |     10 |00:00:00.01 |    4717 |  4096 |  4096 | 4096  (0)|
|   4 |     TABLE ACCESS BY INDEX ROWID BATCHED| TEST     |      1 |  10000 |  10000 |00:00:00.01 |    4717 |       |       |          |
|   5 |      INDEX FULL SCAN                   | I_TEST_1 |      1 |  10000 |  10000 |00:00:00.01 |      44 |       |       |          |

Predicate Information (identified by operation id):
   1 - filter(ROWNUM<11)
   3 - filter(ROWNUM<11)

When I add the rowid to the “order by” clause the optimizer no longer sees walking the index as an option for avoiding work; it wants to collect all the rows from the table, sort them, and then report the first 10. In fact walking the index became such an expensive option that I had to hint the index usage (hence the non-null declaration) to make the optimizer choose it, the default plan for 19.3 was a full tablescan and sort.

It’s just a little example of an edge case, of course. It’s a pity that the code doesn’t recognise the rowid as (effectively) a no-op addition to the ordering when the rest of the “order by” clause matches the index declaration, but in those circumstances the rowid needn’t be there at all and you wouldn’t expect anyone to include it.

As I said at the start – the interesting thing about this behaviour is that it was once described in a bug note that has since disappeared from public view.


Improved Navigation in the WordPress Apps

An app should be intuitive to use, so you can do what you need to do while you’re in a hurry or on the go. The newest versions of the Android and iOS mobile apps are reorganized based on how you actually use them. Publishing and finding what you need have never been faster, so you can spend less time hunting and tapping — and more time creating and engaging. 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

How did we decide on these changes? We analyzed our apps for pain points and hard-to-do tasks. We looked at the data and talked to people about which features are most important to them. We interviewed WordPress users and showed them prototypes. All these changes come from you — thanks!

Fewer tabs for faster focus

We’ve simplified the app into three main sections focused on the key things you do every day: managing your site, finding and reading great content, and keeping up to date with notifications. 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

Your account, where it should be

People expect to find account information and settings in the upper-right corner, so that’s where it is now: get to your profile and account by heading to the My Site screen and tapping on your photo. It’s where you expect it to be when you need it, and out of the way when you don’t. 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

Start drafting, right now

There’s one button to tap to create new posts or pages. It’s big. It’s pink. It’s got a plus sign on it. It’s always there on the My Site screen, waiting. Tap it and type away! 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

The links you use the most, right at the top

There are a lot of things you can do with your site, but there are some things you do more often than others — check stats, edit posts, upload photos. We made links to those actions big, and we put them at the top of the My Site screen, right under a more prominent site name and logo. 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

Content discovery, your way

You’ll now see great content from the sites you follow as soon as you open the Reader. Use the top tabs to switch between different streams of content, or narrow things down with the filter bar if you’re only interested in specific sites or tags. 2048w, 150w, 300w, 768w" sizes="(max-width: 1024px) 100vw, 1024px" />

To see the improvements, make sure you’ve updated your app. The WordPress mobile apps are free and available for both Android and iOS devices. If you have any questions or feedback, reach out to us directly from the app — in My Site, tap your profile image → Help & SupportContact Us.

Many of you are increasingly building your sites and reading other sites on mobile devices, so we’re constantly looking for ways to make our apps easier to use. Look out for upcoming changes that streamline site management and further refine the reading experience!

Code re-use … Not a substitute for brain use

I was doing some code review today of a PL/SQL package, and came across a routine to generate a list of employees for a department.  Truth be told, it wasn’t employees and departments but some anonymity is called for here. Smile

SQL> create or replace
  2  function emp_list(p_dept varchar2) return varchar2 is
  3    l_emps varchar2(4000) := ':';
  4  begin
  5    for i in (
  6      select empno
  7      from   emp
  8      where  deptno = p_dept  )
  9    loop
 10      l_emps := l_emps || i.empno ||':';
 11    end loop;
 12    return l_emps;
 13  end;
 14  /

Function created.

SQL> select emp_list(30) from dual;


Savvy readers will straight away know that rather than “reinvent the wheel”, the function could re-coded with a LISTAGG function, and since at that point, it is just a standard SQL expression, then potentially the PL/SQL function is not required at all. (We’d only know that by knowing the full context of the function’s usage).

SQL> create or replace
  2  function emp_list(p_dept varchar2) return varchar2 is
  3    l_emps varchar2(4000);
  4  begin
  5    select ':'||listagg(empno,':') within group ( order by empno )||':'
  6    into l_emps
  7    from   emp
  8    where  deptno = p_dept;
  9    return l_emps;
 10  end;
 11  /

Function created.

SQL> select emp_list(30) from dual;


However, we can’t be too critical here. We don’t know the background and history of the code – perhaps it was written well before LISTAGG was available? So whilst its an obvious improvement, I’m happy to let that one slide.

But it is easy to be led astray by the allure of “reuse”, and the very next procedure in the package implements the business requirement of: “Does a nominated employee belong to a nominated department?”

Let’s look at the implementation.

SQL> create or replace
  2  function emp_in_dept(p_emp int, p_dept int) return boolean is
  3    l_emps varchar2(4000);
  4  begin
  5    l_emps := emp_list(p_dept);            <<<==== our previous function
  6    return instr(l_emps,':'||p_emp||':') > 0;
  7  end;
  8  /

Function created.

SQL> set serverout on
SQL> begin
  2    --
  3    -- should be true
  4    --
  5    if emp_in_dept(7900,30) then dbms_output.put_line('Yes 7900,30'); end if;
  6    --
  7    -- should be false
  8    --
  9    if emp_in_dept(7499,20) then dbms_output.put_line('Yes 7499,20'); end if;
 10  end;
 11  /
Yes 7900,30

PL/SQL procedure successfully completed.

All I can really say is …. don’t do that. There really is no excuse for this one, because even without the LISTAGG version, the first procedure indicates that:

  • the developer knew of the EMP table and its columns
  • the developer knew the data was the DEPT/EMP relationship
  • the developer knew how to query the table for a given DEPT

so why not implement the routine with the trivial SQL to meet the requirement?

SQL> create or replace
  2  function emp_in_dept(p_emp int, p_dept int) return boolean is
  3    l_dept int;
  4  begin
  5    select count(case when deptno = p_dept then 1 end)
  6    into   l_dept
  7    from   emp
  8    where  empno = p_emp;
  9    return l_dept > 0;
 10  end;
 11  /

Function created.

Therein lies the rub. As developers, we have drilled into us constantly “reuse, reuse, reuse” as if re-using code is the goal as opposed a good guiding principle.

So please…by all means look for opportunities to modularise and re-use your code, but don’t force it into your codebase just for sake for claiming your doing it. That isn’t code RE-use, that is brain NO-use Smile

Video : Using Podman With Existing Dockerfiles (Oracle Database and ORDS)

Today’s video shows me using some of my existing Docker builds with Podman. Specifically a 19c database container and an Oracle REST Data Services (ORDS) container.

For those with an understanding of Docker, it should look really familiar, but it does introduce a twist in the form of a pod.

The video is based on this article.

You can see more information about containers here.

The star of today’s video is Bart Sjerps. It was really hard to find a piece of this recording that didn’t have James Morle wittering over everyone on it. </p />

    	  	<div class=

COVID-19: The Current Situation in the UK and June.

I’ve not said anything about Covid-19 for much longer than I expected, but really it has been a case of watching the coming peak come and go, pretty much following the pattern of Italy, Spain, Belgium and France. I plan to do a post soon which pulls together the current scientific position, but for now I wanted to record where we are and where my gut feeling (based as ever on reliable scientific sources and not so much on what the daily government updates would like us to think) says we will be in a month or so.

We’ve not done very well in the UK. If you are based in the UK you may not be aware of the fact that most of Europe think we have,as a nation, been idiots – failing to learn from other countries, late to lock-down, lock-down was not strict enough, too early to open up, our PPE fiasco… I can’t say I can disagree with them. We have one of the highest deaths-per-million-population rates in Europe, exceeded only by Spain and Belgium. But it could have been worse. A lot worse.

I’m truly relieved my predictions in my last post were (for once) too pessimistic. I misjudged when the peak in deaths would be by over a week – it was 9 days earlier than I thought, happening around the 11th April. As a result of coming sooner, the peak was lower than my little model predicted. Even allowing for that, the increase in number of deaths did not mirror the increase in cases (I used the cases pattern as my template for deaths). I think this is because the UK finally started ramping up it’s testing rate. The more testing you do, the more of the real cases you detect, so some of the increase in cases was simply better testing and not continuing spreading. That’s what happens when the source of your metrics changes, your model loses accuracy.

Deaths are directly related to real case numbers, it does not actually matter how many cases you detect. This is part of why case numbers are a much poorer metric for epidemics, whereas deaths are better. The best metric is a random, large sample for those who have had the disease – but we still do not have reliable, large-scale antibody or similar tests to tell us this.

If you look at the actual figures and compare to what I predicted for the peak of deaths, I seem to have been pretty accurate. I said 1,200 to 1,500 around the 20th April and the peak was 1,172 in the 21st April. But I was predicting hospital deaths only. Up until 29th April this was the number reported each day but since then the daily number of deaths reported included community (mostly care home) deaths. The previous figures were altered to reflect this and the graphs to the right are based on these updated figures. Hospital deaths seem to have peaked at 980 on the 11th April, so I was wrong.

I think it is crucial in science and technology (and actually, just in general) that you be honest when you are wrong – even if (like in this case) I could made a fallacious claim to have hit the nail on the head.

The bottom line is, we are well past the first peak and it did not overwhelm the NHS. It got really close and our issues with personal protective equipment was a scandal and must have resulted in more illness and some avoidable deaths to our front-line NHS staff. But, apparently, saying so is Political.

All in all we followed the pattern of European counties that were impacted by Covid-19 before us and implemented similar country-wide lock-downs.

One difference between us and other European countries that have been hit hard is our tail of cases is thicker and longer. We have not been as rigorous in our lock-down as those other countries (e.g we did not have to have written permission to leave or enter an area and children were not utterly forbidden from leaving home, which are just two examples how our lock-down was softer). I know it might not feel like it, but we were not.

What really concerns me is that we are easing lock-down measures so soon in the UK. Our daily new case rate and number of deaths are both still really quite high. The figures always drop over the weekend, especially Sunday and Monday (due to the numbers reported being for the day before). Over the last 3 days (Wed to Fri) we averaged 1998 new cases and 371 deaths per day. If you think Covid-19 has gone away, every single day there are 371 families who sadly know different.

I understand that the economy is important, that unless things are being manufactured, services provided, money earned and spent, that a large part of our society is not functioning. Maybe I don’t really appreciate how important it is as economics has always looked more like a dark art based on greed than anything logical, but some people feel getting back to normal business is critical and the long-term impact of not doing so is potentially as serious as Covid-19.

I also know that not being able to go to places, eat out, have a drink in the pub, meet up with friends in a building or in more than small numbers is frustrating. For many, not seeing your family and loved ones who are not in your home is very upsetting.

I’m sure that parents are desperate for kids to go back to school (partly for education and partly as it turns out kids are a lot of work), couples need a bit of time apart, people are missing their jobs. Nearly all of us have never had to spend so much time with a very small number of other people.

But I’m also sure that what we don’t want is in 4-8 weeks to have to go into the same level of lock-down as we spent most of this spring in. And the next lock-down may be even more draconian as there is a difference now to where we were at the second week of March when we should have locked down first.

SARS-Cov-2 is now endemic and prevalent across the UK. It is everywhere.

At the start of an epidemic the disease is growing in a small number of places, so usually (such as was the case with MERS and SARS) you can contain it by strong isolation and tracking efforts in those areas it occurs, as most of the population are not exposed. This is why you cannot contain seasonal ‘flu epidemics by isolating people, it does not work if it is wide-spread enough. ‘Flu simply flows through the population and it does in some years kill a lot of people.

With Covid-19 right now, If our R(e) – the effective reproduction number – goes above 1 anywhere across the UK, Covid-19 cases will rapidly increase in that area. And with restrictions being lifted across the whole UK and in England especially, I am privately convinced the disease will burst fourth again in many, many places and it is going to go very wrong again. I think the government is being utterly disingenuous about the impact of opening up schools and my friends who are teachers and medics have no doubt this is a significantly more dangerous step than it is being sold as. It might be the right move, but lying about it’s potential impact is not helpful long-term.

Not only are we relaxing social distancing steps too early, but I feel the government has utterly bolloxed up (technical term meaning “done a jolly poor job of”) the messaging. As examples:

  • The very clear “Stay at Home” became the vacuous “Stay Alert”, which no one seems to be able to clearly define and every one seems to have a different interpretation of.
  • We were given contradicting and non-nonsensical rules such as you could see one family member from outside your household in the park, but you could have people come and view your house. So if you want to see your mum & dad at the same time, put your house up for sale and have them view it.
  • Parts of the UK (Wales, Northern Ireland, Scotland) have said they were not consulted on changes, they do not agree with them, and they are doing their own thing. That’s not confusing to people is it?
  • The whole Cummings affair. Dominic Cummings did break the rules, he acted like a selfish idiot, he lied about what he did, he had pathetically stupid excuses (“I drove my child around in a car to test my eyesight” which shows he either does not care at all for other people’s safety or has too low an IQ to be allowed out on his own). The issue is not that one arrogant, self-important person decided the rules do not apply to him. It is that the government fail to understand that not sanctioning him is being interpreted by many to mean they can make up their own minds about which rules apply to them and which they can ignore. Continuing to say “look, get over it” is simply coming across as telling us all to bugger off.

To help steer us through this crisis, we really needed a government with both the mandate to introduce new rules and also the acceptance by most of the population of those rules, and at least acquiescence from the majority to put up with limitations placed upon us. What we have now is a not just the hard-core “we won’t be told what to do” people that would always be a negative factor in limiting the spread of a disease, but a large number of angry, confused, worried people across the country. Almost everyone I personally know in the UK feel angry, confused, worried, and mostly with a progressively declining respect for the government and their advice.

I know I’m not very good at understanding people, it does not come naturally to me. If someone does not think like I do, I can have a devil of a job working out why. But I’m pretty sure that here in the UK a lot of people are going to start saying “to hell with the lock-down rules, everyone else is ignoring them and I’ve not seen anyone die in front of me…”

I went to see my Mum this week. I had to drive 100+ miles to do it. Unlike in Dominic’s case, it’s allowed now and I have no Covid-19 symptoms. I took a mask, I took my own food, we sat in her garden (I got sunburn, so Covid-19 might not get me but skin cancer might). I assured myself she was OK and that her tech will keep working so we can stay in touch. And I felt a little naughty doing it.

But I made a conscious decision to do it now – as I think SARS-CoV-2 is about at it’s lowest prevalence in our population right now (end of May 2020) than it is going to be for months. Admissions and deaths are going down and I expect at least deaths to continue to do so for another week or two. Personally I am deeply worried that in 4 weeks time new cases, hospital admissions, and deaths will be going up again. I don’t want them to be but I’ll be (very happily) surprised if they don’t go up  – what we see in cases & deaths at any point in time is based on the level of spread one or two weeks ago respectively. I suspect that as I type our R(e) number is going up and will exceed 1 this week.

If you don’t agree with me, just keep an eye on what the scientists are saying. Some are already making noises of anxiety as an article on the BBC is already saying today. Scientists tend to make cautious statements such as “we do not think this is wise” or “we feel there is a danger in this choice of action”. It’s a normal person’s equivalent of screaming “Are you bloody idiots?!?”.  Once again, the experts are saying we should do one thing and the government are doing another. It’s not gone too well to ignore the scientists so far.

There is a T-shirt you can get at the moment, which I really must order a dozen of.

“All disaster movies start with someone ignoring a scientist”.



SQLDeveloper’s “mystats.sql” equivalent

It just occurred to me that I haven’t blogged about SQLDeveloper yet, something I really need to change ;) This post covers SQLDeveloper 19.4, and although I don’t know exactly when the feature you are reading about was added I doubt it was in the latest release.

A little bit of background first

Sometimes the wait interface isn’t enough, so you need to dig a little deeper into the performance issue. In my opinion there are two layers inside Oracle when it comes to performance troubleshooting:

  • The Wait Interface provides valuable insights about session activity, especially when off-CPU and waiting
  • Session counters provide insights into ongoing operations at a lower level, and finer granularity

Tanel Poder’s post I linked to (yes, it’s from 2010, time flies!) provides an excellent introduction to the topic. His (session) snapper.sql script is one of my favourite and most heavily-used tools, especially when investigating an ongoing issue. Have a look at the Snapper landing page to get some more details and ideas about its many capabilities, it can do a LOT.

Adrian Billington’s mystats.sql tracks sessions counters as well, but it takes a different approach. The mystats.sql script works particularly well when you can sandwich a piece of (PL/)SQL between calls to mystats start and mystasts stop. I have been using it extensively for research and even managed to sneak a little improvement in ;)

Here is an example of mystat use. It captures session counters before and after the execution of a SQL statement and prints the delta. Have a look at the GitHub repository for more details about this very useful utility as I’m not going into the details…

SQL> @mystats start s=s

PL/SQL procedure successfully completed.

SELECT /*+ noparallel gather_plan_statistics  */
  2      oi.order_id,
    SUM(oi.unit_price * oi.quantity)
  4  FROM
  5      soe.orders         o,
  6      soe.order_items    oi
  7  WHERE
  8          o.order_id = oi.order_id
  9      AND o.delivery_type = 'Express'
 11      oi.order_id
    SUM(oi.unit_price * oi.quantity) > 45000
 15      2 DESC;

---------- ------------------------------
   1449606                          49324
    577982                          48606
    468019                          47970
   1977685                          46786
   1891120                          45347
   2310221                          45209

6 rows selected.

SQL> @mystats stop t=1

MyStats report : 26-MAY-2020 18:44:51

1. Summary Timings

Type    Statistic Name                                                               Value
------  ----------------------------------------------------------------  ----------------
TIMER   snapshot interval (seconds)                                                  14.76
TIMER   CPU time used (seconds)                                                       2.38

2. Statistics Report

Type    Statistic Name                                                               Value
------  ----------------------------------------------------------------  ----------------
STAT    CPU used by this session                                                       239
STAT    CPU used when call started                                                     238
STAT    CR blocks created                                                               13
STAT    DB time                                                                        692
STAT    Effective IO time                                                        4,415,766
STAT    Number of read IOs issued                                                    1,336
STAT    Requests to/from client                                                         20
STAT    SQL*Net roundtrips to/from client                                               20
STAT    application wait time                                                            9
STAT    buffer is not pinned count                                                       7
STAT    bytes received via SQL*Net from client                                      20,586
STAT    bytes sent via SQL*Net to client                                            10,594
STAT    calls to get snapshot scn: kcmgss                                              791
STAT    calls to kcmgcs                                                                 47
STAT    cell physical IO interconnect bytes                                  1,370,603,520
STAT    consistent changes                                                             944
STAT    consistent gets                                                            278,437
STAT    consistent gets direct                                                     167,309
STAT    consistent gets examination                                                    251
STAT    consistent gets examination (fastpath)                                         251
STAT    consistent gets from cache                                                 111,128
STAT    consistent gets pin                                                        110,877
STAT    consistent gets pin (fastpath)                                             110,876
STAT    data blocks consistent reads - undo records applied                            247
STAT    db block changes                                                               838
STAT    db block gets                                                                2,415
STAT    db block gets from cache                                                     2,415
STAT    db block gets from cache (fastpath)                                          1,970
STAT    dirty buffers inspected                                                         33
STAT    enqueue conversions                                                              4
STAT    enqueue releases                                                                 8
STAT    enqueue requests                                                                 8
STAT    enqueue waits                                                                    1
STAT    execute count                                                                   17
STAT    execute count                                                                   17
STAT    file io wait time                                                       10,452,219
STAT    free buffer inspected                                                          105
STAT    free buffer requested                                                           69
STAT    heap block compress                                                              2
STAT    hot buffers moved to head of LRU                                               193
STAT    index fetch by key                                                               2
STAT    lob writes                                                                     391
STAT    lob writes unaligned                                                           391
STAT    logical read bytes from cache                                          930,144,256
STAT    no work - consistent read gets                                             277,738
STAT    non-idle wait count                                                          1,153
STAT    non-idle wait time                                                             452
STAT    opened cursors cumulative                                                       21
STAT    parse count (hard)                                                               1
STAT    parse count (total)                                                             17
STAT    physical read IO requests                                                    1,337
STAT    physical read bytes                                                  1,370,603,520
STAT    physical read total IO requests                                              1,337
STAT    physical read total bytes                                            1,370,603,520
STAT    physical read total multi block requests                                     1,336
STAT    physical reads                                                             167,310
STAT    physical reads cache                                                             1
STAT    physical reads direct                                                      167,309
STAT    process last non-idle time                                                      15
STAT    recursive calls                                                              2,022
STAT    recursive cpu usage                                                              3
STAT    rollbacks only - consistent read gets                                           26
STAT    rows fetched via callback                                                        1
STAT    session cursor cache count                                                       7
STAT    session cursor cache hits                                                       10
STAT    session logical reads                                                      280,852
STAT    session pga memory                                                       2,276,704
STAT    session pga memory max                                                  65,518,944
STAT    session uga memory                                                         261,952
STAT    session uga memory max                                                  63,036,496
STAT    sorts (memory)                                                                   1
STAT    sorts (rows)                                                                     6
STAT    table fetch by rowid                                                             1
STAT    table scan blocks gotten                                                   277,764
STAT    table scan disk non-IMC rows gotten                                     31,341,195
STAT    table scan rows gotten                                                  31,341,195
STAT    table scans (direct read)                                                        1
STAT    table scans (long tables)                                                        2
STAT    temp space allocated (bytes)                                             1,048,576
STAT    user I/O wait time                                                             442
STAT    user calls                                                                      28
STAT    workarea executions - optimal                                                    6
STAT    workarea memory allocated                                                       12

3. Options Used
- Statistics types : s=s
- Reporting filter : t=1

4. About
- MyStats v3.0 by Adrian Billington (
- Original version based on the SNAP_MY_STATS utility by Jonathan Lewis

End of report

PL/SQL procedure successfully completed.

I have modified mystats slightly so as to sort output by statistic name, rather than the change in value. I find it easier to read that way, but your mileage may vary.

Each time I look at performance instrumentation in the Oracle database I am pleasantly surprised about the level of detail available. I haven’t blogged about it lately, but going back a bit to 12.2 shows the progress made. And Oracle didn’t stop there, either. Using mystats’s output I can derive all sorts of interesting facts, none of which are of importance for this post as I’m purely interesting in reporting the change in session stats ;) When researching how Oracle works, this is quite a wealth of information, and you can find further examples on this blog.

SQLDeveloper can do this, too

If you are using SQLDeveloper and don’t want/need to use the command line, you can get something quite similar as well. Just enter your query into the text window, then hit F6 for “Autotrace”. In the lower part of your Autotrace results, you can see the change in session counters. If not, you may have to swipe the statistics pane into view using the mouse. Figure 1 shows an example:

autotrace and change in session stats - SQLDeveloper 19.4 150w, 300w, 768w, 1587w" sizes="(max-width: 1024px) 100vw, 1024px" />
Figure 1: SQLDeveloper’s Autotrace function displaying change in session statistics for this query


Session counters are super useful for understanding what Oracle does at a more granular level than the wait interface. For the most part, using the wait interface is enough, yet there is the occasional case where more details are needed. I often consider changes in session statistics when researching a particular problem, and thankfully I don’t have to come up with ways to do so as the community has already lent a helping hand!

8 years and counting…

I just noticed today is the 8 year anniversary of working for my current company.

I wrote a blog post about the interview before I got the job (here).

About 3 months after I started the job I wrote an update post, and clearly wasn’t too happy with the way things were going (here).

There was a rather unenthusiastic post about my four year anniversary (here).

Now here I am after eight years and I’m still having the same arguments about my role on an almost daily basis. It’s like a bad relationship I can’t break free from. Some sort of He Hit Me (And It Felt Like A Kiss) kind-of thing.

Let’s see what this next year brings…



PS. At least now I’m working from home, which is better.

PPS. Thanks to the people who contacted me out of concern. This is not a cry for help. </p />

    	  	<div class=

Video : Install Podman on Oracle Linux 8 (OL8)

In today’s video we’ll take a look at installing Podman on Oracle Linux 8 (OL8).

This is based on the article here.

You can see more information about containers here.

The star of today’s video is John King. John’s been on the channel a couple of times before. Once to do a message to one of his super-fans, a work colleague of mine who was impressed that I know John, and once for a regular “.com” appearance. I blame the wife for the terrible audio. </p />

    	  	<div class=

티베로 – The AWR-like “Tibero Performance Repository”

By Franck Pachot

In a previous post I introduced Tibero as The most compatible alternative to Oracle Database. Compatibility is one thing but one day you will want to compare the performance. I’ll not do any benchmark here but show you how you we can look at the performance with TPR – the Tibero Performance Repository – as an equivalent of AWR – the Oracle Automatic Workload Repository. And, as I needed to run some workload, I attempted to run something that has been written with Oracle Database in mind: the Kevin Closson SLOB – Silly Little Oracle Benchmark. The challenge is to make it run on Tibero and get a TPR report.


I’ve downloaded SLOB from:

git clone
tar -zxvf SLOB_distribution/2019.11.18.slob_2.5.2.tar.gz

and I’ll detail what I had to change in order to have it running on Tibero.


The client command line is “tbsql” and has a very good compatibility with sqlplus:

[SID=t6a u@h:w]$ tbsql -h
Usage: tbsql [options] [logon] [script]
  -h,--help        Displays this information
  -v,--version     Displays version information
  -s,--silent      Enables silent mode. Does not display the 
                   start-up message, prompts and commands
  -i,--ignore      Ignore the login script (eg, tbsql.login)
  @filename[.ext] [parameter ...]
[SID=t6a u@h:w]$ tbsql
tbSQL 6
TmaxData Corporation Copyright (c) 2008-. All rights reserved.
SQL> help
 Displays the Help.
{H[ELP]|?} topic
where topic is
 ! {exclamation} % {percent} @ {at}   @@ {double at}
 / {slash}       ACCEPT      APPEND   ARCHIVE LOG
 EDIT            EXECUTE     EXIT     EXPORT
 HELP            HISTORY     HOST     INPUT
 LIST            LOADFILE    LOOP     LS
 PROMPT          QUIT        RESTORE  RUN
 SAVE            SET         SHOW     TBDOWN

However, there are a few things I had to change.

The silent mode is “-s” instead of “-S”

The “-L” (no re-prompt if the connection fails) doesn’t exist: tbsql does not re-prompt, and leaves you in the CLI rather than exiting.

sqlplus does not show feedback for less than 5 rows. tbsql shows it always by default. We can get the same sqlplus output by setting SET FEEDBACK 6

tbsql returns “No Errors” where sqlplus returns “No errors”

You cannot pass additional spaces in the connection string. Sqlplus ignores them bit tbsql complains:

All those were easy to change in the and scripts.
I actually defined a sqlplus() bash function to handle those:

 set -- ${@// /}
 set -- ${@/-L/}
 set -- ${@/-S/-s}
 sed \
 -e '1 i SET FEEDBACK 6' \
 tbsql $* | sed \
 -e 's/No Errors/No errors/'
 echo "--- call stack ---  ${FUNCNAME[0]}()$(basename $0)#${LINENO}$(f=0;while caller $f;do((f++));done|awk '{printf " &2
 echo "--- parameters ---  tbsql $*" >&2

As you can see I’ve added the print of the bash callstack which I used to find those issues. Here is the idea:


The equivalent of TNSPING is TBPROBE. It takes a host:port and display nothing but returns a 0 return code when the connection is ok or 3 when it failed. Note that there are other status like 1 when the connection is ok but the database is read-only, 2 when in mount or nomount. You see here an architecture difference with Oracle: there is no listener but it is the database that listens on a port.
A little detail with no importance here, my database port is 8629 as mentioned in the previous post but tbprobe actually connects to 8630:

[SID=t6a u@h:w]$ strace -fyye trace=connect,getsockname,recvfrom,sendto tbprobe localhost:8629
connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
getsockname(4, {sa_family=AF_NETLINK, nl_pid=41494, nl_groups=00000000}, [12]) = 0
sendto(4, {{len=20, type=RTM_GETADDR, flags=NLM_F_REQUEST|NLM_F_DUMP, seq=1589797671, pid=0}, {ifa_family=AF_UNSPEC, ...}}, 20, 0, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, 12) = 20
connect(4, {sa_family=AF_INET, sin_port=htons(8630), sin_addr=inet_addr("")}, 16) = 0
getsockname(4127.0.0.1:8630]>, {sa_family=AF_INET, sin_port=htons(50565), sin_addr=inet_addr("")}, [28->16]) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8630), sin_addr=inet_addr("")}, 16) = 0
recvfrom(4127.0.0.1:8630]>, "\0\0\0\0\0\0\0@\0\0\0\0\0\0\0\0", 16, 0, NULL, NULL) = 16
recvfrom(4127.0.0.1:8630]>, "\0\0\0\2\0\0\0\17\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\0\0\0\0\6"..., 64, 0, NULL, NULL) = 64
sendto(4127.0.0.1:8630]>, "\0\0\0\204\0\0\0\f\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 28, 0, NULL, 0) = 28
recvfrom(4127.0.0.1:8630]>, "\0\0\0\204\0\0\0\f\0\0\0\0\0\0\0\0", 16, 0, NULL, NULL) = 16
recvfrom(4127.0.0.1:8630]>, "\0\0\0e\0\0\0\0\0\0\0\1", 12, 0, NULL, NULL) = 12
+++ exited with 0 +++

The return code is correct. What actually happens is that Tibero does not seem to use Out-Of-Band but another port to be able to communicate if the default port is in use. And this is the next port number as mentioned in my instance process list as “listener_special_port”:

[SID=t6a u@h:w]$ cat /home/tibero/tibero6/instance/t6a/.proc.list
Tibero 6   start at (2019-12-16 14:03:00) by 54323
shared memory: 140243894161408 size: 3221225472
shm_key: 847723696 1 sem_key: -1837474876 123 listener_pid: 7026 listener_port: 8629 listener_special_port: 8630 epa_pid: -1
7025 MONP
7027 MGWP
7028 FGWP000
7029 FGWP001
7030 PEWP000
7031 PEWP001
7032 PEWP002
7033 PEWP003
7034 AGNT
7035 DBWR
7036 RCWP

This means that when my database listener is 8629 TBPROBE will return “ok” for 8628 and 8629

[SID=t6a u@h:w]$ for p in {8625..8635} ; do tbprobe  localhost:$p ; echo "localhost:$p -> $?" ; done
localhost:8625 -> 3
localhost:8626 -> 3
localhost:8627 -> 3
localhost:8628 -> 0
localhost:8629 -> 0
localhost:8630 -> 3
localhost:8631 -> 3
localhost:8632 -> 3
localhost:8633 -> 3
localhost:8634 -> 3
localhost:8635 -> 3

Anyway, this has no importance here and I just ignore the tnsping test done by SLOB:



Tibero SQL does not allow to create a user with the grant statement and needs explicit CREATE. In I did the following replacement


The implicit creation of a user with a grant statement is an oraclism that is not very useful anyway.
PARALLEL and CACHE attributes are not allowed at the same place as in Oracle:



They just go at the end of the statement and that’s fine.
Tibero has no SYSTEM user by default, I create one. And by the same occasion create the IOPS tablespace:

tbsql sys/tibero <

those are the changes I’ve made to be able to run SLOB and

I also had to change a few things in slob.sql

There is no GET_CPU_TIME() in DBMS_UTILITY so I comment it out:

--v_end_cpu_tm := DBMS_UTILITY.GET_CPU_TIME();
--v_begin_cpu_tm := DBMS_UTILITY.GET_CPU_TIME();

I didn’t check for an equivalent here and just removed it.

The compatibility with Oracle is very good so that queries on V$SESSION are the same, The only thing I changed is the SID userenv that is called TID in Tibero:

SELECT ((10000000000 * (SID + SERIAL#)) + 1000000000000) INTO v_my_serial from v$session WHERE sid = ( select sys_context('userenv','tid') from dual);

I got a TBR-11006: Invalid USERENV parameter before this change.

This session ID is larger so I removed the precision:

--v_my_serial NUMBER(16);
v_my_serial NUMBER;

I got a TBR-5111: NUMBER exceeds given precision. (n:54011600000000000, p:16, s:0) before changing it.

The dbms_output was hanging and I disable it:


I didn’t try to understand the reason. That’s a very bad example of troubleshooting but I just want it to run now.

Again, without trying to understand further, I replaced all PLS_INTEGER by NUMBER as I got: TBR-5072: Failure converting NUMBER to or from a native type

In slob.conf I changed only UPDATE_PCT to 0 for a read-only workload and changed “statspack” to “awr”, and I was able to create 8 schemas:

./ IOPS 8 

(I redirect /dev/null to stdin because my sqlplus() function above reads it)

Now ready to run SLOB.
This is sufficient to run it but I want to collect statistics from the Tibero Performance Repository (TPR).

Tibero Performance Repository is the equivalent of AWR. The package to manage it is DBMS_TPR instead of DBMS_WORKLOAD_REPOSITORY. It has a CREATE_SNAPSHOT procedure, and a REPORT_LAST_TEXT to generate the report between the two last snapshots, without having to get the snapshot ID.
I’ve replaced the whole statistics() calls in by:

tbsql system/manager <<<'exec dbms_tpr.create_snapshot;';


tbsql system/manager <<<'exec dbms_tpr.create_snapshot;';
tbsql system/manager <<<'exec dbms_tpr.report_text_last;';


Now running:

sh 4 

and I can see the 4 sessions near 100% in CPU.
Note that they are threads in Tibero, need to tun “top -H” to see the detail:

TPR (Tibero Performance Repository) Report

1 session LIO

Here is the report for 5 minutes of running on one session:

               *** TPR (Tibero Performance Repository) Report ***

              DB Name : t6a
                  TAC : NO
                  TSC : NO
         Instance Cnt : 1
              Release : 6   r166256 ( LINUX_X86_64 )
            Host CPUs : 48

   Interval condition : 758 (snapshot id) (#=1 reported)
Report Snapshot Range : 2020-05-26 20:02:37 ~ 2020-05-26 20:07:38
  Report Instance Cnt : 1 (from Instance NO. 'ALL')
         Elapsed Time : 5.02 (mins)
              DB Time : 4.99 (mins)
       Avg. Session # : 1.00

I’m running a simple installation. No TSC (Tibero Standby Cluster, the Active Data Guard equivalent) and no TAC (the Oracle RAC equivalent).
This report is a run with one session only (DB time = Elapsed time) and Avg. Session # is 1.00.

 2.1 Workload Summary

                            Per Second           Per TX         Per Exec         Per Call
                       ---------------  ---------------  ---------------  ---------------
          DB Time(s):             1.00             7.68             0.00            42.80
           Redo Size:         3,096.93        23,901.92             0.52       133,167.86
       Logical Reads:       394,911.05     3,047,903.26            66.40    16,981,175.29
       Block Changes:            26.60           205.33             0.00         1,144.00
      Physical Reads:             0.00             0.00             0.00             0.00
     Physical Writes:             1.31            10.08             0.00            56.14
          User Calls:             0.02             0.18             0.00             1.00
              Parses:             0.02             0.18             0.00             1.00
         Hard Parses:             0.00             0.00             0.00             0.00
              Logons:             0.01             0.05             0.00             0.29
            Executes:         5,947.03        45,898.85             1.00       255,722.14
           Rollbacks:             0.00             0.00             0.00             0.00
        Transactions:             0.13             1.00             0.00             5.57

394,911 logical reads per second is comparable to what I can get from Oracle on this Intel(R) Xeon(R) Platinum 8167M CPU @ 2.00GHz but let’s see what happens with some concurrency. I miss the DB CPU(s) which can quickly show that I am running mostly on CPU but this can be calculated from other parts of the report.(DB CPU time is 299,134 which covers the 5 minutes elapsed time). The “Per Call” is interesting as it has more meaning than the “Per Execution” one which counts the recursive executions.

4 sessions LIO

Another report from the run above with 4 concurrent sessions:

               *** TPR (Tibero Performance Repository) Report ***
DB Name : t6a
                  TAC : NO
                  TSC : NO
         Instance Cnt : 1
              Release : 6   r166256 ( LINUX_X86_64 )
            Host CPUs : 48
Interval condition : 756 (snapshot id) (#=1 reported)
Report Snapshot Range : 2020-05-2619:54:48 ~ 2020-05-2619:59:49
  Report Instance Cnt : 1 (from Instance NO. 'ALL')
         Elapsed Time : 5.02 (mins)
              DB Time : 19.85 (mins)
       Avg. Session # : 1.00

Ok, there’s a problem in the calculation of “Avg. Session #” which should be 19.85 / 5.02 = 3.95 for my 4 sessions.

About the Host:

 1.1 CPU Usage

                Total       B/G           Host CPU Usage(%)
               DB CPU    DB CPU  ----------------------------------
Instance#    Usage(%)  Usage(%)   Busy   User    Sys   Idle  IOwait
-----------  --------  --------  -----  -----  -----  -----  ------
          0       7.9       7.9    7.9    7.8    0.1   92.1     0.0

mostly idle as I have 38 vCPUs there.

 1.2 Memory Usage
HOST Mem Size :    322,174M
                      Total SHM Size :      3,072M
                   Buffer Cache Size :      2,048M
               Avg. Shared Pool Size :     288.22M
                  Avg. DD Cache Size :       8.22M
                  Avg. PP Cache Size :      63.44M
                       DB Block Size :          8K
                     Log Buffer Size :         10M

My workload size (80MB defined in slob.conf) is much smaller than the buffer cache.
and then I expect an average of 4 active sessions in CPU:

 2.1 Workload Summary
Per Second          Per TX        Per Call
                  --------------- --------------- ---------------
      DB Time(s):            3.96           38.41           79.38
       Redo Size:        3,066.07       29,770.52       61,525.73
   Logical Reads:      427,613.99    4,151,993.87    8,580,787.33
   Block Changes:           26.36          255.90          528.87
  Physical Reads:            0.00            0.00            0.00
 Physical Writes:            0.99            9.61           19.87
      User Calls:            0.05            0.48            1.00
          Parses:            0.03            0.29            0.60
     Hard Parses:            0.00            0.00            0.00
          Logons:            0.02            0.16            0.33
        Executes:       67,015.04      650,694.45    1,344,768.53
       Rollbacks:            0.00            0.00            0.00
    Transactions:            0.10            1.00            2.07

3.96 average session is not so bad. But 427,613 LIOPS is only a bit higher than the 1 session run, but now with 4 concurrent sessions. 4x CPU usage for only 10% higher throughput…

At this point I must say that I’m not doing a benchmark here. I’m using the same method as I do with Oracle, for which I know quite well how it works, but here Tibero is totally new for me. I’ve probably not configured it correctly and the test I’m doing may not be correct. I’m looking at the number here only to understand a bit more how it works.

The Time Model is much more detailed than Oracle one:

 2.2 Workload Stats

                                                                         DB         DB
            Category                                       Stat         Time(ms)   Time(%)
--------------------  -----------------------------------------  ---------------  --------
Request Service Time  -----------------------------------------        1,190,760    100.00
                                            SQL processing time        1,200,818    100.84
                           reply msg processing time for others                0      0.00
                                             commit by msg time                0      0.00
                              SQL processing (batchupdate) time                0      0.00
                                           rollback by msg time                0      0.00
                                                   msg lob time                0      0.00
                                                    msg xa time                0      0.00
                                                   msg dpl time                0      0.00
                                            msg dblink 2pc time                0      0.00
                                                  msg tsam time                0      0.00
                                             msg long read time                0      0.00
      SQL Processing  -----------------------------------------        1,200,818    100.84
                                       SQL execute elapsed time          369,799     31.06
                                          csr fetch select time          355,744     29.88
                                             parse time elapsed           83,992      7.05
                                       sql dd lock acquire time           25,045      2.10
                                                ppc search time            5,975      0.50
                                          csr fetch insert time              115      0.01
                                          csr fetch delete time               37      0.00
                                        hard parse elapsed time                2      0.00
                                        total times to begin tx                1      0.00
                                      failed parse elapsed time                1      0.00
                                      sql dml lock acquire time                0      0.00
                                              cursor close time                0      0.00
                        stat load query hard parse elapsed time                0      0.00
                        stat load query soft parse time elapsed                0      0.00
                              csr fetch direct path insert time                0      0.00
                                           csr fetch merge time                0      0.00
                                                 optimizer time                0      0.00
                                          csr fetch update time                0      0.00
                                 stat load query row fetch time                0      0.00
              Select  -----------------------------------------               17      0.00
                                           table full scan time               11      0.00
                                                 hash join time                6      0.00
                                                      sort time                0      0.00
                                        op_proxy execution time                0      0.00
              Insert  -----------------------------------------                1      0.00
                                              tdd mi total time                1      0.00
                                            tdi insert key time                0      0.00
                                            tdd insert row time                0      0.00
                                              tdi mi total time                0      0.00
                                            tdi fast build time                0      0.00
              Update  -----------------------------------------                0      0.00
                                             tdd update rp time                0      0.00
                                            tdd update row time                0      0.00
                                              tdd mu total time                0      0.00
                                    idx leaf update nonkey time                0      0.00
              Delete  -----------------------------------------               15      0.00
                                            tdd delete row time               15      0.00
                                             tdd delete rp time                0      0.00
                                              tdd md total time                0      0.00
                                              tdi md total time                0      0.00
                                            tdi delete key time                0      0.00

I am surprised to spend 7% of the time in parsing, as I expect the few queries to be parsed only once there, which is confirmed by the Workload Summary above.

Having a look at the ratios:

 3.1 Instance Efficiency

      Buffer Cache Hit %:    100.00
           Library Hit %:    100.00
                PP Hit %:     99.54
             Latch Hit %:     98.44
        Redo Alloc Hit %:    100.00
         Non-Parse CPU %:     92.95

confirms that 7% of the CPU time is about parsing.

We have many statistics. Here are the timed-base ones:

 6.1 Workload Stats (Time-based)

                                     Stat         Time(ms)    Avg. Time(ms)              Num             Size
-----------------------------------------  ---------------  ---------------  ---------------  ---------------
                      SQL processing time        1,200,818        120,081.8               10                0
                Inner SQL processing time        1,200,817        120,081.7               10                0
                         req service time        1,190,760         79,384.0               15                0
                              DB CPU time        1,120,908              1.6          705,270                0
                 SQL execute elapsed time          369,799              0.0       20,174,294                0
                    csr fetch select time          355,744              0.0       20,174,264                0
                         tscan rowid time          187,592              0.0       20,174,102                0
               PSM execution elapsed time          129,820              0.0       60,514,594                0
                       parse time elapsed           83,992              0.0       20,174,308                0
                     tdi fetch start time           47,440              0.0       20,175,956        1,660,966
                 sql dd lock acquire time           25,045              0.0       20,171,527                0
                 isgmt get cr in lvl time           25,004              0.0       20,390,418       22,268,417
                        isgmt get cr time           21,500              0.0       22,479,405                0
                tscan rowid pick exb time           18,734              0.0      106,200,851                0
                    tscan rowid sort time           15,529              0.0       20,173,326                0
                         ppc search time            5,975              0.0       20,174,325                0
                           dd search time            4,612              0.0       40,344,560                0
                  hard parse elapsed time                2              0.1               13                0
                failed parse elapsed time                1              0.1                5                0

This parse time is not hard parse.
The non-timed-based statistics are conveniently ordered by number which is more useful than by alphabetical order:

 6.2 Workload Stats (Number-based)

                                     Stat              Num             Size         Time(ms)
-----------------------------------------  ---------------  ---------------  ---------------
                     candidate bh scanned      128,715,142      153,638,765                0
               consistent gets - no clone      128,700,485                0                0
  fast examines for consistent block gets      128,700,414                0                0
                    consistent block gets      128,698,143                0                0
                 block pin - not conflict      128,691,338                0              796
                              block unpin      128,691,332                0              333
                      rowid sort prefetch      106,200,861       18,945,339                0
                     tscan rowid pick exb      106,200,851                0           18,734
                          dd search count       40,344,560                0            4,612
Number of conflict DBA while scanning can       24,917,669                0                0

                    tdi fetch start total       20,175,956        1,660,966           47,440
           parse count (for all sessions)       20,174,308                0           83,992
                         csr fetch select       20,174,264                0          355,744
                              tscan rowid       20,174,102                0          187,592
                         tscan rowid sort       20,173,326                0           15,529
               memory tuner prof register       20,171,661       20,171,661              198
                            execute count       20,171,528                0                0
                      sql dd lock acquire       20,171,527                0           25,045
                      parse count (total)                9                0                0

and this clearly means that I had as many parses as counts. Then I realized that there was nothing about a parse-to-execute ratio in the “Instance Efficiency” which is the only ratio I read at in Oracle “Instance Efficiency”. Even if the terms are similar there’s something different from Oracle.
The only documentation I’ve found is in Korean:
According to this, “parse time elapsed” is the time spent in “parse count (for all sessions)”, and covers parsing, syntax and semantic analysis which is what we call soft parse in Oracle. “parse count (total)” is parsing, transformation and optimization, which is what we call hard parse in Oracle. With this very small knowledge, it looks like, even if called from PL/SQL, a soft parse occurred for each execution. Look also at the “dd’ statistics: “sql dd lock acquire time” is 2.1% of DB time and looks like serialization on the Data Dictionary. And, even if not taking lot of time (“dd search time” is low) the “dd search count” is called 2 times per execution: soft parse of the small select has to read the Data Dictionary definitions.

Of course we have wait events (not timed events as this section does not include the CPU):

 3.2 Top 5 Wait Events by Wait Time

                                                  Time          Wait          Avg           Waits       DB
                         Event            Waits  -outs(%)       Time(s)      Wait(ms)           /TX   Time(%)
------------------------------  ---------------  --------  ------------  ------------  ------------  --------
           spinlock total wait          787,684      0.00         45.47          0.06  2,540,916.13      3.82
          dbwr write time - OS                7      0.00          0.16         23.14         22.58      0.01
spinlock: cache buffers chains            9,837      0.00          0.12          0.01     31,732.26      0.01
               redo write time               36      0.00          0.03          0.78        116.13      0.00
     log flush wait for commit               31      0.00          0.03          0.81        100.00      0.00

Only “spinlock total wait” is significant here.
Here is the section about latches:

 7.7 Spinlock(Latch) Statistics

                                            Get    Get     Avg.Slps       Wait           Nowait   Nowait     DB
                          Name          Request   Miss(%)     /Miss       Time(s)       Request   Miss(%)   Time(%)
------------------------------  ---------------  --------  --------  ------------  ------------  --------  --------
         SPIN_SPIN_WAITER_LIST        2,190,429      4.07      3.60         51.69             0      0.00      4.34
                    SPIN_ALLOC      161,485,088     10.40      3.71         41.42             0      0.00      3.48
                SPIN_LC_BUCKET       60,825,921      0.53     25.55          3.31             0      0.00      0.28
               SPIN_ROOT_ALLOC      126,036,981      0.00     79.52          0.16   126,040,272      0.00      0.01
               SPIN_BUF_BUCKET      257,429,840      0.00     15.82          0.12            34      0.00      0.01
               SPIN_RECR_UNPIN      121,038,780      0.00     57.14          0.08        36,039      0.01      0.01
                 SPIN_SQLSTATS       40,383,027      0.36      0.61          0.07             0      0.00      0.01

This looks like very generic Latch protected by spinlock.

While I was there I ran a Brendan Gregg Flamegraph during the run:

perf script -i ./ | FlameGraph/ | FlameGraph/ --width=1200 --hash --cp > /tmp/tibero-slob.svg 300w, 768w, 1205w" sizes="(max-width: 1024px) 100vw, 1024px" />

if you ever traced some Oracle PL/SQL call stacks, you can see that Tibero is completely different implementation. But the features are very similar. TPR is really like AWR. And there is also an ASH equivalent. You may have seen in the previous post that I have set ACTIVE_SESSION_HISTORY=Y in the .tip file (Tibero instance parameters). You can query a v$active_session_history.


Given the similarity with Oracle, let’s do a good old ‘tkprof’.
I run the SLOB call with SQL_TRACE enabled:

[SID=t6a u@h:w]$ tbsql user1/user1

tbSQL 6

TmaxData Corporation Copyright (c) 2008-. All rights reserved.

Connected to Tibero.

SQL> alter session set sql_trace=y;

Session altered.

SQL> @slob 1 0 0 300 10240 64 LITE 0 FALSE 8 16 3 0 .1 .5 0

PSM completed.

SQL> alter session set sql_trace=y;

Session altered.

The raw trace has been generated, which contains things like this:

PARSING IN CSR=#8 len=87, uid=172, tim=1590498896169612
                        FROM cf1
                        WHERE ( custid > ( :B1 - :B2 ) ) AND  (custid < :B1)
[PARSE] CSR=#8 c=0, et=29, cr=0, cu=0, p=0, r=0, tim=1590498896169655
[EXEC] CSR=#8 c=0, et=48, cr=0, cu=0, p=0, r=0, tim=1590498896169720
[FETCH] CSR=#8 c=0, et=307, cr=66, cu=0, p=0, r=1, tim=1590498896170044
[PSM] OBJ_ID=-1, ACCESS_NO=0 c=0, et=14, cr=0, cu=0, p=0, r=0, tim=1590498896170090
[STAT] CSR=#8 ppid=4826 cnt_in_L=1 cnt=1 dep=0 'column projection (et=2, cr=0, cu=0, co=63, cpu=0, ro=1)'
[STAT] CSR=#8 ppid=4826 cnt_in_L=64 cnt=1 dep=1 'sort aggr (et=6, cr=0, cu=0, co=63, cpu=0, ro=1)'
[STAT] CSR=#8 ppid=4826 cnt_in_L=64 cnt=64 dep=2 'table access (rowid) CF1(3230) (et=258, cr=64, cu=0, co=63, cpu=0, ro=60)'
[STAT] CSR=#8 ppid=4826 cnt_in_L=0 cnt=64 dep=3 'index (range scan) I_CF1(3235) (et=20, cr=2, cu=0, co=2, cpu=0, ro=60)'
[PSM] OBJ_ID=-1, ACCESS_NO=0 c=0, et=62, cr=0, cu=0, p=0, r=0, tim=1590498896170170

And all this can be aggregated by TBPROF:

tbprof tb_sqltrc_17292_63_2107964.trc tb_sqltrc_17292_63_2107964.txt sys=yes sort="prscnt"

Which gets something very similar to Oracle tkprof:

                        FROM cf1
                        WHERE ( custid > ( :B1 - :B2 ) ) AND  (custid < :B1)

 stage     count       cpu   elapsed   current     query      disk      rows
 parse         1      0.00      0.00         0         0         0         0
  exec    829366     28.41     27.68         0         0         0         0
 fetch    829366    137.36    135.18         0  55057089         0    829366
   sum   1658733    165.77    162.86         0  55057089         0    829366

    rows  u_rows        execution plan
   829366       -       column projection (et=859685, cr=0, cu=0, co=52250058, cpu=0, ro=829366)
   829366       -        sort aggr (et=3450526, cr=0, cu=0, co=52250058, cpu=0, ro=829366)
   53079424       -       table access (rowid) CF1(3230) (et=106972426, cr=53079424, cu=0, co=52250058, cpu=0, ro=49761960)
   53079424       -        index (range scan) I_CF1(3235) (et=9256762, cr=1977665, cu=0, co=1658732, cpu=0, ro=49761960)

But here I’m puzzled. From the TPR statistics, I got the impression that each SQL in the PSM (Persistent Stored Procedure – the PL/SQL compatible procedural language) was soft parsed but I was wrong: I see only one parse call here. Is there something missing there? I don’t think so. The total time in this profile is 162.86 seconds during a 300 seconds run without any think time. Writing the trace file is not included there. if I compare the logical reads per second during the SQL time: 55057089/162.86=338064 I am near the value I got without sql_trace.

I leave it with unanswered questions about the parse statistics. The most important, which was the goal of this post, is that there’s lot of troubleshooting tools, similar to Oracle, and I was able to run something that was really specific to Oracle, with sqlplus, SQL, and PL/SQL without the need for many changes.

Cet article 티베로 – The AWR-like “Tibero Performance Repository” est apparu en premier sur Blog dbi services.