PG does not go to ACTIVE state after OS reboot

[Francisco Javier Rangel]

Hi ,

I have a UCCE installation (simplexed) but after 2 or 3 suddenly server restarts (SO issues) the jwg1(also pims) does not go to active state, stay in IDLE , I have verified  PG is enabled, CUCM user have the right permissions.

The last 3 days was working perfectly untils this unexpected restarts.

jgw1 logs says:

11:55:43:442 PG1A-jgw1 Initializing Event Management System (EMS) Library.
11:55:43:443 PG1A-jgw1 Trace: EMS Server pipe labax\PG1A\jgw1EMSPipe enabled for labax\PG1A\jgw1
11:55:43:443 PG1A-jgw1 Trace: Release 9.0.1.0 , Build 1454
11:55:43:476 PG1A-jgw1 Trace: JGW arg 0, jgw1
11:55:43:476 PG1A-jgw1 Trace: JGW arg 1, CLEAN
11:55:43:476 PG1A-jgw1 Trace: JGW arg 2, SIMPLEX
11:55:43:476 PG1A-jgw1 Trace: JGW arg 3, A
11:55:43:476 PG1A-jgw1 Trace: JGW arg 4, C:\icm\labax\pg1a
11:55:43:476 PG1A-jgw1 Trace: JGW arg 5, 1
11:55:43:476 PG1A-jgw1 Trace: JGW arg 6, ICM\labax\PG1A
11:55:43:476 PG1A-jgw1 Trace: starting java program main method...
11:55:43:794 PG1A-jgw1 Trace: 0: 10.133.25.111: Mar 14 2016 11:55:43.793 -0700: %_Infrastructure-5-AUDIT_LOG_LEVEL: %[ss_log_level=INFO]: Log Level now set [id:9002]

 
11:55:43:794 PG1A-jgw1 Trace: 0: 10.133.25.111: Mar 14 2016 11:55:43.794 -0700: %_apache-5-AUDIT_LOG_LEVEL: %[ss_log_level=INFO]: Log Level now set [id:9002]

 
11:55:43:794 PG1A-jgw1 Trace: 1: 10.133.25.111: Mar 14 2016 11:55:43.794 -0700: %_apache-5-AUDIT_LOG_LEVEL: %[ss_log_level=WARN]: Log Level now set [id:9002]

 
11:55:43:794 PG1A-jgw1 Trace: 0: 10.133.25.111: Mar 14 2016 11:55:43.794 -0700: %_springframework-5-AUDIT_LOG_LEVEL: %[ss_log_level=INFO]: Log Level now set [id:9002]

 
11:55:43:794 PG1A-jgw1 Trace: 1: 10.133.25.111: Mar 14 2016 11:55:43.794 -0700: %_springframework-5-AUDIT_LOG_LEVEL: %[ss_log_level=WARN]: Log Level now set [id:9002]

 
11:55:43:799 PG1A-jgw1 Trace: 1: 10.133.25.111: Mar 14 2016 11:55:43.799 -0700: %_Infrastructure-6-AUDIT_LOG_LEVEL_MASK: %[svcmgr_log_level=WARN][svcmgr_name=org.apache][svcmgr_trace_mask=0]: ServiceabilityManager log level and trace mask [id:9018]

 
11:55:43:799 PG1A-jgw1 Trace: 2: 10.133.25.111: Mar 14 2016 11:55:43.799 -0700: %_Infrastructure-6-AUDIT_LOG_LEVEL_MASK: %[svcmgr_log_level=INFO][svcmgr_name=Infrastructure][svcmgr_trace_mask=0]: ServiceabilityManager log level and trace mask [id:9018]

 
11:55:43:799 PG1A-jgw1 Trace: 3: 10.133.25.111: Mar 14 2016 11:55:43.799 -0700: %_Infrastructure-6-AUDIT_LOG_LEVEL_MASK: %[svcmgr_log_level=WARN][svcmgr_name=org.springframework][svcmgr_trace_mask=0]: ServiceabilityManager log level and trace mask [id:9018]

 
11:55:43:799 PG1A-jgw1 Trace: 4: 10.133.25.111: Mar 14 2016 11:55:43.799 -0700: %_Infrastructure-6-AUDIT_LOG_SIZE: %[log_limit_governor_name=null][max_dir_size=5000][max_file_size=50]: Maximum log file size and maximum logging directory size in MB [id:9017]

 
11:55:43:800 PG1A-jgw1 Trace: 5: 10.133.25.111: Mar 14 2016 11:55:43.800 -0700: %_Infrastructure-5-VERSION: %[build_date=Dec 31, 1969 3:59 PM][build_type=rel][product_name=Unknown product][version_number=Unknown product_-1_-1_-1_-1_-1_-1_-1]: Product version information. [id:9058]

 
11:55:43:800 PG1A-jgw1 Trace: 6: 10.133.25.111: Mar 14 2016 11:55:43.800 -0700: %_Infrastructure-6-AUDIT_LOG_CONFIG_FILE: %[file_name=C:\icm\conf\log4j.xml]: Logging configuration file [id:9003]

 
11:55:43:811 PG1A-jgw1 Trace: 7: 10.133.25.111: Mar 14 2016 11:55:43.811 -0700: %_Infrastructure-6-THREAD_POOL_MANAGER_SET_MAX_THREADS: %[id=JTAPIGW][thread_count=500][thread_pool_weight=5.0]: Set ThreadPoolManager's max number of allowed threads based on its weight relative to other mana
11:55:43:819 PG1A-jgw1 Trace: Monitor Server pipe labax\PG1A\jgw1CmdPipe enabled for labax\PG1A\jgw1
11:55:43:830 PG1A-jgw1 Trace: JVM Total Memory: 32440320 JVM Free Memory: 31079312 JVM Heap in Use: 1361008 JVM has 95.80458% free memory
11:55:43:830 PG1A-jgw1 Trace: [pool-1-thread-1-JTAPIGW-1 - ThreadAddressManager]ThreadAddressManager starts
11:55:43:830 PG1A-jgw1 Trace: ThreadAddressManager::Waiting for next retry
11:55:43:830 PG1A-jgw1 Trace: Configuring JTAPI Object
11:55:43:830 PG1A-jgw1 Trace: Calling getJtapiPeer for peer: com.cisco.jtapi.CiscoJtapiPeerImpl
11:55:43:989 PG1A-jgw1 Trace: getJtapiPeer returned successfully.  JTapiPeer class name: com.cisco.jtapi.CiscoJtapiPeerImpl
11:55:43:990 PG1A-jgw1 Trace: JTapiObj:initializeJTapi: Values for UseProgressAsDisconnectedCauses are: 0
11:55:43:990 PG1A-jgw1 Trace: CiscoJtapiVersion: Cisco Jtapi version 9.0(1.10000)-1 Release
11:55:43:990 PG1A-jgw1 Trace: BuildDescription: Release BuildNumber: 10000 RevisionNumber: 1 MajorVersion: 9 MinorVersion: 0 ExtendedBuildNumber: 1
11:55:43:990 PG1A-jgw1 Trace: Not using CiscoSynchronousObserver interface.
11:55:43:990 PG1A-jgw1 Trace: Initializing JTAPI TraceManager.
11:55:43:992 PG1A-jgw1 Trace: disableAll() TraceManager for CTICLIENT
11:55:43:992 PG1A-jgw1 Trace: Calling getProvider() 10.133.25.114;login=ICMPGUSER;passwd=<***edited***>
11:55:44:621 PG1A-jgw1 Trace: Returned successfully from getProvider()
11:55:44:621 PG1A-jgw1 Trace: disableAll() TraceManager for CTICLIENT
11:55:44:622 PG1A-jgw1 Trace: Waiting for the provider to be in service
11:55:44:622 PG1A-jgw1 Trace: ProvOutOfServiceEv
11:55:44:622 PG1A-jgw1 Trace: ProvInServiceEv
11:55:44:622 PG1A-jgw1 Trace: Provider is in service
11:55:44:622 PG1A-jgw1 Trace: Creating Instruments for 2 addresses
11:55:44:626 PG1A-jgw1 Trace: JTapiServer: Wait for adding CallObservers to  2 addresses
11:55:44:627 PG1A-jgw1 Trace: ThreadAddressManager: Adding AddressObservers to 2 addresses
11:55:44:627 PG1A-jgw1 Trace: [pool-1-thread-1-JTAPIGW-1 - ThreadAddressManager]ThreadAddressManager ends adding observers after 0 milsecs
11:55:44:627 PG1A-jgw1 Trace: ThreadAddressManager::processNextQueuedMsg: msgHashtable.size = 0
11:55:44:627 PG1A-jgw1 Trace: ThreadAddressManager::Waiting for next retry
11:55:44:826 PG1A-jgw1 Trace: JTapiServer: Complete waiting for adding CallObservers to 2 addresses
11:55:44:826 PG1A-jgw1 Trace: Successfully configured JTAPI Object.
11:55:44:826 PG1A-jgw1 Trace: Creating server socket on port 40029 to listen for PIM connections.

Any Idea?

thanks in advance

[Sasikumar Divvela]

From the above logs i see that JGW is opening server socket and waiting for pim to connect ("11:55:44:826 PG1A-jgw1 Trace: Creating server socket on port 40029 to listen for PIM connections."). Can you please share the complete logs (jgw,pim,opc) to check further.

Regards,

Sasikumar.

[Francisco Javier Rangel]

Hi Sasi,

Thanks for the response, attached opc logs, I can see the messages:

11:33:07:116 PG1A-opc Configuration response for Logical Controller 5000 cotained OPI error code 1 (E_UNKNOWN_INTERFACE_CTRLR_ID).

also in event viewer I can see:

Error configuring PG on logical controller ID 5000; the ID is invalid. Returned error 1.

Maybe I have to rebuild. :S

Thanks in advance.

[Sasikumar Divvela · Accepted solution]

Hi Francisco,

I don't think you need to rebuild. This is normal error when the opc doesn't load config from the router. The error represents opc is not able to recognize the logical controller id since it didn't find in it's memory.

From the logs i can see that there is no config request went from the pg, we should see something similar to below in the opc logs

23:38:44:230 PG2A-opc Trace: ConfigurePGReq LCID=5001, IC=17.1 PD=16.81 RC=17.81 ConfigSeqNum=-1, 0 Peripheral(s) down during DMP failure
23:38:44:280 PG2A-opc SideA pim1 process is OK.
23:38:45:230 PG2A-opc PG configuration received (OPI-ICRev: 17.1, OPI-PDRev: 16.81, OPI-RCRev: 17.81)
LastHHUpdateTime = 03/14/2016 18:00:00.

After this opc will load all the config(agent,skill group, DialNumbers etc..) and pass it to respective pims.

In your case i don't see any config request in opc . Probably you may need to check what your router is doing .is your router up and running ?

And  i see that PG is not connected to routerB.

11:16:23:158 PG1A-opc PGAgent on sideA reported DMP In-Service (Router Connections:: SideA=CONNECTED SideB=DISCONNECTED). 

Regards,

Sasikumar

[Francisco Javier Rangel]

Thanks a lot Sasi,

You're ryt, seems like something went wrong with the config after those unexpected and suddently restarts   and opc was unable to get the config from router.

Seems like someone delete the config for PG on CManager :O.

I just reconfigure PG and now all the pims are  active. 

[Chintan Gajjar · Accepted solution]

did you enable pim while installing PG? is your PG able to download config from router?

[Francisco Javier Rangel]

Hi, thanks for the response.

Yes, Actually was working fine until yesterday, I realized that the servers was  offline and went down 3 times (suddently shutdown).

[Francisco Javier Rangel]

Also youre ryt!!

Missing config  :O .  

Thanks a lot for your help.