powered by Jive Software

Unexpected error while broadcasting shared group rename for user

Hi!
Openfire version 4.4.2
Java openjdk-8-jdk
Ldap Users 763
Ldap groups 109

At “Enable contact list group sharing” “All users” a huge number of errors appear and the server freezes.
Has anyone encountered this?

{"log":"07:49:35.764 [Jetty-QTP-AdminConsole-62] WARN  org.jivesoftware.openfire.roster.Roster - Unexpected error while broadcasting shared group rename for user 'FedorovaIV@belwest.corp'!\n","stream":"stdout","time":"2019-09-26T07:49:35.907229026Z"}
{"log":"org.jivesoftware.openfire.user.UserNotFoundException: FedorovaIV@belwest.corp\n","stream":"stdout","time":"2019-09-26T07:49:35.907241397Z"}
{"log":"\u0009at org.jivesoftware.openfire.roster.Roster.getRosterItem(Roster.java:218) ~[xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907261152Z"}
{"log":"\u0009at org.jivesoftware.openfire.roster.Roster.shareGroupRenamed(Roster.java:1125) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.90728007Z"}
{"log":"\u0009at org.jivesoftware.openfire.roster.RosterManager.groupModified(RosterManager.java:370) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907297794Z"}
{"log":"\u0009at org.jivesoftware.openfire.event.GroupEventDispatcher.dispatchEvent(GroupEventDispatcher.java:145) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.90731507Z"}
{"log":"\u0009at org.jivesoftware.openfire.group.DefaultGroupPropertyMap.insertProperty(DefaultGroupPropertyMap.java:483) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907331995Z"}
{"log":"\u0009at org.jivesoftware.openfire.group.DefaultGroupPropertyMap.put(DefaultGroupPropertyMap.java:78) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907349895Z"}
{"log":"\u0009at org.jivesoftware.openfire.group.DefaultGroupPropertyMap.put(DefaultGroupPropertyMap.java:89) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907367031Z"}
{"log":"\u0009at org.jivesoftware.openfire.admin.group_002dedit_jsp._jspService(group_002dedit_jsp.java:342) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907382033Z"}
{"log":"\u0009at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70) [apache-jsp-8.5.40.jar:8.5.40]\n","stream":"stdout","time":"2019-09-26T07:49:35.907391902Z"}
{"log":"\u0009at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api-3.1.0.jar:3.1.0]\n","stream":"stdout","time":"2019-09-26T07:49:35.907401579Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907411156Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907420933Z"}
{"log":"\u0009at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129) [sitemesh-2.4.2.jar:?]\n","stream":"stdout","time":"2019-09-26T07:49:35.907431942Z"}
{"log":"\u0009at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77) [sitemesh-2.4.2.jar:?]\n","stream":"stdout","time":"2019-09-26T07:49:35.907441757Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907451082Z"}
{"log":"\u0009at org.jivesoftware.util.LocaleFilter.doFilter(LocaleFilter.java:73) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907460616Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90746993Z"}
{"log":"\u0009at org.jivesoftware.util.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:49) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907487833Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907498605Z"}
{"log":"\u0009at org.jivesoftware.admin.PluginFilter.doFilter(PluginFilter.java:226) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907508142Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907517486Z"}
{"log":"\u0009at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:234) [xmppserver-4.4.2.jar:4.4.2]\n","stream":"stdout","time":"2019-09-26T07:49:35.907527054Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90753644Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90754589Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907555268Z"}
{"log":"\u0009at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [jetty-security-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907564736Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907574288Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907584871Z"}
{"log":"\u0009at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1700) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907594713Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907604074Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907613517Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907623133Z"}
{"log":"\u0009at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) [jetty-servlet-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907632802Z"}
{"log":"\u0009at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1667) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907642247Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907651968Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907661651Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907671067Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907698382Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:152) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907710096Z"}
{"log":"\u0009at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907719594Z"}
{"log":"\u0009at org.eclipse.jetty.server.Server.handle(Server.java:505) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907729077Z"}
{"log":"\u0009at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90773857Z"}
{"log":"\u0009at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267) [jetty-server-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907749134Z"}
{"log":"\u0009at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [jetty-io-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907759019Z"}
{"log":"\u0009at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [jetty-io-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907768508Z"}
{"log":"\u0009at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [jetty-io-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90777789Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907787291Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907796724Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.90780636Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907816088Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907825633Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:698) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907835216Z"}
{"log":"\u0009at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:804) [jetty-util-9.4.18.v20190429.jar:9.4.18.v20190429]\n","stream":"stdout","time":"2019-09-26T07:49:35.907844617Z"}
{"log":"\u0009at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]\n","stream":"stdout","time":"2019-09-26T07:49:35.907854013Z"}

The error itself tells you that the user to which the roster change is sent does not exist on your server. Can you verify that a user with the JID “FedorovaIV@belwest.corp” exists on your server?

This error will be logged for every (non-existing) user that is affected by the name change, but is otherwise ignored. I don’t see how this can make the server freeze. Maybe there’s a larger issue at play?

Judging by the output format of your logs, you’re using a modified version of Openfire. Have you tried doing this with an unmodified version of Openfire?

User FedorovaIV@belwest.corp exists. The same error for all AD users. A full log consists of millions of records of this kind. Openfire launched in docker, tried different versions, the same error.

Same issue with Openfire 4.2.1 (663 ldap users, 156 ldap groups, 30 shared groups)
If I rename group (shared for all users) - Openfire web console thinks ~10 min
After 10 min - console successfully save the group

all. log is full of this messages:
2020.04.07 15:46:09 WARN [Jetty-QTP-AdminConsole-36]: org.jivesoftware.openfire.roster.Roster - Unexpected error while broadcasting shared group rename for user ‘COMP$@domail.local’!

Server try to broadcast shared group renaming to all domain computers, offline users and users without any Jabber clients

Is it possible to decrease “broadcasting shared group rename” timeout?

I believe this is fixed with the present version of Openfire, 4.5.1

1 Like

Thanks! Upgrade to 4.5.1 fixed issue. Now group renaming is very fast