After a while granting permissions to a MUC for a LDAP group, OF shows a different name of the LDAP group. For instance when I grant permissions to group “cmd” after an unkown while OF change the name to dtpg====. This happens also to other 2 MUC. When I click on the group under the MUC config pages/Permissions it leads me to nothing because the group does not exits. All the other 5 MUC are good to go. Name of these groups remains as set up.
Do the other two rooms also change from cmd to dtpg====, or is the naming different? I do not recognize the name dtpg====. Does it exist in your LDAP directory?
Can you find any references to dtpg==== anywhere in the system (including the database and log files)?
The other 5 unaffected MUCs - do they have this group assigned? Do these, or the affected groups, have any other groups assigned?
This is Openfire 4.7.1?
the other two rooms had the same strange group name yesterday. After setting th correct groups in the morning I’ve got this now. Different weird names from the day before. In addition I have added a second group and also this group was changed from what ever.
User have no access to the MUC.
the other MUCs have different groups assigned. Working well.
Yes last version of OF. 4.7.1
The second group I have assigned to one of the MUC pictured below, is one of those I am using for a MUC what is not affected. So should not be an ldap issue, at least I think so.
Slapcat on the ldap server shows all posix groups in the correct way and in addition even the self developed ldap admin tool php based shows all groups properly.
I dont know what is going on here…
- Removed records from database
- I cleared the OF cache
- Re-added the groups to the MUC again
And then the OF sql functions writing new strange records to the database.
I have added a second group which is called sysadmin.
OF admin console parses it to edsn6ob4dk======
Please see logs row 3 below.
And I have just reconized , no matter what MUC I touch, it just occurs to any MUC now.
2022.07.12 16:40:00 TRACE [hz.openfire.cached.thread-4]: com.hazelcast.crdt.CRDTReplicationTask - [10.0.0.102]:5701 [openfire] [3.12.5] Skipping replication of hz:impl:PNCounterService for target Member [10.0.0.103]:5701 - 6d873ee9-2314-4c69-a3c0-852182bfdfb4
2022.07.12 16:40:00 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.group.GroupJID - Parsing JID from string: edsn6ob4dk======@xxxx.net/e0cbf0e62d03796f31da47099682b72b
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Trying to find a groups's RDN based on their group name: 'uid'. Field: 'admins', Base DN: 'dc=xxxx,dc=net' ...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Creating a DirContext in LdapManager.getContext() for baseDN 'dc=xxxx,dc=net'...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Created hashtable with context values, attempting to create context...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - ... context created successfully, returning.
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Starting LDAP search for group 'admins'...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - ... search finished for group 'admins'.
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Processing relative LDAP SearchResult: 'cn=admins,ou=groups: null:null:{cn=cn: admins}'
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Creating a DirContext in LdapManager.getContext() for baseDN 'dc=xxxx,dc=net'...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - Created hashtable with context values, attempting to create context...
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapManager - ... context created successfully, returning.
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.ldap.LdapGroupProvider - Loading members of group: admins
2022.07.12 16:40:00 INFO [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.muc.MUCRoom - Applying affiliation change for andre.dombrowsky@xxxx.net
2022.07.12 16:40:00 INFO [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.muc.MUCRoom - New affiliation: owner
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.spi.RoutingTableImpl - Unable to route packet. No session is available so store offline. <message from="admins@spt-rooms.xxxx.net" to="omel.roberts@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.spi.RoutingTableImpl - Failed to route packet to JID: omel.roberts@xxxx.net packet: <message from="admins@spt-rooms.xxxx.net" to="omel.roberts@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.MessageRouter - Message sent to unreachable address: <message from="admins@spt-rooms.xxxx.net" to="omel.roberts@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 TRACE [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.MessageRouter - Delegating to offline message strategy.
2022.07.12 16:40:00 TRACE [hz.openfire.partition-operation.thread-0]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Routing User Sessions for [10.0.0.102]:5701 - 5e882ecd-5348-44cc-afdf-fe5e19c4e871, thread ID: 234603
2022.07.12 16:40:00 TRACE [hz.openfire.partition-operation.thread-0]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Routing User Sessions
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.spi.RoutingTableImpl - Unable to route packet. No session is available so store offline. <message from="admins@spt-rooms.xxxx.net" to="dan.fortune@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.spi.RoutingTableImpl - Failed to route packet to JID: dan.fortune@xxxx.net packet: <message from="admins@spt-rooms.xxxx.net" to="dan.fortune@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.MessageRouter - Message sent to unreachable address: <message from="admins@spt-rooms.xxxx.net" to="dan.fortune@xxxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="admins@spt-rooms.xxxx.net"/></message>
2022.07.12 16:40:00 TRACE [Jetty-QTP-AdminConsole-234603]: org.jivesoftware.openfire.MessageRouter - Delegating to offline message strategy.
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.apache.mina.filter.ssl.SslFilter - Session Server[71779](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=198 cap=4096: 3C 6D 65 73 73 61 67 65 20 66 72 6F 6D 3D 22 61...]
2022.07.12 16:40:00 TRACE [Jetty-QTP-AdminConsole-234603]: class org.jivesoftware.openfire.streammanagement.StreamManager[10.0.0.112] - Added stanza of type 'message' to collection of unacknowledged stanzas (x=194). Collection size is now 5.
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: class org.jivesoftware.openfire.streammanagement.StreamManager[10.0.0.112] - Requesting acknowledgement from peer, as we have 5 or more unacknowledged stanzas.
2022.07.12 16:40:00 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 71779
Queue : [MESSAGE_SENT, ]
2022.07.12 16:40:00 DEBUG [Jetty-QTP-AdminConsole-234603]: org.apache.mina.filter.ssl.SslFilter - Session Server[71779](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=27 cap=32: 3C 72 20 78 6D 6C 6E 73 3D 27 75 72 6E 3A 78 6D...]
2022.07.12 16:40:00 DEBUG [socket_c2s-thread-22]: org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 71779
2022.07.12 16:40:00 DEBUG [NioProcessor-4]: org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 71779
Queue : [MESSAGE_SENT, ]
this is really weird. what db are you using?
MySQL
- Server: Localhost via UNIX socket
- Server-Typ: MariaDB
- Server-Version: 10.3.32-MariaDB-log - MariaDB Server
- Protokoll-Version: 10
Table character set
utf8_general_ci
What’s the Linux flavour?
Which LDAP provider are you using?
Linux RedHat 8
Linux version 4.18.0-348.23.1.el8_5.x86_64 (mockbuild@x86-vm-07.build.eng.bos.redhat.com) (gcc version 8.5.0 20210514 (Red Hat 8.5.0-4) (GCC)) #1 SMP Tue Apr 12 11:20:32 EDT 2022
Openldap
$OpenLDAP: slapd 2.4.48 (Dec 15 2021 12:13:34)
But it was working for a long time without any issues. Not able able to say when it commenced, did not touch the MUCs for long.
This is just one posix group result of ldapsearch.
Looks good to me.
id=000001eb
dn: cn=hq,ou=groups,dc=xxx,dc=net
gidNumber: 200
cn: hq
description: Heads of xxx Headquarter, Chatgroup
objectClass: top
objectClass: posixGroup
structuralObjectClass: posixGroup
entryUUID: b6517766-9539-103c-84d2-553f5dc60a43
creatorsName: cn=xxx,dc=xxx,dc=net
createTimestamp: 20220711074918Z
memberUid: hans.k
memberUid: ralf.b
memberUid: wolfgang.h
memberUid: arkadiusz.r
memberUid: stephen.n
memberUid: kenneth.f
memberUid: rosario.m
memberUid: david.r
entryCSN: 20220711075310.264485Z#000000#001#000000
modifiersName: cn=xxx,dc=xxx,dc=net
modifyTimestamp: 20220711075310Z
This is a base32 encoded representation of sysadm. For ‘group’ JIDs, we use base32 encoding. It looks like the encoded representation unexpectedly escapes somewhere.
Any clue what I am supposed to do in order to fix this?
I don’t think that there’s anything that you can do about this. This seems to be a bug in Openfire. I have raised it in our bug tracker system as [OF-2468] - Ignite Realtime Jira
Ok thank you Guus
fyi. .I’m not seeing this issue with Windows, AD, and MS SQL stack. I wonder if replacing the mysql jdbc driver included with openfire with the mariadb one would do anything for you. might be worth a try.
for fun, I’ve loaded up a mariadb on my windows machine to see what happens.
all vanilla
openfire 4.7.1
windows AD
MariaDB 10.3.35
so far so good for me. no oddities
Still have this issue after updating OF to 4.7.2.
As Guus mentioned he thinks it’s a bug of OF.
I dont think it has something to do with SQL. But I could be wrong. Since I dont know what the code does and the Debug logs are not that verbose I do not get where parsing sticks.
OF, when it comes to parsing logs the base32 but close after this the proper name of the group is visible going through the logs. So in the datebase is the wrong name but in the admin console is still the correct name visible until the cache gets purged or a restart of the OF service was performed. If I delete the related database record it is still in the cache and will not be seen any longer after a while or directly after performing a service restart.
On the group summery page and everywhere else the groups are shown properly.
2022.07.18 16:04:45 DEBUG [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.group.GroupJID - Parsing JID from string: cdmm8===@xxx.net/dfff0a7fa1a55c8c1a4966c19f6da452
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-3]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Routing User Sessions for [10.0.0.102]:5701 - 12e7dca0-f735-4b79-9a5a-23047f791515, thread ID: 34
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-3]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Routing User Sessions
2022.07.18 16:04:45 DEBUG [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.spi.RoutingTableImpl - Unable to route packet. No session is available so store offline. <message from="cmd@cmd-rooms.xxx.net" to="heinrich.ebel@xxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="cmd@cmd-rooms.xxx.net"/></message>
2022.07.18 16:04:45 DEBUG [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.spi.RoutingTableImpl - Failed to route packet to JID: heinrich.ebel@xxx.net packet: <message from="cmd@cmd-rooms.xxx.net" to="heinrich.ebel@xxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="cmd@cmd-rooms.xxx.net"/></message>
2022.07.18 16:04:45 DEBUG [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.MessageRouter - Message sent to unreachable address: <message from="cmd@cmd-rooms.xxx.net" to="heinrich.ebel@xxx.net"><x xmlns="http://jabber.org/protocol/muc#user"/><x xmlns="jabber:x:conference" jid="cmd@cmd-rooms.xxx.net"/></message>
2022.07.18 16:04:45 TRACE [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.MessageRouter - Delegating to offline message strategy.
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Sequences for [10.0.0.102]:5701 - 12e7dca0-f735-4b79-9a5a-23047f791515, thread ID: 34
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-1]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Sequences
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-3]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock MUC Service 'cmd-rooms' Rooms for [10.0.0.102]:5701 - 12e7dca0-f735-4b79-9a5a-23047f791515, thread ID: 34
2022.07.18 16:04:45 TRACE [Jetty-QTP-AdminConsole-34]: org.jivesoftware.openfire.muc.spi.LocalMUCRoomManager - Syncing room 'cmd' of service 'cmd-rooms' (destroy: false)
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-3]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock MUC Service 'cmd-rooms' Rooms
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-0]: com.hazelcast.concurrent.lock.operations.LockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Acquired lock Sequences for [10.0.0.102]:5701 - 12e7dca0-f735-4b79-9a5a-23047f791515, thread ID: 34
2022.07.18 16:04:45 TRACE [hz.openfire.partition-operation.thread-0]: com.hazelcast.concurrent.lock.operations.UnlockOperation - [10.0.0.102]:5701 [openfire] [3.12.5] Released lock Sequences
2022.07.18 16:04:46 TRACE [hz.openfire.InvocationMonitorThread]: com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor - [10.0.0.102]:5701 [openfire] [3.12.5] Scanning all invocations