Docker-images: oracle/database:19.3.0-ee not connecting using sqlplus

[kenshaw]

When launching the oracle/database:19.3.0-ee image (freshly built) with the following:

docker run --name oracle -p 1521:1521 -p 5500:5500 \
  -e ORACLE_SID=orasid \
  -e ORACLE_PDB=db1 \
  -e ORACLE_PWD=P4ssw0rd \
  -e ORACLE_CHARACTERSET=AL32UTF8 \
  -v /media/src/opt/oracle:/opt/oracle/oradata \
  oracle/database:19.3.0-ee

I am not able to connect using sqlplus:

ken@ken-desktop:/opt/oracle/instantclient_19_3$ ./sqlplus system/P4ssw0rd@localhost:1521/orasid

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Aug 13 20:08:56 2019
Version 19.3.0.0.0

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

^C^R
^C^C^C^C^C

Simply the command never finishes or "hangs up" so to speak. I am on Ubuntu 18.04, using a Ryzen processor (simply mentioning it in case it is relevant, as I'm thinking this is some kind of platform compatibility issue).

I formerly had no problems with 12.2 running in a Docker image with the same system. Would appreciate any feedback/help/insight! This is with a fresh database (no attempt has been made to run a setup script).

The output of the docker run command was:

LSNRCTL for Linux: Version 19.0.0.0.0 - Production on 13-AUG-2019 12:55:05

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

Starting /opt/oracle/product/19c/dbhome_1/bin/tnslsnr: please wait...

TNSLSNR for Linux: Version 19.0.0.0.0 - Production
System parameter file is /opt/oracle/product/19c/dbhome_1/network/admin/listener.ora
Log messages written to /opt/oracle/diag/tnslsnr/75aa1b4da311/listener/alert/log.xml
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1)))
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=0.0.0.0)(PORT=1521)))

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1)))
STATUS of the LISTENER
------------------------
Alias                     LISTENER
Version                   TNSLSNR for Linux: Version 19.0.0.0.0 - Production
Start Date                13-AUG-2019 12:55:06
Uptime                    0 days 0 hr. 0 min. 0 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Parameter File   /opt/oracle/product/19c/dbhome_1/network/admin/listener.ora
Listener Log File         /opt/oracle/diag/tnslsnr/75aa1b4da311/listener/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC1)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=0.0.0.0)(PORT=1521)))
The listener supports no services
The command completed successfully

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Aug 13 12:55:06 2019
Version 19.3.0.0.0

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

Connected to an idle instance.

SQL> selecORACLE instance started.

Total System Global Area 2.0267E+10 bytes
Fixed Size         19765312 bytes
Variable Size        2885681152 bytes
Database Buffers     1.7314E+10 bytes
Redo Buffers           47341568 bytes

Database mounted.
Database opened.
SQL> Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0
The Oracle base remains unchanged with value /opt/oracle
#########################
DATABASE IS READY TO USE!
#########################
The following output is now a tail of the alert.log:
29170717,29173618,29181568,29182920,29183298,29186091,29191827,29201143,
29201695,29209545,29210577,29210610,29210624,29210683,29213641,29219627,
29224294,29225861,29229839,29235934,29242906,29243749,29244495,29244766,
29244968,29248723,29249583,29251564,29255616,29260224,29261695,29271019,
29273360,29282090,29282666,29285453,29285621,29290235,29292232,29293806,
29294753,29299830,29307090,29307109,29311336,29329675,29330791,29339299,
29357821,29360467,29360775,29367971,29368725,29379299,29379381,29380527,
29381000,29382296,29391301,29393649,29402110,29411931,29413360,29457319,
29465047
===========================================================
2019-08-13T12:56:00.534655+00:00


***********************************************************************

Fatal NI connect error 12537, connecting to:
 (ADDRESS=(PROTOCOL=tcp)(HOST=172.17.0.1)(PORT=34896))

  VERSION INFORMATION:
    TNS for Linux: Version 19.0.0.0.0 - Production
    Oracle Bequeath NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
    TCP/IP NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
  Version 19.3.0.0.0
  Time: 13-AUG-2019 12:56:00
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12537

TNS-12537: TNS:connection closed
    ns secondary err code: 12560
    nt main err code: 507

TNS-00507: Connection closed
    nt secondary err code: 0
    nt OS err code: 0
2019-08-13T12:56:00.536564+00:00
opiodr aborting process unknown ospid (530) as a result of ORA-609


^CStopping container.
SIGINT received, shutting down database!

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Aug 13 12:56:35 2019
Version 19.3.0.0.0

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


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

SQL> 2019-08-13T12:56:35.342429+00:00
Shutting down ORACLE instance (immediate) (OS id: 564)
2019-08-13T12:56:37.054987+00:00
Stopping background process SMCO
2019-08-13T12:56:38.075043+00:00
Shutting down instance: further logons disabled
2019-08-13T12:56:38.110864+00:00
Stopping background process CJQ0
2019-08-13T12:56:38.112123+00:00
Killed process oracle@75aa1b4da311 (Q001) with pid is 98, OS pid 522
2019-08-13T12:56:38.112242+00:00
Process termination requested for pid 522 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
Stopping background process MMNL
2019-08-13T12:56:39.118752+00:00
Stopping background process MMON
2019-08-13T12:56:41.167201+00:00
alter pluggable database all close immediate
2019-08-13T12:56:41.170926+00:00
DB1(3):JIT: pid 564 requesting stop
DB1(3):Buffer Cache flush deferred for PDB 3
Pluggable database DB1 closed
Completed: alter pluggable database all close immediate
PDB$SEED(2):JIT: pid 564 requesting stop
PDB$SEED(2):Buffer Cache flush deferred for PDB 2
License high water mark = 4
Dispatchers and shared servers shutdown

Data Pump shutdown on PDB: 1 in progress
2019-08-13T12:56:41.271310+00:00
Process termination requested for pid 562 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
2019-08-13T12:56:41.282659+00:00
Process termination requested for pid 125 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
2019-08-13T12:56:41.282716+00:00
Process termination requested for pid 129 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
2019-08-13T12:56:41.286680+00:00
Process termination requested for pid 127 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
2019-08-13T12:56:41.294722+00:00
Process termination requested for pid 123 [source = rdbms], [info = 2] [request issued by pid: 564, uid: 54321]
2019-08-13T12:56:42.287894+00:00
ALTER DATABASE CLOSE NORMAL
2019-08-13T12:56:42.310993+00:00
Stopping Emon pool
alter pluggable database all close immediate
Completed: alter pluggable database all close immediate
2019-08-13T12:56:43.312382+00:00

IM on ADG: Start of Empty Journal 

IM on ADG: End of Empty Journal 
Stopping Emon pool
stopping change tracking
2019-08-13T12:56:43.341624+00:00
Shutting down archive processes
2019-08-13T12:56:43.341804+00:00
TT00 (PID:111): Gap Manager exiting
2019-08-13T12:56:44.341968+00:00
Archiving is disabled
2019-08-13T12:56:44.342201+00:00
Thread 1 closed at log sequence 7
Successful close of redo thread 1
2019-08-13T12:56:44.344549+00:00
Buffer Cache invalidation for all PDBs started
Database closed.
Database dismounted.
Buffer Cache invalidation for all PDBs complete
Completed: ALTER DATABASE CLOSE NORMAL
ALTER DATABASE DISMOUNT
Shutting down archive processes
Archiving is disabled
Completed: ALTER DATABASE DISMOUNT
2019-08-13T12:56:45.487108+00:00
.... (PID:564): Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
2019-08-13T12:56:46.487939+00:00
JIT: pid 564 requesting stop
.... (PID:564): Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
JIT: pid 564 requesting stop
2019-08-13T12:56:46.508452+00:00
Stopping background process VKTM
ORACLE instance shut down.
2019-08-13T12:56:56.831934+00:00
Instance shutdown complete (OS id: 564)
SQL> Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

LSNRCTL for Linux: Version 19.0.0.0.0 - Production on 13-AUG-2019 12:57:00

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

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1)))
The command completed successfully

[kenshaw]

Oh, it's worth mentioning that if I pass an invalid SID to sqlplus, it immediately reports that the SID is bad:

ken@ken-desktop:/opt/oracle/instantclient_19_3$ ./sqlplus system/P4ssw0rd@localhost:1521/badsid

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Aug 13 20:13:13 2019
Version 19.3.0.0.0

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

ERROR:
ORA-12514: TNS:listener does not currently know of service requested in connect
descriptor


Enter user-name: 

I've tried many variations of the username/password, and none are able to connect.

[doodlydroll]

I had same problem. It works for me with docker-ce-18.09.1-3.el7.x86_64 but not with 19.03.5-3.el7.
From what I see TNS protocol sends out-of-bad message which does not get propagated onto the docker bridge network.

[mark-au]

I've been able to reproduce; I used docker-engine-19.03.1.ol-1.0.0.el7.x86_64 on Oracle Linux 7. For the client I used oracle-instantclient19.5-sqlplus-19.5.0.0.0-1.x86_64.

$ sqlplus system/P4ssw0rd@//localhost:1521/orasid

SQL*Plus: Release 19.0.0.0.0 - Production on Wed Jan 15 11:04:40 2020
Version 19.5.0.0.0

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

ERROR:
ORA-12637: Packet receive failed


Enter user-name: 

and on server logs

***********************************************************************

Fatal NI connect error 12170, connecting to:
 (ADDRESS=(PROTOCOL=tcp)(HOST=172.17.0.1)(PORT=56162))

  VERSION INFORMATION:
    TNS for Linux: Version 19.0.0.0.0 - Production
    Oracle Bequeath NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
    TCP/IP NT Protocol Adapter for Linux: Version 19.0.0.0.0 - Production
  Version 19.3.0.0.0
  Time: 15-JAN-2020 00:05:40
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12535

TNS-12535: TNS:operation timed out
    ns secondary err code: 12606
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
2020-01-15T00:05:40.226882+00:00
opiodr aborting process unknown ospid (3615) as a result of ORA-609

[mark-au]

Any immediate thoughts @gvenzl or should we review the Docker networking aspect?

[gvenzl]

Nope, sorry. This seems to be a networking-related or perhaps some security-related issue with Docker.

[ppronko-sugarcrm]

As far as i can see you are creating a portable database (PDB), so you should try:
oracle$ sqlplus user/pass@//localhost:1521/pdb (connecting to PDB)
OR you can try to connect to the whole instance:

oracle$ sqlplus / as sysdba //(on a server as oracle user)
sqlplus> SELECT name, pdb FROM   v$services ORDER BY name; //names of pdbs
sqlplus>  ALTER SESSION SET CONTAINER="PDB_NAME"
sqplus>  ALTER CREATE USER ....  identiFIED BY ... 

Please check outhttps://github.com/oracle/docker-images.git and https://github.com/sugarcrm/libra/tree/develop/images/oracle for details. Of contact me directly if you have any questions.

[ppronko-sugarcrm]

It is slightly confusing that first @kenshaw log contains keyboard interrupt (^C) that shuts the database down. However, I presume, that the next attempts were not interrupted. Also, I cannot see any database creation container logs, maybe they are skipped?

^CStopping container.
SIGINT received, shutting down the database!

There are several important points:

• To run oracle EE you need at least 4GB of memory to avoid any surprises.
• If you are using official oracle image from oracle GitHub, then please be very accurate with mounting a volume(s), it should be writable by "oracle" (uid: 54321) user inside the container. You can always try to run the container without permanent volume first.
• As a corner case you can try to run oracle container in privileged mode (-- privileged flag for docker). It may help to avoid issues with SElinux and other Linux protection stuff.

Normally running container will show something like

The following output is now a tail of the alert.log:
Resize operation completed for file# 10, old size 327680K, new size 337920K

[mark-au]

I've had another look at this and made a little progress via a workaround. By default docker uses 172.17.0.0/16 for its bridge network with 172.17.0.1 assigned to the host and 172.17.0.2 to the first container.

If I start a container using podman run --name oracle -p 1521:1521 -p 5500:5500 -e ORACLE_SID=orasid -e ORACLE_PDB=db1 -e ORACLE_PWD=P4ssw0rd -e ORACLE_CHARACTERSET=AL32UTF8 oracle/database:19.3.0-ee

• I cannot connect using sqlplus system/P4ssw0rd@//localhost1521/db1
• I cannot connect using sqlplus system/P4ssw0rd@//127.0.0.1:1521/db1
• I can connect using sqlplus system/P4ssw0rd@//172.17.0.2:1521/db1

I thought that these different references would give different sqlplus connect strings but they were identical in listener.log regardless of if they worked or failed:
Using localhost:
11-FEB-2020 05:39:16 * (CONNECT_DATA=(SERVICE_NAME=db1)(CID=(PROGRAM=sqlplus)(HOST=barney.removed)(USER=barney))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.17.0.1)(PORT=38972)) * establish * db1 * 0
Using 172.17.0.2
11-FEB-2020 05:40:38 * (CONNECT_DATA=(SERVICE_NAME=db1)(CID=(PROGRAM=sqlplus)(HOST=barney.removed)(USER=barney))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.17.0.1)(PORT=38980)) * establish * db1 * 0

It feels like a name resolution timeout but I'm not seeing anything obvious on the bridge network. It's about a minute long:
~~~
$ touch empty
$ time sqlplus system/P4ssw0rd@//172.17.0.2:1521/db1 < empty

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Feb 11 16:47:05 2020
Version 19.5.0.0.0

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

Last Successful login time: Tue Feb 11 2020 16:47:01 +11:00

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

SQL> Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

real 0m1.038s
user 0m0.011s
sys 0m0.006s

$ time sqlplus system/P4ssw0rd@//localhost:1521/db1 < empty

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Feb 11 16:47:13 2020
Version 19.5.0.0.0

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

ERROR:
ORA-12637: Packet receive failed

Enter user-name:
real 1m0.039s
user 0m0.004s
sys 0m0.007s
~~~

What may be of use is you can workaround it by reusing the networking namespace:
docker run -ti --rm --network container:oracle oracle/instantclient:19 sqlplus system/P4ssw0rd@//localhost:1521/db1

[Djelibeybi]

What's the MTU on the bridge for Docker? I'm wondering if this isn't some weird firewalld interaction with pathmtu packets or something. Does it work if firewalld is disabled?

[mark-au]

Bridge MTU is 1500 by default which should be fine. Symptoms remain if firewalld.service is stopped and docker.service restarted but I appreciate the suggestions

[Djelibeybi]

Very curious. It's at this point that I'd pull out DTrace and start looking for where it's hanging.

[mark-au]

Did some testing with same image on different docker-engine versions:

• docker-engine-18.03.1.ol-0.0.15.el7 - succeed
• docker-engine-18.09.1.ol-1.0.5.el7 - succeed
• docker-engine-18.09.1.ol-1.0.8.el7 - succeed
• docker-engine-18.09.8.ol-1.0.4.el7 - succeed
• docker-engine-19.03.1.ol-1.0.0.el7 - fail

[cjbj]

You can work around the ORA-12637: Packet receive failed error by creating a sqlnet.ora file on the "client" side (e.g. SQL*Plus) containing DISABLE_OOB=ON. For quick tests on Linux, you can create ~/.sqlnet.ora.

There was a change in Oracle Net in 19c to automatically choose the out-of-band break setting, but it seems some network stacks are not processing packets correctly, so using the sqlnet.ora override can help. In one case looked at, the Docker engine seemed to be affected in userland-proxy mode. Docker 18.09.8 was ok but 18.09.9 hung at connect. Franck Pachot has a blog post about this at https://medium.com/@FranckPachot/19c-instant-client-and-docker-1566630ab20e.

A similar packet issue with VirtualBox networking was fixed in VirtualBox 6.0.14.

[mark-au]

Thanks @cjbj, we'll include in OracleDatabase/SingleInstance/README.md's Known Issue list

[gvenzl]

Will be fixed via PR #1529 (Explain error ORA-12637 on Database 19c FAQ)