Guest

Cisco PGW 2200 Softswitch

Understanding prov-sync, prov-dply, and pom.dataSync

Document ID: 28160

Updated: Jan 31, 2006

   Print

Introduction

The TransPath Man-Machine Language (MML) commands prov-sync and prov-dply and the pom.dataSync parameter affect the synchronization of provisioning data between a redundant pair of Cisco Media Gateway Controllers (MGCs). However, there are some important differences between these various mechanisms that are not well understood. This document attempts to shed some light on this matter and provides guidelines to use to troubleshoot as well.

Prerequisites

Requirements

Readers of this document should have knowledge of this topic:

Components Used

This document has been written with MGC Software Release 9.2(2) in mind. However, the mechanisms discussed commonly exist in other software releases.

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.

Conventions

For more information on document conventions, refer to the Cisco Technical Tips Conventions.

Synchronization of Provisioning Data

Provisioning data are the data files that result from MGC configuration commands that are issued during an MML provisioning session. These data files carry a .dat filename extension. When the MGC is used as a virtual switch controller (VSC) instead of a signaling controller (SC), some data files carry a .bin and .dialPlan filename extension as well.

Data files are held in separate directories in /opt/CiscoMGC/etc/CONFIG_LIB. The directories themselves carry the name CFG_provsession. (The variable provsession refers to the session name chosen in MML when the provisioning session was started.)

One of these CFG_ directories holds the data files for the active MGC configuration. A symbolic link called active_link in the /opt/CiscoMGC/etc directory is pointed to this CFG_ directory. The .dat files of the active configuration are also copied to /opt/CiscoMGC/etc, and in a VSC configuration, the .bin and .dialPlan files in /opt/CiscoMGC/dialPlan are replaced by those from the active CFG_ directory.

Another symbolic link in /opt/CiscoMGC/etc, called prov_link, points to the CFG_ directory that holds the last provisioned session (which may or may not equal the active configuration). The remaining CFG_ directories contain data files from previous (old) configurations that can be reactivated if needed.

active_link and prov_link

!--- The active_link equals prov_link after the prov-cpy or 
!--- prov-dply command is issued in MML.
 
% pwd 
/opt/CiscoMGC/etc� 
% ls -l | grep ^l 
lrwxrwxrwx�� 1 mgcusr�� mgcgrp��� 42 Oct 19 11:05� active_link -> 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� 
lrwxrwxrwx�� 1 mgcusr�� mgcgrp��� 41 Oct 19 11:06� prov_link -> 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest4

In a redundant MGC configuration with an active and a standby MGC, it is important to keep provisioning data synchronized between both hosts to prevent loss of service during a failover condition. This process of provisioning data synchronization is controlled by the Provisioning Object Manager (POM). There are several ways of doing this, and each method is applicable to a particular situation. They share these similarities:

  • File attributes (name, size, and date of last modification) of data files on both hosts are compared. Those files with nonmatching attributes are transferred to the standby MGC.

  • The .dat files from the CFG_ directory that hold the active configuration are copied to /opt/CiscoMGC/etc, as shown here:

    cp -p /opt/CiscoMGC/etc/CONFIG_LIB/CFG_active_session/[a-z]*.dat 
    /opt/CiscoMGC/etc/
    

    When the MGC is used as a VSC, these commands are executed as well:

    rm -f /opt/CiscoMGC/etc/../dialPlan/*.bin 
    cp -p /opt/CiscoMGC/etc/CONFIG_LIB/CFG_active_session/*.bin 
    /opt/CiscoMGC/etc/../dialPlan/
    rm -f /opt/CiscoMGC/etc/../dialPlan/*.dialPlan 
    cp -p /opt/CiscoMGC/etc/CONFIG_LIB/CFG_active_session/*.dialPlan 
    /opt/CiscoMGC/etc/../dialPlan/
    
  • Dynamic reconfiguration is triggered on the standby host to reflect the newly synchronized active configuration.

A discussion of each of the synchronization methods follows.

prov-sync

The prov-sync command goes through all CFG_ provisioning directories in /opt/CiscoMGC/etc/CONFIG_LIB on the active MGC. It pushes those directories and files that are different or do not already exist to the standby MGC.

prov-sync
mml> prov-sync 
�� MGC-01 - Media Gateway Controller 2002-10-11 14:32:19.950 
��� MET� 
M� COMPLD� 
�� "PROV-SYNC" 
�� ;

Because this command operates on all provisioning directories, it is important to put a limitation on the number of provisioning directories maintained in /opt/CiscoMGC/etc/CONFIG_LIB. To do this, set the parameter diskmonitor.CfgRmDirs in the XECfgParm.dat file to the maximum number of allowable configurations. (The default value is 64.)

caution Caution: The diskmonitor.CfgRmDirs parameter on the redundant MGC pair must match. Otherwise, functionality and system performance may be adversely affected.

diskmonitor.CfgRmDirs
% grep diskmonitor.CfgRmDirs /opt/CiscoMGC/etc/XECfgParm.dat 
diskmonitor.CfgRmDirs = 64��� # remove old config directories if more 
than X exist (0 = disable)

You should use the /opt/CiscoMGC/local/config-lib utility to remove old or unwanted configurations manually because it does not allow an administrator to accidentally remove the active configuration. If you delete a configuration, you should delete it on both systems, if possible.

config-lib
% cd 
/opt/CiscoMGC/local� 
% config-lib

 � The Configuration File Library Main Menu� 

1. List Configuration Versions in Library� 
2. Save Production to a new Library Version� 
3. Copy Library Version to Production� 
4. Remove Configuration Library Version� 
Enter Selection or 'q' to quit> 4 

�� Configuration Versions� 

1. pomtest19� 
2. 190802-1� 
3. 190802-2� 
4. 190802-3� 
***Current Production Version = pomtest19� 
Enter Selection or 'q' to go back> 1 

Are you sure you want to delete this version (y/n)? y 
Deleting...

prov-dply

The prov-dply command performs the prov-cpy functions in that it makes the provisioned session the active configuration on the current host, but it also pushes that same configuration to the standby. This command operates on only one configuration: the active one.

prov-dply

!--- The prov-dply command needs an active provisioning session.
� 
mml> prov-sta::srcver="active",dstver="pom-test8" 
�� MGC-01 - Media Gateway Controller 2002-10-11 14:41:11.351 MET 
M� COMPLD 
�� "PROV-STA" 
�� ; 
mml> prov-dply 
�� MGC-01 - Media Gateway Controller 2002-10-11 14:41:22.045 MET 
M� COMPLD 
�� "PROV-DPLY" 
�� ;

pom.dataSync

While both prov-sync and prov-dply can only be executed on the active MGC, the pom.dataSync parameter in the XECfgParm.dat file allows the synchronization of provisioning data to be triggered from the standby host. (This leaves unaltered the actual flow of provisioning data from active to standby.)

Default pom.dataSync Setting
% grep pom.dataSync /opt/CiscoMGC/etc/XECfgParm.dat 
pom.dataSync = false�� # don't synch slave data with master

The pom.dataSync parameter indicates that POM on the standby should synchronize its active configuration data files with those of its peer at MGC startup or failover; if different, it should trigger dynamic reconfiguration. Allowable values are:

  • true—POM is enabled; data is synchronized.

  • false—POM is disabled; there is no data synchronization (default).

If you have a standalone MGC, set this value to false. If you have two MGC hosts in a failover configuration, set this value to true on both hosts to accommodate failover conditions in which the current active host can become the standby host.

When the initial MGC configuration on the active host is deployed, you must change the pom.dataSync parameter to true in the XECfgParm.dat file on the standby host. After setting this parameter to true, you can start the MGC on the standby host. As the MGC comes up, the data on the standby host is synchronized with the data on the active host. The standby host then goes into the standby state.

This parameter operates on only one configuration: the active one.

Note: During the upgrade of a redundant MGC configuration, verify that the pom.dataSync parameter is set to false on the standby host prior to booting the upgraded software. Also, do not forget to change the setting back to true once the peer host has been upgraded successfully as well.

Note: If you set pom.dataSync to false, it does not disable synchronization of provisioning data through the use of prov-dply or prov-sync.

Troubleshoot

When provisioning synchronization fails, the failure reported by prov-sync or prov-dply in MML is usually not very informative.

The first thing to do (preferably on the host that will be standby) is to verify whether any error messages popped up in the /opt/CiscoMGC/var/log/platform.log file at the time of synchronization. Another option is to use tail -f /opt/CiscoMGC/var/log/platform.log to look in real time at the log file during synchronization.

In particular, search the log file for messages containing the strings pomMgr or XEFileService.

File Ownership and Permissions

Provisioning synchronization compares file attributes (name, size, and time of last modification) and transfers the files for which the attributes do not match. However, the files must be accessible first. If POM has trouble processing certain files or directories, it should be apparent from relevant error messages in the platform.log file.

prov-sync Fails Due to Incorrect Directory Permissions on Standby Host

!--- POM retrieved the CFG_pom-test1/accRespCat.dat file� 
!--- from the peer and stored a temporary copy. When� 
!--- it attempted to move the file to its final destination  
!--- (the�CFG_pom-test1 directory), it failed because� 
!--- permissions on the destination directory were�incorrect.

% pwd 
/opt/CiscoMGC/var/log 
% tail -f platform.log 

Mon Oct 14 12:27:01:708 2002 WET | ProvObjectManager (PID 10788)� 
XEFileService::tftp_endReceived: Error on rename: temp file is: 
/tmp/.tftptmpaccRespCat.dat.tftp� 
file to write to is: /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pom-test1/accRespCat.dat 

Mon Oct 14 12:27:01:708 2002 WET | ProvObjectManager (PID 10788) <Error> 
XEFileService::tftp_endReceived: temporary file rename error 13
!--- Error 13 indicates permission denied. See� 
!--- /usr/include/sys/errno.h for more information. 


Mon Oct 14 12:27:01:750 2002 WET | ProvObjectManager (PID 10788) <Error> 
GEN_ERR_XFER_FILE: pomMgr::fileXferCallback: file transfer failed for 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pom-test1, status = 2 

!--- Status 2 indicates failure.

File access is determined by file ownership and file permission modes. Because most MGC processes (including POM) run under user ID mgcusr, data files and those directories holding them should belong to user ID mgcusr and group ID mgcgrp. Furthermore, permission modes for data files should allow read and write access to mgcusr and mgcgrp. Directories containing these data files should include eXecute permission for mgcusr and mgcgrp as well.

Correct File/Directory Permissions and Ownership
% ls -ld /opt/CiscoMGC/etc 
drwxrwxr-x�� 5 mgcusr�� mgcgrp� 2048 Oct 18 14:57 
/opt/CiscoMGC/etc 

!--- If you see "drwxrwx---" instead of "drwxrwxr-x"�on a 
!--- CFG_ directory, it has been polled from the�peer host by POM.
!--- This one, however, has been provisioned locally.

% ls -ld /opt/CiscoMGC/etc/CONFIG_LIB/CFG_* 
drwxrwxr-x�� 2 mgcusr�� mgcgrp� 1536 Oct 13 10:13 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1 

!--- Output suppressed.


!--- Any data file should belong to mgcusr/mgcgrp� 
!--- and be readable and writable for both mgcusr 
!--- and mgcgrp. Depending on whether the file was� 
!--- retrieved by POM or locally created, the� 
!--- last three permission bits can be "rw-" or "r--".
 
% ls -l /opt/CiscoMGC/etc/*.dat 
-rw-rw-rw-�� 1 mgcusr�� mgcgrp��� 58 Oct� 3 16:42 
/opt/CiscoMGC/etc/accRespCat.dat 

!--- Output suppressed.
 
-rw-rw-rw-�� 1 mgcusr�� mgcgrp 7 Dec 13� 2001 
/opt/CiscoMGC/etc/version.dat 
-rw-rw-r--�� 1 mgcusr�� mgcgrp 16164 Oct� 8 16:15 
/opt/CiscoMGC/etc/XECfgParm.dat

Note: In a redundant MGC configuration, you may notice that data file and CFG_ directory permissions for the Others category (the three right-most permission bits) vary. The permissions may vary from Read and Execute permission to No permissions for CFG_ directories, and from Read and Write permission to only Read permission for data files. This usually depends on whether the file/directory was created locally or was retrieved from the peer host by POM. The most significant file permissions are those for the user and group (mcgusr and mgcgrp).

Note: When you verify file ownership and permissions for data files of the active configuration, remember to verify both locations where these data files are kept: in /opt/CiscoMGC/etc and in the CFG_ directory pointed to by /opt/CiscoMGC/etc/active_link. In a VSC configuration, remember to verify dial plan data files ending with .bin and .dialPlan filename extensions in /opt/CiscoMGC/dialPlan/ and in the CFG_ directories.

If file permissions do not appear to be correct, they may have been manually changed by accident, or the umask value for mgcusr may no longer be correct. The umask value determines the file permissions creation mask for the user shell execution environment. By default, it is configured in /opt/CiscoMGC/local/.cshrc and should equal 2.

Verifying mgcusr umask Setting

!--- The mgcusr belongs to mgcgrp.
 
mgcusr@demask% id 
uid=20000(mgcusr)gid=20000(mgcgrp)� 

!--- This shows the current umask. 

mgcusr@demask% umask 
2 

!--- This is the default umask for the mgcusr shell� 
!--- execution environment.
 
mgcusr@demask% grep umask /opt/CiscoMGC/local/.cshrc 
umask 002

Usually, you should not change file permissions and file ownership manually. If necessary, however, this shows how to restore values back to normal:

Restoring File/Directory Permissions and Ownership

!--- Caution: The following commands must be issued with� 
!--- root privileges. This makes all .dat files 
!--- in /opt/CiscoMGC/etc�owned and readable/writable by
!--- mgcusr and mgcgrp, as well as readable to others. 

# pwd 
/opt/CiscoMGC/etc 
# chown mgcusr:mgcgrp *.dat 
# chmod ug+rw,o+r *.dat 

!--- This does the same for all .dat files in all� 
!--- /opt/CiscoMGC/etc/CONFIG_LIB/CFG_* directories with use of� 
!--- the recursive (-R) operator. 

# pwd 
/opt/CiscoMGC/etc/CONFIG_LIB 
# chown -R mgcusr:mgcgrp CFG_* 
# chmod -R ug+rw,o+r CFG_*/*.dat 

!--- This sets the permissions on the CFG_ directories 
!--- themselves right.
 
# chmod ug+rwx,o+rx CFG_* 

!--- The commands below are only needed when using the 
!--- MGC in a VSC configuration.
 
# chmod -R ug+rw,o+r CFG_*/*.bin 
# chmod -R ug+rw,o+r CFG_*/*.dialPlan 

# pwd 
/opt/CiscoMGC 
# chown -R mgcusr:mgcgrp dialPlan
# chmod -R ug+rw,o+r dialPlan/*.*

Note: If you are unsure about file permissions and ownership, view /opt/CiscoMGC/etc/CONFIG_LIB/new. This directory contains the minimum data files required to configure the MGC. These are the data files that an initial installation of the MGC application uses. Users that wish to provision the MGC from scratch can use this directory as the source.

Apart from incorrect file/directory ownership and permissions, there are some other potential issues. They are discussed below.

Timeouts

For large configurations or during periods of high network usage, the prov-dply and prov-sync commands may time out and should be reexecuted. Preferably, this is done when network usage has decreased, or, in the case of a prov-sync timeout, after unwanted configurations have been removed with the config-lib utility.

File Transfer Timeout

!--- This error was seen in platform.log when prov-sync 
!--- was issued on several CFG_ directories at once.
 
Fri Oct 18 22:45:52:890 2002 WET | ProvObjectManager (PID 8791) <Error> 
GEN_ERR_XFER_FILE: pomMgr::fileXferCallback: 
file transfer failed for /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7,status = 3
 

!--- Status 3 indicates timeout.

If you need to make repeated attempts to complete the synchronization successfully, you may also be running into the Network Problems described below.

Network Problems

Layer 1

Layer 1 network problems can prevent file transfers from completing successfully. Since POM uses TFTP over Reliable User Data Protocol (RUDP) for actual file transfers, look at the platform.log file for RUDP- and TFTP-related errors.

The UNIX command netstat -i allows you to verify if any input or output errors or any collisions have occurred on the Ethernet connections. Typically, you should compare its output taken before the provisioning synchronization, and again after the provisioning synchronization. A common problem is mismatched Ethernet duplex settings between network hosts and switches. You should not have any collisions when working in full duplex; that is typically the way you want to work.

prov-sync Fails Due to Mismatched Ethernet Duplex Settings Between MGC and Catalyst Ethernet Switch
% netstat -i
Name� Mtu� Net/Dest� Address��� Ipkts Ierrs Opkts� Oerrs Collis Queue 
lo0�� 8232 loopback� localhost� 48276� 0 48276� 0 0� 0 
hme0� 1500 demask��� demask 5752225 0 4761967 0 0� 0 
hme1� 1500 demask1�� demask1��� 5339378 2 5132615 243� 2430�� 0 

% mml 

Copyright © 1998-2001, Cisco Systems, Inc. 

Session 1 is in use, using session 3 
mml> prov-sync 
�� MGC-01 - Media Gateway Controller 2002-10-14 18:58:10.099 MET 
M� DENY 
�� SROF 
� "PROV-SYNC: error transferring data files 
This may due to large number of files being transferred. 
You can re-invoke this command." 
�� /* Status, Requested Operation Failed on the component */ 
�� ; 
mml> quit 
% netstat -i 
Name� Mtu� Net/Dest� Address��� Ipkts Ierrs Opkts� Oerrs Collis Queue 
lo0�� 8232 loopback� localhost� 48276� 0 48276� 0 0� 0 
hme0� 1500 demask��� demask 5753323 0 4763036 0 0� 0 
hme1� 1500 demask1�� demask1��� 5340413 2 5133272 327� 2607�� 0 

!--- When you check the platform.log file, the messages below� 
!--- appear repeatedly. 

Mon Oct 14 18:58:10:178 2002 MEST | ProvObjectManager (PID 16151) <Error> 
file /vobs/NSSU_Main/lib_src/rudp/src/rudp_api.cpp, 
line 963: Error - send window full: No buffer space available(132) 

Mon Oct 14 18:58:10:264 2002 MEST | ProvObjectManager (PID 16151) <Error> 
XEFileService::tftp_ackReceived: block number out of 
synch. Send error message to peer

If your equipment is connected to a Cisco Catalyst switch, you can use the show port and set port commands to view and change port settings.

To examine or set a specific Ethernet interface on the MGC, specify it as follows:

# ndd -set driver instance #

Note: The variable driver can be /dev/hme, /dev/qfe, or /dev/eri, depending on the type of network card. The variable # is the interface number.

To examine parameter values, use the ndd -get command. In particular, link_speed reveals whether the interface is operating in 10 Mbps or 100 Mbps mode (settings of 0 and 1, respectively); link_mode reveals whether it is running at half or full duplex (0 and 1, respectively).

ndd -get /dev/hme link_speed 
ndd -get /dev/hme link_mode

To perform a hard set of the link_speed and link_mode parameters for hme#, several other parameters must be set with the ndd -set command. In these parameter names, 10 or 100 refers to link_speed, fdx or hdx refers to link_mode, and autoneg refers to autonegotiation capability. The setting corresponding to the desired mode should be set to 1 and all other parameters should be set to 0. (An adv_autoneg_cap of 1 is the default.) For example, to set hme# to 100/full duplex, use:

ndd -set /dev/hme instance #
 
ndd -set /dev/hme adv_100T4_cap 0 
ndd -set /dev/hme adv_100fdx_cap 1 
ndd -set /dev/hme adv_100hdx_cap 0 
ndd -set /dev/hme adv_10fdx_cap 0 
ndd -set /dev/hme adv_10hdx_cap 0 
ndd -set /dev/hme adv_autoneg_cap 0

The ndd -set commands can be used in the /etc/rc2.d/S69inet initialization script to set the interface mode during boot, rather than allowing autonegotiation. This can be useful if one of the interfaces is connected to an older switch that is not autonegotiating the line speed or mode correctly. To list all parameters supported by the network card driver, use:

ndd driver \?

The line speed and mode can also be set for all Ethernet interfaces on the system if you set the following in the /etc/system file and reboot:

  • 100 Mb, full duplex:

    set hme:hme_adv_autoneg_cap=0 
    set hme:hme_adv_100fdx_cap=1
    
  • 100 Mb, half duplex:

    set hme:hme_adv_autoneg_cap=0 
    set hme:hme_adv_100fdx_cap=0 
    set hme:hme_adv_100hdx_cap=1
    
  • 10 Mb, full duplex:

    set hme:hme_adv_autoneg_cap=0
    set hme:hme_adv_100fdx_cap=0 
    set hme:hme_adv_100hdx_cap=0 
    set hme:hme_adv_10fdx_cap=1 
    set hme:hme_adv_10hdx_cap=0
    
  • 10 Mb, half duplex:

    set hme:hme_adv_autoneg_cap=0 
    set hme:hme_adv_100fdx_cap=0 
    set hme:hme_adv_100hdx_cap=0 
    set hme:hme_adv_10fdx_cap=0 
    set hme:hme_adv_10hdx_cap=1
    

Upper Layers

On a higher layer, POM uses User Datagram Protocol (UDP) port 4001 for signaling and UDP port 4002 for actual TFTP file transfers. These ports are default values, controlled by the pom.port parameter in XECfgParm.dat. Normal POM port states for a redundant pair of MGCs are shown here:

POM UDP Ports
mgcusr@demask% grep pom.port XECfgParm.dat 
pom.port = default��� # use port 4001 when set to 
default 

mgcusr@demask% netstat -a | egrep .400\[0-9\] 

!--- UDP port 4001 is used for POM signaling. 

demask.4001� mgc-bru-3a.cisco.com.4001�� Connected 
demask1.4001 10.48.85.65.4001�� Connected 

!--- UDP port 4002 is used for POM TFTP file transfers. 

demask.4002 Idle 
demask1.4002��� Idle

prov-sync Fails

Besides these guidelines, there are some guidelines that are specific to prov-sync. The prov-sync command is the only synchronization method that goes through all CFG_ directories. If it fails, you should verify whether prov-dply works instead because prov-dply only operates on the active configuration. If prov-dply works and prov-sync does not, the problem may be with any of the CFG_ directories except the active one.

In this case, check file and directory attributes on the CFG_ directories. Verify that the diskmonitor.CfgRmDirs parameter in the XECfgParm.dat file is set and matched on both hosts. Also, verify that the actual number of CFG_ directories stored is less than or equal to the value set in diskmonitor.CfgRmDirs.

Try to remove obsolete configurations with use of the /opt/CiscoMGC/local/config-lib utility. Be sure you delete them on both systems, if they are available on both.

Verify diskmonitor.CfgRmDirs

!--- Verify the diskmonitor.CfgRmDirs setting. 

% grep -i cfgrmdir /opt/CiscoMGC/etc/XECfgParm.dat 
diskmonitor.CfgRmDirs = 64��� # remove old config 
directories if more than X exist (0 = disable) 

!--- Count the number of CFG_ directories currently stored.

% pwd 
/opt/CiscoMGC/etc/CONFIG_LIB 
% ls -ld CFG_* | wc -l 64
!--- There are 64 directories.

Standby MGC Out-of-Service After Startup or Failover

A failure in data synchronization during startup or failover causes the standby to remain Out-of-Service (OOS) until the issue is resolved.

There are different reasons why the standby host remains OOS. Complete these steps to determine if the problem is with provisioning synchronization:

  1. Temporarily, set the pom.dataSync parameter in XECfgParm.dat to false.

  2. Reboot the MGC application.

  3. Verify if the host goes into standby mode this time.

If it does, provisioning synchronization is likely to be the problem. You should proceed to check the logs and verify file ownership and permissions for the active configuration, as explained in the section File Ownership and Permissions.

If the issue happened after you upgraded the MGC software or patch level, it is possible that after the upgrade of the standby, but before the upgrade of the active host, the standby was booted with pom.dataSync set to true. This causes POM to retrieve the old data files from the active host. It means that the upgraded software on the standby host tries to run with old data files. The format of the old data files may or may not be compatible with the new data files, which depends on the compatibility level between both versions of software. This would not present a problem if you performed prov-sync before the upgrade and set pom.dataSync to false before you booted the upgraded host. Set pom.dataSync back to true when both hosts have been successfully upgraded.

The safest way to recover from this situation is to revert to the previous release or patch level, and follow the correct procedure in a second attempt.

Debug

For issues with provisioning synchronization, the process of interest is POM. You can debug POM on the active host, the standby host, or on both. However, it is typically best to debug such issues on the host that will be standby.

How to Debug

Follow this procedure to debug issues with prov-sync and prov-dply (on the standby host):

  1. Execute the /opt/CiscoMGC/bin/log_rotate.sh script to start with a clean platform.log file.

  2. In MML, issue set-log:pom-01:debug,confirm to set the logging level for the POM-01 process to debug.

  3. On the active host, issue the prov-sync or prov-dply command.

  4. After the command has completed, issue the command set-log:pom-01:err to set the POM-01 logging level back to normal (err).

  5. Verify that the debug messages have been stored in the /opt/CiscoMGC/var/log/platform.log file.

    Note: Debug messages are marked by a trailing <Debug> string.

For pom.dataSync issues upon startup, follow this procedure (on the standby host):

  1. Issue /etc/init.d/CiscoMGC stop to stop the MGC application.

  2. Add the parameter pom.logPrio to the XECfgParm.dat file, and set it to Debug.

    pom.logPrio set to Debug
    % grep pom.logPrio /opt/CiscoMGC/etc/XECfgParm.dat 
    pom.logPrio = Debug
    

  3. Execute the /opt/CiscoMGC/bin/log_rotate.sh script to start with a clean platform.log file.

  4. Issue /etc/init.d/CiscoMGC start to start the MGC application.

  5. Wait until the host has gone into standby mode.

    To verify this, issue rtrv-ne in MML. If the problem is that the standby remains OOS, allow the debug to run long enough to capture the problem.

  6. In MML, issue set-log:pom-01:err to disable POM debugging.

  7. Remove the line pom.logPrio = Debug from the XECfgParm.dat file, or comment it out by placing the character # in front of it.

  8. Verify that the debug messages have been stored in the /opt/CiscoMGC/var/log/platform.log file.

The procedure to debug issues with pom.dataSync upon failover is nearly the same as it is for prov-sync and prov-dply. The only differences are that you execute all steps on the host that will fail over (the current active host) and that, instead of using the prov-sync or prov-dply commands, you should issue the command or action that will trigger the failover.

caution Caution: Be careful when you debug such an issue. It is possible that the configuration of both MGCs is no longer in synchronization, and the setup may fail over to an undesired configuration.

Note: The POM-01 debug can be quite verbose. Enable it just before you issue the command that triggers the synchronization, and disable it immediately after command completion. It is best not to enable the debug during high system load.

Debug POM-01 (Shown on Active Host)
% /opt/CiscoMGC/bin/log_rotate.sh% mml 

Copyright © 1998-2001, Cisco Systems, Inc. 

mml> set-log:pom-01:debug,confirm 
�� MGC-01 - Media Gateway Controller 2002-10-13 16:00:37.401 MET 
M� COMPLD 
�� "POM-01" 
�� ; 
mml> prov-sync 
�� MGC-01 - Media Gateway Controller 2002-10-13 16:00:42.190 MET 
M� COMPLD 
�� "PROV-SYNC" 
�� ; 
mml> set-log:pom-01:err 
�� MGC-01 - Media Gateway Controller 2002-10-13 16:00:47.870 MET 
M� COMPLD 
�� "POM-01" 
�� ; 
mml> quit 
% ls -l /opt/CiscoMGC/var/log/platform.log 
-rw-rw-r--�� 1 mgcusr�� mgcgrp� 499028 Oct 13 16:00 
/opt/CiscoMGC/var/log/platform.log

What to Look For

After the debug information has been logged to a file, search the file for lines containing pomMgr and XEFileService. There are many other messages collected, but these two are the most interesting and informative. To see the dynamic reconfiguration as a result of synchronization, you can also search for XETable and cfgEventHandler.

To identify problems with file transfers, search for lines containing tftp and operationStatus. (See the (operation) Status table.) The response status (resp status) value sent back to the peer also can be of help. It reflects the POM status code.

prov-sync Fails Due to Incorrect Permissions on Directory CFG_pom-test1 on Standby Host
Mon Oct 14 12:27:01:750 2002 WET | ProvObjectManager 
(PID 10788) <Debug> 
pomMgr::fileXferCallback: Entering with path = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pom-test1, 
operationStatus = 2
 

!--- Status 2 indicates failure. 

Mon Oct 14 12:27:01:751 2002 WET | ProvObjectManager 
(PID 10788) <Debug> 
pomMgr::sendPeerMsg: sending msg type 101, subtype 
709, 
resp status 2021
 

!--- This status indicates an error in file transfer.

Examples

Note: Only the most informative debug messages are shown. Others are omitted, especially RUDP messages.

prov-sync

This example shows the results of prov-sync as seen on the standby host, with one complete directory that needs transfer (CFG_pomtest20):

prov-sync

!--- The active MGC is 10.48.84.24.
!--- The standby MGC is 10.48.84.65. 
!--- The active configuration is CFG_pomtest7.

Sun Oct 20 16:07:09:707 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
UDP recv() 193 bytes from 10.48.84.24:4001 10.48.84.65 (fd=9)� 

!--- This is the default pom.port (UDP port 4001).


!--- The synchronization request is received from the peer.
� 
Sun Oct 20 16:07:09:707 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::handleEvent:Received Evt 100, Msg. Type 709 

!--- This indicates POM_REQ_T and POM_PEER_SYNC_MT.

Sun Oct 20 16:07:09:707 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. Platform state = 2.� 

!--- This indicates platform state 2 (standby).� 

Sun Oct 20 16:07:09:707 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. instandby box,mgrState= 1 

!--- This indicates POM mgrState 1 (READY). 

Sun Oct 20 16:07:09:707 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData: Starting Warmstart.� 

Sun Oct 20 16:07:09:710 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData: NOW� initiating file transfer for multiple� directories� 

Sun Oct 20 16:07:09:711 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::transferFile called by the application ,localpath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1: remotepath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1: filename CFG_pomtest1� 

!--- Output suppressed.

Sun Oct 20 16:07:09:711 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
In XEFileService::bftfrSndHandShake()� 

!--- The "bftfr" indicates before transfer.

Sun Oct 20 16:07:09:711 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
bftfrSndHandShake():paths as received in bftfr are: localPath: 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� remote path:� 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 

Sun Oct 20 16:07:09:711 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake , after strcpy: localPath = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 
, remote path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 
filename = CFG_pomtest1� 

Sun Oct 20 16:07:09:712 2002 WET | ProvObjectManager (PID 11017) <Info>� 
XEFileService::countFilesInDir(): no. of files in the directory 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1 is 55� 

Sun Oct 20 16:07:09:715 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::getDirAttributes(): success� 

Sun Oct 20 16:07:09:715 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake - Dir:total number of characters to be sent = 1822� 

Sun Oct 20 16:07:09:716 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::transferFile called by the application ,localpath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2: remotepath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2: filename CFG_pomtest2� 

!--- Output suppressed: the previous message is repeated for each�� 
!--- CFG directory found; CFG_pomtest1 to CFG_pomtest7�and CFG_pomtest20.
 
Sun Oct 20 16:07:09:717 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData total count attempted = 8� 

!--- POM has found 8 CFG_ directories.

Sun Oct 20 16:07:09:717 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData: successfully initiated file transfer for 8 directories� 

!--- For each CFG directory, POM checks to determine
!--- if files need to be transferred.

Sun Oct 20 16:07:09:741 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::checkReqResult: Entering with requestTransfer = 1� 

Sun Oct 20 16:07:09:741 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::checkReqResult:setting transferState to (FREE)� 

Sun Oct 20 16:07:09:741 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::fileXferCallback: Entering with path = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1, operationStatus = 4� 

!--- This indicates operationStatus 4 (no_need_to_transfer).

Sun Oct 20 16:07:09:843 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. Platform state = 2.� 

Sun Oct 20 16:07:09:843 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. instandby box,mgrState= 6 

!--- This indicates POM mgrState 6 (XFER_WAIT). 


!--- Subtype 713 (POM_RESTART_RESP_TIMER_MT) indicates that POM� 
!--- is still working on the last command and has yet to finish.
� 
Sun Oct 20 16:07:09:843 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 100, subtype 713, resp status 0 

Sun Oct 20 16:07:09:843 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
UDP send() 62 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=62� 

Sun Oct 20 16:07:09:843 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData: Ending Warmstart.� 

!--- Output suppressed: the above messages are repeated for every� 
!--- CFG directory. Because only CFG_pomtest1 and CFG_pomtest1� 
!--- need to be transferred, only those are shown here.


!--- CFG_pomtest7 is the active configuration.

Sun Oct 20 16:07:10:542 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
bftfrSndHandShake():paths as received in bftfr are: localPath: 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7� remote path:� 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7� 

Sun Oct 20 16:07:10:542 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake , after strcpy: localPath = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7� 
, remote path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7� 
filename = CFG_pomtest7� 

Sun Oct 20 16:07:10:543 2002 WET | ProvObjectManager (PID 11017) <Info>� 
XEFileService::countFilesInDir(): no. of files in the directory 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7 is 55� 

Sun Oct 20 16:07:10:545 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::getDirAttributes(): success� 

Sun Oct 20 16:07:10:546 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake - Dir:total number of characters to be sent = 1822� 

Sun Oct 20 16:07:10:573 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::hndShakeCallBack- In Handshake� count as Int is 1� 

Sun Oct 20 16:07:10:573 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::hndShakeCallBack- Message Type in hndShakeCallBack is N� 

!--- "N" indicates not matched. 


!--- CFG_pomtest7/components.dat did not match and is read� 
!--- via TFTP from the peer. 

Sun Oct 20 16:07:10:573 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::tftp_readfile- accessing current entry in the directory file list: 
components.dat

!--- The "aftfr" indicates after transfer. 

Sun Oct 20 16:07:10:923 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::aftfrSndHandShake():localpath:
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7, 
�� remotepath:/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7� 

Sun Oct 20 16:07:10:924 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::getFileAttributes(): for 
file:/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7/components.dat succeeded� 

!--- The operationStatus 5 indicates file_integrity_success. 

Sun Oct 20 16:07:10:936 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::fileXferCallback: Entering with path = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7, operationStatus = 5� 

!--- Output suppressed.

Sun Oct 20 16:07:11:002 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
In XEFileService::bftfrSndHandShake()� 

!--- CFG_pomtest20 is not present on standby and needs to be� 
!--- transferred completely.

Sun Oct 20 16:07:11:002 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
bftfrSndHandShake():paths as received in bftfr are: localPath: 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� remote path:� 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� 

Sun Oct 20 16:07:11:002 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake , after strcpy: localPath = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� 
, remote path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� 
filename = CFG_pomtest20� 

Sun Oct 20 16:07:11:002 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::bftfrSndHandShake()-param->general.count < = 0 for case get_dir� 

Sun Oct 20 16:07:11:011 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::hndShakeCallBack- In Handshake� count as Int is 55� 

Sun Oct 20 16:07:11:011 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::hndShakeCallBack- Message Type in hndShakeCallBack is N� 

!--- "N" indicates not matched.� 
!--- At this point, each data file in CFG_pomtest20 is� 
!--- transferred by TFTP to the standby.
� 
Sun Oct 20 16:07:11:011 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::tftp_readfile- accessing current entry in the directory file list: 
accRespCat.dat 

!--- Output suppressed: the previous message is repeated for� 
!--- every data file; 55 in total.

Sun Oct 20 16:07:22:763 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::aftfrSndHandShake():localpath:
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20, 
�� remotepath:/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20� 

Sun Oct 20 16:07:22:763 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XEFileService::getFileAttributes(): for 
file:/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20/accRespCat.dat succeeded� 

!--- Output suppressed: the previous message is repeated for� 
!--- every data file; 55 in total. 

Sun Oct 20 16:07:22:838 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::fileXferCallback: Entering with path = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest20, operationStatus = 5� 

Sun Oct 20 16:07:22:895 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. Platform state = 2.� 

Sun Oct 20 16:07:22:895 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. instandby box,mgrState= 6�

!--- Symbolic link /opt/CiscoMGC/etc/active_link is created.� 

Sun Oct 20 16:07:22:897 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::setupActvLink. Set link to [/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7].
!--- Symbolic link /opt/CiscoMGC/etc/prov_link is created.�
 
Sun Oct 20 16:07:22:900 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::setupProvLink. Set link to [/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7].

!--- Data files of the active configuration are copied� 
!--- to /opt/CiscoMGC/etc.�
 
Sun Oct 20 16:07:22:927 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::prepareActvFiles. Executing command [cp -p 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest7/[a-z]*.dat /opt/CiscoMGC/etc/].� 

!--- Dynamic reconfiguration:�reload changed objects from files into � 
!--- memory-resident maps and destroy superseded versions.� 
!--- delCnt, updCnt, insCnt, and purge count show the number� 
!--- of objects that need "change".

Sun Oct 20 16:07:23:164 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XETable::reload: validation = 0, process = ProvObjectManager, table = components, delCnt 
= 0, updCnt = 0, insCnt = 0� 

Sun Oct 20 16:07:23:165 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::sendUpdateRequest: reloading components� 

Sun Oct 20 16:07:23:165 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
XETable::purge: validation = 1, process = ProvObjectManager, table = components, purge 
count = 0� 

!--- Output suppressed: the previous three messages are� 
!--- repeated for every XETable. 

Sun Oct 20 16:07:23:711 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 100, subtype 713, resp status 0� 

Sun Oct 20 16:07:23:712 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
UDP send() 62 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=62� 

Sun Oct 20 16:07:23:712 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData: Ending Warmstart.� 

Sun Oct 20 16:07:23:714 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::peerSyncProvData. peer 0� 

!--- An indication is sent to the peer that POM synchronization� 
!--- was successful.
� 
Sun Oct 20 16:07:23:716 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 101, subtype 709, 
resp status 0
 

!--- This indicates POM_RSP_T and POM_PEER_SYNC_MT.
� 
Sun Oct 20 16:07:23:716 2002 WET | ProvObjectManager (PID 11017) <Debug>� 
UDP send() 62 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=62

prov-dply

This debug output shows the results of prov-dply as seen on the standby host after the description of one destination point code (DPC) component had been changed:

prov-dply

!--- The active MGC is 10.48.84.24.
!--- The standby MGC is 10.48.84.65.
!--- The deployed configuration is CFG_pomtest2.
 
Sun Oct 13 11:42:23:481 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
UDP recv() 76 bytes from 10.48.84.24:4001 10.48.84.65 (fd=9)� 

!--- A deploy request is received from the peer.
 
Sun Oct 13 11:42:23:481 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::handleEvent: Received Evt 100, Msg. Type 708 

!--- This indicates POM_REQ_T and POM_PEER_DEPLOY_MT. 

Sun Oct 13 11:42:23:481 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::handlePOMEvt: type 100� 

Sun Oct 13 11:42:23:483 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::transferFile called by the application ,localpath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2: remotepath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2: filename CFG_pomtest2� 

!--- Output suppressed.
 
Sun Oct 13 11:42:23:483 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
In XEFileService::bftfrSndHandShake()� 

Sun Oct 13 11:42:23:483 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
bftfrSndHandShake():paths as received in bftfr are: localPath: 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2� remote path:� 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2� 

Sun Oct 13 11:42:23:484 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::bftfrSndHandShake , after strcpy: localPath = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2� 
, remote path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2� 
filename = CFG_pomtest2� 

Sun Oct 13 11:42:23:484 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::bftfrSndHandShake()-param->general.count < = 0 for case get_dir� 

Sun Oct 13 11:42:23:545 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::hndShakeCallBack- In Handshake� count as Int is 55� 

Sun Oct 13 11:42:23:546 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::hndShakeCallBack- Message Type in hndShakeCallBack is N� 

!--- "N" indicates not matched. 

Sun Oct 13 11:42:23:546 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::tftp_readfile- accessing current entry in the directory file list: 
accRespCat.dat� 

!--- Output suppressed: the previous message is repeated for every� 
!--- .dat file transferred by TFTP; 55 files. 

Sun Oct 13 11:42:35:998 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::aftfrSndHandShake():localpath:
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2,remotepath: 
�� /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2� 

Sun Oct 13 11:42:35:999 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XEFileService::getFileAttributes(): for 
file:/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2/accRespCat.dat succeeded� 

!--- Output suppressed: the previous message is repeated for each� 
!--- .dat file; 55 files. 

Sun Oct 13 11:42:36:031 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::fileXferCallback: Entering with path = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2, operationStatus = 5 

!--- The operationStatus 5 indicates file_integrity_success.
 
Sun Oct 13 11:42:36:271 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::peerDeployProvData. Copying data files [/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest2].� 

!—-- Copy .dat files to /opt/CiscoMGC/etc. 

Sun Oct 13 11:42:36:296 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::prepareActvFiles. Executing command [cp -p /opt/CiscoMGC/etc/CONFIG_LIB/
CFG_pomtest2/[a-z]*.dat /opt/CiscoMGC/etc/].� 

Sun Oct 13 11:42:36:455 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::UpdateHdlr: sending update notification components� 

Sun Oct 13 11:42:36:455 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
cfgEventHandler: sending update notification for components� 

!--- Dynamic reconfiguration: updCnt is 1 for the components table 
!--- because one DPC�component was changed.

Sun Oct 13 11:42:36:459 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XETable::reload: validation = 0, process = ProvObjectManager, table = 
components, delCnt = 0, updCnt = 1, insCnt = 0� 

Sun Oct 13 11:42:36:462 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::sendUpdateRequest: reloading components� 

Sun Oct 13 11:42:36:462 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
XETable::purge: validation = 1, process = ProvObjectManager, table = components, 
purge count = 1 

!--- Output suppressed: the previous three messages are repeated� 
!--- for every XETable. 


!--- An indication is sent to the peer that POM DEPLOY was successful.

Sun Oct 13 11:42:37:351 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 101, subtype 708, 
resp status 0
 

!--- This indicates POM_RSP_T and POM_PEER_DEPLOY_MT.
 
Sun Oct 13 11:42:37:352 2002 WET | ProvObjectManager (PID 15141) <Debug>� 
UDP send() 62 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=62

pom.dataSync on Startup

This debug output shows pom.dataSync on startup:

pom.dataSync

!--- The active MGC is 10.48.84.24.
!--- The standby MGC is 10.48.84.65.

Tue Oct 15 22:17:15:572 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::initialize: starting ...� 

!--- Output suppressed. 


Tue Oct 15 22:17:16:960 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::signalCallback: link1 state = 2, link2 state = 1� 

!--- The link states are defined in this way: 0 is down, 
!--- 1 is up, 2 is start, and 3 is invalid. 
!--- Output suppressed. 
 
Tue Oct 15 22:17:16:987 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::signalCallback: link1 state = 1, link2 state = 1� 

!--- Output suppressed. 
 
Tue Oct 15 22:17:17:003 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomProcEvtHdlr:� heartbeat...� 

!--- Output suppressed. 
 
Tue Oct 15 22:17:42:024 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomProcEvtHdlr::handleGoStandbyLocal - POM is trying to switch the its role to Standby.� 

!--- A PEER_SYNC request is sent to the peer. 
!--- This is different from prov-sync, in which the request� 
!--- would be received from the peer.
 
Tue Oct 15 22:17:42:026 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 100, subtype 709, resp status 0� 

!--- This indicates POM_REQ_T and POM_PEER_SYNC_MT.

Tue Oct 15 22:17:42:026 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
UDP send() 279 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=279� 

Tue Oct 15 22:17:42:043 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
UDP recv() 281 bytes from 10.48.84.24:4001 10.48.84.65 (fd=9)� 

Tue Oct 15 22:17:42:043 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
formatted read from 10.48.84.24:4001 10.48.84.65 (fd=9), event type 101� 

Tue Oct 15 22:17:42:043 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::handleEvent: Received Evt 101, Msg. Type 709 

!--- This indicates POM_RSP_T and POM_PEER_SYNC_MT. 

Tue Oct 15 22:17:42:044 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData. Platform state = 2.� 

!--- A platform state 2 indicates standby. 

Tue Oct 15 22:17:42:044 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData. instandby box,mgrState= 4 

!--- This indicates PEER_WAIT.

Tue Oct 15 22:17:42:044 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData: Starting Warmstart.� 

Tue Oct 15 22:17:42:047 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData: Initiate active-version filexfer.� 

Tue Oct 15 22:17:42:047 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::transferFile called by the application ,localpath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1: remotepath 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1: filename CFG_pomtest1� 

Tue Oct 15 22:17:42:047 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::transferFile: transfer state is FREE, going to serveReqFromQueue� 

Tue Oct 15 22:17:42:048 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::serveReqFromQueuesetting transferState to (OCCUPIED)� 

Tue Oct 15 22:17:42:048 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::serveReqFromQueuesetting requestTransfer to (YES)� 

Tue Oct 15 22:17:42:048 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
In XEFileService::bftfrSndHandShake()� 

!--- In the output below, the active�configuration directory 
!--- (CFG_pomtest1) is perused in search of�nonmatching files.
 
Tue Oct 15 22:17:42:048 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
bftfrSndHandShake():paths as received in bftfr are: localPath: 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� remote path:� 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 

Tue Oct 15 22:17:42:048 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::bftfrSndHandShake , after strcpy: localPath = 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 
, remote path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 
filename = CFG_pomtest1� 

Tue Oct 15 22:17:42:049 2002 WET | ProvObjectManager (PID 1764) <Info>� 
XEFileService::countFilesInDir(): no. of files in the directory 
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1 is 55� 

Tue Oct 15 22:17:42:053 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::getDirAttributes(): success� 

Tue Oct 15 22:17:42:053 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::bftfrSndHandShake - Dir:total number of charaters to be sent = 1822� 

Tue Oct 15 22:17:42:055 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData file xfer = CFG_pomtest1� 

!--- One directory has been searched.
!--- This is different from MML prov-sync, which would have� 
!--- searched through all CFG directories. 

Tue Oct 15 22:17:42:055 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData: successfully initiated file transfer for 1 directories� 

Tue Oct 15 22:17:42:069 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::hndShakeCallBack- In Handshake� count as Int is 1� 

Tue Oct 15 22:17:42:070 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::hndShakeCallBack- Message Type in hndShakeCallBack is N� 

!--- "N" indicates not matched. 

Tue Oct 15 22:17:42:070 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::tftp_readfile- accessing current entry in the directory file list: 
components.dat 

Tue Oct 15 22:17:42:492 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::aftfrSndHandShake():localpath:
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1,remotepath: 
�� /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1� 

Tue Oct 15 22:17:42:493 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::getFileAttributes(): for file:
/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1/components.dat succeeded� 

Tue Oct 15 22:17:42:504 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::checkReqResult: Entering with requestTransfer = 1� 

Tue Oct 15 22:17:42:504 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XEFileService::checkReqResult:setting transferState to (FREE)� 

!--- The operationStatus 5 indicates file_integrity_success. 

Tue Oct 15 22:17:42:504 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::fileXferCallback: Entering with path = /opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1, 
operationStatus = 5 

Tue Oct 15 22:17:42:597 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData. Platform state = 2.� 

Tue Oct 15 22:17:42:597 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData. instandby box,mgrState= 6� 

!--- The symbolic link /opt/CiscoMGC/etc/active_link is created. 

Tue Oct 15 22:17:42:598 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::setupActvLink. Set link to [/opt/CiscoMGC/etc/CONFIG_LIB/CFG_pomtest1].
!--- The symbolic link /opt/CiscoMGC/etc/prov_link is created. 

Tue Oct 15 22:17:42:602 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::setupProvLink. Set link to [/opt/CiscoMGC/etc/CONFIG_LIB/CFG_p1test].
!--- Data files of the active configuration are copied to� 
!--- /opt/CiscoMGC/etc. 

Tue Oct 15 22:17:42:639 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::prepareActvFiles. Executing command [cp -p /opt/CiscoMGC/etc/CONFIG_LIB/
CFG_pomtest1/[a-z]*.dat /opt/CiscoMGC/etc/].� 

!--- Dynamic reconfiguration is shown below.

Tue Oct 15 22:17:42:785 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XETable::reload: validation = 0, process = ProvObjectManager, table = components, delCnt = 0, 
updCnt = 0, insCnt = 0� 

Tue Oct 15 22:17:42:785 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::sendUpdateRequest: reloading components� 

Tue Oct 15 22:17:42:786 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
XETable::purge: validation = 1, process = ProvObjectManager, table = components, 
purge count = 0� 

!--- Output suppressed: the previous three messages are repeated� 
!--- for every XETable.
 
Tue Oct 15 22:17:43:377 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::sendPeerMsg: sending msg type 100, subtype 713, 
resp status 0
 

Tue Oct 15 22:17:43:378 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
UDP send() 62 bytes to 10.48.84.24:4001 10.48.84.65 (fd=9), written=62� 

Tue Oct 15 22:17:43:379 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData: Ending Warmstart.� 

Tue Oct 15 22:17:43:382 2002 WET | ProvObjectManager (PID 1764) <Debug>� 
pomMgr::peerSyncProvData. procM 0

Error/Debug Message Reference Tables

POM Event Types
Code Value
POM_REQ_T 100
POM_RSP_T 101

POM Event Subtypes
Code Value
POM_START_MT 700
POM_STOP_MT 701
POM_COPY_MT 702
POM_DEPLOY_MT 703
POM_SYNC_MT 704
POM_RESET_TIMER_MT 705
POM_TIMER_WARN_MT 706
POM_TIMER_EXPIRED_MT 707
POM_PEER_DEPLOY_MT 708
POM_PEER_SYNC_MT 709
POM_VALIDATION_RESULT_MT 710
POM_DISABLE_IDLE_TIMER_MT 711
POM_ENABLE_IDLE_TIMER_MT 712
POM_RESTART_RESP_TIMER_MT 713

pomMgrStates
Code Value
UNDEFINED 0
READY 1
CFGM_WAIT 2
CFGM_NO_WAIT 3
PEER_WAIT 4
CFGM_VALIDATION_WAIT 5
XFER_WAIT 6

(operation) Status
Code Value
unknown 0
success 1
fail 2
timeout 3
no_need_to_transfer 4
file_integrity_success 5
file_integrity_fail 6
link_down 7

POM Status Codes
Code Value Significance
XE_NORMAL 0 Requested operation completed successfully.
POM_NO_SES 2000 This client has no active POM session.
POM_SES_IN_USE 2001 The POM session is already in use.
POM_INVALID_SRC 2002 The source directory does not exist.
POM_WAIT_FOR_RESP 2003 Waiting for response; cannot send message to POM.
POM_TIMER_WARN 2004 The POM session idle warning.
POM_TIMER_EXPIRED 2005 The POM session has closed due to inactivity.
POM_CRT_DST_DIR 2006 Error creating destination directory.
POM_CRT_PROV_LNK 2007 Error creating provisioning link.
POM_CRT_ACTV_LINK 2008 Error creating active link.
POM_CPY_SRC 2009 Error copying data files from source to destination.
POM_CFGM_WAIT 2010 The POM cannot process request; waiting for response from CfgM.
POM_CFGM_TIMEOUT 2011 The CfgM response timed out.
POM_UPDATE_FAILED 2012 Update of data files failed.
POM_CFGM_SEND 2013 Error sending request to CfgM.
POM_CPY_ETC 2014 Error copying data files to etc directory.
POM_POST_PROC 2015 Error in post provisioning processing.
POM_SES_ACTIVE 2016 The POM session is already active.
POM_SEND 2017 Error sending request to POM.
POM_DST_DIR_EXISTS 2018 Destination directory exists; cannot overwrite.
POM_PEER_TIMEOUT 2019 Peer POM response timed out.
POM_PEER_SES_IN_USE 2020 Peer POM session in use.
POM_XFER_ERR 2021 Error transferring data files.
POM_PEER_SYNC_ERR 2022 Platform is in non-ready state. Data synchronization aborted.
POM_INVALID_DST 2023 The source/destination version cannot be a full or a relative path. It cannot have any special characters other than "-" and "_".
POM_VALIDATION_FAILED 2024 Validation of data files failed.
POM_KEYWORD_DST 2025 The destination version cannot use the keywords "active" and "new".
POM_NO_ACTV_SES 2026 No active POM sessions.
POM_ACTV_SRC 2027 The active directory cannot be used as a destination.
POM_STAND_ALONE 2028 Deploy/sync cannot be performed in standalone mode.
POM_VALIDATION_TIMEOUT 2029 Validation has timed-out. Data deployment aborted.
POM_VER_MISMATCH 2030 A .dat file version mismatch.
POM_PEER_NOT_STANDBY 2031 Deploy/sync cannot be performed with a nonstandby peer.
POM_PEER_INCOMPATIBLE 2032 Provisioning cannot be performed due to an incompatible peer version.

Related Information

Updated: Jan 31, 2006
Document ID: 28160