Author Archives: Martin Bach

About Martin Bach

Oracle DBA and Linux enthusiast, part time author and presenter.

Tips'n'tricks: understanding "too many authentication failures" in SSH

Virtualbox VMs powered by Vagrant require authentication via SSH keys so you don’t have to provide a password each time vagrant up is doing its magic. Provisioning tools you run as part of the vagrant up command also rely on the SSH key based authentication to work properly. This is documented in the official Vagrant documentation set.

I don’t want to use unknown SSH keys with my own Vagrant boxes as a matter of principle. Whenever I create a new custom box I resort to a dedicated SSH key I’m using just for this purpose. This avoids the trouble with Vagrant’s “insecure key pair”, all I need to do is add config.ssh.private_key_path = "/path/to/key" to the Vagrantfile.

The documentation further reads I have to use a NAT device as the first network card in the VM. For some of my VMs I define an additional NIC using a host-only, private network for communication between say for example middle tier and database layer. I don’t want to mess around with port forwarding to enable communication between my VMs, and Vagrant makes it super easy to define another NIC.

This sounds interesting, but what does that have to do with this post?

Please bear with me, I’m building up a story ;) It will all make sense in a minute…

Connecting to the VM’s second interface

With all that in place it’s easy to SSH into my Vagrant box. Assume I have a Vagrant VM with an IP address of 192.168.56.202 to which I want to connect via SSH. Remember when I said I have a dedicated SSH key for my Vagrant boxes? The SSH key is stored in ~/.ssh/vagrant. The SSH command to connect to the environment is simple:

$ ssh -i ~/.ssh/vagrant vagrant@192.169.56.202

… and this connects me without having to provide a password.

Saving time for the lazy

Providing the path to the SSH key to use gets a little tedious after a while. There are a couple of solutions to this; there might be more, but I only know about these two:

  • Create a configuration in ~/.ssh/config Except that doesn’t work particularly well with keys for which you defined a passphrase as you now have to enter the passphrase each time
  • Add the key to the SSH agent

On Linux and MacOS I prefer the second method, especially since I’m relying on passphrases quite heavily. Recently I encountered a problem with this approach, though. When trying to connect to the VM, I received the following error message:

$ ssh vagrant@192.169.56.202
Received disconnect from 192.169.56.202 port 22:2: Too many authentication failures
Disconnected from 192.169.56.202 port 22

What’s that all about? I am sure I have the necessary key added to the agent:

$ ssh-add -l | grep -c vagrant
1

Well it turns out that if you have too many non-matching keys, you can run into the pre-authentication problem like I did. The first step in troubleshooting SSH connections (at least to me) is to enable the verbose option:

$ ssh -v vagrant@192.169.56.202

[ ... more detail ... ]

debug1: Will attempt key: key1 ... redacted ... agent
debug1: Will attempt key: key10 ... redacted ... agent
debug1: Will attempt key: key2 ... redacted ... agent
debug1: Will attempt key: key3 ... redacted ... agent
debug1: Will attempt key: key4 ... redacted ... agent
debug1: Will attempt key: key5 ... redacted ... agent
debug1: Will attempt key: key6 ... redacted ... agent
debug1: Will attempt key: key7 ... redacted ... agent
debug1: Will attempt key: key8 ... redacted ... agent
debug1: Will attempt key: key9 ... redacted ... agent

[ ... ]

debug1: Next authentication method: publickey
debug1: Offering public key: key1 ... redacted ... agent
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password

[...]

debug1: Offering public key: key5 ... redacted ... agent
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
Received disconnect from 192.169.56.202 port 22:2: Too many authentication failures
Disconnected from 192.169.56.202 port 22

It is my understanding that SSH is querying the agent for SSH keys, and it receives them. After trying key1 through key5 and not finding a match, it decides to stop and returns said error message.

There are quite a few keys currently added to my running agent:

$ ssh-add -l | wc -l
11

The Solution

The solution is quite straight forward: I need to store keys with the agent, but I have to indicate which of the stored keys to log in to my VM. This is probably best done in ~/.ssh/config:

$ cat ~/.ssh/config 

192.168.56.202
    IdentityFile ~/.ssh/vagrant

In summary, I’m now using a combination of the 2 approaches I outlined above to great effect: now I can log in without having to worry about the keys stored by my agent, and the order in which they are stored.

Ansible Tips’n’tricks: rebooting Vagrant boxes after a kernel upgrade

Occasionally I have to reboot my Vagrant boxes after kernel updates have been installed as part of an Ansible playbook during the “vagrant up” command execution.

I create my own Vagrant base boxes because that’s more convenient for me than pulling them from Vagrant’s cloud. However they, too, need TLC and updates. So long story short, I run a yum upgrade after spinning up Vagrant boxes in Ansible to have access to the latest and greatest (and hopefully most secure) software.

To stay in line with Vagrant’s philosophy, Vagrant VMs are lab and playground environments I create quickly. And I can dispose of them equally quickly, because all that I’m doing is controlled via code. This isn’t something you’d do with Enterprise installations!

Vagrant and Ansible for lab VMs!

Now how do you reboot a Vagrant controlled VM in Ansible? Here is how I’m doing this for VirtualBox 6.0.14 and Vagrant 2.2.6. Ubuntu 18.04.3 comes with Ansible 2.5.1.

Finding out if a kernel upgrade is needed

My custom Vagrant boxes are all based on Oracle Linux 7 and use UEK as the kernel of choice. That is important because it determines how I can find out if yum upgraded the kernel (eg UEK) as part of a “yum upgrade”.

There are many ways to do so, I have been using the following code snippet with some success:

 - name: check if we need to reboot after a kernel upgrade
    shell: if [ $(/usr/bin/rpm -q kernel-uek|/usr/bin/tail -n 1) != kernel-uek-$(uname -r) ]; then /usr/bin/echo 'reboot'; else /usr/bin/echo 'no'; fi
    register: must_reboot

So in other words I compare the last line from rpm -q kernel-uek to the name of the running kernel. If they match – all good. If they don’t, it seems there is a newer kernel-uek* RPM on disk than that of the running kernel. If the variable “must_reboot” contains “reboot”, I guess I have to reboot.

Rebooting

Ansible introduced a reboot module recently, however my Ubuntu 18.04 system’s Ansible version is too old for that and I wanted to stay with the distribution’s package. I needed an alternative.

There are lots of code snippets out there to reboot systems in Ansible, but none of them worked for me. So I decided to write the process up in this post :)

The following block worked for my very specific setup:

  - name: reboot if needed
    block:
    - shell: sleep 5 && systemctl reboot
      async: 300
      poll: 0
      ignore_errors: true

    - name: wait for system to come back online
      wait_for_connection:
        delay: 60
        timeout: 300
    when: '"reboot" in must_reboot.stdout'

This works nicely with the systems I’m using.

Except there’s a catch lurking in the code: when installing Oracle the software is made available via Virtualbox’s shared folders as defined in the Vagrantfile. When rebooting a Vagrant box outside the Vagrant interface (eg not using the vagrant reload command), shared folders aren’t mounted automatically. In other words, my playbook will fail trying to unzip binaries because it can’t find them. Which isn’t what I want. To circumvent this situation I add the following instruction into the block you just saw:

    - name: re-mount the shared folder after a reboot
      mount:
        path: /mnt
        src: mnt
        fstype: vboxsf
        state: mounted

This re-mounts my shared folder, and I’m good to go!

Summary

Before installing Oracle software in Vagrant for lab and playground use I always want to make sure I have all the latest and greatest patches installed as part of bringing a Vagrant box online for the first time.

Using Ansible I can automate the entire process from start to finish, even including kernel updates in the process. These are applied before I install the Oracle software!

Upgrading the kernel (or any other software components for that matter) post Oracle installation is more involved, and I usually don’t need to do this during the lifetime of the Vagrant (playground/lab) VM. Which is why Vagrant is beautiful, especially when used together with Ansible.

orachk can now warn about unwanted cleanup of files in /var/tmp/.oracle

Some time ago @martinberx mentioned on twitter that one of his Linux systems suffered from Clusterware issues for which there wasn’t a readily available explanation. It turned out that the problem he faced were unwanted (from an Oracle perspective at least) automatic cleanup operations in /var/tmp/.oracle. You can read more at the original blog post.

The short version is this: systemd (1) – successor to SysV init and Upstart – tries to be helpful removing unused files in a number of “temp” directories. However some of the files it can remove are essential for Clusterware, and without them all sorts of trouble ensue.

A note about this post’s shell life and versions used

In case you found this post via a search engine, here are the key properties of the system I worked on while compiling this post – an Oracle Linux 7.7 VM and orachk 19.2.0_20190717. Everything in IT has a shell life, and this post is no different. It is likely to become obsolete with new releases of the operating system and/or orachk versions.

orachk

My Oracle Suport (MOS) has been updated, there are finally hits when searching for “tmpfiles.d” for Oracle/RedHat Linux 7. Exadata users find the issue documented as EX50. More importantly, orachk 19.2.0_20190717 (and potentially earlier releases, I haven’t checked) warn you about this potential stability issue as you can see in figure 1:

Figure 1: orachk warns about potential problems

This is great news for database administrators as this might have gone undetected otherwise. It should be noted though that the suggested solution underneath Action/Repair is incomplete. You cannot simply copy and paste the 3 lines mentioned in that section as the documentation for tmpfiles.d (5) reveals. Subsequent orachk runs confirm this by still flagging the outcome of the check as critical.

Ensuring the check passes

A little more digging into the issue and corresponding MOS notes revealed that a different syntax is needed. This has already been covered in a couple of other blog posts, I’m adding the information here to save you time. With the amended configuration added towards the end of /usr/lib/tmpfiles.d/tmp.conf, orachk was happy:

[root@server1]# cat /usr/lib/tmpfiles.d/tmp.conf
# This file is part of systemd.
#
# systemd is free software; you can redistribute it and/or modify it
# under the terms of the GNU Lesser General Public License as published by
# the Free Software Foundation; either version 2.1 of the License, or
# (at your option) any later version.

# See tmpfiles.d(5) for details

[ ... more output ... ]

x /tmp/.oracle*
x /var/tmp/.oracle*
x /usr/tmp/.oracle*

I re-ran the orachk command and thankfully, the test succeeded as you can see this in figure 2:

Figure 2: with a little extra configuration the check passes.

I have no idea if systemd picks the change in my configuration file up without restarting the timer, so I’m also doing this for good measure:

[root@server1 ~]# systemctl restart systemd-tmpfiles-clean.timer

With these remediation steps in place, you have done everything Oracle documented to be safe from Clusterware issues caused by systemd. Shortly before hitting the publish button @FritsHoogland let me know that Oracle’s Grid Infrastructure RU 19.4 has a go at fixing this issue. It doesn’t add all the lines to satisfy orachk though, and you need to review /usr/lib/tmpfiles.d/tmp.conf after applying the 19.4 Grid Infrastructure RU.

Ansible tips’n’tricks: executing a loop conditionally

When writing playbooks, I occasionally add optional tasks. These tasks are only executed if a corresponding configuration variable is defined. I usually define configuration variables either in group_vars/* or alternatively in the role’s roleName/default/ directory.

The “when” keyword can be used to test for the presence of a variable and execute a task if the condition evaluates to “true”. However this isn’t always straight-forward to me, and recently I stumbled across some interesting behaviour that I found worth mentioning. I would like to point out that I’m merely an Ansible enthusiast, and by no means a pro. In case there is a better way to do this, please let me know and I’ll update the post :)

Before showing you my code, I’d like to add a little bit of detail here in case someone finds this post via a search engine:

  • Ansible version: ansible 2.8.2
  • Operating system: Fedora 29 on Linux x86-64

The code

This is the initial code I started with:

$ tree
.
├── inventory.ini
├── roles
│   └── example
│       ├── defaults
│       │   └── main.yml
│       └── tasks
│           └── main.yml
└── variables.yml

4 directories, 4 files

$ nl variables.yml 
      1  ---
      2  - hosts: blogpost
      3    become: yes
      4    roles:
      5    - example

$ nl roles/example/defaults/main.yml 
     1  #
     2  # some variables
     3  #

     4  oracle_disks: ''

$ nl roles/example/tasks/main.yml
     1  ---
     2  - name: print lenght of oracle_disks variable
     3    debug: 
     4      msg: "The variable has a length of {{ oracle_disks | length }}"

     5  - name: format disk devices
     6    parted:
     7      device: "{{ item }}"
     8      number: 1
     9      state: present
    10      align: optimal
    11      label: gpt
    12    loop: "{{ oracle_disks }}"
    13    when: oracle_disks | length > 0

This will not work, as you can see in a minute.

The error

And indeed, the execution of my playbook (variables.yml) failed:

$ ansible-playbook -vi inventory.ini variables.yml 
Using /etc/ansible/ansible.cfg as config file

PLAY [blogpost] ******************************************************************************************************

TASK [Gathering Facts] ***********************************************************************************************
ok: [server6]

TASK [example : print lenght of oracle_disks variable] ***************************************************************
ok: [server6] => {}

MSG:

The variable has a length of 0


TASK [example : format disk devices] *********************************************************************************
fatal: [server6]: FAILED! => {}

MSG:

Invalid data passed to 'loop', it requires a list, got this instead: . 
Hint: If you passed a list/dict of just one element, try adding wantlist=True 
to your lookup invocation or use q/query instead of lookup.


PLAY RECAP ***********************************************************************************************************
server6                    : ok=2    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

The intention was to not execute the task named “format disk devices” if oracle_disks has a length of 0. This seems to be evaluated too late though, and it turned out to be the wrong check anyway. I tried various permutations of the scheme, but none were successful while oracle_disks was set to the empty string. Which is wrong, but please bear with me …

No errors with meaningful values

The loop syntax in the role’s tasks/main.yml file is correct though, once I set the variable to a list, it worked:

$ nl roles/example/defaults/main.yml
      1  #
      2  # some variables
      3  #
        
      4  oracle_disks: 
      5  - /dev/vdc
      6  - /dev/vdd

$ ansible-playbook -vi inventory.ini variables.yml
Using /etc/ansible/ansible.cfg as config file

PLAY [blogpost] ******************************************************************************************************

TASK [Gathering Facts] ***********************************************************************************************
ok: [server6]

TASK [example : print lenght of oracle_disks variable] ***************************************************************
ok: [server6] => {}

MSG:

The variable has a length of 2

TASK [example : format disk devices] *********************************************************************************
changed: [server6] => (item=/dev/vdc) => {
    "ansible_loop_var": "item",
    "changed": true,
    "disk": {
        "dev": "/dev/vdc",
        "logical_block": 512,
        "model": "Virtio Block Device",
        "physical_block": 512,
        "size": 10485760.0,
        "table": "gpt",
        "unit": "kib"
    },
    "item": "/dev/vdc",
    "partitions": [
        {
            "begin": 1024.0,
            "end": 10484736.0,
            "flags": [],
            "fstype": "",
            "name": "primary",
            "num": 1,
            "size": 10483712.0,
            "unit": "kib"
        }
    ],
    "script": "unit KiB mklabel gpt mkpart primary 0% 100%"
}
changed: [server6] => (item=/dev/vdd) => {
    "ansible_loop_var": "item",
    "changed": true,
    "disk": {
        "dev": "/dev/vdd",
        "logical_block": 512,
        "model": "Virtio Block Device",
        "physical_block": 512,
        "size": 10485760.0,
        "table": "gpt",
        "unit": "kib"
    },
    "item": "/dev/vdd",
    "partitions": [
        {
            "begin": 1024.0,
            "end": 10484736.0,
            "flags": [],
            "fstype": "",
            "name": "primary",
            "num": 1,
            "size": 10483712.0,
            "unit": "kib"
        }
    ],
    "script": "unit KiB mklabel gpt mkpart primary 0% 100%"
}

PLAY RECAP ***********************************************************************************************************
server6                    : ok=3    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

So what gives? It once more goes to show that as soon as you do things right, they start working.

Checking if a variable is defined

How can I prevent the task from being executed? There are probably a great many ways of achieving this goal, I learned that not defining oracle_disks seems to work for me. Here I’m commenting out all references to the variable before trying again:

$ cat roles/example/defaults/main.yml 
#
# some variables
#

#oracle_disks: 
#- /dev/vdc
#- /dev/vdd

$ cat roles/example/tasks/main.yml 
---
- name: print lenght of oracle_disks variable
  debug: 
    msg: "The variable has a length of {{ oracle_disks | length }}"
  when: oracle_disks is defined

- name: format disk devices
  parted:
    device: "{{ item }}"
    number: 1
    state: present
    align: optimal
    label: gpt
  loop: "{{ oracle_disks }}" 
  when: oracle_disks is defined

$ ansible-playbook -vi inventory.ini variables.yml 
Using /etc/ansible/ansible.cfg as config file

PLAY [blogpost] ******************************************************************************************************

TASK [Gathering Facts] ***********************************************************************************************
ok: [server6]

TASK [example : print lenght of oracle_disks variable] ***************************************************************
skipping: [server6] => {}

TASK [example : format disk devices] *********************************************************************************
skipping: [server6] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
}

PLAY RECAP ***********************************************************************************************************
server6                    : ok=1    changed=0    unreachable=0    failed=0    skipped=2    rescued=0    ignored=0 

With the variable not defined, the task is skipped as intended.

As you read earlier, using the empty string (”) isn’t the right way to mark a variable as “empty”. I guess this is where my other programming languages influenced me a bit (cough * perl * cough). The proper way to indicate there are no items in the list (as per the documentation) is this:

$ nl roles/example/defaults/main.yml 
     1  #
     2  # some variables
     3  #

     4  oracle_disks: []

$ nl roles/example/tasks/main.yml 
     1  ---
     2  - name: print lenght of oracle_disks variable
     3    debug: 
     4      msg: "The variable has a length of {{ oracle_disks | length }}"
     5    when: oracle_disks is defined

     6  - name: format disk devices
     7    parted:
     8      device: "{{ item }}"
     9      number: 1
    10      state: present
    11      align: optimal
    12      label: gpt
    13    loop: "{{ oracle_disks | default([]) }}" 

The default() assignment in tasks/main.yml line 13 shouldn’t be necessary with the assignment completed in defaults/main.yml line 4. It doesn’t seem to hurt either. Instead of the conditional check message you will see the task executed, but since there is nothing to loop over, it finishes straight away:

$ ansible-playbook -vi inventory.ini variables.yml 
Using /etc/ansible/ansible.cfg as config file

PLAY [blogpost] ***********************************************************************************************************************************************************************

TASK [Gathering Facts] ****************************************************************************************************************************************************************
ok: [server6]

TASK [example : print lenght of oracle_disks variable] ********************************************************************************************************************************
ok: [server6] => {}

MSG:

The variable has a length of 0


TASK [example : format disk devices] **************************************************************************************************************************************************

PLAY RECAP ****************************************************************************************************************************************************************************
server6                    : ok=2    changed=0    unreachable=0    failed=0    skipped=1    rescued=0    ignored=0

Happy coding!

Dead Connection Detection (DCD) and the Oracle database

Dead Connection Detection is a useful feature of the Oracle database: it allows for the cleanup of “dead” sessions so they don’t linger around consuming memory and other system resources. The idea is simple: if the database detects that a client process is no longer connected to its server process, it cleans up. This can happen in many ways, in most cases this kind of problem is triggered by an end user.

A dead connection shouldn’t be confused with idle connections: an idle connection still maintains the network link between client and server process, except that there is no activity. Idle connections aren’t maintained/controlled via DCD, there are other tools in the database handling such cases.

As a by product, DCD can also help with overly eager firewalls forcibly removing seemingly idle network connections. I found the following posts and the references therein very useful:

With Oracle 12c Oracle changed the way DCD works by no longer relying on its network layer but rather pushing the functionality into the TCP stack on platforms that support it. This change in behaviour is also explained in an Oracle white paper from 2014.

For the first part of this post I set sqlnet.expire_time to 1 as per a MOS note I found, your value is probably different. The parameter is documented in the Net*8 reference, please use it to work out what the best value is for you. As others have pointed out, this parameter has to go into the RDBMS home, more specifically $ORACLE_HOME/network/admin/sqlnet.ora. I am using Oracle 19.4 on Oracle Linux 7.7 for this blog post. I have seen the same behaviour in 12.1.0.2 as well in my lab.

Background

In addition to the proven methods of checking whether TCP_KEEPALIVE is enabled for a given session I wanted to show another one. Using the ss(8) utility it is possible to show socket options. I also tried lsof but on my system I couldn’t get it to print the options:

SQL> select spid from v$process where addr = (select paddr from v$session where username = 'MARTIN');

SPID
------------------------
13656

SQL> exit 

...

[root@server2 ~]# lsof -nP -p 13656 -T f
lsof: unsupported TCP/TPI info selection: f
lsof 4.87

Although the man-page for lsof reads:

       -T [t]   controls the reporting of some TCP/TPI information,  also  reported  by  net‐
                stat(1),  following  the network addresses.  In normal output the information
                appears in parentheses, each item except TCP or TPI state name identified  by
                a keyword, followed by `=', separated from others by a single space:

                     <TCP or TPI state name>
                     QR=<read queue length>
                     QS=<send queue length>
                     SO=<socket options and values>
                     SS=<socket states>
                     TF=<TCP flags and values>
                     WR=<window read length>
                     WW=<window write length>

                Not all values are reported for all UNIX dialects.  Items values (when avail‐
                able) are reported after the item name and '='.

                When the field output mode is in effect  (See  OUTPUT  FOR  OTHER  PROGRAMS.)
                each item appears as a field with a `T' leading character.

                -T with no following key characters disables TCP/TPI information reporting.

                -T with following characters selects the reporting of specific TCP/TPI infor‐
                mation:

                     f    selects reporting of socket options,
                          states and values, and TCP flags and
                          values.

So let’s try something else: ss(8) – another utility to investigate sockets

Revealing socket options

I have used ss(8) in the past when I didn’t have netstat available, which is more and more common now that netstat is deprecated and its designated successor is ss :)

As far as I know you can’t limit ss to show information just for a PID, I use grep to limit the output. The output is in fact very wide, which is why this might not look pretty on the blog depending on whether the renderer decides to wrap output or not.

[root@server2 ~]# ss -nop | egrep 'NetidState|13656'
NetidState Recv-Q Send-Q                                    Local Address:Port                                      Peer Address:Port                                                                                                           
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,4.412ms,0)        
[root@server2 ~]# 

I used the following options:

  • -n for “Do not try to resolve service names”
  • -o for “Show timer information” and finally
  • -p to “Show process using socket”.

The main option here is -o. As per the man page:

       -o, --options
              Show timer information. For tcp protocol, the output format is:

              timer:(<timer_name>,<expire_time>,<retrans>)

              <timer_name>
                     the name of the timer, there are five kind of timer names:

                     on: means one of these timers: tcp retrans timer, tcp early retrans timer and tail loss probe timer
                     keepalive: tcp keep alive timer
                     timewait: timewait stage timer
                     persist: zero window probe timer
                     unknown: none of the above timers

              <expire_time>
                     how long time the timer will expire

              <retrans>
                     how many times the retran occurs

With a little shell loop I can show how that timer is decrementing:

[root@server2 ~]# for i in $(seq 1 5); do ss -nop | grep 13656; sleep 1 ; done
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,20sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,19sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,18sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,17sec,0)          
tcp  ESTAB 0      0                               [::ffff:192.168.100.22]:1521                           [::ffff:192.168.100.21]:25780                           users:(("oracle_13656_si",pid=13656,fd=18)) timer:(keepalive,16sec,0)          
[root@server2 ~]# 

Summary

Using the ss utility it is possible to check if a keepalive timer is implemented as a means to support DCD with 12.1 and later releases. Invoking ss(8) hasn’t caused any problems on my system, but as with every such tool you need to ensure it’s safe to use before attempting to look at an important system.

Little things worth knowing: keeping enq: TM enqueue at bay during direct path inserts

Direct path inserts are commonly found in processing where data are shifted from one source to another. There are many permutations of the theme, this post details the way SQL Loader (sqlldr) behaves.

I have previously written about sqlldr and concurrent direct path inserts. The behaviour for releases <= 12.1 is described in the first post, the most welcome changes in 12.2 went into the second post. Since the fastest way of doing something is not to do it at all, I thought it might be worth demonstrating a useful technique to keep the dreaded TM enqueue at bay. Please note that these do not only apply to sqlldr, inserts with the append hint for example behave the same way in my experience.

I used Oracle 19.4.0 on Oracle Linux 7 for this post, the content should apply to older database releases, too. The data model is once more provided by Swingbench, I’m using the SH benchmark this time. As I said on twitter yesterday, @TanelPoder scripts are simply too good to afford writing my own, so I’m using them in this post where possible.

Please note that I’m using partitioning in this post, which is a cost option on top of Enterprise Edition. Always ensure your system is properly licensed for features you use.

Preparations

Let’s assume for a moment that you would like to load another batch of records into the (Swingbench) sh.sales table. The table is range partitioned on time_id, and split into quarterly partitions – at least for the later ones. On my system I count 68 partitions, with the latest containing records up to January 1st 2014. I added a couple of partitions for the next 2 quarters to allow for the new data load.

SQL> select partition_name, partition_position,high_value 
  2  from user_tab_partitions where table_name = 'SALES' 
  3   and partition_position >= 68;

PARTITION_NAME     PARTITION_POSITION HIGH_VALUE
----------------- ------------------- -----------------------------------------------------------------------------------
SALES_Q4_2013                      68 TO_DATE(' 2014-01-01 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN')   
SALES_Q1_2014                      69 TO_DATE(' 2014-04-01 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN')   
SALES_Q2_2014                      70 TO_DATE(' 2014-07-01 00:00:00', 'SYYYY-MM-DD HH24:MI:SS', 'NLS_CALENDAR=GREGORIAN')   

I created CSV files of the data to be loaded by simply adding 3 and 6 months to the last populated partition.

spool /u01/app/oracle/admin/ORCL/sqlldr/sales_q1_2014.csv
select /*csv*/ 
 prod_id,
 cust_id,
 add_months(time_id,3) time_id,
 channel_id,
 promo_id,
 quantity_sold,
 seller,
 fulfillment_center,
 courier_org,
 tax_country,
 tax_region,
 amount_sold 
from sales partition (sales_q4_2013);

spool off
spool  /u01/app/oracle/admin/ORCL/sqlldr/sales_q2_2014.csv

select /*csv*/ 
 prod_id,
 cust_id,
 add_months(time_id,6) time_id,
 channel_id,
 promo_id,
 quantity_sold,
 seller,
 fulfillment_center,
 courier_org,
 tax_country,
 tax_region,
 amount_sold 
from sales partition (sales_q4_2013);

spool off
exit

Using the csv “hint” and executing this little script in sqlcl allows me to spool the files into the desired format (I made sure I have plenty of space available in /u01/app/oracle/admin). Now let’s try loading the data. As always, I use a control file although there might be better ways of doing this. It contains the following instructions:

options (direct=true,skip=1)
load data
append into table sales
fields terminated by ',' optionally enclosed by '"'
date format "dd-mon-yy"
trailing nullcols
(
  PROD_ID,                                                                        
  CUST_ID,                                                                        
  TIME_ID,                                                                        
  CHANNEL_ID,                                                                     
  PROMO_ID,                                                                       
  QUANTITY_SOLD,                                                                  
  SELLER,                                                                         
  FULFILLMENT_CENTER,                                                             
  COURIER_ORG,                                                                    
  TAX_COUNTRY,                                                                    
  TAX_REGION,                                                                     
  AMOUNT_SOLD
)

Test #1

Now let’s load the data! Since I’m not the most patient person I launched 2 sessions in parallel using a screen (1) session

$ sqlldr /@sh control=load_sales.ctl data=sales_q1_2014.csv log=load_q1.log bad=load_q1.bad direct_path_lock_wait=true

$ sqlldr /@sh control=load_sales.ctl data=sales_q2_2014.csv log=load_q2.log bad=load_q2.bad direct_path_lock_wait=true

While monitoring the load process I was surprised to see session 2 waiting:

SQL> select sid,seq#,event,state from v$session where program like '%sqlldr%';

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1228        578 SQL*Net more data from client                                    WAITED SHORT TIME
      1470         97 enq: TM - contention                                             WAITING

2 rows selected.

Each process should insert data into separate partitions, so why is there a wait? Maybe there is a clue in v$session_wait:

SQL> @sw 1470

    SID STATE   EVENT                                          SEQ# SEC_IN_WAIT P1                  P2                  P3                  P1TRANSL
------- ------- ---------------------------------------- ---------- ----------- ------------------- ------------------- ------------------- ------------------------------------------
   1470 WAITING enq: TM - contention                             98           6 name|mode=          object #= 78758     table/partition= 0  0x544D0006: TM mode 6
                                                                                0x00000000544D0006


1 row selected.

I noticed that p3 mentions a table or partition flag, which triggered my interest. After a little bit of research I found this section in the documentation: 12.3.2 Direct Path Load of a Partitioned or Subpartitioned Table which provides some clues. Object# 78758 is the table in my database:

SQL> @oid 78758

owner                     object_name                    object_type        SUBOBJECT_NAME                 CREATED             LAST_DDL_TIME       status    DATA_OBJECT_ID
------------------------- ------------------------------ ------------------ ------------------------------ ------------------- ------------------- --------- --------------
SH                        SALES                          TABLE                                             2019-08-29 15:14:53 2019-08-29 23:06:27 VALID

What if I tried to insert into a partition straight away?

Test #2

Let’s try that with the following 2 control files. The main differences are a) referencing the input file directly and b) the specification of the target partition in the append clause:

$ cat load_sales_q1_2014.ctl
options (skip=1,direct=true)
load data
infile  /u01/app/oracle/admin/ORCL/sqlldr/sales_q1_2014.csv
append into table sales partition (sales_q1_2014)
fields terminated by ',' optionally enclosed by '"'
date format "dd-mon-yy"
trailing nullcols
( 
  PROD_ID,
  CUST_ID,
  TIME_ID,
  CHANNEL_ID,
  PROMO_ID,
  QUANTITY_SOLD,
  SELLER,
  FULFILLMENT_CENTER,
  COURIER_ORG,
  TAX_COUNTRY,
  TAX_REGION,
  AMOUNT_SOLD
)

$ cat load_sales_q2_2014.ctl
options (skip=1,direct=true)
load data
infile  /u01/app/oracle/admin/ORCL/sqlldr/sales_q2_2014.csv
append into table sales partition (sales_q2_2014)
fields terminated by ',' optionally enclosed by '"'
date format "dd-mon-yy"
trailing nullcols
( 
  PROD_ID,
  CUST_ID,
  TIME_ID,
  CHANNEL_ID,
  PROMO_ID,
  QUANTITY_SOLD,
  SELLER,
  FULFILLMENT_CENTER,
  COURIER_ORG,
  TAX_COUNTRY,
  TAX_REGION,
  AMOUNT_SOLD
)

The slightly adjusted commands for sqlldr are as follows:

$ sqlldr /@sh control=load_sales_q1_2014.ctl log=load_q1.log bad=load_q1.bad direct_path_lock_wait=true

$ sqlldr /@sh control=load_sales_q2_2014.ctl log=load_q2.log bad=load_q2.bad direct_path_lock_wait=true

With the change in place I couldn’t notice any TM enqueues when running these in parallel:

SQL> select sid,seq#,event,state from v$session where program like '%sqlldr%';

no rows selected

SQL>
SQL> r
  1* select sid,seq#,event,state from v$session where program like '%sqlldr%'

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1251        627 direct path write temp                                           WAITED KNOWN TIME
      1488        475 PGA memory operation                                             WAITED SHORT TIME

SQL> r
  1* select sid,seq#,event,state from v$session where program like '%sqlldr%'

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1251        819 direct path write temp                                           WAITING
      1488        664 direct path write temp                                           WAITING

SQL> r
  1* select sid,seq#,event,state from v$session where program like '%sqlldr%'

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1251       1070 SQL*Net more data from client                                    WAITED SHORT TIME
      1488        906 direct path write temp                                           WAITED KNOWN TIME

SQL> r
  1* select sid,seq#,event,state from v$session where program like '%sqlldr%'

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1251       1332 db file sequential read                                          WAITED SHORT TIME
      1488       1143 library cache lock                                               WAITING

SQL> r
  1* select sid,seq#,event,state from v$session where program like '%sqlldr

       SID       SEQ# EVENT                                                            STATE
---------- ---------- ---------------------------------------------------------------- -------------------
      1251       1824 db file sequential read                                          WAITED SHORT TIME
      1488       1372 db file sequential read                                          WAITING

That looks ok, and switching back through both screen sessions I can see both invocations of sqlldr completed ok:

$ sqlldr /@sh control=load_sales_q1_2014.ctl log=load_q1.log bad=load_q1.bad direct_path_lock_wait=true

SQL*Loader: Release 19.0.0.0.0 - Production on Thu Aug 29 22:44:53 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Path used:      Direct

Load completed - logical record count 652437.

Table SALES, partition SALES_Q1_2014:
  652437 Rows successfully loaded.

Check the log file:
  load_q1.log
for more information about the load.

$ sqlldr /@sh control=load_sales_q2_2014.ctl log=load_q2.log bad=load_q2.bad direct_path_lock_wait=true

SQL*Loader: Release 19.0.0.0.0 - Production on Thu Aug 29 22:44:54 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

Path used:      Direct

Load completed - logical record count 652437.

Table SALES, partition SALES_Q2_2014:
  652437 Rows successfully loaded.

Check the log file:
  load_q2.log
for more information about the load.

Summary

When you are trying to load data into a table concurrently using direct path inserts, you will have to wait on a TM enqueue unless your table is partitioned and you are specifying different partitions as the target in each process. More generally speaking, Oracle will hold a TM enqueue on the segment you are loading into, so 2 processes attempting a direct path insert into a (sub) partition will equally have to serialise.

NB: if you are using direct path mode for sqlldr and your target segment is indexed, make sure to read chapter 12 in the Database Utilities Guide to learn about the implications of direct path load and index maintenance.

ORA-14300 partitioning key maps to a partition outside maximum permitted number of partitions and NULLs

While researching interval partitioning in Oracle 19c I came across a phenomenon I had already solved a long time ago but then forgot about. This time I decided to write about it so I don’t have to spend 5 minutes rediscovering the wheel. As always, if you are following along, make sure you are appropriately licensed for this feature

The Situation

Consider the following example:

SQL*Plus: Release 19.0.0.0.0 - Production on Fri Aug 16 09:32:17 2019
Version 19.4.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.

Last Successful login time: Fri Aug 16 2019 09:07:55 +02:00

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.4.0.0.0

SQL> create table t (id, vc, d) 
  2  partition by range (id) interval (5000)
  3  ( 
  4   partition p1 values less than (5000)
  5  ) as
  6  select object_id, object_name, created from dba_objects;
create table t (id, vc, d)
*
ERROR at line 1:
ORA-14300: partitioning key maps to a partition outside maximum permitted
number of partitions

SQL> !oerr ora 14300
14300, 00000, "partitioning key maps to a partition outside maximum permitted number of partitions"
// *Cause:  The row inserted had a partitioning key that maps to a partition number greater than 1048575
// *Action  Ensure that the partitioning key falls within 1048575 partitions or subpartitions.

I knew about the limit of 1048575 partitions, but that shouldn’t be the case here:

SQL> select max(object_id), max(object_id) / 5000 from dba_objects;

MAX(OBJECT_ID) MAX(OBJECT_ID)/5000
-------------- -------------------
         75743             15.1486

There shouldn’t be more than 16 partitions …

NEARBY: not having a not-null constraint on a partition key might be an indication of a sub-optimal design choice.

A quick search revealed an article on AskTom mentioning NULLs. I hadn’t thought about NULL values in dba_objects.object_id, but apparently there are:

SQL> select object_id, object_name, object_type from dba_objects where object_id is null;

 OBJECT_ID OBJECT_NAME                    OBJECT_TYPE
---------- ------------------------------ -----------------------
           SYS_HUB                        DATABASE LINK

Today I learned that database links don’t have object_ids. Neither is there a data_object_id.

Summary

Don’t try inserting NULLs as a partitioning key if that partition key uses interval partitioning. The error message, although strictly speaking correct, lead me astray for a moment:

SQL> create table t (id, vc, d) 
  2  partition by range (id) interval (5000)
  3  (
  4   partition p1 values less than (5000)
  5  )
  6  as
  7  select object_id, object_name, created from dba_objects 
  8  WHERE OBJECT_ID IS NOT NULL;

Table created.

Problem solved! Another, probably better approach, would be the addition of a not null constraint in the first place:

SQL> create table t (id not null, vc, d)
  2  partition by range (id) interval (5000)
  3  (
  4   partition p1 values less than (5000)
  5  )
  6  as select object_id, object_name, created from dba_objects;

ERROR at line 6:
ORA-01400: cannot insert NULL into ("MARTIN"."T"."ID")

The intention of my post was to help users who get an ORA-14300 although they don’t exceed the partition limit. It’s not a post about good design ;)

Interlude

This actually works for non-interval partitioned tables, but ONLY if you have a catch all partition:

SQL> select dbms_rowid.rowid_object(rowid) from t1 where id is null;

DBMS_ROWID.ROWID_OBJECT(ROWID)
------------------------------
                         75564

SQL> select object_name, subobject_name, object_id, data_object_id 
  2  from dba_objects where data_object_id = 75564
  3  /

OBJECT_NAME          SUBOBJECT_NAME        OBJECT_ID DATA_OBJECT_ID
-------------------- -------------------- ---------- --------------
T1                   PMAX                      75564          75564

SQL> select high_value from user_tab_partitions where table_name = 'T1' and partition_name = 'PMAX'
  2  /

HIGH_VALUE
------------------------------
MAXVALUE

Hope this helps!