I got to try changing some line values and repeating the send profiles
while checking the logs you mentioned. Although I am certainly not a
pro at digesting them, what I think I see is that mongo replication is
happening correctly from the primary (which might explain why running
sipxagent on the secondary actually allows it to get the information)
but then an exception occurs (related to conferencing?).
at
org.sipfoundry.sipxconfig.conference.ConferenceBridgeConfig.findMailboxS
erver(ConferenceBridgeConfig.java:46)
I did not see anything in the secondary servers sipxagent.log (although
the file is pretty chock full, I think there was no change during the
send profiles. I will try to confirm this by watching time stamps and
the like). I have copied the tail ends that I believe are relevant
below.
-=[ Primary - sipxconfig.log ]=-
"2012-07-12T14:59:58.840000Z":1045:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:00:06.041000Z":1046:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:00:07.175000Z":1047:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:00:47.205000Z":1048:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:00:47.318000Z":1049:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:00:52.472000Z":1050:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:00:53.642000Z":1051:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:01:05.274000Z":1052:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:01:05.392000Z":1053:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:01:11.107000Z":1054:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:01:12.213000Z":1055:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:01:36.789000Z":1056:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:01:36.902000Z":1057:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:01:42.482000Z":1058:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:01:43.568000Z":1059:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:01:55.199000Z":1060:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:01:55.354000Z":1061:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:02:01.411000Z":1062:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:02:02.538000Z":1063:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:02:14.260000Z":1064:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:02:14.410000Z":1065:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:02:19.855000Z":1066:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:02:21.023000Z":1067:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:02:32.520000Z":1068:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:02:32.637000Z":1069:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:02:38.249000Z":1070:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:02:39.351000Z":1071:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
"2012-07-12T15:07:28.275000Z":1072:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:07:28.307000Z":1073:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:13:52.592000Z":1074:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:13:52.626000Z":1075:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:15:44.392000Z":1076:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:15:44.429000Z":1077:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:15:44.462000Z":1078:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@0:
RemoteIpAddress: null; SessionId: 1iv1dhy62xbtw"
"2012-07-12T15:15:52.913000Z":1079:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:15:52.941000Z":1080:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@1de6:
RemoteIpAddress: null; SessionId: null"
"2012-07-12T15:15:52.972000Z":1081:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@b364:
RemoteIpAddress: null; SessionId: 2hmbd1alpdqxk"
"2012-07-12T15:15:56.189000Z":1082:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-17:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@ffff6a82:
RemoteIpAddress: null; SessionId: 1x4p4niz6yji1"
"2012-07-12T15:33:47.571000Z":1083:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:P2-13:00000000:LoggerListener:"Authentication event
AuthenticationSuccessEvent: superadmin; details:
org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@166c8:
RemoteIpAddress: 10.1.11.41; SessionId: 67okhnd5blf3a"
"2012-07-12T15:34:37.033000Z":1084:JAVA:INFO:config.acd.dcf.patlive.loca
l:P2-17:00000000:SipxReplicationContextImpl:"Start replication: IMDB
regeneration"
"2012-07-12T15:34:37.263000Z":1085:JAVA:INFO:config.acd.dcf.patlive.loca
l:P2-17:00000000:ReplicationManagerImpl:"Starting async parallel
regeneration of mongo group of 126 entities on 2 threads using chunks of
1000 users"
"2012-07-12T15:34:39.404000Z":1086:JAVA:INFO:config.acd.dcf.patlive.loca
l:P2-17:00000000:ReplicationManagerImpl:"Regeneration of entities
finished in 2s | 0m."
"2012-07-12T15:34:42.171000Z":1088:JAVA:INFO:config.acd.dcf.patlive.loca
l:P2-17:00000000:auditlog:"Replicated in Mongo DBDatabase regeneration
to config.acd.dcf.patlive.local"
"2012-07-12T15:34:45.208000Z":1090:JAVA:INFO:config.acd.dcf.patlive.loca
l:pool-1-thread-1:00000000:auditlog:"Replicated: 1 - Publish finished
replication event ..."
"2012-07-12T15:34:49.171000Z":1091:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
work to do. Notifying providers."
"2012-07-12T15:34:49.525000Z":1092:JAVA:ERR:config.acd.dcf.patlive.local
:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
generation"
java.lang.NullPointerException
at
org.sipfoundry.sipxconfig.conference.ConferenceBridgeConfig.findMailboxS
erver(ConferenceBridgeConfig.java:46)
at
org.sipfoundry.sipxconfig.conference.ConferenceBridgeConfig.getDocument(
ConferenceBridgeConfig.java:32)
at
org.sipfoundry.sipxconfig.conference.ConferenceConfiguration.replicate(C
onferenceConfiguration.java:71)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runProviders(ConfigMa
nagerImpl.java:158)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerI
mpl.java:138)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(Con
figManagerImpl.java:309)
at
org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2012-07-12T15:34:51.886000Z":1093:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:51.887000Z":1094:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:52.399000Z":1095:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:52.399000Z":1096:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:52.533000Z":1097:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:52.533000Z":1098:JAVA:WARNING:config.acd.dcf.patlive.l
ocal:Replication worker thread:00000000:RulesXmlFile:"Cannot read from
external mapping rules file: "
"2012-07-12T15:34:53.135000Z":1099:JAVA:ERR:config.acd.dcf.patlive.local
:Replication worker thread:00000000:ConfigManagerImpl:"Configuration
generation"
java.lang.NullPointerException
at
org.sipfoundry.sipxconfig.conference.ConferenceBridgeConfig.findMailboxS
erver(ConferenceBridgeConfig.java:46)
at
org.sipfoundry.sipxconfig.conference.ConferenceBridgeConfig.getDocument(
ConferenceBridgeConfig.java:32)
at
org.sipfoundry.sipxconfig.conference.ConferenceConfiguration.replicate(C
onferenceConfiguration.java:71)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runProviders(ConfigMa
nagerImpl.java:158)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerI
mpl.java:138)
at
org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(Con
figManagerImpl.java:309)
at
org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2012-07-12T15:34:53.138000Z":1100:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 127.0.0.1 "
"2012-07-12T15:34:58.691000Z":1101:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.54 "
"2012-07-12T15:34:59.870000Z":1102:JAVA:INFO:config.acd.dcf.patlive.loca
l:Replication worker thread:00000000:AgentRunner:"Starting agent run
/usr/bin/sipxagent --host 192.168.167.55 "
-=[ Secondary (.54) - sipxagent.log ]=-
cf3> =========================================================
cf3> methods in bundle sipxlogwatcher_setup (3)
cf3> =========================================================
cf3>
cf3> -> This promise has already been verified
cf3>
cf3> . . . . . . . . . . . . . . . . . . . . . . . . . . . .
cf3> Skipping whole next promise (any), as context !src.!sipxlogwatcher
is not relevant
cf3> . . . . . . . . . . . . . . . . . . . . . . . . . . . .
cf3> -> Aggregate compliance (promises kept/repaired) for bundle
"sipxlogwatcher_setup" = 100.0%
cf3> -> Method invoked successfully
cf3>
cf3> + Private classes augmented:
cf3>
cf3> - Private classes diminished:
cf3> - firewall
cf3> - unmanaged_dns
cf3> - unmanaged_dhcpd
cf3> - unmanaged_firewall
cf3> - unmanaged_ntpd
cf3> - sipxsqa
cf3> - sipxacdstatistics
cf3> - dhcpd
cf3> - tunnel
cf3> - sipxopenfire
cf3> - sipxrls
cf3> - sipximbot
cf3> - sipxrecording
cf3> - sipxpage
cf3> - sipxivr
cf3> - moh
cf3> - sipxpublisher
cf3> - apache
cf3> - mongod_arbiter
cf3> - ftp
cf3> - tftp
cf3> - sipxpark
cf3>
cf3>
cf3>
cf3> =========================================================
cf3> methods in bundle zz_sipxlogwatcher (2)
cf3> =========================================================
cf3>
cf3>
cf3> + Private classes augmented:
cf3>
cf3> - Private classes diminished:
cf3> - firewall
cf3> - unmanaged_dns
cf3> - unmanaged_dhcpd
cf3> - unmanaged_firewall
cf3> - unmanaged_ntpd
cf3> - sipxsqa
cf3> - sipxacdstatistics
cf3> - dhcpd
cf3> - tunnel
cf3> - sipxopenfire
cf3> - sipxrls
cf3> - sipximbot
cf3> - sipxrecording
cf3> - sipxpage
cf3> - sipxivr
cf3> - moh
cf3> - sipxpublisher
cf3> - apache
cf3> - mongod_arbiter
cf3> - ftp
cf3> - tftp
cf3> - sipxpark
cf3>
cf3>
cf3>
cf3> =========================================================
cf3> methods in bundle zz_sipxlogwatcher (3)
cf3> =========================================================
cf3>
cf3> -> Aggregate compliance (promises kept/repaired) for bundle
"zz_sipxlogwatcher" = 100.0%
cf3> Outcome of version (not specified) (agent-0): Promises observed to
be kept 92%, Promises repaired 7%, Promises not repaired 1%
cf3> -> Checked 5926 objects with 483 promises, efficiency 92.46
cf3> -> No lock purging scheduled
Daniel Chang
PATLive
-----Original Message-----
From: [email protected]
[mailto:[email protected]] On Behalf Of George
Niculae
Sent: Wednesday, July 11, 2012 5:30 PM
To: sipXecs developer discussions
Subject: Re: [sipx-dev] Send profiles does not appear to propagate to
two secondary servers
On Thu, Jul 12, 2012 at 12:09 AM, Dan Chang <[email protected]>
wrote:
> I know the push for 4.6 is on (thanks for the great work devs!) but I
was
> hoping someone might be able to give me a tip on how to pursue
debugging an
> issue I am seeing with clustering.
>
>
>
> We have a main SipXecs server and two secondary servers clustered.
Contact
> Center is enable on the two secondary servers but not the main server.
When
> adding new OpenACD lines to the Contact Center I noticed that Send
Profiles
> was not propagating the information to the secondary servers (or more
> specifically, even with pressing Send Profiles we could still not
reach the
> lines by calling in to the extensions and
> /var/sipxdata/freeswitch/conf/dialplan/sipX_context.xml did not seem
to get
> the correct configuration).
>
>
>
> However, when we ran sipxagent on the first secondary server it
appeared to
> "take" the line data, and it also seemed to pass it on to the second
> secondary server. Has anyone seen this kind of behavior, or maybe
have some
> tips about what I might look for in the logs to see what is going on?
>
I suspect this wasn't seen as we tested contact center on master only.
You should check first sipxconfig.log to see if replication triggered
when such change and sipxagent.log file from one of secondaries if
replication triggered but change not propagated (any entry in job
status page when you do this?). Post back with these files if you
don't figure it out.
George
_______________________________________________
sipx-dev mailing list
[email protected]
List Archive: http://list.sipfoundry.org/archive/sipx-dev/
_______________________________________________
sipx-dev mailing list
[email protected]
List Archive: http://list.sipfoundry.org/archive/sipx-dev/