[cisco-voip] 4.1(3) -> 5.0(4) fails
Andre Beck
cisco-voip at ibh.net
Thu Feb 15 04:11:41 EST 2007
Hi Robin,
On Thu, Feb 15, 2007 at 08:18:56AM +0100, Robin Inderberg wrote:
>
> Do you have the install.log?
Yep, saved that to an USB stick and groked it up and down without seeing
much that would explain the issues.
> I have had the same problem, but with a different version.
>
> "12/13/2006 03:07:42 display_screen|Arguments: "Critial Error" "The installation has encountered a unrecoverable internal error. For further assistance report the following information to your support provider.
>
> Script "/usr/local/cm/script/5.0.4.2000-1/cm-dbl-install W1 PostInstall 5.0.4.2000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log" exited with errors (1)"
Aah. The "good" thing about that is now I'm sure it will also happen with
5.0(4a) and all my tries to get the 5.0(4) upgraded to 5.0(4a) before
the DMA load will be in vain...
> Could you send me these files,
> C:\CiscoWebs\DMA\Status.htm
> C:\CiscoWebs\DMA\bin\*.log
> C:\Program Files\Cisco\trace\DBL\installdb*.log
>
> And I can compare our problems,
I don't have files from the Windows install anymore (blown away) and I
wouldn't like to send the install.log around as it contains weakly
obfuscated passwords which happen to be in use here (not that I wouldn't
trust you, but I'm even in doubt whether I would want to send this file
to TAC, the same way I'm in doubt with IOS password "encryption"). But
let's talk about what in this file or in the DMA might be of interest.
First, I had a verification warning during DMA (after I finally came to
the verification phase, I had to use kill.exe on the database service
that hung in "Stopping" state), it was about the description field of
the personal directory containing an umlaut ("Persönliches Telefonbuch").
It didn't read like it would be a real problem and so I continued. If
you had a similar warning, I'd try to reinstall 4.1(3), eliminate that
warning and DMA again but given that this takes a day of work (mostly
spent waiting, but nonetheless) I'd like to have confidence in the
character set issue beeing involved.
Second, let's have a closer look to the log starting at
02/12/2007 15:06:44 IPM| begin-of-session "Database Installation", 1 items|<LVL::Info>
02/12/2007 15:06:44 IPM| ipmDoTimedCommand: cmd="/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log", est(sec)=2400, max(sec)=120
00|<LVL::Debug>
02/12/2007 15:06:44 IPM| begin-of-work: [cmd="/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log"]|<LVL::Info>
02/12/2007 15:06:44 IPM-Child|execlp(/tmp/.ipmJrkOXw) for cmd "/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log"|<LVL::Debug>
It's not that much, so I'll include it here:
02/12/2007 15:16:01 IPM|(CAPTURE) Inside doInstallPost...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Verifying SDI directory [/var/log/active/cm/trace/dbl/sdi]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) chown database.ccmbase /var/log/active/cm/trace/dbl/sdi|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) chmod 775 /var/log/active/cm/trace/dbl/sdi|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside setupPreferences...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside dbllib.py getDBName(0)...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Fresh on PUB, hence dbname is defaulted to [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) dbname so far [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) final dbname is [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Updating prefs [/usr/local/cm/conf/dbl/prefs.xml]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside getHostName() ....|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside getHostName() ....|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside getHostName() ....|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Updating prefs [/usr/local/cm/conf/dbl/sdi/prefs.xml]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Updating prefs [/usr/local/cm/conf/dbnotify/sdi/prefs.xml]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Updating prefs [/usr/local/conf/cisco_database_layer_monitor/output/prefs.xml]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside getPublisherFromInstallPrefs...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) (odbc setup moved to dbl init)|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside fixSQLLibPaths....|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside fixSQLLibPaths....|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside doInstallPost_installDB ...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside installdb ...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside dbllib.py getDBName(0)...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Fresh on PUB, hence dbname is defaulted to [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) dbname so far [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) final dbname is [ccm0500v0000]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Start DBMS|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) su -c 'if [ -f /usr/local/cm/db/informix/local/ids.env ]; then source /usr/local/cm/db/informix/local/ids.env; fi ; oninit' - informix|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) IDSWillStart...ok|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Using port [54320]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/dbfuncs.sql.pathed.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/makedb.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_super /usr/local/cm/db/csv|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) installCsv: rc=1|<LVL::Debug>
^^^^
^^^^
It's not obvious, but this might mean a return code of 1, an error. However,
the process continues without much fuzz:
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_super /usr/local/cm/db/csv/newinstall/ApplicationUserDirGroupMap.csv|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_super /usr/local/cm/db/csv/newinstall/LDAPFilter.csv|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_super /usr/local/cm/db/csv/products|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) xml DSN=ccm_super /usr/local/cm/db/xml/xml|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) catalog DSN=ccm_super AlarmCatalog /usr/local/cm/db/xml/alarmcatalog|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) catalog DSN=ccm_super TraceCatalog /usr/local/cm/db/xml/tracecatalog|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) creating ccmw1 using /usr/local/cm/db/create_ccmw1.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccmw1 /usr/local/cm/db/create_ccmw1.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) installSchema DSN=ccm_w1 /usr/local/cm/db/exported|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_w1 /usr/local/cm/db/exported|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) installSchema DSN=ccm_w1 /usr/local/cm/db/csv/directory|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_w1 /usr/local/cm/db/csv/directory|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccmw1 /usr/local/cm/db/sql/dbl/migration/conv4to5_auto_fix.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Update Statistics DSN=ccm_w1|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Convert Database 4 to 5: DSN=ccm_w1 to DSN=ccm_super|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) UpdateLoadInfo: DSN=ccm_super file:/usr/local/cm/db/loadinfo/loadinfo.txt|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/dbl_common|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/dbl|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/dbl_gen|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/dbl_trig|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/sql/ccm|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) sql ccm0500v0000 /usr/local/cm/db/informix/ertools/checksum/checksum.sql|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Cleanup Dblcnqueue DSN=ccm_super|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Update Statistics DSN=ccm_super|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Failure 1|<LVL::Debug>
^^^^^^^^^
Whoops. The first clear sign of a problem.
Theres just this following:
02/12/2007 15:16:01 IPM|(CAPTURE) /usr/local/cm/bin/dbl start --safe --nopreflight|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) rm -f /tmp/*.txt /tmp/*.log /tmp/*.err /tmp/psqlx /tmp/*.bin /tmp/af* /tmp/shmem*|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) Inside getPublisherFromPrefs...|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) 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 -p 54320 -f W1 /usr/local/cm /common/download/windows 5.0.4.1000-1 4.1.3 installdb_w1.log'|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) cm-dbl-install [1]|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) rc=1|<LVL::Debug>
^^^^
Seems my return code theory applies.
02/12/2007 15:16:01 IPM| end-of-work: [cmd="/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log"]|<LVL::Info>
02/12/2007 15:16:01 IPM|Child's return-status = 0x00000100|<LVL::Debug>
02/12/2007 15:16:01 IPM|Internal Error, File:ipm.c:1858, Function: ipmDoTimedCommand(), Script "/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/insta
ll/install.log" exited with errors (1)|<LVL::Critical>
02/12/2007 15:16:03 IPM| end-of-session "Database Installation": 559.280 secs.|<LVL::Info>
02/12/2007 15:16:03 IPM|Close progress meter ""|<LVL::Info>
02/12/2007 15:16:03 post_install.sh|check_for_critical_error, found /common/log/install/critical.log, exiting|<LVL::Error>
02/12/2007 15:16:03 display_screen|Arguments: "Critial Error" "The installation has encountered a unrecoverable internal error. For further assistance report the following information to your support provider.
Script "/usr/local/cm/script/5.0.4.1000-1/cm-dbl-install W1 PostInstall 5.0.4.1000-1 "4.1.3" /usr/local/cm/ /common/download/windows/ /common/log/install/install.log" exited with errors (1)
The system will now halt.
So it seems the real location of the error is in the import of the CSV
exported DMA data to the database:
02/12/2007 15:16:01 IPM|(CAPTURE) csv DSN=ccm_super /usr/local/cm/db/csv|<LVL::Debug>
02/12/2007 15:16:01 IPM|(CAPTURE) installCsv: rc=1|<LVL::Debug>
Is it the same for you? The strange point is that /usr/local/cm/db/csv
obviously is a directory and the above might not be an error at all,
as the installation continues to import CSVs from below this directory
later...
TIA,
Andre.
--
The _S_anta _C_laus _O_peration
or "how to turn a complete illusion into a neverending money source"
-> Andre Beck +++ ABP-RIPE +++ IBH Prof. Dr. Horn GmbH, Dresden <-
More information about the cisco-voip
mailing list