Infrastructure at your Service

Marc Wagner

oracle update-dcscomponents failure during ODA patching to 19.11

By July 21, 2021 Oracle No Comments

You might know that since ODA 19.10, the ODA metadata database is now stored in a MySQL database and not in the apache derby database any more. During a patching to 19.10 or 19.11 from a release earlier than 19.10, the apache derby database will be migrated to a mysql database. This is performed during the odacli update-dcscomponent command. Starting 19.10, DCS Agent will then use MySQL server to display any metadata information, as for example when running odacli list-databases command. MySQL server is automatically installed and configured during the dcscomponent update. MySQL server does not run with root user. A new operating system user, called odamysql, will be created. This user is not allowed to run any shell and thus can not be used for logging. systemctl oda-mysql service can be used to stop and start MySQL server. Stopping MySQL server will stop the DCS Agent as well.


I recently patched an ODA from version 19.9 to 19.11. During the patching, update-dcscomponent failed on the metadata migration which blocked the entire patching project. Troubleshooting together with customer we could find a workaround that I wanted to share with you.

Failure during odacli update-dcscomponents

Running the update of all components failed into following error:

[[email protected] patch]# /opt/oracle/dcs/bin/odacli update-dcscomponents -v 19.11.0.0.0
DCS-10008:Failed to update DCScomponents: 19.11.0.0.0
 
Internal error while patching the DCS components :
DCS-10001:Internal error encountered: DCS-10001:Internal error encountered: Failed to configure MySQL for ODA...DCS-Agent shutdown is successful.
[[email protected] patch]# 

Failure in DCS Admin log file

During the troubleshooting, we could see that the MySQL server package has been installed successfully but found, in the dcs-admin.log stored in /opt/oracle/dcs/log directory, the following errors related to the MySQL configuration:

2021-07-20 09:18:45,177 DEBUG [dw-24 - PUT /dcscomponents] [] c.o.d.a.u.MySQLTask: Configure MySQL for ODA
2021-07-20 09:18:45,177 DEBUG [dw-24 - PUT /dcscomponents] [] c.o.d.c.u.CommonsUtils: 
run: cmd= '[/opt/oracle/dcs/mysql/etc/configodamysql.sh]'
2021-07-20 09:18:50,993 DEBUG [Thread-30] [] c.o.d.c.u.CommonsUtils: Output :
Initialize MySQL - Failed
2021-07-20 09:18:50,993 DEBUG [dw-24 - PUT /dcscomponents] [] c.o.d.c.u.c.DCSProcessBuilder: Return code: 1
2021-07-20 09:18:50,993 DEBUG [dw-24 - PUT /dcscomponents] [] c.o.d.c.u.c.CommandExecutor: Return code: 1
2021-07-20 09:18:50,993 ERROR [dw-24 - PUT /dcscomponents] [] c.o.d.a.u.MySQLTask: Exception : DCS-10001:Internal error encountered: Failed to configure MySQL for ODA..
ncountered: Failed to configure MySQL for ODA..
2021-07-20 09:18:50,994 ERROR [dw-24 - PUT /dcscomponents] [] c.o.d.a.r.DcsComponentServiceTaskFactory: Current status - DCS-Agent shutdown is successful. 
2021-07-20 09:18:50,997 INFO [dw-24 - PUT /dcscomponents] [] c.o.d.a.r.DcsComponentServiceTaskFactory: Components {zookeeper ,MySQL, Agent, Dcs-Cli, Dcs-Controller} upgrade operation completed.
2021-07-20 09:18:50,997 ERROR [dw-24 - PUT /dcscomponents] [] c.o.d.a.r.DcsComponentLifecycleApi: Internal error while patching the DCS components  


Failure in MySQL log files

Going further with the troubleshooting, we could find the following in the MySQL log file:

[[email protected] patch]# cd /opt/oracle/dcs/mysql/log/
  
[[email protected] log]# ls -ltrh
total 4.0K
-rw-r----- 1 odamysql odamysql 2.3K Jul 20 09:18 mysqldb.log
  
[[email protected] log]# more mysqldb.log
2021-07-20T07:18:45.946735Z 0 [System] [MY-013169] [Server] /opt/oracle/dcs/mysql/bin/mysqld (mysqld 8.0.23-commercial) initializing of server in progress as process 66381
2021-07-20T07:18:45.952983Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-07-20T07:18:45.959155Z 1 [Warning] [MY-012582] [InnoDB] io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
2021-07-20T07:18:45.959220Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 1.
2021-07-20T07:18:46.459426Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 2.
2021-07-20T07:18:46.959669Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 3.
2021-07-20T07:18:47.459946Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 4.
2021-07-20T07:18:47.960193Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 5.
2021-07-20T07:18:48.460487Z 1 [Warning] [MY-012582] [InnoDB] io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
2021-07-20T07:18:48.460594Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 1.
2021-07-20T07:18:48.960802Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 2.
2021-07-20T07:18:49.461068Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 3.
2021-07-20T07:18:49.961352Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 4.
2021-07-20T07:18:50.461608Z 1 [Warning] [MY-012583] [InnoDB] io_setup() attempt 5.
2021-07-20T07:18:50.961904Z 1 [ERROR] [MY-012584] [InnoDB] io_setup() failed with EAGAIN after 5 attempts.
2021-07-20T07:18:50.962203Z 1 [ERROR] [MY-012954] [InnoDB] Cannot initialize AIO sub-system
2021-07-20T07:18:50.962314Z 1 [ERROR] [MY-012929] [InnoDB] InnoDB Database creation was aborted with error Generic error. You may need to delete the ibdata1 file before trying to start up again.
2021-07-20T07:18:50.962557Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2021-07-20T07:18:50.962716Z 0 [ERROR] [MY-013236] [Server] The designated data directory /opt/oracle/dcs/mysql/data/ is unusable. You can remove all files that the server added to it.
2021-07-20T07:18:50.962890Z 0 [ERROR] [MY-010119] [Server] Aborting
2021-07-20T07:18:50.963406Z 0 [System] [MY-010910] [Server] /opt/oracle/dcs/mysql/bin/mysqld: Shutdown complete (mysqld 8.0.23-commercial)  MySQL Enterprise Server - Commercial.


It seems there were troubles with InnoDB function because the ODA has no Asynchronous IO available. This is another question why and we opened a SR on the Oracle support portal to have an explanation and ensure our next workaround is adequate.

Workaround

The workaround is to add innodb_use_native_aio = 0 parameter to both mysql cnf files : mysqldb_ssl.cnf and mysqldb.cnf and manually run configodamysql.sh before executing again odacli update-dcscomponents command.

Adding innodb_use_native_aio = 0 parameter to both mysql cnf files

[[email protected] /u01]# cd /opt/oracle/dcs/mysql/etc
  
[[email protected] etc]# ls -ltrh
total 40K
-rwxr-x--- 1 odamysql odamysql  892 May 31 04:05 oda-mysql.service
-rwxr-x--- 1 odamysql odamysql  596 May 31 04:05 mysqldb_ssl.cnf.bak
-rwxr-x--- 1 odamysql odamysql  399 May 31 04:05 mysqldb.cnf.bak
-rwxr-x--- 1 odamysql odamysql 1.9K May 31 04:05 getodamysqlport.sh
-rwxr-x--- 1 odamysql odamysql   55 May 31 04:05 enable_auth_socket.sql
-rwxr-x--- 1 odamysql odamysql 6.6K May 31 04:05 configodamysql.sh
-rwxr-x--- 1 odamysql odamysql 2.4K May 31 04:05 cleanodamysql.sh
-rwxr-x--- 1 odamysql odamysql  399 Jul 20 11:57 mysqldb.cnf
-rwxr-x--- 1 odamysql odamysql  596 Jul 20 11:57 mysqldb_ssl.cnf
  
[[email protected] etc]# cp -p mysqldb_ssl.cnf mysqldb_ssl.cnf.bak.20210720
  
[[email protected] etc]# vi mysqldb_ssl.cnf
  
[[email protected] etc]# diff mysqldb_ssl.cnf mysqldb_ssl.cnf.bak.20210720
16d15
< innodb_use_native_aio = 0
  
[[email protected] etc]# cp -p mysqldb.cnf mysqldb.cnf.bak.20210720
  
[[email protected] etc]# vi mysqldb.cnf
  
[[email protected] etc]# diff mysqldb.cnf mysqldb.cnf.bak.20210720
12d11
< innodb_use_native_aio = 0
  
[[email protected] etc]# grep innodb_use_native_aio *
mysqldb.cnf:innodb_use_native_aio = 0
mysqldb_ssl.cnf:innodb_use_native_aio = 0


Start DCS Agent again

DCS Agent has been stopped during dcs-components update and needs to be restarted.

[[email protected] etc]# ps -ef | grep dcs-agent
root     90513 25271  0 11:58 pts/3    00:00:00 grep --color=auto dcs-agent
  
[[email protected] etc]# systemctl start initdcsagent
  
[[email protected] etc]# ps -ef | grep dcs-agent
root     90893     1  0 11:58 ?        00:00:00 /bin/sh -c . /opt/oracle/dcs/bin/setupJreAgent.sh;$JAVA -Xms128m -Xmx256m -XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m -XX:+DisableExplicitGC -XX:ParallelGCThreads=4 -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:/opt/oracle/dcs/log/gc-dcs-agent-%t-%p.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M -Doracle.security.jps.config=/opt/oracle/dcs/agent/jps-config.xml -jar  /opt/oracle/dcs/bin/dcs-agent*.jar server /opt/oracle/dcs/conf/dcs-agent.json >/opt/oracle/dcs/log/dcsagent-stdout_$(date +%Y%m%d-%H%M).log 2>/opt/oracle/dcs/log/dcsagent-stderr_$(date +%Y%m%d-%H%M).log
root     90894 90893 99 11:58 ?        00:00:04 /opt/oracle/dcs/java/1.8.0_281/bin/java -Xms128m -Xmx256m -XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m -XX:+DisableExplicitGC -XX:ParallelGCThreads=4 -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:/opt/oracle/dcs/log/gc-dcs-agent-%t-%p.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M -Doracle.security.jps.config=/opt/oracle/dcs/agent/jps-config.xml -jar /opt/oracle/dcs/bin/dcs-agent-19.9.0.0.0.jar server /opt/oracle/dcs/conf/dcs-agent.json
root     91038 25271  0 11:59 pts/3    00:00:00 grep --color=auto dcs-agent
[[email protected] etc]# 


Manually execute the configodamysql.sh script

[[email protected] /]# cd /opt/oracle/dcs/mysql/etc/
  
[[email protected] etc]# ls -l
total 48
-rwxr-x--- 1 odamysql odamysql 2393 May 31 04:05 cleanodamysql.sh
-rwxr-x--- 1 odamysql odamysql 6731 May 31 04:05 configodamysql.sh
-rwxr-x--- 1 odamysql odamysql   55 May 31 04:05 enable_auth_socket.sql
-rwxr-x--- 1 odamysql odamysql 1923 May 31 04:05 getodamysqlport.sh
-rwxr-x--- 1 odamysql odamysql  425 Jul 20 12:00 mysqldb.cnf
-rwxr-x--- 1 odamysql odamysql  399 May 31 04:05 mysqldb.cnf.bak
-rwxr-x--- 1 odamysql odamysql  399 Jul 20 11:57 mysqldb.cnf.bak.20210720
-rwxr-x--- 1 odamysql odamysql  622 Jul 20 11:58 mysqldb_ssl.cnf
-rwxr-x--- 1 odamysql odamysql  596 May 31 04:05 mysqldb_ssl.cnf.bak
-rwxr-x--- 1 odamysql odamysql  596 Jul 20 11:57 mysqldb_ssl.cnf.bak.20210720
-rwxr-x--- 1 odamysql odamysql  892 May 31 04:05 oda-mysql.service
  
[[email protected] etc]# ./configodamysql.sh
/opt/oracle/dcs/mysql/data directory should be empty to proceed further with ODA MySQL post install configuration
  
[[email protected] etc]# cd ../data
  
[[email protected] data]# ls
binlog.index
  
[[email protected] data]# rm binlog.index -f
  
[[email protected] data]# cd ../etc
  
[[email protected] etc]# ./configodamysql.sh
Initialize MySQL - Done
Starting MySQL for ODA - Done
mysql: [Warning] Using a password on the command line interface can be insecure.
Enable server-side auth_socket authentication plugin for MySQL root user - Done
Generating RSA private key, 2048 bit long modulus
................+++
.................................................................................................................................................................................................+++
e is 65537 (0x10001)
Generating a 2048 bit RSA private key
...................................................................................+++
.........................................+++
writing new private key to 'server-key.pem'
-----
writing RSA key
Signature ok
subject=/CN=ODA01
Getting CA Private Key
Generating a 2048 bit RSA private key
....................................................+++
...+++
writing new private key to 'dcsagent-client-key.pem'
-----
writing RSA key
Signature ok
subject=/CN=dcsagent
Getting CA Private Key
Generating a 2048 bit RSA private key
.................................+++
.+++
writing new private key to 'rhp-client-key.pem'
-----
writing RSA key
Signature ok
subject=/CN=rhp user
Getting CA Private Key
All certificates : OK
mkdir: cannot create directory ‘/opt/oracle/dcs/odamysqlcert/’: File exists
Generate certificates for CA, MySQL Server and Clients (DCS Agent & RHP) - Done
Enable SSL and Restart MySQL - Done
Create database dcsagentdb - Done
Create user dcsagent - Done
Grant privileges to user dcsagent - Done
Create database GHSUSER21 - Done
Create user GHSUSER21 - Done
Grant privileges to user GHSUSER21 - Done
Create schemas, users for CS Agent & RHP - Done
Warning: Unable to load '/usr/share/zoneinfo/iso3166.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leapseconds' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/tzdata.zi' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone1970.tab' as time zone. Skipping it.
Load the timezone tables in mysql database - Done
MySQL installed version details :
/opt/oracle/dcs/mysql/bin/mysql  Ver 8.0.23-commercial for Linux on x86_64 (MySQL Enterprise Server - Commercial)
MySQL installation and configuration.....Completed


We can check that mySQL server daemon is now running :

[[email protected] etc]# ps -ef | grep mysql
odamysql 26130     1 11 12:07 ?        00:00:01 /opt/oracle/dcs/mysql/bin/mysqld --defaults-file=/opt/oracle/dcs/mysql/etc/mysqldb.cnf
root     27198 35360  0 12:08 pts/4    00:00:00 grep --color=auto mysql


Execute again odacli update-dcscomponents

[[email protected] etc]# /opt/oracle/dcs/bin/odacli update-dcscomponents -v 19.11.0.0.0
{
  "jobId" : "ff4d652d-b394-4c43-9195-a0740d1a08e6",
  "status" : "Success",
  "message" : "Update-dcscomponents is successful on all the node(s):DCS-Agent shutdown is successful. MySQL already on required version. Metadata migration is successful. Metadata schema update is done. dcsagent RPM upgrade is successful.  dcscli RPM upgrade is successful.  dcscontroller RPM upgrade is successful.  Successfully ran setupAgentAuth.sh zookeeper RPM upgrade is successful.  DCS-Agent restart is successful. ",
  "reports" : null,
  "createTimestamp" : "July 20, 2021 12:09:47 PM CEST",
  "description" : "Update-dcscomponents job completed and is not part of Agent job list",
  "updatedTime" : "July 20, 2021 12:11:48 PM CEST"
}


And we can see that the dcscomponents update is now successfull. We could also test that the Apache derby database repository is no more existing :

[[email protected] etc]# cd /opt/oracle/dcs/
[[email protected] dcs]# ls
agent  bin  clients  commonstore  conf  configuredcs.pl  dcsagent_wallet  dcscli  dcs-ui  docs  ft  Inventory  java  log  mesg  mysql  odajavasdk  odamysqlcert  oracle.ahf  rdbaas  sample
[[email protected] dcs]# 


And that new MySQL metadata database is running fine executing any commands like odacli list-databases.

As explained previously, we opened a SR on oracle support to know the root cause, to have feedback on this workaround and in case of any other resolution. I will update this post accordingly as soon as we have got a feedback.

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Marc Wagner
Marc Wagner

Senior Consultant