Unable to get credentials

45 views
Skip to first unread message

Massimo Vignone

unread,
May 28, 2018, 7:17:21 AM5/28/18
to sipxcom-users
After creating a new user, sipregistrar shows me the following message

sipx-mo-2 sipregistrar "2018-05-28T11:15:26.409321Z":450793:AUTH:ERR:sipx-mo-2.mydomain.net::7ff0e0737700:sipxregistry:"Unable to get credentials for '6628@mydomain.net', realm='unimore.it', user='6628/64167f14b131'"

The phone can't register.

The problem is on a cluster upgraded to 18.04 release.

Any hint?

Massimo

George Niculae

unread,
May 28, 2018, 7:21:07 AM5/28/18
to Massimo Vignone, sipxcom-users
Try sending profiles to server and check if no failed task in job status page.  Did you follow upgrafe procedure for 18.04?

George 

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To post to this group, send email to sipxco...@googlegroups.com.
Visit this group at https://groups.google.com/group/sipxcom-users.
To view this discussion on the web visit https://groups.google.com/d/msgid/sipxcom-users/0c06218e-027e-45d5-b1d6-79a9b7df1e2b%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Massimo Vignone

unread,
May 28, 2018, 7:38:32 AM5/28/18
to sipxcom-users
Yes, i followed the upgrade instructions.

Apart from the problem utlined in SIPX-745, everything seems to work well.

Today I started to create more users, and I've got th "unable to get credential" issue.

Now I've sent profile on the configuration server, and I've got the following messages:

'IMDB regeneration -> Failed'
'Configuration generation -> Internal Error Replication: insert/update failed - null'

George Niculae

unread,
May 28, 2018, 7:41:24 AM5/28/18
to Massimo Vignone, sipxcom-users
Pls send sipxconfig.log file, there should be an error in there

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To post to this group, send email to sipxco...@googlegroups.com.
Visit this group at https://groups.google.com/group/sipxcom-users.

Massimo Vignone

unread,
May 28, 2018, 7:47:27 AM5/28/18
to sipxcom-users
This are the last entries I've found in the log file...

...
"2018-05-28T11:32:52.938000Z":3074349:JAVA:WARNING:sipx-mo-1.mydomain.net:qtp2081745117-31080:00000000:LoggerListener:"Authentication event AuthenticationSuccessEvent: superadmin; details: org.sipfoundry.sipxconfig.security.SipxAuthenticationDetails@166c8: RemoteIpAddress: 192.168.254.156; SessionId: ys38zkxvfu5mcaf0aydpt117"
"2018-05-28T11:33:01.721000Z":3074571:JAVA:INFO:sipx-mo-1.mydomain.net:pool-56-thread-1:00000000:SipxReplicationContextImpl:"Start replication: IMDB regeneration"
"2018-05-28T11:33:01.724000Z":3074572:JAVA:WARNING:sipx-mo-1.mydomain.net:pool-56-thread-1:00000000:SipxReplicationContextImpl:"Replication failed: IMDB regeneration"
com.mongodb.MongoException: not talking to master and retries used up
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:315)
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:317)
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:317)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:269)
    at com.mongodb.DBCollectionImpl.find(DBCollectionImpl.java:84)
    at com.mongodb.DB.command(DB.java:320)
    at com.mongodb.DB.command(DB.java:299)
    at com.mongodb.DB.command(DB.java:374)
    at com.mongodb.DB.command(DB.java:246)
    at com.mongodb.DBCollection.drop(DBCollection.java:1102)
    at com.mongodb.DBCollectionImpl.drop(DBCollectionImpl.java:287)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.dropDatasetDb(ReplicationManagerImpl.java:174)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateAllData(ReplicationManagerImpl.java:301)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateAllData(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl$ReplicationWorker$1.replicate(SipxReplicationContextImpl.java:63)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.doWithJob(SipxReplicationContextImpl.java:101)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.access$300(SipxReplicationContextImpl.java:37)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl$ReplicationWorker.run(SipxReplicationContextImpl.java:67)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:473)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
    at java.lang.Thread.run(Thread.java:748)
"2018-05-28T11:33:08.718000Z":3074665:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Configuration work to do. Notifying providers."
"2018-05-28T11:33:08.722000Z":3074666:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ResLimitsConfiguration:"Write FEATURED resource limits"
"2018-05-28T11:33:09.815000Z":3074667:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AbstractSetting:"Cannot find setting: im-portal in user-portal"
"2018-05-28T11:33:11.584000Z":3074773:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:RulesXmlFile:"Cannot read from external mapping rules file: "
"2018-05-28T11:33:11.584000Z":3074774:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:RulesXmlFile:"Cannot read from external mapping rules file: "
"2018-05-28T11:33:12.955000Z":3074775:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Running Signal XMPP configuration change"
"2018-05-28T11:33:12.956000Z":3074776:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 127.0.0.1  --bundle touch_xmpp_update "
"2018-05-28T11:33:15.074000Z":3074777:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 127.0.0.1 "
"2018-05-28T11:33:22.395000Z":3075124:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.168.2 "
"2018-05-28T11:33:28.900000Z":3075650:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.168.3 "
"2018-05-28T11:33:37.410000Z":3075826:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.169.1 "
"2018-05-28T11:33:56.044000Z":3076083:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ReplicationManagerImpl:"Replication: insert/update failed - org.sipfoundry.sipxconfig.acccode.AuthCode@2"
com.mongodb.CommandFailureException: { "serverUsed" : "sipx-mo-1.mydomain.net:27017" , "ok" : 0.0 , "errmsg" : "not master" , "code" : 10107 , "codeName" : "NotMaster"}
    at com.mongodb.CommandResult.getException(CommandResult.java:76)
    at com.mongodb.CommandResult.throwOnError(CommandResult.java:140)
    at com.mongodb.DBCollectionImpl.createIndex(DBCollectionImpl.java:399)
    at com.mongodb.DBCollection.createIndex(DBCollection.java:597)
    at com.mongodb.DBCollection.ensureIndex(DBCollection.java:726)
    at com.mongodb.DBCollection.ensureIndex(DBCollection.java:666)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.getDbCollection(ReplicationManagerImpl.java:795)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.findOrCreate(ReplicationManagerImpl.java:716)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:367)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:340)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2018-05-28T11:33:56.045000Z":3076084:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ReplicationManagerImpl:"Replication: insert/update failed - org.sipfoundry.sipxconfig.acccode.AuthCode@2"
org.sipfoundry.sipxconfig.common.UserException: Replication: insert/update failed - null
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:376)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:340)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2018-05-28T11:33:56.045000Z":3076085:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Configuration generation"
org.sipfoundry.sipxconfig.common.UserException: Replication: insert/update failed - null
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:349)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2018-05-28T11:38:45.705000Z":3078372:JAVA:INFO:sipx-mo-1.mydomain.net:qtp2081745117-31108:00000000:SimpleCommandRunner:"/usr/bin/mongodb-status --full"
"2018-05-28T11:38:46.029000Z":3078373:JAVA:INFO:sipx-mo-1.mydomain.net:qtp2081745117-31108:00000000:SimpleCommandRunner:"/usr/bin/mongodb-analyzer"
"2018-05-28T11:39:07.256000Z":3078634:JAVA:INFO:sipx-mo-1.mydomain.net:pool-57-thread-1:00000000:SipxReplicationContextImpl:"Start replication: IMDB regeneration"
"2018-05-28T11:39:07.259000Z":3078635:JAVA:WARNING:sipx-mo-1.mydomain.net:pool-57-thread-1:00000000:SipxReplicationContextImpl:"Replication failed: IMDB regeneration"
com.mongodb.MongoException: not talking to master and retries used up
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:315)
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:317)
    at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:317)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:269)
    at com.mongodb.DBCollectionImpl.find(DBCollectionImpl.java:84)
    at com.mongodb.DB.command(DB.java:320)
    at com.mongodb.DB.command(DB.java:299)
    at com.mongodb.DB.command(DB.java:374)
    at com.mongodb.DB.command(DB.java:246)
    at com.mongodb.DBCollection.drop(DBCollection.java:1102)
    at com.mongodb.DBCollectionImpl.drop(DBCollectionImpl.java:287)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.dropDatasetDb(ReplicationManagerImpl.java:174)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateAllData(ReplicationManagerImpl.java:301)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateAllData(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl$ReplicationWorker$1.replicate(SipxReplicationContextImpl.java:63)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.doWithJob(SipxReplicationContextImpl.java:101)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.access$300(SipxReplicationContextImpl.java:37)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl$ReplicationWorker.run(SipxReplicationContextImpl.java:67)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:473)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
    at java.lang.Thread.run(Thread.java:748)
"2018-05-28T11:39:14.254000Z":3078728:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Configuration work to do. Notifying providers."
"2018-05-28T11:39:14.258000Z":3078729:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ResLimitsConfiguration:"Write FEATURED resource limits"
"2018-05-28T11:39:15.318000Z":3078730:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AbstractSetting:"Cannot find setting: im-portal in user-portal"
"2018-05-28T11:39:17.070000Z":3078731:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:RulesXmlFile:"Cannot read from external mapping rules file: "
"2018-05-28T11:39:17.070000Z":3078732:JAVA:WARNING:sipx-mo-1.mydomain.net:Replication worker thread:00000000:RulesXmlFile:"Cannot read from external mapping rules file: "
"2018-05-28T11:39:18.409000Z":3078733:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Running Signal XMPP configuration change"
"2018-05-28T11:39:18.409000Z":3078734:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 127.0.0.1  --bundle touch_xmpp_update "
"2018-05-28T11:39:20.531000Z":3078735:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 127.0.0.1 "
"2018-05-28T11:39:27.746000Z":3078817:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.168.2 "
"2018-05-28T11:39:34.346000Z":3078901:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.168.3 "
"2018-05-28T11:39:42.367000Z":3079239:JAVA:INFO:sipx-mo-1.mydomain.net:Replication worker thread:00000000:AgentRunner:"Starting agent run /usr/bin/sipxagent --host 192.168.169.1 "
"2018-05-28T11:40:00.950000Z":3079321:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ReplicationManagerImpl:"Replication: insert/update failed - org.sipfoundry.sipxconfig.acccode.AuthCode@2"
com.mongodb.CommandFailureException: { "serverUsed" : "sipx-mo-1.mydomain.net:27017" , "ok" : 0.0 , "errmsg" : "not master" , "code" : 10107 , "codeName" : "NotMaster"}
    at com.mongodb.CommandResult.getException(CommandResult.java:76)
    at com.mongodb.CommandResult.throwOnError(CommandResult.java:140)
    at com.mongodb.DBCollectionImpl.createIndex(DBCollectionImpl.java:399)
    at com.mongodb.DBCollection.createIndex(DBCollection.java:597)
    at com.mongodb.DBCollection.ensureIndex(DBCollection.java:726)
    at com.mongodb.DBCollection.ensureIndex(DBCollection.java:666)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.getDbCollection(ReplicationManagerImpl.java:795)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.findOrCreate(ReplicationManagerImpl.java:716)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:367)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:340)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2018-05-28T11:40:00.950000Z":3079322:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ReplicationManagerImpl:"Replication: insert/update failed - org.sipfoundry.sipxconfig.acccode.AuthCode@2"
org.sipfoundry.sipxconfig.common.UserException: Replication: insert/update failed - null
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:376)
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:340)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
"2018-05-28T11:40:00.951000Z":3079323:JAVA:ERR:sipx-mo-1.mydomain.net:Replication worker thread:00000000:ConfigManagerImpl:"Configuration generation"
org.sipfoundry.sipxconfig.common.UserException: Replication: insert/update failed - null
    at org.sipfoundry.sipxconfig.commserver.imdb.ReplicationManagerImpl.replicateEntity(ReplicationManagerImpl.java:349)
    at sun.reflect.GeneratedMethodAccessor1105.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy44.replicateEntity(Unknown Source)
    at org.sipfoundry.sipxconfig.commserver.SipxReplicationContextImpl.generate(SipxReplicationContextImpl.java:47)
    at org.sipfoundry.sipxconfig.acccode.AuthCodesConfig.postReplicate(AuthCodesConfig.java:77)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.runPostProviders(ConfigManagerImpl.java:258)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl.doWork(ConfigManagerImpl.java:188)
    at org.sipfoundry.sipxconfig.cfgmgt.ConfigManagerImpl$ConfigWorker.work(ConfigManagerImpl.java:396)
    at org.sipfoundry.sipxconfig.common.LazyDaemon.run(LazyDaemon.java:48)
...

George Niculae

unread,
May 28, 2018, 7:53:47 AM5/28/18
to Massimo Vignone, sipxcom-users
Looks like Mongo was not backed up / restored properly, what does it say when you type mongo?

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To post to this group, send email to sipxco...@googlegroups.com.
Visit this group at https://groups.google.com/group/sipxcom-users.

Massimo Vignone

unread,
May 28, 2018, 8:01:04 AM5/28/18
to sipxcom-users
Here's mongo output:

[root@sipx-mo-1 ~]# mongo
MongoDB shell version v3.4.10
connecting to: mongodb://127.0.0.1:27017
MongoDB server version: 3.4.10
Server has startup warnings:
2018-05-22T09:16:26.779+0200 I STORAGE  [initandlisten]
2018-05-22T09:16:26.779+0200 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-05-22T09:16:26.779+0200 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-05-22T09:16:28.111+0200 I CONTROL  [initandlisten]
2018-05-22T09:16:28.111+0200 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2018-05-22T09:16:28.111+0200 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2018-05-22T09:16:28.111+0200 I CONTROL  [initandlisten]
2018-05-24T16:39:22.220+0200 W COMMAND  [conn28453] the eval command is deprecated
2018-05-24T17:11:22.798+0200 W COMMAND  [conn28789] the eval command is deprecated
2018-05-24T17:42:55.147+0200 W COMMAND  [conn29121] the eval command is deprecated
2018-05-24T18:14:56.252+0200 W COMMAND  [conn29462] the eval command is deprecated
2018-05-24T18:46:28.002+0200 W COMMAND  [conn29787] the eval command is deprecated
2018-05-24T19:18:31.157+0200 W COMMAND  [conn30127] the eval command is deprecated
2018-05-24T19:50:01.538+0200 W COMMAND  [conn30452] the eval command is deprecated
2018-05-24T20:22:01.997+0200 W COMMAND  [conn30794] the eval command is deprecated
2018-05-24T20:53:35.902+0200 W COMMAND  [conn31125] the eval command is deprecated
2018-05-24T21:25:37.622+0200 W COMMAND  [conn31462] the eval command is deprecated
2018-05-24T21:44:53.661+0200 W COMMAND  [conn31721] the eval command is deprecated
2018-05-24T22:10:12.517+0200 W COMMAND  [conn32001] the eval command is deprecated
2018-05-24T22:41:46.903+0200 W COMMAND  [conn32344] the eval command is deprecated
2018-05-24T23:13:47.075+0200 W COMMAND  [conn32678] the eval command is deprecated
2018-05-24T23:45:23.415+0200 W COMMAND  [conn33009] the eval command is deprecated
2018-05-25T00:17:26.485+0200 W COMMAND  [conn33354] the eval command is deprecated
2018-05-25T00:48:59.388+0200 W COMMAND  [conn33683] the eval command is deprecated
2018-05-25T01:21:07.703+0200 W COMMAND  [conn34026] the eval command is deprecated
2018-05-25T01:52:39.132+0200 W COMMAND  [conn34361] the eval command is deprecated
2018-05-25T02:24:40.285+0200 W COMMAND  [conn34696] the eval command is deprecated
2018-05-25T02:56:11.967+0200 W COMMAND  [conn35030] the eval command is deprecated
2018-05-25T03:28:14.697+0200 W COMMAND  [conn35364] the eval command is deprecated
2018-05-25T03:59:45.155+0200 W COMMAND  [conn35697] the eval command is deprecated
2018-05-25T04:31:45.643+0200 W COMMAND  [conn36029] the eval command is deprecated
2018-05-25T05:03:16.089+0200 W COMMAND  [conn36376] the eval command is deprecated
2018-05-25T05:35:16.735+0200 W COMMAND  [conn36702] the eval command is deprecated
2018-05-25T06:06:50.284+0200 W COMMAND  [conn37034] the eval command is deprecated
2018-05-25T06:38:51.246+0200 W COMMAND  [conn37377] the eval command is deprecated
2018-05-25T07:10:24.780+0200 W COMMAND  [conn37719] the eval command is deprecated
2018-05-25T07:42:25.414+0200 W COMMAND  [conn38047] the eval command is deprecated
sipxecs:SECONDARY>

George Niculae

unread,
May 28, 2018, 8:04:31 AM5/28/18
to Massimo Vignone, sipxcom-users
so that's a secondary node, are you running multiple nodes? what is the output for rs.status() and rs.config() ?

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To post to this group, send email to sipxco...@googlegroups.com.
Visit this group at https://groups.google.com/group/sipxcom-users.

Massimo Vignone

unread,
May 28, 2018, 8:08:44 AM5/28/18
to sipxcom-users
sipxecs:SECONDARY>  rs.status()
{
    "set" : "sipxecs",
    "date" : ISODate("2018-05-28T12:06:51.044Z"),
    "myState" : 2,
    "term" : NumberLong(7),
    "syncingTo" : "sipx-mo-2.mydomain.net:27017",
    "heartbeatIntervalMillis" : NumberLong(2000),
    "optimes" : {
        "lastCommittedOpTime" : {
            "ts" : Timestamp(1527509210, 2),
            "t" : NumberLong(7)
        },
        "appliedOpTime" : {
            "ts" : Timestamp(1527509210, 2),
            "t" : NumberLong(7)
        },
        "durableOpTime" : {
            "ts" : Timestamp(1527509210, 2),
            "t" : NumberLong(7)
        }
    },
    "members" : [
        {
            "_id" : 2,
            "name" : "sipx-mo-1.mydomain.net:27017",
            "health" : 1,
            "state" : 2,
            "stateStr" : "SECONDARY",
            "uptime" : 535825,
            "optime" : {
                "ts" : Timestamp(1527509210, 2),
                "t" : NumberLong(7)
            },
            "optimeDate" : ISODate("2018-05-28T12:06:50Z"),
            "syncingTo" : "sipx-mo-2.mydomain.net:27017",
            "configVersion" : 15,
            "self" : true
        },
        {
            "_id" : 3,
            "name" : "sipx-mo-2.mydomain.net:27017",
            "health" : 1,
            "state" : 1,
            "stateStr" : "PRIMARY",
            "uptime" : 535822,
            "optime" : {
                "ts" : Timestamp(1527509208, 2),
                "t" : NumberLong(7)
            },
            "optimeDurable" : {
                "ts" : Timestamp(1527509208, 2),
                "t" : NumberLong(7)
            },
            "optimeDate" : ISODate("2018-05-28T12:06:48Z"),
            "optimeDurableDate" : ISODate("2018-05-28T12:06:48Z"),
            "lastHeartbeat" : ISODate("2018-05-28T12:06:49.954Z"),
            "lastHeartbeatRecv" : ISODate("2018-05-28T12:06:49.917Z"),
            "pingMs" : NumberLong(0),
            "electionTime" : Timestamp(1526973386, 1),
            "electionDate" : ISODate("2018-05-22T07:16:26Z"),
            "configVersion" : 15
        },
        {
            "_id" : 4,
            "name" : "sipx-re-1.mydomain.net:27017",
            "health" : 1,
            "state" : 2,
            "stateStr" : "SECONDARY",
            "uptime" : 318062,
            "optime" : {
                "ts" : Timestamp(1527509208, 2),
                "t" : NumberLong(7)
            },
            "optimeDurable" : {
                "ts" : Timestamp(1527509208, 2),
                "t" : NumberLong(7)
            },
            "optimeDate" : ISODate("2018-05-28T12:06:48Z"),
            "optimeDurableDate" : ISODate("2018-05-28T12:06:48Z"),
            "lastHeartbeat" : ISODate("2018-05-28T12:06:49.076Z"),
            "lastHeartbeatRecv" : ISODate("2018-05-28T12:06:49.218Z"),
            "pingMs" : NumberLong(0),
            "syncingTo" : "sipx-mo-2.mydomain.net:27017",
            "configVersion" : 15
        }
    ],
    "ok" : 1
}
sipxecs:SECONDARY> rs.config()
{
    "_id" : "sipxecs",
    "version" : 15,
    "protocolVersion" : NumberLong(1),
    "members" : [
        {
            "_id" : 2,
            "host" : "sipx-mo-1.mydomain.net:27017",
            "arbiterOnly" : false,
            "buildIndexes" : true,
            "hidden" : false,
            "priority" : 1,
            "tags" : {
                "clusterId" : "1",
                "shardId" : "2"
            },
            "slaveDelay" : NumberLong(0),
            "votes" : 1
        },
        {
            "_id" : 3,
            "host" : "sipx-mo-2.mydomain.net:27017",
            "arbiterOnly" : false,
            "buildIndexes" : true,
            "hidden" : false,
            "priority" : 1,
            "tags" : {
                "shardId" : "2",
                "clusterId" : "8"
            },
            "slaveDelay" : NumberLong(0),
            "votes" : 1
        },
        {
            "_id" : 4,
            "host" : "sipx-re-1.mydomain.net:27017",
            "arbiterOnly" : false,
            "buildIndexes" : true,
            "hidden" : false,
            "priority" : 0,
            "tags" : {
                "shardId" : "1",
                "clusterId" : "10"
            },
            "slaveDelay" : NumberLong(0),
            "votes" : 1
        }
    ],
    "settings" : {
        "chainingAllowed" : true,
        "heartbeatIntervalMillis" : 2000,
        "heartbeatTimeoutSecs" : 10,
        "electionTimeoutMillis" : 10000,
        "catchUpTimeoutMillis" : 60000,
        "getLastErrorModes" : {
           
        },
        "getLastErrorDefaults" : {
            "w" : 1,
            "wtimeout" : 0
        },
        "replicaSetId" : ObjectId("5affd630a11ebefd1edd93aa")
    }
}
sipxecs:SECONDARY>

George Niculae

unread,
May 28, 2018, 8:17:49 AM5/28/18
to Massimo Vignone, sipxcom-users
Looks good, just try to restart mongo on


so you get mongo primary node back on sipx-mo-1, then restart sipxconfig and send profiles again

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To post to this group, send email to sipxco...@googlegroups.com.
Visit this group at https://groups.google.com/group/sipxcom-users.

Massimo Vignone

unread,
May 28, 2018, 8:29:45 AM5/28/18
to sipxcom-users
Now imdb has been generated correctly. And the user is registered.

Do you think that the problem was due to the IMDB database corrupted?

And, when you want regenerate imdb, the mongo node have to be  primary?

Thank for your support!

Massimo

George Niculae

unread,
May 28, 2018, 8:36:30 AM5/28/18
to Massimo Vignone, sipxcom-users
Well the problem was that sipxconfig wasn't able to connect to the different primary, so IMDB failed to regenerate and user wasn't replicated. As a best practice mongo primary should be on sipxecs primary but replication shouldn't fail if on a different one IMO, maybe something we will be needed to have a deeper look into.

George

Massimo Vignone

unread,
May 28, 2018, 9:27:21 AM5/28/18
to sipxcom-users
Thanks a lot for your support.
Reply all
Reply to author
Forward
0 new messages