Cisco Unified Communications Manager / CUCM IP 8.6,10,12 Install Error Solution

Install Errors on Version 12:

This error happened on QEMU emulator version 2.11.1 pve-qemu-kvm_2.11.1-5
on Proxmox/Debian but installing on QEMU .12 on Centos 6 did not produce the error.

*Update it is not related to the OS or QEMU version. This happened in Centos 6 too after a second install.

What really causes this even though you successfully installed already using the same settings and same machine?

The problem is related to IO, I believe there is some sort of timer on the database install portion and the install declares itself dead and stops if a certain amount of queries or files are not copied within a certain amount of time. Don't believe me, take a normal HDD and load it up with a few VMs, see if CUCM installs. Then add more CUCMs and try to install again and you will at some port have too little IOPS to successfully complete the install.

I have installed successfully but CUCM seems picky about the order of steps (eg. if you configure the wizard later or now). It also seems to need 4096MB of RAM at the most and a single CPU to avoid the error. I am going to make a step-by-step guide as it seems very finicky to avoid this problem on the DB install process.

Critical Error The installation has encountered a unrecoverable internal error. For further assistance report the following information to your support provider. "/usr/local/cm/script/cm-dbl-install install PostInstall 12.01.10000 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt" failed (1) The system will now halt. Continuing will allow you to view diagnostic information before halting.

irt-df cucm12.img Filesystem 1K-blocks Used Available Use% cucm12.img:/dev/sda1 21688188 10620380 10829752 49% cucm12.img:/dev/sda2 21688188 44992 20518436 1% cucm12.img:/dev/sda3 245679 2322 226154 1% cucm12.img:/dev/sda6 75790432 4113716 67803692 6% root@proxmoxdal01:/mnt/space# guestmount -a /dev/^C root@proxmoxdal01:/mnt/space# mkdir mount root@proxmoxdal01:/mnt/space# guestmount -a /dev/sda1 mount/ guestmount: error: you must specify either -i at least one -m option. Try `guestmount --help' for more information. root@proxmoxdal01:/mnt/space# guestmount -m -a /dev/sda1 mount/ guestmount: error: you must specify at least one -a or -d option. Try `guestmount --help' for more information. root@proxmoxdal01:/mnt/space# guestmount -m -d /dev/sda1 mount/ guestmount: error: you must specify at least one -a or -d option. Try `guestmount --help' for more information. root@proxmoxdal01:/mnt/space# guestmount -d /dev/sda1 mount/ guestmount: error: you must specify either -i at least one -m option. Try `guestmount --help' for more information. root@proxmoxdal01:/mnt/space# guestmount -a cucm12.img -m /dev/sda1 --ro mount/ #actually /dev/sda6 has what we need inside /log/install/install.log 04/11/2019 22:32:16 InstallWizard|'/usr/local/platform/bin/clm/clm_ctl set install_configuration_complete yes' executed successfully| 04/11/2019 22:32:16 InstallWizard|written 6522 bytes to /usr/local/platform/conf/platformConfig.xml| 04/11/2019 22:32:16 InstallWizard|re encrypted file stored in platformConfig file| 04/11/2019 22:32:16 appmanager.sh|/usr/local/bin/base_scripts/InstallWizard returned 0| 04/11/2019 22:32:16 component_install|Initializing xproduct.sh API| 04/11/2019 22:32:16 component_install|Initializing xcomponent.sh API| 04/11/2019 22:32:16 component_install|Initializing xplatformconfig.sh API| 04/11/2019 22:32:16 component_install|PATH=/usr/local/cm/db/informix:/usr/local/cm/db/informix/bin:/usr/local/cm/bin:/usr/local//thirdparty/java/j2sdk/bin:/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/sbin:/home/sftpuser:/root/.security:/root/bin:/usr/local/sbin:/sbin:/usr/sbin:/bin:/usr/bin:/sbin:/home/sftpuser:/root/.security:/sbin:/home/sftpuser:/root/.security| 04/11/2019 22:32:16 component_install|LD_LIBRARY_PATH=/usr/local/lib:/usr/local/thirdparty/java/j2sdk/jre/lib/i386:/usr/local/thirdparty/java/j2sdk/jre/lib/i386/server:/usr/lib/pgsql:/usr/lib:/usr/local/cm/lib:/usr/local/platform/lib:/usr/local/lib:/usr/local/thirdparty/java/j2sdk/jre/lib/i386:/usr/local/thirdparty/java/j2sdk/jre/lib/i386/server:/usr/lib/pgsql:/usr/lib:/usr/local/cm/lib:/usr/local/lib:/usr/local/thirdparty/java/j2sdk/jre/lib/i386:/usr/local/thirdparty/java/j2sdk/jre/lib/i386/server:/usr/lib/pgsql:/usr/lib:/usr/local/cm/lib::/usr/local/platform/lib:/usr/local/platform/lib| 04/11/2019 22:32:16 component_install|Parse argument type=infrastructure_post| 04/11/2019 22:32:16 component_install|Parse argument mode=install| 04/11/2019 22:32:17 component_install|Install infrastructure_post component, mode install| 04/11/2019 22:32:17 component_install|Initialize product data, mode install| 04/11/2019 22:32:17 component_install|Initialize "to" side product version| 04/11/2019 22:32:17 component_install|Access "to" side API| 04/11/2019 22:32:17 component_install|Got version 12.0.1.10000-10| 04/11/2019 22:32:17 component_install|Initialize "to" side product version complete| 04/11/2019 22:32:17 component_install|Initialize product data complete| 04/11/2019 22:32:17 component_install|Initialize component data, mode install| 04/11/2019 22:32:17 component_install|Initialize ucplatform_post "to" side version| 04/11/2019 22:32:17 component_install|Access "to" side API| 04/11/2019 22:32:17 component_install|Got version 12.0.1.10000-10| 04/11/2019 22:32:17 component_install|Initialize ucplatform_post "to" side version complete| 04/11/2019 22:32:17 component_install|Initialize global data complete| 04/11/2019 22:32:17 component_install|Build the command list for ucplatform_post| 04/11/2019 22:32:17 component_install|Initialize command list| 04/11/2019 22:32:17 component_install|Build ucplatform_post install phase commands| 04/11/2019 22:32:17 component_install|Processing ucplatform_post install element| 04/11/2019 22:32:18 component_install|Processing ucplatform_post phase element| 04/11/2019 22:32:18 component_install|Processing ucplatform_post import element| 04/11/2019 22:32:18 component_install|Building the command list for ucplatform_post is complete| 04/11/2019 22:32:18 component_install|Command execution for ucplatform_post component RTMTStart| 04/11/2019 22:32:18 component_install|Execute commands in the command list for ucplatform_post component| 04/11/2019 22:32:18 component_install|No commands to execute for ucplatform_post component| 04/11/2019 22:32:18 component_install|Command execution for ucplatform_post component is complete| 04/11/2019 22:32:18 component_install|Command execution for ucplatform_post component RTMTFinish| 04/11/2019 22:32:18 component_install|Initialize component data, mode install| 04/11/2019 22:32:18 component_install|Initialize thirdparty "to" side version| 04/11/2019 22:32:18 component_install|Access "to" side API| 04/11/2019 22:32:18 component_install|Got version 12.0.1.10000-10| 04/11/2019 22:32:18 component_install|Initialize thirdparty "to" side version complete| 04/11/2019 22:32:18 component_install|Initialize global data complete| 04/11/2019 22:32:18 component_install|Build the command list for thirdparty| 04/11/2019 22:32:18 component_install|Initialize command list| 04/11/2019 22:32:18 component_install|Build thirdparty install phase commands| 04/11/2019 22:32:18 component_install|Processing thirdparty install element| 04/11/2019 22:32:18 component_install|Processing thirdparty package element| 04/11/2019 22:32:18 component_install|Checking if RPM /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-lib-1.0.0.0-1.i386.rpm exists| 04/11/2019 22:32:18 component_install|Add "rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-lib-1.0.0.0-1.i386.rpm" to command list| 04/11/2019 22:32:18 component_install|Processing thirdparty package element| 04/11/2019 22:32:18 component_install|Checking if RPM /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-jar-lib-1.0.0.0-1.i386.rpm exists| 04/11/2019 22:32:19 component_install|Add "rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-jar-lib-1.0.0.0-1.i386.rpm" to command list| 04/11/2019 22:32:19 component_install|Building the command list for thirdparty is complete| 04/11/2019 22:32:19 component_install|Command execution for thirdparty component RTMTStart| 04/11/2019 22:32:19 component_install|Execute commands in the command list for thirdparty component| 04/11/2019 22:32:19 IPM|Normalizer search path is /opt/cisco/install/bin| 04/11/2019 22:32:19 IPM|Checking normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:19 IPM|Returning normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:20 IPM|Open progress meter "Component Install"| 04/11/2019 22:32:20 IPM| begin-of-session "Installing thirdparty component", 2 items| 04/11/2019 22:32:20 IPM| begin-analysis: [2 commands]| 04/11/2019 22:32:20 IPM| command #1: 3973452 bytes, 0 seconds: rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-lib-1.0.0.0-1.i386.rpm| 04/11/2019 22:32:20 IPM| command #2: 6237296 bytes, 0 seconds: rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-jar-lib-1.0.0.0-1.i386.rpm| 04/11/2019 22:32:20 IPM| end-analysis: 2 total objects, 10210748 total bytes, 0 total seconds, 0.067 secs.| 04/11/2019 22:32:20 IPM| begin-work: [2 items]| 04/11/2019 22:32:20 IPM|Execute rpm command "rpm --percent -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-lib-1.0.0.0-1.i386.rpm "| 04/11/2019 22:32:25 IPM| item 1: rpm-install 3973452 bytes (5.224 secs.)| 04/11/2019 22:32:25 IPM|Execute rpm command "rpm --percent -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/thirdparty/cm-jar-lib-1.0.0.0-1.i386.rpm "| 04/11/2019 22:32:31 IPM| item 2: rpm-install 6237296 bytes (6.037 secs.)| 04/11/2019 22:32:31 IPM| end-work: 2 items 11.272 secs. total| 04/11/2019 22:32:33 IPM| end-of-session "Installing thirdparty component": 13.278 secs.| 04/11/2019 22:32:33 IPM|Close progress meter "Component Install"| 04/11/2019 22:32:33 component_install|Command execution for thirdparty component is complete| 04/11/2019 22:32:33 component_install|Command execution for thirdparty component RTMTFinish| 04/11/2019 22:32:33 component_install|Initialize component data, mode install| 04/11/2019 22:32:33 component_install|Initialize serviceability_core "to" side version| 04/11/2019 22:32:33 component_install|Access "to" side API| 04/11/2019 22:32:34 component_install|Got version 12.0.1.10000-10| 04/11/2019 22:32:34 component_install|Initialize serviceability_core "to" side version complete| 04/11/2019 22:32:34 component_install|Initialize global data complete| 04/11/2019 22:32:34 component_install|Build the command list for serviceability_core| 04/11/2019 22:32:34 component_install|Initialize command list| 04/11/2019 22:32:34 component_install|Build serviceability_core install phase commands| 04/11/2019 22:32:34 component_install|Processing serviceability_core install element| 04/11/2019 22:32:34 component_install|Processing serviceability_core package element| 04/11/2019 22:32:34 component_install|Checking if RPM /common/rpm-archive/12.0.1.10000-10/RPMS/serviceability_core/cm-pi-0.0.0.1-0.i386.rpm exists| 04/11/2019 22:32:34 component_install|Add "rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/serviceability_core/cm-pi-0.0.0.1-0.i386.rpm" to command list| 04/11/2019 22:32:34 component_install|Building the command list for serviceability_core is complete| 04/11/2019 22:32:34 component_install|Command execution for serviceability_core component RTMTStart| 04/11/2019 22:32:34 component_install|Execute commands in the command list for serviceability_core component| 04/11/2019 22:32:35 IPM|Normalizer search path is /opt/cisco/install/bin| 04/11/2019 22:32:35 IPM|Checking normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:35 IPM|Returning normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:36 IPM|Open progress meter "Component Install"| 04/11/2019 22:32:36 IPM| begin-of-session "Installing core serviceability component", 1 items| 04/11/2019 22:32:36 IPM| begin-analysis: [1 commands]| 04/11/2019 22:32:36 IPM| command #1: 4318680 bytes, 0 seconds: rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/serviceability_core/cm-pi-0.0.0.1-0.i386.rpm| 04/11/2019 22:32:36 IPM| end-analysis: 1 total objects, 4318680 total bytes, 0 total seconds, 0.076 secs.| 04/11/2019 22:32:36 IPM| begin-work: [1 items]| 04/11/2019 22:32:36 IPM|Execute rpm command "rpm --percent -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/serviceability_core/cm-pi-0.0.0.1-0.i386.rpm "| 04/11/2019 22:32:41 IPM| item 1: rpm-install 4318680 bytes (5.131 secs.)| 04/11/2019 22:32:41 IPM| end-work: 1 items 5.141 secs. total| 04/11/2019 22:32:43 IPM| end-of-session "Installing core serviceability component": 7.154 secs.| 04/11/2019 22:32:43 IPM|Close progress meter "Component Install"| 04/11/2019 22:32:43 component_install|Command execution for serviceability_core component is complete| 04/11/2019 22:32:43 component_install|Command execution for serviceability_core component RTMTFinish| 04/11/2019 22:32:43 component_install|Initialize component data, mode install| 04/11/2019 22:32:43 component_install|Initialize database "to" side version| 04/11/2019 22:32:43 component_install|Access "to" side API| 04/11/2019 22:32:43 component_install|Got version 12.0.1.10000-10| 04/11/2019 22:32:43 component_install|Initialize database "to" side version complete| 04/11/2019 22:32:43 component_install|Initialize global data complete| 04/11/2019 22:32:43 component_install|Build the command list for database| 04/11/2019 22:32:43 component_install|Initialize command list| 04/11/2019 22:32:43 component_install|Build database install phase commands| 04/11/2019 22:32:43 component_install|Processing database install element| 04/11/2019 22:32:43 component_install|Processing database package element| 04/11/2019 22:32:43 component_install|Checking if RPM /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbms-1.0.0.0-1.i386.rpm exists| 04/11/2019 22:32:43 component_install|Add "rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbms-1.0.0.0-1.i386.rpm" to command list| 04/11/2019 22:32:44 component_install|Processing database package element| 04/11/2019 22:32:44 component_install|Checking if RPM /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbl-1.0.0.0-1.i386.rpm exists| 04/11/2019 22:32:44 component_install|Add "rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbl-1.0.0.0-1.i386.rpm" to command list| 04/11/2019 22:32:44 component_install|Processing database phase element| 04/11/2019 22:32:44 component_install|Processing database import element| 04/11/2019 22:32:44 component_install|Processing database phase element| 04/11/2019 22:32:44 component_install|Processing database migration element| 04/11/2019 22:32:44 component_install|Processing database phase element| 04/11/2019 22:32:44 component_install|Processing database postinstall element| 04/11/2019 22:32:44 component_install|Processing database script element| 04/11/2019 22:32:44 component_install|Add "cm-dbms-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt" to command list| 04/11/2019 22:32:45 component_install|Processing database script element| 04/11/2019 22:32:45 component_install|Add "cm-dbl-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt" to command list| 04/11/2019 22:32:45 component_install|Building the command list for database is complete| 04/11/2019 22:32:45 component_install|Command execution for database component RTMTStart| 04/11/2019 22:32:45 component_install|Execute commands in the command list for database component| 04/11/2019 22:32:45 IPM|Normalizer search path is /opt/cisco/install/bin| 04/11/2019 22:32:45 IPM|Checking normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:45 IPM|Returning normalizer /opt/cisco/install/bin/pmNormalizeGeneric| 04/11/2019 22:32:46 IPM|Open progress meter "Component Install"| 04/11/2019 22:32:46 IPM| begin-of-session "Installing database component", 4 items| 04/11/2019 22:32:46 IPM| begin-analysis: [4 commands]| 04/11/2019 22:32:46 IPM| command #1: 423348056 bytes, 0 seconds: rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbms-1.0.0.0-1.i386.rpm| 04/11/2019 22:32:46 IPM| command #2: 12611328 bytes, 0 seconds: rpm -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbl-1.0.0.0-1.i386.rpm| 04/11/2019 22:32:46 IPM| command #3: 0 bytes, 4800 seconds: sh -path /opt/cisco/install/database/scripts:/usr/local/cm/script -t 4800 -c cm-dbms-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt| 04/11/2019 22:32:46 IPM| command #4: 0 bytes, 21600 seconds: sh -path /opt/cisco/install/database/scripts:/usr/local/cm/script -t 21600 -c cm-dbl-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt| 04/11/2019 22:32:46 IPM| end-analysis: 4 total objects, 435959384 total bytes, 26400 total seconds, 0.133 secs.| 04/11/2019 22:32:46 IPM| begin-work: [4 items]| 04/11/2019 22:32:46 IPM|Execute rpm command "rpm --percent -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbms-1.0.0.0-1.i386.rpm "| 04/11/2019 22:33:23 IPM| item 1: rpm-install 423348056 bytes (36.504 secs.)| 04/11/2019 22:33:23 IPM|Execute rpm command "rpm --percent -iv --replacefiles /common/rpm-archive/12.0.1.10000-10/RPMS/database/cm-dbl-1.0.0.0-1.i386.rpm "| 04/11/2019 22:33:41 IPM| item 2: rpm-install 12611328 bytes (18.213 secs.)| 04/11/2019 22:33:41 IPM|Execute shell command "/usr/local/cm/script/cm-dbms-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt "| 04/11/2019 23:00:17 IPM| item 3: shell-script 0 bytes (1596.499 secs.)| 04/11/2019 23:00:17 IPM|Execute shell command "/usr/local/cm/script/cm-dbl-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt "| 04/11/2019 23:58:20 IPM|Internal Error, File:ipm.c:2011, Function: ipmReadNormalizedInputLine(), "/usr/local/cm/script/cm-dbl-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt " failed (1)| 04/11/2019 23:58:22 IPM| end-of-session "Installing database component": 5136.088 secs.| 04/11/2019 23:58:22 IPM|Close progress meter "Component Install"| 04/11/2019 23:58:22 component_install|Writing database into /common/log/install/component_failed.xml file.| 04/11/2019 23:58:22 component_install|/common/log/install/component_failed.xml created : 0| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:15 2019 cm-dbms-install DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.ParamObject.validate DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.ParamObject.validate DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doActionInstall DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doActionInstall DEBUG: Inside doActionInstall...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doInstallPost_installDB DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doInstallPost_installDB DEBUG: Inside doInstallPost...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doCreateLogDirectory DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doCreateLogDirectory DEBUG: Verifying SDI directory [/var/log/active/cm/trace/dbl/sdi]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:17 2019 cm-dbl-install.doCreateLogDirectory DEBUG: chown database.ccmbase /var/log/active/cm/trace/dbl/sdi| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.doCreateLogDirectory DEBUG: chmod 775 /var/log/active/cm/trace/dbl/sdi| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.doCreateLogDirectory DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: Inside setupPreferences...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: current_db [ccm12_0_1_10000_10]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: chown database.ccmbase /usr/local/cm/conf/dbl/prefs.xml ; chmod 644 /usr/local/cm/conf/dbl/prefs.xml| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: Updating prefs [/usr/local/cm/conf/dbl/prefs.xml]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.shortHostName DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: chown database.ccmbase /usr/local/cm/conf/dbl/sdi/prefs.xml ; chmod 664 /usr/local/cm/conf/dbl/sdi/prefs.xml| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: Updating prefs [/usr/local/cm/conf/dbl/sdi/prefs.xml]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: chown database.ccmbase /usr/local/cm/conf/dbnotify/sdi/prefs.xml ; chmod 664 /usr/local/cm/conf/dbnotify/sdi/prefs.xml| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: Updating prefs [/usr/local/cm/conf/dbnotify/sdi/prefs.xml]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: python "/usr/local/cm/bin/dbl" setprefs /common/log/install/capture.txt| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 dblsetprefs-plugin.run DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 dblsetprefs-plugin.run DEBUG: Create Preferences entries for various database components| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 dblsetprefs-plugin.run DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.setupPreferences DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.getPublisherFromInstallPrefs DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.getPublisherFromInstallPrefs DEBUG: Inside getPublisherFromInstallPrefs...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.getPublisherFromInstallPrefs DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.doInstallPost_installDB DEBUG: (odbc setup moved to dbl init)| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.fixSQLLibPaths DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.fixSQLLibPaths DEBUG: Inside fixSQLLibPaths....| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.fixSQLLibPaths DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.fixSQLLibPaths DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:18 2019 cm-dbl-install.fixSQLLibPaths DEBUG: Inside fixSQLLibPaths....| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.fixSQLLibPaths DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.doInstallPost_installDB DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.doInstallPost_installDB DEBUG: Inside doInstallPost_installDB ...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.installdb DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.installdb DEBUG: Inside installdb ...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 cm-dbl-install.installdb DEBUG: python "/usr/local/cm/bin/dbl" start --safe --nopreflight --log=/common/log/install/capture.txt| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 dblstart-plugin.run DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:19 2019 dblstart-plugin.run DEBUG: Start DBMS| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 dblstart-plugin.run DEBUG: do preflight| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 dblstart-plugin.run DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.installdb DEBUG: rm -f /tmp/*.txt /tmp/*.log /tmp/*.err /var/log/active/cm/trace/dbl/sdi/psqlx /tmp/*.bin /tmp/af* /tmp/shmem*| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.installdb DEBUG: Disk size present in dbl/prefs is 128| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.getPublisherFromPrefs DEBUG: -->| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.getPublisherFromPrefs DEBUG: Inside getPublisherFromPrefs...| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.getPublisherFromPrefs DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:00:34 2019 cm-dbl-install.installdb DEBUG: su -l informix -s /bin/sh -c 'source /usr/local/cm/db/dblenv.bash /usr/local/cm ; source /usr/local/cm/db/informix/local/ids.env ; "/usr/local/cm/bin/installdb" -f IN "/usr/local/cm" "/usr/local/cm" 12.0.1.10000-10 12.0.1.10000-10 installdb_in.log'| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install.installdb DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install.doInstallPost_installDB DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install.doInstallPost_installDB DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install.doActionInstall DEBUG: <--| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install DEBUG: cm-dbl-install [1]| 04/11/2019 23:58:22 component_install|(CAPTURE) Thu Apr 11 23:58:18 2019 cm-dbl-install DEBUG: <--| 04/11/2019 23:58:22 component_install|File:/opt/cisco/install/bin/component_install:821, Function: exec_progmeter(), /opt/cisco/install/bin/progmeter failed (1)| 04/11/2019 23:58:22 appmanager.sh|Internal Error, File:/usr/local/bin/base_scripts/appmanager.sh:153, Function: install(), failed to install infrastructure_post components| 04/11/2019 23:58:22 post_install|File:/opt/cisco/install/bin/post_install:1030, Function: install_applications(), /usr/local/bin/base_scripts/appmanager.sh -install failed (1)| 04/11/2019 23:58:22 post_install|Exiting with result 1| 04/11/2019 23:58:22 post_install|INSTALL_TYPE="Basic Install"| 04/11/2019 23:58:22 post_install|File:/opt/cisco/install/bin/post_install:721, Function: check_for_critical_error(), check_for_critical_error, found /common/log/install/critical.log, exiting| 04/11/2019 23:58:23 post_install|(CAPTURE) Mail notification cancelled - smtp server address for email not found! [/usr/local/platform/conf/platformConfig.xml]| 04/11/2019 23:58:23 display_screen|Arguments: "Critical Error" "The installation has encountered a unrecoverable internal error. For further assistance report the following information to your support provider. "/usr/local/cm/script/cm-dbl-install install PostInstall 12.0.1.10000-10 12.0.1.10000-10 /usr/local/cm/ /usr/local/cm/ /common/log/install/capture.txt " failed (1) The system will now halt. Continuing will allow you to dump diagnostic information before halting." "Continue"| 04/11/2019 23:58:23 display_screen|Button label size information 66, 1, 66| 04/11/2019 23:58:23 platform-events.sh|Received request for platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/11/2019 23:58:23 platform-events.sh|emitting platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/11/2019 23:58:23 platform-events.sh|emitted platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/11/2019 23:58:23 display_screen|installWizard service activated| 04/12/2019 00:28:58 display_screen|newtFormRun exited. reason=1| 04/12/2019 00:28:58 display_screen|installWizard service deactivated| 04/12/2019 00:28:58 post_install|Dumping diagnostic information to USB| 04/12/2019 00:28:58 display_screen|Arguments: "INSTALLATION FAILED" "Would you like to dump diagnostic information?" "Yes" "No"| 04/12/2019 00:28:58 display_screen|Button label size information 66, 2, 33| 04/12/2019 00:28:58 platform-events.sh|Received request for platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/12/2019 00:28:58 platform-events.sh|emitting platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/12/2019 00:28:58 platform-events.sh|emitted platform-event (platform-install-paused-for-input TYPE=INSTALL_PAUSED)| 04/12/2019 00:28:58 display_screen|installWizard service activated| 04/12/2019 00:29:00 display_screen|newtFormRun exited. reason=1| 04/12/2019 00:29:00 display_screen|installWizard service deactivated| 04/12/2019 00:29:00 post_install|Installer selected not to dump diagnostics| 04/12/2019 00:29:00 post_install|========================= Installation failed. =========================| 04/12/2019 00:29:00 post_install|Copy /usr/local/bin/base_scripts/INSTALLATION_FAILED to /etc/rc.d/init.d/| 04/12/2019 00:29:00 post_install|Calling "cp /usr/local/bin/base_scripts/INSTALLATION_FAILED /etc/rc.d/init.d"| 04/12/2019 07:35:52 display_screen|Arguments: "INSTALLATION FAILED" "The installation has failed and must be restarted to recover from the failure. You may dump diagnostic information at this time to the USB Key. Would you like to dump diagnostic information?" "Yes" "No"| 04/12/2019 07:35:52 display_screen|Button label size information 66, 2, 33| 04/12/2019 07:35:52 display_screen|installWizard service activated| -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000031.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000032.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000033.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000034.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000035.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000036.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000037.log -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000038.log -rw-rw-r--. 1 512 505 50 Apr 12 14:33 dbl_installdb~num.bin -rw-rw-r--. 1 512 505 1.0M Apr 12 14:33 dbl_installdb00000039.log -rw-rw-r--. 1 512 505 771K Apr 12 14:58 dbl_installdb00000040.log /log/taos-log-a/cm/trace/dbl/sdi/installdb# -rw-rw-r--. 1 512 505 771K Apr 12 14:58 dbl_installdb00000040.log 23:56:20.773 |-->DriverManager::FreeConnection() 23:56:20.773 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:20.773 |<--DriverManager::FreeConnection() 23:56:20.773 |-->DriverManager::FreeConnectionFailOver() 23:56:20.773 |-->DriverManager::getFailOverConnWrapper() 23:56:20.773 |<--DriverManager::getFailOverConnWrapper() 23:56:20.773 |<--DriverManager::FreeConnectionFailOver() 23:56:24.777 | ConnMonitorTask::svc() Timeout occured on select() 23:56:24.777 |-->DriverManager::FreeConnection() 23:56:24.777 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:24.777 |<--DriverManager::FreeConnection() 23:56:24.777 |-->DriverManager::FreeConnectionFailOver() 23:56:24.777 |-->DriverManager::getFailOverConnWrapper() 23:56:24.777 |<--DriverManager::getFailOverConnWrapper() 23:56:24.777 |<--DriverManager::FreeConnectionFailOver() 23:56:28.781 | ConnMonitorTask::svc() Timeout occured on select() 23:56:28.781 |-->DriverManager::FreeConnection() 23:56:28.781 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:28.781 |<--DriverManager::FreeConnection() 23:56:28.781 |-->DriverManager::FreeConnectionFailOver() 23:56:28.781 |-->DriverManager::getFailOverConnWrapper() 23:56:28.781 |<--DriverManager::getFailOverConnWrapper() 23:56:28.781 |<--DriverManager::FreeConnectionFailOver() 23:56:32.785 | ConnMonitorTask::svc() Timeout occured on select() 23:56:32.785 |-->DriverManager::FreeConnection() 23:56:32.785 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:32.785 |<--DriverManager::FreeConnection() 23:56:32.785 |-->DriverManager::FreeConnectionFailOver() 23:56:32.785 |-->DriverManager::getFailOverConnWrapper() 23:56:32.785 |<--DriverManager::getFailOverConnWrapper() 23:56:32.785 |<--DriverManager::FreeConnectionFailOver() 23:56:36.789 | ConnMonitorTask::svc() Timeout occured on select() 23:56:36.790 |-->DriverManager::FreeConnection() 23:56:36.790 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:36.790 |<--DriverManager::FreeConnection() 23:56:36.790 |-->DriverManager::FreeConnectionFailOver() 23:56:36.790 |-->DriverManager::getFailOverConnWrapper() 23:56:36.790 |<--DriverManager::getFailOverConnWrapper() 23:56:36.790 |<--DriverManager::FreeConnectionFailOver() 23:56:40.794 | ConnMonitorTask::svc() Timeout occured on select() 23:56:40.794 |-->DriverManager::FreeConnection() 23:56:40.794 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:40.794 |<--DriverManager::FreeConnection() 23:56:40.794 |-->DriverManager::FreeConnectionFailOver() 23:56:40.794 |-->DriverManager::getFailOverConnWrapper() 23:56:40.794 |<--DriverManager::getFailOverConnWrapper() 23:56:40.794 |<--DriverManager::FreeConnectionFailOver() 23:56:44.797 | ConnMonitorTask::svc() Timeout occured on select() 23:56:44.797 |-->DriverManager::FreeConnection() 23:56:44.797 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:44.797 |<--DriverManager::FreeConnection() 23:56:44.797 |-->DriverManager::FreeConnectionFailOver() 23:56:44.797 |-->DriverManager::getFailOverConnWrapper() 23:56:44.797 |<--DriverManager::getFailOverConnWrapper() 23:56:44.797 |<--DriverManager::FreeConnectionFailOver() 23:56:48.801 | ConnMonitorTask::svc() Timeout occured on select() 23:56:48.801 |-->DriverManager::FreeConnection() 23:56:48.802 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:48.802 |<--DriverManager::FreeConnection() 23:56:48.802 |-->DriverManager::FreeConnectionFailOver() 23:56:48.802 |-->DriverManager::getFailOverConnWrapper() 23:56:48.802 |<--DriverManager::getFailOverConnWrapper() 23:56:48.802 |<--DriverManager::FreeConnectionFailOver() 23:56:52.806 | ConnMonitorTask::svc() Timeout occured on select() 23:56:52.806 |-->DriverManager::FreeConnection() 23:56:52.806 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:52.806 |<--DriverManager::FreeConnection() 23:56:52.806 |-->DriverManager::FreeConnectionFailOver() 23:56:52.806 |-->DriverManager::getFailOverConnWrapper() 23:56:52.806 |<--DriverManager::getFailOverConnWrapper() 23:56:52.806 |<--DriverManager::FreeConnectionFailOver() 23:56:56.809 | ConnMonitorTask::svc() Timeout occured on select() 23:56:56.810 |-->DriverManager::FreeConnection() 23:56:56.810 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:56:56.810 |<--DriverManager::FreeConnection() 23:56:56.810 |-->DriverManager::FreeConnectionFailOver() 23:56:56.810 |-->DriverManager::getFailOverConnWrapper() 23:56:56.810 |<--DriverManager::getFailOverConnWrapper() 23:56:56.810 |<--DriverManager::FreeConnectionFailOver() 23:57:00.813 | ConnMonitorTask::svc() Timeout occured on select() 23:57:00.813 |-->DriverManager::FreeConnection() 23:57:00.813 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:00.813 |<--DriverManager::FreeConnection() 23:57:00.813 |-->DriverManager::FreeConnectionFailOver() 23:57:00.813 |-->DriverManager::getFailOverConnWrapper() 23:57:00.813 |<--DriverManager::getFailOverConnWrapper() 23:57:00.813 |<--DriverManager::FreeConnectionFailOver() 23:57:04.817 | ConnMonitorTask::svc() Timeout occured on select() 23:57:04.817 |-->DriverManager::FreeConnection() 23:57:04.817 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:04.817 |<--DriverManager::FreeConnection() 23:57:04.817 |-->DriverManager::FreeConnectionFailOver() 23:57:04.817 |-->DriverManager::getFailOverConnWrapper() 23:57:04.817 |<--DriverManager::getFailOverConnWrapper() 23:57:04.817 |<--DriverManager::FreeConnectionFailOver() 23:57:08.821 | ConnMonitorTask::svc() Timeout occured on select() 23:57:08.821 |-->DriverManager::FreeConnection() 23:57:08.821 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:08.821 |<--DriverManager::FreeConnection() 23:57:08.821 |-->DriverManager::FreeConnectionFailOver() 23:57:08.821 |-->DriverManager::getFailOverConnWrapper() 23:57:08.821 |<--DriverManager::getFailOverConnWrapper() 23:57:08.821 |<--DriverManager::FreeConnectionFailOver() 23:57:12.825 | ConnMonitorTask::svc() Timeout occured on select() 23:57:12.825 |-->DriverManager::FreeConnection() 23:57:12.825 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:12.825 |<--DriverManager::FreeConnection() 23:57:12.825 |-->DriverManager::FreeConnectionFailOver() 23:57:12.825 |-->DriverManager::getFailOverConnWrapper() 23:57:12.825 |<--DriverManager::getFailOverConnWrapper() 23:57:12.825 |<--DriverManager::FreeConnectionFailOver() 23:57:16.829 | ConnMonitorTask::svc() Timeout occured on select() 23:57:16.829 |-->DriverManager::FreeConnection() 23:57:16.829 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:16.829 |<--DriverManager::FreeConnection() 23:57:16.829 |-->DriverManager::FreeConnectionFailOver() 23:57:16.829 |-->DriverManager::getFailOverConnWrapper() 23:57:16.829 |<--DriverManager::getFailOverConnWrapper() 23:57:16.829 |<--DriverManager::FreeConnectionFailOver() 23:57:20.833 | ConnMonitorTask::svc() Timeout occured on select() 23:57:20.833 |-->DriverManager::FreeConnection() 23:57:20.833 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:20.833 |<--DriverManager::FreeConnection() 23:57:20.833 |-->DriverManager::FreeConnectionFailOver() 23:57:20.833 |-->DriverManager::getFailOverConnWrapper() 23:57:20.834 |<--DriverManager::getFailOverConnWrapper() 23:57:20.834 |<--DriverManager::FreeConnectionFailOver() 23:57:24.838 | ConnMonitorTask::svc() Timeout occured on select() 23:57:24.838 |-->DriverManager::FreeConnection() 23:57:24.838 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:24.838 |<--DriverManager::FreeConnection() 23:57:24.838 |-->DriverManager::FreeConnectionFailOver() 23:57:24.838 |-->DriverManager::getFailOverConnWrapper() 23:57:24.838 |<--DriverManager::getFailOverConnWrapper() 23:57:24.838 |<--DriverManager::FreeConnectionFailOver() 23:57:28.842 | ConnMonitorTask::svc() Timeout occured on select() 23:57:28.842 |-->DriverManager::FreeConnection() 23:57:28.842 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:28.842 |<--DriverManager::FreeConnection() 23:57:28.842 |-->DriverManager::FreeConnectionFailOver() 23:57:28.842 |-->DriverManager::getFailOverConnWrapper() 23:57:28.842 |<--DriverManager::getFailOverConnWrapper() 23:57:28.842 |<--DriverManager::FreeConnectionFailOver() 23:57:32.846 | ConnMonitorTask::svc() Timeout occured on select() 23:57:32.846 |-->DriverManager::FreeConnection() 23:57:32.846 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:32.846 |<--DriverManager::FreeConnection() 23:57:32.846 |-->DriverManager::FreeConnectionFailOver() 23:57:32.846 |-->DriverManager::getFailOverConnWrapper() 23:57:32.846 |<--DriverManager::getFailOverConnWrapper() 23:57:32.846 |<--DriverManager::FreeConnectionFailOver() 23:57:36.851 | ConnMonitorTask::svc() Timeout occured on select() 23:57:36.851 |-->DriverManager::FreeConnection() 23:57:36.851 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:36.851 |<--DriverManager::FreeConnection() 23:57:36.851 |-->DriverManager::FreeConnectionFailOver() 23:57:36.851 |-->DriverManager::getFailOverConnWrapper() 23:57:36.851 |<--DriverManager::getFailOverConnWrapper() 23:57:36.851 |<--DriverManager::FreeConnectionFailOver() 23:57:40.855 | ConnMonitorTask::svc() Timeout occured on select() 23:57:40.855 |-->DriverManager::FreeConnection() 23:57:40.855 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:40.855 |<--DriverManager::FreeConnection() 23:57:40.855 |-->DriverManager::FreeConnectionFailOver() 23:57:40.855 |-->DriverManager::getFailOverConnWrapper() 23:57:40.855 |<--DriverManager::getFailOverConnWrapper() 23:57:40.855 |<--DriverManager::FreeConnectionFailOver() 23:57:44.859 | ConnMonitorTask::svc() Timeout occured on select() 23:57:44.859 |-->DriverManager::FreeConnection() 23:57:44.859 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:44.859 |<--DriverManager::FreeConnection() 23:57:44.859 |-->DriverManager::FreeConnectionFailOver() 23:57:44.859 |-->DriverManager::getFailOverConnWrapper() 23:57:44.859 |<--DriverManager::getFailOverConnWrapper() 23:57:44.859 |<--DriverManager::FreeConnectionFailOver() 23:57:48.863 | ConnMonitorTask::svc() Timeout occured on select() 23:57:48.863 |-->DriverManager::FreeConnection() 23:57:48.863 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:48.863 |<--DriverManager::FreeConnection() 23:57:48.863 |-->DriverManager::FreeConnectionFailOver() 23:57:48.863 |-->DriverManager::getFailOverConnWrapper() 23:57:48.863 |<--DriverManager::getFailOverConnWrapper() 23:57:48.863 |<--DriverManager::FreeConnectionFailOver() 23:57:52.867 | ConnMonitorTask::svc() Timeout occured on select() 23:57:52.867 |-->DriverManager::FreeConnection() 23:57:52.867 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:52.867 |<--DriverManager::FreeConnection() 23:57:52.867 |-->DriverManager::FreeConnectionFailOver() 23:57:52.867 |-->DriverManager::getFailOverConnWrapper() 23:57:52.867 |<--DriverManager::getFailOverConnWrapper() 23:57:52.867 |<--DriverManager::FreeConnectionFailOver() 23:57:56.872 | ConnMonitorTask::svc() Timeout occured on select() 23:57:56.872 |-->DriverManager::FreeConnection() 23:57:56.872 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:57:56.872 |<--DriverManager::FreeConnection() 23:57:56.872 |-->DriverManager::FreeConnectionFailOver() 23:57:56.872 |-->DriverManager::getFailOverConnWrapper() 23:57:56.872 |<--DriverManager::getFailOverConnWrapper() 23:57:56.872 |<--DriverManager::FreeConnectionFailOver() 23:58:00.875 | ConnMonitorTask::svc() Timeout occured on select() 23:58:00.875 |-->DriverManager::FreeConnection() 23:58:00.875 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:58:00.875 |<--DriverManager::FreeConnection() 23:58:00.875 |-->DriverManager::FreeConnectionFailOver() 23:58:00.875 |-->DriverManager::getFailOverConnWrapper() 23:58:00.875 |<--DriverManager::getFailOverConnWrapper() 23:58:00.875 |<--DriverManager::FreeConnectionFailOver() 23:58:04.879 | ConnMonitorTask::svc() Timeout occured on select() 23:58:04.879 |-->DriverManager::FreeConnection() 23:58:04.879 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:58:04.879 |<--DriverManager::FreeConnection() 23:58:04.879 |-->DriverManager::FreeConnectionFailOver() 23:58:04.880 |-->DriverManager::getFailOverConnWrapper() 23:58:04.880 |<--DriverManager::getFailOverConnWrapper() 23:58:04.880 |<--DriverManager::FreeConnectionFailOver() 23:58:08.884 | ConnMonitorTask::svc() Timeout occured on select() 23:58:08.884 |-->DriverManager::FreeConnection() 23:58:08.884 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:58:08.884 |<--DriverManager::FreeConnection() 23:58:08.884 |-->DriverManager::FreeConnectionFailOver() 23:58:08.884 |-->DriverManager::getFailOverConnWrapper() 23:58:08.884 |<--DriverManager::getFailOverConnWrapper() 23:58:08.884 |<--DriverManager::FreeConnectionFailOver() 23:58:12.888 | ConnMonitorTask::svc() Timeout occured on select() 23:58:12.888 |-->DriverManager::FreeConnection() 23:58:12.888 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:58:12.888 |<--DriverManager::FreeConnection() 23:58:12.888 |-->DriverManager::FreeConnectionFailOver() 23:58:12.888 |-->DriverManager::getFailOverConnWrapper() 23:58:12.888 |<--DriverManager::getFailOverConnWrapper() 23:58:12.888 |<--DriverManager::FreeConnectionFailOver() 23:58:16.892 | ConnMonitorTask::svc() Timeout occured on select() 23:58:16.892 |-->DriverManager::FreeConnection() 23:58:16.892 | DriverManager::FreeConnection() All [1] connections in pool are being used. 23:58:16.892 |<--DriverManager::FreeConnection() 23:58:16.892 |-->DriverManager::FreeConnectionFailOver() 23:58:16.892 |-->DriverManager::getFailOverConnWrapper() 23:58:16.892 |<--DriverManager::getFailOverConnWrapper() 23:58:16.892 |<--DriverManager::FreeConnectionFailOver() 23:58:17.859 | updatestatsAUS Refresh result 1021 23:58:17.859 |-->XResultSetPtr::~XResultSetPtr, ptr = [0x8eafa28] 23:58:17.859 |-->XResultSetPtr::release1() 23:58:17.859 | XResultSetPtr::release1() REL ResultSetPtr: count = [1], ptr = [0x8eafa28], manageStmt = [YES] 23:58:17.859 | XResultSetPtr::release1() ABOUT TO DEL RS, ptr = [0x8eafa28] 23:58:17.860 | XResultSetPtr::release1() ABOUT TO DEL STMT = [0x8ee51d8] 23:58:17.860 |<--XResultSetPtr::release1() 23:58:17.860 |<--XResultSetPtr::~XResultSetPtr, ptr = [0x8eafa28] 23:58:17.860 |-->Connector::Connector()-chardsn 23:58:17.860 | Connector::Connector()-chardsn useDSN [DSN=sysmaster;DATABASE=sysadmin] 23:58:17.860 | Connector::Connector()-chardsn Commit [1] 23:58:17.860 |-->DriverManager::stickpasswd() 23:58:17.860 | DriverManager::stickpasswd() DSN is [DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.860 | DriverManager::stickpasswd() Found match with [DSN=ccm] semicolon index[31] 47 23:58:17.860 |<--DriverManager::stickpasswd() 23:58:17.860 | Connector::Connector()-chardsn m_dsn[DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.860 |<--Connector::Connector()-chardsn 23:58:17.860 |-->Connector::execute() (nil) 23:58:17.860 |set isolation to committed read last committed 23:58:17.860 |-->Connector::getTempStatement() 23:58:17.860 |-->Connector::ensureConnection() 23:58:17.860 |-->Connector::connect() 23:58:17.860 | Connector::connect() ==> DSN [DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.860 |-->Connector::tryConnection() 23:58:17.860 |-->DriverManager::getConnection() 23:58:17.860 | DriverManager::getConnection() [4281] dsn=[DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.860 |-->DriverManager::getConnectionFromPool() 23:58:17.860 |-->DriverManager::findUnused() 23:58:17.860 | DriverManager::findUnused() [4281] Pool=[1] DSN=[DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.861 | DriverManager::findUnused() [4281] Could not find an unused connection to [DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300]. 23:58:17.861 |<--DriverManager::findUnused() 23:58:17.861 | DriverManager::getConnectionFromPool() [4281] Did not find free connection for DSN [DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300]. Going to DriverManager. 23:58:17.896 | DriverManager::getConnectionFromPool() [4281] odbc::Connection* [0x8ee5028] [46] 23:58:17.896 |-->DriverManager::addConn() 23:58:17.896 |<--DriverManager::addConn() 23:58:17.896 |<--DriverManager::getConnectionFromPool() 23:58:17.896 | DriverManager::getConnection() [4281] Connections In Use [2] In Pool [2] Total Given [76214] Constructed [46] Destructed [44] 23:58:17.896 |<--DriverManager::getConnection() 23:58:17.896 | Connector::tryConnection() Trying m_connection [0x8ee5028] 23:58:17.896 | Connector::tryConnection() Have connection: testing tryConnection 23:58:17.896 | Connector::tryConnection() set auto commit 23:58:17.896 |-->Connector::getTempStatement() 23:58:17.896 |-->Connector::ensureConnection() 23:58:17.896 | Connector::ensureConnection() m_connection [0x8ee5028] 23:58:17.896 |<--Connector::ensureConnection() 23:58:17.897 | Connector::getTempStatement() StatementPtr [0x8ea5310] 23:58:17.897 |<--Connector::getTempStatement() 23:58:17.897 | Connector::tryConnection() ###execute [set lock mode to wait 30] 23:58:17.897 | Connector::tryConnection() Try SUCCEEDED m_connection [0x8ee5028] 23:58:17.897 |<--Connector::tryConnection() 23:58:17.897 |<--Connector::connect() 23:58:17.897 | Connector::ensureConnection() m_connection [0x8ee5028] 23:58:17.897 |<--Connector::ensureConnection() 23:58:17.897 | Connector::getTempStatement() StatementPtr [0x8ee51d8] 23:58:17.897 |<--Connector::getTempStatement() 23:58:17.898 | Connector::execute() (nil) Result [FALSE] 23:58:17.898 |<--Connector::execute() (nil) 23:58:17.898 | updatestatsAUS execute function sysadmin:exectask("Alert Cleanup") 23:58:17.898 |-->Connector::executeQuery() 0x8ee5028 23:58:17.898 |execute function sysadmin:exectask("Alert Cleanup") 23:58:17.898 |-->XResultSetPtr::XResultSetPtr 23:58:17.898 | XResultSetPtr::XResultSetPtr count = [0], ptr = [(nil)], manageStmt =[NULL] 23:58:17.898 |<--XResultSetPtr::XResultSetPtr 23:58:17.898 |-->Connector::ensureStatement() 23:58:17.898 |-->Connector::ensureConnection() 23:58:17.898 | Connector::ensureConnection() m_connection [0x8ee5028] 23:58:17.898 |<--Connector::ensureConnection() 23:58:17.898 | Connector::ensureStatement() Statement [0x8ee51d8] 23:58:17.898 |<--Connector::ensureStatement() 23:58:17.898 | Connector::executeQuery() 0x8ee5028 Creating ResultSetPtr for stmt [0x8ee51d8], managed 23:58:17.899 |-->XResultSetPtr::XResultSetPtr 23:58:17.899 | XResultSetPtr::XResultSetPtr count = [1], ptr = [0x8e39368], manageStmt =[YES] 23:58:17.899 |<--XResultSetPtr::XResultSetPtr 23:58:17.899 |-->XResultSetPtr::release1() 23:58:17.899 |<--XResultSetPtr::release1() 23:58:17.899 |-->XResultSetPtr::~XResultSetPtr, ptr = [0x8e39368] 23:58:17.899 |-->XResultSetPtr::release1() 23:58:17.899 | XResultSetPtr::release1() REL ResultSetPtr: count = [2], ptr = [0x8e39368], manageStmt = [YES] 23:58:17.899 |<--XResultSetPtr::release1() 23:58:17.899 |<--XResultSetPtr::~XResultSetPtr, ptr = [0x8e39368] 23:58:17.899 | Connector::executeQuery() 0x8ee5028 ptr = [0x8e39368] 23:58:17.899 |<--Connector::executeQuery() 0x8ee5028 23:58:17.899 |-->Connector::executeQuery() 0x8ee5028 23:58:17.899 |execute function sysadmin:exectask("Alert Cleanup") 23:58:17.899 |-->XResultSetPtr::XResultSetPtr 23:58:17.899 | XResultSetPtr::XResultSetPtr count = [0], ptr = [(nil)], manageStmt =[NULL] 23:58:17.899 |<--XResultSetPtr::XResultSetPtr 23:58:17.899 |-->Connector::ensureStatement() 23:58:17.899 |-->Connector::ensureConnection() 23:58:17.899 | Connector::ensureConnection() m_connection [0x8ee5028] 23:58:17.899 |<--Connector::ensureConnection() 23:58:17.899 | Connector::ensureStatement() Statement [0x8ea54e8] 23:58:17.899 |<--Connector::ensureStatement() 23:58:17.899 | Connector::executeQuery() 0x8ee5028 Creating ResultSetPtr for stmt [0x8ea54e8], managed 23:58:17.900 |-->XResultSetPtr::XResultSetPtr 23:58:17.900 | XResultSetPtr::XResultSetPtr count = [1], ptr = [0x8ea5420], manageStmt =[YES] 23:58:17.900 |<--XResultSetPtr::XResultSetPtr 23:58:17.900 |-->XResultSetPtr::release1() 23:58:17.900 |<--XResultSetPtr::release1() 23:58:17.900 |-->XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.900 |-->XResultSetPtr::release1() 23:58:17.900 | XResultSetPtr::release1() REL ResultSetPtr: count = [2], ptr = [0x8ea5420], manageStmt = [YES] 23:58:17.900 |<--XResultSetPtr::release1() 23:58:17.900 |<--XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.900 | Connector::executeQuery() 0x8ee5028 ptr = [0x8ea5420] 23:58:17.900 |<--Connector::executeQuery() 0x8ee5028 23:58:17.900 |-->XResultSetPtr::release1() 23:58:17.900 | XResultSetPtr::release1() REL ResultSetPtr: count = [1], ptr = [0x8e39368], manageStmt = [YES] 23:58:17.900 | XResultSetPtr::release1() ABOUT TO DEL RS, ptr = [0x8e39368] 23:58:17.900 | XResultSetPtr::release1() ABOUT TO DEL STMT = [0x8ee51d8] 23:58:17.900 |<--XResultSetPtr::release1() 23:58:17.900 |-->XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.900 |-->XResultSetPtr::release1() 23:58:17.900 | XResultSetPtr::release1() REL ResultSetPtr: count = [2], ptr = [0x8ea5420], manageStmt = [YES] 23:58:17.900 |<--XResultSetPtr::release1() 23:58:17.900 |<--XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.964 | updatestatsAUS Alert clean Count 0 23:58:17.964 |-->XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.964 |-->XResultSetPtr::release1() 23:58:17.964 | XResultSetPtr::release1() REL ResultSetPtr: count = [1], ptr = [0x8ea5420], manageStmt = [YES] 23:58:17.964 | XResultSetPtr::release1() ABOUT TO DEL RS, ptr = [0x8ea5420] 23:58:17.964 | XResultSetPtr::release1() ABOUT TO DEL STMT = [0x8ea54e8] 23:58:17.964 |<--XResultSetPtr::release1() 23:58:17.964 |<--XResultSetPtr::~XResultSetPtr, ptr = [0x8ea5420] 23:58:17.964 |-->Connector::~Connector() 23:58:17.964 | Connector::~Connector() Connector being destroyed DSN=[DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.964 |-->DriverManager::retConnectionToPoolWithError() 23:58:17.964 | DriverManager::retConnectionToPoolWithError() [4281] Clear bad ODBC connection. 23:58:17.964 |-->DriverManager::clearConn() 23:58:17.964 | DriverManager::clearConn() moving connection [45] to FAILOVER list 23:58:17.964 |<--DriverManager::clearConn() 23:58:17.964 | DriverManager::retConnectionToPoolWithError() [4281] Connections In Use [1] In Pool [1] Total Returned [76213] 23:58:17.964 |<--DriverManager::retConnectionToPoolWithError() 23:58:17.964 |<--Connector::~Connector() 23:58:17.964 |-->Connector::~Connector() 23:58:17.964 | Connector::~Connector() Connector being destroyed DSN=[DSN=sysmaster;DATABASE=sysadmin;RECVTIMEOUT=300] 23:58:17.964 |-->DriverManager::retConnectionToPoolWithError() 23:58:17.964 | DriverManager::retConnectionToPoolWithError() [4281] Clear bad ODBC connection. 23:58:17.964 |-->DriverManager::clearConn() 23:58:17.964 | DriverManager::clearConn() moving connection [46] to FAILOVER list 23:58:17.964 |<--DriverManager::clearConn() 23:58:17.964 | DriverManager::retConnectionToPoolWithError() [4281] Connections In Use [0] In Pool [0] Total Returned [76214] 23:58:17.964 |<--DriverManager::retConnectionToPoolWithError() 23:58:17.964 |<--Connector::~Connector() 23:58:17.964 |<--updatestatsAUS 23:58:17.964 |-->Connector::Connector()-stringdsn 23:58:17.964 | Connector::Connector()-stringdsn useDSN [DSN=ccm_super] 23:58:17.964 | Connector::Connector()-stringdsn Commit [1] 23:58:17.964 |-->DriverManager::stickpasswd() 23:58:17.964 | DriverManager::stickpasswd() DSN is [DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.964 | DriverManager::stickpasswd() Found match with [DSN=ccm] semicolon index[13] 29 23:58:17.964 |<--DriverManager::stickpasswd() 23:58:17.964 | Connector::Connector()-stringdsn m_dsn[DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.964 |<--Connector::Connector()-stringdsn 23:58:17.964 |-->Connector::execute() (nil) 23:58:17.964 |execute procedure enablenotify() 23:58:17.964 |-->Connector::getTempStatement() 23:58:17.964 |-->Connector::ensureConnection() 23:58:17.965 |-->Connector::connect() 23:58:17.965 | Connector::connect() ==> DSN [DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.965 |-->Connector::tryConnection() 23:58:17.965 |-->DriverManager::getConnection() 23:58:17.965 | DriverManager::getConnection() [4281] dsn=[DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.965 |-->DriverManager::getConnectionFromPool() 23:58:17.965 |-->DriverManager::findUnused() 23:58:17.965 | DriverManager::findUnused() [4281] Pool=[0] DSN=[DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.965 | DriverManager::findUnused() [4281] Could not find an unused connection to [DSN=ccm_super;RECVTIMEOUT=300]. 23:58:17.965 |<--DriverManager::findUnused() 23:58:17.965 | DriverManager::getConnectionFromPool() [4281] Did not find free connection for DSN [DSN=ccm_super;RECVTIMEOUT=300]. Going to DriverManager. 23:58:17.995 | DriverManager::getConnectionFromPool() [4281] odbc::Connection* [0x8e2c620] [47] 23:58:17.995 |-->DriverManager::addConn() 23:58:17.995 |<--DriverManager::addConn() 23:58:17.995 |<--DriverManager::getConnectionFromPool() 23:58:17.995 | DriverManager::getConnection() [4281] Connections In Use [1] In Pool [1] Total Given [76215] Constructed [47] Destructed [46] 23:58:17.995 |<--DriverManager::getConnection() 23:58:17.995 | Connector::tryConnection() Trying m_connection [0x8e2c620] 23:58:17.995 | Connector::tryConnection() Have connection: testing tryConnection 23:58:17.995 | Connector::tryConnection() set auto commit 23:58:17.995 |-->Connector::getTempStatement() 23:58:17.995 |-->Connector::ensureConnection() 23:58:17.995 | Connector::ensureConnection() m_connection [0x8e2c620] 23:58:17.995 |<--Connector::ensureConnection() 23:58:17.995 | Connector::getTempStatement() StatementPtr [0x8ea92b0] 23:58:17.995 |<--Connector::getTempStatement() 23:58:17.995 | Connector::tryConnection() ###execute [set lock mode to wait 30] 23:58:17.995 | Connector::tryConnection() Try SUCCEEDED m_connection [0x8e2c620] 23:58:17.995 |<--Connector::tryConnection() 23:58:17.995 |<--Connector::connect() 23:58:17.995 | Connector::ensureConnection() m_connection [0x8e2c620] 23:58:17.995 |<--Connector::ensureConnection() 23:58:17.996 | Connector::getTempStatement() StatementPtr [0x8ea92b0] 23:58:17.996 |<--Connector::getTempStatement() 23:58:17.997 | Connector::execute() (nil) Result [FALSE] 23:58:17.997 |<--Connector::execute() (nil) 23:58:17.997 |-->Connector::~Connector() 23:58:17.997 | Connector::~Connector() Connector being destroyed DSN=[DSN=ccm_super;RECVTIMEOUT=300] 23:58:17.997 |-->DriverManager::retConnectionToPool() 23:58:17.997 | DriverManager::retConnectionToPool() [4281] ODBC connection [0x8e2c620] returned to pool. 23:58:17.997 | DriverManager::retConnectionToPool() [4281] Connections In Use [0] In Pool [1] Total Returned [76215] 23:58:17.997 |<--DriverManager::retConnectionToPool() 23:58:17.997 |<--Connector::~Connector()