NPE in VCardModule.process/JDBCMucDAO.updateRoomAvatar (#148)

Wojciech Kapcia (Tigase) opened 3 years ago

[2022-06-12 19:47:01:293] [SEVERE  ] [              in_7-muc ] StanzaProcessor.processPacket()  : java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null when processing from=sess-man@ip-172-31-38-91.us-west-2.compute.internal, to=null, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq xmlns="jabber:client" id="YGkHb-SA4Sgz" from="…@sure.im/Conversations.mgHg" type="set" to="…@muc.sure.im"><vCard xmlns="vcard-temp"><PHOTO><TYPE>image/jpeg</TYPE><BINVAL>… ... , SIZE=9193, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=null
java.lang.RuntimeException: java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null
	at tigase.muc.modules.VCardModule.process(VCardModule.java:139)
	at tigase.component.modules.StanzaProcessor.execute(StanzaProcessor.java:214)
	at tigase.component.modules.StanzaProcessor.process(StanzaProcessor.java:201)
	at tigase.component.modules.StanzaProcessor.processPacket(StanzaProcessor.java:103)
	at tigase.component.AbstractKernelBasedComponent.processPacket(AbstractKernelBasedComponent.java:81)
	at tigase.muc.MUCComponent.processPacket(MUCComponent.java:122)
	at tigase.muc.cluster.MUCComponentClustered.processPacket(SourceFile:87)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1398)
Caused by: java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null
	at tigase.muc.repository.JDBCMucDAO.updateRoomAvatar(JDBCMucDAO.java:290)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at tigase.stats.StatisticsInvocationHandler.invoke(StatisticsInvocationHandler.java:75)
	at jdk.proxy2/jdk.proxy2.$Proxy53.updateRoomAvatar(Unknown Source)
	at tigase.muc.repository.MucDAOMDBean.updateRoomAvatar(MucDAOMDBean.java:106)
	at tigase.muc.repository.inmemory.InMemoryMucRepository.updateRoomAvatar(InMemoryMucRepository.java:137)
	at tigase.muc.modules.VCardModule.processSet(VCardModule.java:208)
	at tigase.muc.modules.VCardModule.process(VCardModule.java:132)
	... 7 more

Related
- NullPointerException when processing message with subject (#142) Won't Fix
- NPE in JDBCMucDAO.setSubject (#145) Closed

Activities

Wojciech Kapcia (Tigase) commented 3 years ago

This is same (well, very similar) issue to #issue #142 and boils down to the ID being generated by the database and sometimes not populated on time in the application. @andrzej.wojcik we already discussed it in January and the notion was that "JID is long and uses space" hence using bigint here but... we already have both JID and sha1(JID) columns and indexes so I think we could simply use those instead of autoincremented IDs from the database? What do you think?
Andrzej Wójcik (Tigase) commented 3 years ago

In theory, we could, but it would not solve the issue as you have 2 requests (1 to create room and 1 to set vcard) sent by the client 1 by 1 (without waiting for the result). Due to that, there is a race condition on the server side (in the MUC component) as both requests may be (and most likely are) processed at the same time. Now we have NPE/Internal Server Exception, but without this "id" requirement, we would get failure to update entry on the SQL side (as there may be no room config yet, when vcard is being saved).

I think we should "serialized" room creation and vcard (iq-set) processing on the server side to be on the same thread (we should queue it properly).
Wojciech Kapcia (Tigase) commented 3 years ago

Shouldn't those already be processed on same thread and thus be queued? Seems like packetHash() problem?

Though, I'm not sure if storing the room in the repository (i.e. db not InMemory one) is triggered on event thus causing the issue (the RoomWithId.setId() is called only after the call finishes)?
Andrzej Wójcik (Tigase) commented 3 years ago

I think this packetHash() may be correct but depending on a clustering version, it may be routed between cluster nodes, and then packets will end up on a different thread.

AFAIR RoomWithId.setId() is called after room is stored to the database, but it needs to be stored in memory to make sure no other concurrent request will happen (if I'm correct).
Wojciech Kapcia (Tigase) commented 3 years ago

I think that it's handled differently - direct storing to the repository was disabled (see https://github.com/tigase/tigase-muc/blob/4288f2620647f520c8a33806764a725b5b395e32/src/main/java/tigase/muc/repository/inmemory/InMemoryMucRepository.java#L169-L169 as result of #epicgames-21 ) and it's handled later on: https://github.com/tigase/tigase-muc/blob/4288f2620647f520c8a33806764a725b5b395e32/src/main/java/tigase/muc/modules/PresenceModuleImpl.java#L365-L365 via tigase.muc.RoomConfig#notifyConfigUpdate(boolean) so while it's done is slightly different place (and later on) it's still should be handled by the same thread so it seems more like concurrency issue and packets not being handled by the same thread (i.e. issue with packetHash()?
Andrzej Wójcik (Tigase) commented 3 years ago

Actually, packetHash() looks ok. I'm not sure what is actually happening here, with just part of a log, but I wonder if it was not possible that room creation (in the database) throw an exception that caused id not to be set while the room was left in the memory (in the Map). That could cause an issue like that.
Wojciech Kapcia (Tigase) commented 3 years ago

If there was an exception it wasn't logged, though it seems lack of id after storing to the database should even throw exception (see https://github.com/tigase/tigase-muc/blob/4288f2620647f520c8a33806764a725b5b395e32/src/main/java/tigase/muc/repository/JDBCMucDAO.java#L92-L92). Possibly #issue #145 is also relevant here.
Andrzej Wójcik (Tigase) commented 3 years ago

But this would not set the id nor will it remove the room from the cache of rooms and #issue #145 most likely is caused by the same issue.
Andrzej Wójcik (Tigase) commented 3 years ago

Just a wild guess, didn't someone try to use emoji in localpart of the MUC room?

Wojciech Kapcia (Tigase) commented 3 years ago

(private comment) Longer log:

[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] SessionManager.processPacket()   : Packet processed by: [vcard-temp]
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] JabberIqPrivacy.allowed()        : Using privacy list: null
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] MobileV2.filter()                : packet without destination
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] DomainFilter.filter()            : Filtering (packet): from=c2s@ip-172-31-38-91.us-west-2.compute.internal/192.168.96.2_5223_172.31.13.186_49882, to=sess-man@ip-172-31-38-91.us-west-2.compute.internal, serverAuthorisedStanzaFrom=Optional[ferris_dawn@sure.im/Conversations.mgHg], DATA=<iq xmlns="jabber:client" id="5CNpDxtIdPVH" from="ferris_dawn@sure.im/Conversations.mgHg" type="set" to="azovuka@muc.sure.im"><vCard xmlns="vcard-temp"><PHOTO><TYPE>image/jpeg</TYPE><BINVAL>/9j/4AAQSkZJRgABAQAAAQABAAD/4gIoSUNDX1BST0ZJTEUAAQEAAAIYAAAAAAIQAABtbnRyUkdC
IFhZWiAAAAAAAAAAAAAAAABhY3NwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAA9tYAAQAA
AADTLQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAlk
ZXNjAAAA8AAAAHRyWFlaAAABZAAAABRnWFlaAAABeAAAABRiWFlaAAABjAAAABRyVFJDAAABoAAA
AChnVFJDAAABoAAAAChiVFJDAAABoAAAACh3dHB0AAAByAAAABRjcHJ0AAAB3AAAADxtbHVjAAAA
AAAAAAEAAAAMZW5VUwAAAFgAAAAcAHMAUgBHAEIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFhZWiAA
AAAAAABvogAAOPUAAAOQWFlaIAAAAAAAAGKZAAC3hQAAGNpYWVogAAAAAAAAJKAAAA+EAAC2z3Bh
cmEAAAAAAAQAAAACZmYAAPKnAAANWQAAE9AAAApbAAAAAAAAAABYWVogAAAAAAAA9tYAAQAAAADT
LW1sdWMAAAAAAAAAAQAAAAxlblVTAAAAIAAAABwARwBvAG8AZwBsAGUAIABJAG4AYwAuACAAMgAw
ADEANv/bAEMACAUGBwYFCAcGBwkICAkMEwwMCwsMGBESDhMcGB0dGxgbGh8jLCUf ... , SIZE=9193, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=d4545b4e-e931-4d82-a302-050eb219b7cf
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] DomainFilter.getDomains()        : Domains read from user session: ALL for VHost: sure.im
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] MessageRouter.processPacket()    : Processing packet: from=sess-man@ip-172-31-38-91.us-west-2.compute.internal, to=null, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq xmlns="jabber:client" id="5CNpDxtIdPVH" from="ferris_dawn@sure.im/Conversations.mgHg" type="set" to="azovuka@muc.sure.im"><vCard xmlns="vcard-temp"><PHOTO><TYPE>image/jpeg</TYPE><BINVAL>/9j/4AAQSkZJRgABAQAAAQABAAD/4gIoSUNDX1BST0ZJTEUAAQEAAAIYAAAAAAIQAABtbnRyUkdC
IFhZWiAAAAAAAAAAAAAAAABhY3NwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAA9tYAAQAA
AADTLQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAlk
ZXNjAAAA8AAAAHRyWFlaAAABZAAAABRnWFlaAAABeAAAABRiWFlaAAABjAAAABRyVFJDAAABoAAA
AChnVFJDAAABoAAAAChiVFJDAAABoAAAACh3dHB0AAAByAAAABRjcHJ0AAAB3AAAADxtbHVjAAAA
AAAAAAEAAAAMZW5VUwAAAFgAAAAcAHMAUgBHAEIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFhZWiAA
AAAAAABvogAAOPUAAAOQWFlaIAAAAAAAAGKZAAC3hQAAGNpYWVogAAAAAAAAJKAAAA+EAAC2z3Bh
cmEAAAAAAAQAAAACZmYAAPKnAAANWQAAE9AAAApbAAAAAAAAAABYWVogAAAAAAAA9tYAAQAAAADT
LW1sdWMAAAAAAAAAAQAAAAxlblVTAAAAIAAAABwARwBvAG8AZwBsAGUAIABJAG4AYwAuACAAMgAw
ADEANv/bAEMACAUGBwYFCAcGBwkICAkMEwwMCwsMGBESDhMcGB0dGxgbGh8jLCUf ... , SIZE=9193, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=null
[2022-06-12 19:47:04:061] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): Called for : azovuka@muc.sure.im
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): No componentID matches (fast lookup against exact address): azovuka@muc.sure.im, for map: [s2s@ip-172-31-38-91.us-west-2.compute.internal, amp@ip-172-31-38-91.us-west-2.compute.internal, pubsub@ip-172-31-38-91.us-west-2.compute.internal, socks5@ip-172-31-38-91.us-west-2.compute.internal, muc@ip-172-31-38-91.us-west-2.compute.internal, push@ip-172-31-38-91.us-west-2.compute.internal, http@ip-172-31-38-91.us-west-2.compute.internal, vhost-man@ip-172-31-38-91.us-west-2.compute.internal, message-router@ip-172-31-38-91.us-west-2.compute.internal, sess-man@ip-172-31-38-91.us-west-2.compute.internal, c2s@ip-172-31-38-91.us-west-2.compute.internal, ext@ip-172-31-38-91.us-west-2.compute.internal, eventbus@ip-172-31-38-91.us-west-2.compute.internal, cl-comp@ip-172-31-38-91.us-west-2.compute.internal, ext-disco@ip-172-31-38-91.us-west-2.compute.internal, bosh@ip-172-31-38-91.us-west-2.compute.internal, stats@ip-172-31-38-91.us-west-2.compute.internal, ws2s@ip-172-31-38-91.us-west-2.compute.internal, upload@ip-172-31-38-91.us-west-2.compute.internal, monitor@ip-172-31-38-91.us-west-2.compute.internal, cluster-contr@ip-172-31-38-91.us-west-2.compute.internal, message-archive@ip-172-31-38-91.us-west-2.compute.internal, mix@ip-172-31-38-91.us-west-2.compute.internal]; trying VHost lookup
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): No component name matches (VHost lookup against component name): azovuka@muc.sure.im, for map: [ext, vhost-man, upload, amp, c2s, ws2s, monitor, bosh, push, cl-comp, socks5, ext-disco, stats, eventbus, s2s, http, muc, sess-man, message-archive, cluster-contr, mix, message-router, pubsub], for all VHosts: [hosts count: 35]; trying other forms of addressing
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): Component matched: azovuka@muc.sure.im, for comp: [ext, vhost-man, upload, amp, c2s, ws2s, monitor, bosh, push, cl-comp, socks5, ext-disco, stats, eventbus, s2s, http, muc, sess-man, message-archive, cluster-contr, mix, message-router, pubsub], basename: sure.im
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): Called for : azovuka@muc.sure.im
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): No componentID matches (fast lookup against exact address): azovuka@muc.sure.im, for map: [s2s@ip-172-31-38-91.us-west-2.compute.internal, amp@ip-172-31-38-91.us-west-2.compute.internal, pubsub@ip-172-31-38-91.us-west-2.compute.internal, socks5@ip-172-31-38-91.us-west-2.compute.internal, muc@ip-172-31-38-91.us-west-2.compute.internal, push@ip-172-31-38-91.us-west-2.compute.internal, http@ip-172-31-38-91.us-west-2.compute.internal, vhost-man@ip-172-31-38-91.us-west-2.compute.internal, message-router@ip-172-31-38-91.us-west-2.compute.internal, sess-man@ip-172-31-38-91.us-west-2.compute.internal, c2s@ip-172-31-38-91.us-west-2.compute.internal, ext@ip-172-31-38-91.us-west-2.compute.internal, eventbus@ip-172-31-38-91.us-west-2.compute.internal, cl-comp@ip-172-31-38-91.us-west-2.compute.internal, ext-disco@ip-172-31-38-91.us-west-2.compute.internal, bosh@ip-172-31-38-91.us-west-2.compute.internal, stats@ip-172-31-38-91.us-west-2.compute.internal, ws2s@ip-172-31-38-91.us-west-2.compute.internal, upload@ip-172-31-38-91.us-west-2.compute.internal, monitor@ip-172-31-38-91.us-west-2.compute.internal, cluster-contr@ip-172-31-38-91.us-west-2.compute.internal, message-archive@ip-172-31-38-91.us-west-2.compute.internal, mix@ip-172-31-38-91.us-west-2.compute.internal]; trying VHost lookup
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): No component name matches (VHost lookup against component name): azovuka@muc.sure.im, for map: [ext, vhost-man, upload, amp, c2s, ws2s, monitor, bosh, push, cl-comp, socks5, ext-disco, stats, eventbus, s2s, http, muc, sess-man, message-archive, cluster-contr, mix, message-router, pubsub], for all VHosts: [hosts count: 35]; trying other forms of addressing
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.getLocalComponent(): Component matched: azovuka@muc.sure.im, for comp: [ext, vhost-man, upload, amp, c2s, ws2s, monitor, bosh, push, cl-comp, socks5, ext-disco, stats, eventbus, s2s, http, muc, sess-man, message-archive, cluster-contr, mix, message-router, pubsub], basename: sure.im
[2022-06-12 19:47:04:062] [FINEST  ] [              in_7-muc ] MessageRouter.processPacket()    : 1. Packet will be processed by: muc@ip-172-31-38-91.us-west-2.compute.internal, from=sess-man@ip-172-31-38-91.us-west-2.compute.internal, to=null, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq xmlns="jabber:client" id="5CNpDxtIdPVH" from="ferris_dawn@sure.im/Conversations.mgHg" type="set" to="azovuka@muc.sure.im"><vCard xmlns="vcard-temp"><PHOTO><TYPE>image/jpeg</TYPE><BINVAL>/9j/4AAQSkZJRgABAQAAAQABAAD/4gIoSUNDX1BST0ZJTEUAAQEAAAIYAAAAAAIQAABtbnRyUkdC
IFhZWiAAAAAAAAAAAAAAAABhY3NwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAA9tYAAQAA
AADTLQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAlk
ZXNjAAAA8AAAAHRyWFlaAAABZAAAABRnWFlaAAABeAAAABRiWFlaAAABjAAAABRyVFJDAAABoAAA
AChnVFJDAAABoAAAAChiVFJDAAABoAAAACh3dHB0AAAByAAAABRjcHJ0AAAB3AAAADxtbHVjAAAA
AAAAAAEAAAAMZW5VUwAAAFgAAAAcAHMAUgBHAEIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFhZWiAA
AAAAAABvogAAOPUAAAOQWFlaIAAAAAAAAGKZAAC3hQAAGNpYWVogAAAAAAAAJKAAAA+EAAC2z3Bh
cmEAAAAAAAQAAAACZmYAAPKnAAANWQAAE9AAAApbAAAAAAAAAABYWVogAAAAAAAA9tYAAQAAAADT
LW1sdWMAAAAAAAAAAQAAAAxlblVTAAAAIAAAABwARwBvAG8AZwBsAGUAIABJAG4AYwAuACAAMgAw
ADEANv/bAEMACAUGBwYFCAcGBwkICAkMEwwMCwsMGBESDhMcGB0dGxgbGh8jLCUf ... , SIZE=9193, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=null
[2022-06-12 19:47:04:063] [SEVERE  ] [              in_7-muc ] StanzaProcessor.processPacket()  : java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null when processing from=sess-man@ip-172-31-38-91.us-west-2.compute.internal, to=null, serverAuthorisedStanzaFrom=Optional.empty, DATA=<iq xmlns="jabber:client" id="5CNpDxtIdPVH" from="ferris_dawn@sure.im/Conversations.mgHg" type="set" to="azovuka@muc.sure.im"><vCard xmlns="vcard-temp"><PHOTO><TYPE>image/jpeg</TYPE><BINVAL>/9j/4AAQSkZJRgABAQAAAQABAAD/4gIoSUNDX1BST0ZJTEUAAQEAAAIYAAAAAAIQAABtbnRyUkdC
IFhZWiAAAAAAAAAAAAAAAABhY3NwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAA9tYAAQAA
AADTLQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAlk
ZXNjAAAA8AAAAHRyWFlaAAABZAAAABRnWFlaAAABeAAAABRiWFlaAAABjAAAABRyVFJDAAABoAAA
AChnVFJDAAABoAAAAChiVFJDAAABoAAAACh3dHB0AAAByAAAABRjcHJ0AAAB3AAAADxtbHVjAAAA
AAAAAAEAAAAMZW5VUwAAAFgAAAAcAHMAUgBHAEIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFhZWiAA
AAAAAABvogAAOPUAAAOQWFlaIAAAAAAAAGKZAAC3hQAAGNpYWVogAAAAAAAAJKAAAA+EAAC2z3Bh
cmEAAAAAAAQAAAACZmYAAPKnAAANWQAAE9AAAApbAAAAAAAAAABYWVogAAAAAAAA9tYAAQAAAADT
LW1sdWMAAAAAAAAAAQAAAAxlblVTAAAAIAAAABwARwBvAG8AZwBsAGUAIABJAG4AYwAuACAAMgAw
ADEANv/bAEMACAUGBwYFCAcGBwkICAkMEwwMCwsMGBESDhMcGB0dGxgbGh8jLCUf ... , SIZE=9193, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set, STABLE_ID=null
java.lang.RuntimeException: java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null
	at tigase.muc.modules.VCardModule.process(VCardModule.java:139)
	at tigase.component.modules.StanzaProcessor.execute(StanzaProcessor.java:214)
	at tigase.component.modules.StanzaProcessor.process(StanzaProcessor.java:201)
	at tigase.component.modules.StanzaProcessor.processPacket(StanzaProcessor.java:103)
	at tigase.component.AbstractKernelBasedComponent.processPacket(AbstractKernelBasedComponent.java:81)
	at tigase.muc.MUCComponent.processPacket(MUCComponent.java:122)
	at tigase.muc.cluster.MUCComponentClustered.processPacket(SourceFile:87)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1398)
Caused by: java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "tigase.muc.RoomWithId.getId()" is null
	at tigase.muc.repository.JDBCMucDAO.updateRoomAvatar(JDBCMucDAO.java:290)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at tigase.stats.StatisticsInvocationHandler.invoke(StatisticsInvocationHandler.java:75)
	at jdk.proxy2/jdk.proxy2.$Proxy53.updateRoomAvatar(Unknown Source)
	at tigase.muc.repository.MucDAOMDBean.updateRoomAvatar(MucDAOMDBean.java:106)
	at tigase.muc.repository.inmemory.InMemoryMucRepository.updateRoomAvatar(InMemoryMucRepository.java:137)
	at tigase.muc.modules.VCardModule.processSet(VCardModule.java:208)
	at tigase.muc.modules.VCardModule.process(VCardModule.java:132)
	... 7 more

Room data from repo:

mysql> select * from tig_muc_rooms where jid = 'azovuka@muc.sure.im' \G
*************************** 1. row ***************************
             room_id: 4466
                 jid: azovuka@muc.sure.im
            jid_sha1: db3c5a8612d1c8b589773cff3ab9d087f79a3506
                name: ?????-???
              config: <x xmlns="jabber:x:data" type="form"><field var="muc#roomconfig_roomname" label="Natural-Language Room Name" type="text-single"><value>?????-???</value></field><field var="muc#roomconfig_roomdesc" label="Short Description of Room" type="text-single"/><field var="muc#roomconfig_persistentroom" label="Make Room Persistent?" type="boolean"><value>1</value></field><field var="muc#roomconfig_publicroom" label="Make Room Publicly Searchable?" type="boolean"><value>0</value></field><field var="muc#roomconfig_moderatedroom" label="Make Room Moderated?" type="boolean"><value>0</value></field><field var="muc#roomconfig_membersonly" label="Make Room Members Only?" type="boolean"><value>1</value></field><field var="muc#roomconfig_allowinvites" label="Allow Occupants to Invite Others?" type="boolean"><value>1</value></field><field var="muc#roomconfig_allowpm" label="Who Can Send Private Messages?" type="list-single"><value>anyone</value><option label="Anyone"><value>anyone</value></option><option label="Anyone with Voice"><value>participants</value></option><option label="Moderators Only"><value>moderators</value></option><option label="Nobody"><value>none</value></option></field><field var="muc#roomconfig_passwordprotectedroom" label="Password Required to Enter?" type="boolean"><value>0</value></field><field var="muc#roomconfig_roomsecret" label="Password" type="text-single"/><field var="muc#roomconfig_whois" label="Who May Discover Real JIDs?" type="list-single"><value>anyone</value><option label="Moderators Only"><value>moderators</value></option><option label="Anyone"><value>anyone</value></option></field><field var="muc#roomconfig_changesubject" label="Allow Occupants to Change Subject?" type="boolean"><value>0</value></field><field var="muc#roomconfig_enablelogging" label="Enable Public Logging?" type="boolean"><value>0</value></field><field var="logging_format" label="Logging format:" type="list-single"><value>html</value><option label="HTML"><value>html</value></option><option label="Plain text"><value>plain</value></option></field><field var="muc#maxhistoryfetch" label="Maximum Number of History Messages Returned by Room" type="text-single"><value>50</value></field><field var="muc#roomconfig_maxusers" label="Maximum Number of Occupants" type="list-single"><option label="10"><value>10</value></option><option label="20"><value>20</value></option><option label="30"><value>30</value></option><option label="50"><value>50</value></option><option label="100"><value>100</value></option><option label="None"><value>none</value></option></field><field var="muc#roomconfig_maxresources" label="Maximum Number of Single Occupant Resources" type="list-single"><option label="5"><value>5</value></option><option label="10"><value>10</value></option><option label="20"><value>20</value></option><option label="30"><value>30</value></option><option label="50"><value>50</value></option><option label="100"><value>100</value></option><option label="None"><value>none</value></option></field><field var="tigase#presence_delivery_logic" label="Presence delivery logic" type="list-single"><value>PREFERE_PRIORITY</value><option label="PREFERE_LAST"><value>PREFERE_LAST</value></option><option label="PREFERE_PRIORITY"><value>PREFERE_PRIORITY</value></option></field><field var="tigase#presence_filtering" label="Enable filtering of presence (broadcasting presence only between selected groups" type="boolean"><value>0</value></field><field var="tigase#presence_filtered_affiliations" label="Affiliations for which presence should be delivered" type="list-multi"><option label="outcast"><value>outcast</value></option><option label="none"><value>none</value></option><option label="member"><value>member</value></option><option label="admin"><value>admin</value></option><option label="owner"><value>owner</value></option></field><field var="tigase#welcome_messages" label="Send welcome messages on room creation" type="boolean"><value>1</value></field></x>
             creator: ferris_dawn@sure.im
       creation_date: 2022-06-12 15:05:05.697000
             subject: NULL
subject_creator_nick: NULL
        subject_date: NULL
              avatar: image/jpeg;/9j/4AAQSkZJRgABAQAAAQABAAD/4gIoSUNDX1BST0ZJTEUAAQEAAAIYAAAAAAIQAABtbnRyUkdCIFhZWiAAAAAAAAAAAAAAAABhY3NwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAQAA9tYAAQAAAADTLQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAlkZXNjAAAA8AAAAHRyWFlaAAABZAAAABRnWFlaAAABeAAAABRiWFlaAAABjAAAABRyVFJDAAABoAAAAChnVFJDAAABoAAAAChiVFJDAAABoAAAACh3dHB0AAAByAAAABRjcHJ0AAAB3AAAADxtbHVjAAAAAAAAAAEAAAAMZW5VUwAAAFgAAAAcAHMAUgBHAEIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFhZWiAAAAAAAABvogAAOPUAAAOQWFlaIAAAAAAAAGKZAAC3hQAAGNpYWVogAAAAAAAAJKAAAA+EAAC2z3BhcmEAAAAAAAQAAAACZmYAAPKnAAANWQAAE9AAAApbAAAAAAAAAABYWVogAAAAAAAA9tYAAQAAAADTLW1sdWMAAAAAAAAAAQAAAAxlblVTAAAAIAAAABwARwBvAG8AZwBsAGUAIABJAG4AYwAuACAAMgAwADEANv/bAEMABQQEBAQDBQQEBAYFBQYIDQgIBwcIEAsMCQ0TEBQTEhASEhQXHRkUFhwWEhIaIxocHh8hISEUGSQnJCAmHSAhIP/bAEMBBQYGCAcIDwgIDyAVEhUgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgICAgIP/AABEIAMAAwAMBIgACEQEDEQH/xAAcAAACAgMBAQAAAAAAAAAAAAAAAQIDBAUGBwj/xAA9EAABAwMDAQcDAgQEBAcAAAABAgMRAAQhBRIxQQYTIlFhcYEHFDKRoSOxwfAVUnLRM4Lh8QgkNEJTg5L/xAAaAQEAAwEBAQAAAAAAAAAAAAAAAQIFBAMG/8QALBEAAgIBAwMCBQQDAAAAAAAAAAECAxEEBSESMTJBYVFxgZHwEyKhsSMz4f/aAAwDAQACEQMRAD8A+y6KWaM0A6KWaJoB0Us080AUUs06AKKM0ZoAopUTQDopTTzQBRRmlmgHRRmjNAFFLNPNAFFFFAFFFFAKig06AVFFAoAoo6UZoAop0qAKKKKAKKKKAKKKKADRRNYt5qNhp6Ervr1i1SowC84EA+0mobS5ZKTbwjKork776idkLBwIc1lt5RxFukux7lIIFZWkdtOzmtud1ZainvTw26ktqV7Tz8V4rUVOXSpLPzPd6a5R6nB4+R0VFFFe5zhRRmigDrQaOtFAOlTilQDpGgUUATRRRwaAdLpRNE0A6OK09/2l0DTe8F7q9qwtsSpCnBuH/LzXDax9X9Ptkqb0nTbm7dJhC3QG0Ef5smT7Yrmt1VNXnJHXTo77/wDXBs9QmorcQhJUtSUpGSSYivB7z6jdrbt3vbW9t7ZokDu220zjmCqc1zep6te6uoo1K8ubuJUEuOqCm+hgCP8Aasuzeal4Jv8Ag1q9ivfnJL+T3rV+2Wi6Xpzl03dN3ricJZYWFFZ9xgVx6/q0ssubNCKHADtKnsDyJG0H9K8l3LtbouWyC7tG0oB2qGeSn8TxyI+aidVsENqfeve7ESpt4wofHI/vFZdu66ibzB4X58TWp2WiCxNdX57G61j6jdpXtU7pzW126VJLgZtiG1CD0AyRmMk+tam8UdVSi4v7teouoOHXlbyfmqSzYauyNzTd2lMFIUZKSeCD+ufKrW7F3ZC2VW6043NcK6ZEftmsyy6yflJs2a6qauIRUfoQQm3Kg42EpURCkkdI49arDDjaj/C2kiQpE8xMx0qSrJvYn7hrcEfi60omRPkc9PiqLy6Uw0hLt0G2F+FLwlO0/wCoEQefKqxkWcPVGw0ztrrtje/ao1ZxFzJKWXXjK0zyE9a9D0z6s6kwpprVbFp5tPhW43IUfMzwf0HxXlrVu6hoJ3/fHcFBVyBKB5pVz/Or9rrbii+2t1sgkhKwvu8TyBu8+ldtWrtr8JGXfo6bOJwR9F6X267Naq8GLfUUIcIkJe8G72Jwa6RDiHEBba0rScgpMg18oIbSGEOMJUEqMJCzsWMYGeQY8jWVZdrtV7MJW9pl7drcUf8A0yIKYmD4T4TEZIyPStend2+LI/YxbtmXeqX3Pqeia8M0/wCsWvtIaVfaM3eNwd6kEtrGevI/YTXpOhdvuzOvW6XLe/Qw5EqaeISUmMieK1qtbTb4v7mTdoL6VmUePbk6ulQTWFqGrabpTAf1G8atmzwVqia63JRWWzjjFyeIrLM6lMVw2vfUzQNIaaFm5/iVw8SEtNSIxMkkYrmNR+qt5c6Ypm2sRptwvHeuOb9o6kCK4Ldw09eU5Zfsd9W26mxKSjhe/H/T14qSlJUVAAdZridY+p3ZzS3HGWVuX7zZKVBkQhJ9VHp6ia8avtS1S8uCu+vnbhzKRuVvSrPG0znHp1yK1xKW2lm2NqpThUZUlKUlXQSn+WTWRdvMpLFUcfM29PslcXm6WfZcHoeo/WDUry2UdIsLe1QEypxxzeQJ5BwB+9chqPbTtXqDJCtYeWHEylCMII90+nv7GtP9q9bqNz3YbTKQW0rKk+nMRz5ZxWSyW2tyF265QApTATlI6e3ByMcxWXZqr7OZSb/PY26tJpafCC/v+zHaDq0NubkrMErSpW4zHIOJA98+lScUi1aS5qFwhLCD43gQhJI8zOP7zVrrzBhDTDuxY8QSwokTAyBmfIj94qt9N/3SjYMl9aHMt3G5G3qE7gnxD98+XHJ08nT1krks2Num4S8ENFQALnScAA/71YUouUNlxHfJV4Q4kmYjqnH95xV7bb71mHFMBt0okie8B4noAetVufavJP3KEgttyhaiWykGZyMgeH9sExTpI68osQwhtQ+0Lb7aYQRMdOJ6R5eVYN5pqHrhKS2lTgBUkQdyPMTHHuf1rNatmW7pGpMbXVrb2L8RhyYInMTAEYz+1ZSTar2vuBawoRtMkpk4gDkYmc+9RgqrHF5Ry6V39qp1Ns006y5CV90kl0DJmARPsIMD5robA97atuNul9SkgSuNyo9sA54wRNReZadcTcIKm3MhLityd3OCMTgHp5+tDNm2pj7m5U4yuSpwtuTznk4j36detS0iZT6jKUz3ralMBK4wAkxnjJx+0GsRywtXStdzapbfI8Y/IKn25H+1Z65SltQGMBLnmD/m8zUCq6cuQ4MsPShJQkqkwIMjp0+eapjB5qTzwa23bYTubSttLO4huRsKSOYKjKpORHNXISBtUUh4JKhuT+Q6ER5/FK60a3Vcm6WwlFykfw1jwlRI5IjOT6/0poWQpKnWt4BKC6laS42RAIMc5jjjqBU/IvlS9cift231NvsqKCopUVFEEichQIx18iPSpFTqHFbgXAmOEng9R5ipKZW+kXiEJeWnwpdSUgkehn4zBwaw7Zm4cuFy64qRKkBoBEgkAztyqRxIMVOclOj4A6th+6cYShxh0p8LgSQF+cEcEeX7VUAltHdPKWHW4BdAAVHnOAR/XnyrcFVuysJuD3IIhLiiAkx0Oev9isF7WNMYV3paU86AU/8AE8KvWIkdf+uK9IKT7I8nJR4Z1Wp/UXtNq7LrbKmbK1XmLae8CZwd0z0MxFcO+6t4tpuHC+FGULdcKlcYVPyD+3rWxTZuv2hSltNs2QSlJUVqTjxCOMmOJByetY7DF1pq1pS8hy2UCsLWDvQI8SSJAOcmBxMCc172Wzt5nLLJphVUsVRSK2e6ecLLwHelPdpeQkECB+JgTGcycT0rJSbdq4bt3VpbUpP8MOHwmByD5fyj3NYWptXhcTeWb7yXELQsNhAcCkkbSFAgEZOP1jBrL7uyuC3bO2Kz4CEJSjBVGBIkpHPTofjzS7ZPRy9UUXDTV613Z1B61cAlLjTx2gdFECAQQRz8eVL7fUrHukFarloJy86QSqB/lAgjjxHj2rYBq1snFJU84w3ISEDIwQApIAwPU8ekVp727sn0lD76W1MgqQ82nvVNePmBBGUkeRInpFTx9AnJ8JG1Zc3243NLAQSlSEoBJkzwckGZgc4jyrEVYBhAdfUd4UNjwzCQfD4RB6gQZMjHQCVrdJbZ++t3NrC0gpW4CFCCZSTyBzGBE4xxnNAlgBfdpO0bSHNyUETwCAIHHA/aqcIhtplXdF1a0OMrZcbx4SrxZBJERuHAKc/E0koUmXndhUEBKiCqG8nKem39xnoIEkodW+s/dN/w/EksgIKB4p5JB9scGearRcXKQglh4tp3FTqU7TMcpCiTmQYIMweaYzwG8g47avOmxTdDvlgO9ykjvE5jckEevXBPrzY0m3TdOuqbeeEqRJgpVieJ8JxByJgkipJskItmg1dPFLxUe8TBwf8AT8/iRzV6EP21wsJKrhtISVIWfEcZVOJMfrBzxU5KtrshM29q7p7aGmu5ZcgJTsKCiCTtI6EeQx0jIrFtkqQUN3INvcAhSLgGQcR7Z/r7Gto4nu0KWpCEtBAUC6RtPM7ugIM5nqeOa1vf2+p2+y1eKHysqKVgpWhUHJTEz5ZiJgkURVPPBlKVcrvkotVBLcEvJUkkqiBKT0/TrV4beacS7PgcSJAEfOT8Vr7K6aeUu2dSVXTJCm1gnKSf1gjHSk3otoxdofY3792e/JWUjqBJBHoZMetUeD0xhtMyxfbfC87vC8I2J5nAEGc8/E/FxcDTKpUVtETMg7euT1E9f51iPtypIedaba3DJUJUkZgeRkA8HA6Gte7r1swttCnjdO7gpSkpKEkHpEq6+p/3lQbXBRyijZBTwT3y+8SRCFoQoKSg9DJAPWJ9fmol9p515tZ7tLapcK17QnJ/Tz5nn55l3tBdfdFxhwsMJHhZSAJzIyMj/t5Vrn9SeeTLityiPEqcqInJ8+T+teipz3Ic32ijtjqen2CSFOrcWAZUYAVBiSYzWove1JXKWUpwTsO0SB5T/wBq5Jy4UW1KWriSSarJUVwa9lXBehT9OUuZM2D1446tS1uKUVGSSZmsZThVyqqQPPNMcxVj0jBI3Flrmo2av+N37ZgFDxKgB6ZxW1Rqun3qCm7723PJKVHbu6HGRnPHQZxXN7Tz6QKiRGBxFeGEdkoJ8o7q3u1W7QuWz9xKggustBRKCeFc8deAJmYkmTl2ENpvmu7WhUIOwzIVED9xnoBOYArimX3mCC04pB6FJitmnW1Kt+5faSo58QwT7+dVccHO6Wnk3z14t1KnXLVovW7qW+9UyoJlUfiRMAynqYyTxFYTdhall66vdPbTfqJDrqUJQViecf1Mwc+VYlu4zeAJXeKaKdstOeIKSnPOB+2P1rPbs121y68EtvLcBSq6cBU6J/EAJSCRmOREDmq44K4cXgxmNHtW3UtWri0lmSlCCSkp9fSZ5NZdq24NQcSLxwJACVNrWpQn2Bgf9enJuUBJNq2kOKaVBgJkjaQePXmOah9rdLU2p4I3kEHqFZ4BxPPHxXm84L9We7NihRSz3rQQgghZQQUTOOYkeXFXEnepLjJKUjwLTE8cA+eT5citWxZu2feBYRaMu+AKKh+fQzuM8cEDjmrrW/aubxdkzegPQTLbqXMCCSBzGSJgx8VOH3PNr1RiW6r1vvbd26Nq4lZUF94naUSMDBiRB/r0GY48dy0J7xwRvIWokp5BSPYxj3rWX91pjV8tT+oJDaCrcEklTk+cHjAjEYrVXHaZDKj9lbKfcCVQp5e0SfQTP6jmpxJvg9X0vlnUsXumXLqgi5auEIUUL2kFUj8hjg54HnSbu2GX9zv2zaEpSVKCyoAxG3cQMc+4jAkVxDuu37qDLqWwo7lpaTtCj78/vWIXnlqV3q1KX/7ioyR817KrnLPJvjETsLvXdJYdCWbNLwSD49oAk5IgicmDx0rU3Ouv92EW6UNeKR3c+EY69cCP1rSHvIjceZnmo+Y6mvVQikVw/Vl716+++HHFqURkZqtTiifyJNVwAYBmlOY6edXyT0okVHgHpSUrpIkVFUAQTnyo9TM0JwKDBFSHAk5qPoBmmCYwcTTBJP0pAj4pbs81GBIkzFQSu5sAB5wKFbTASScZkdaWef2qIwQYPIrxOpAqUkHyqsySCIGatUfjoapJjIxnmql0WoVAOazbe9urcEM3C0AkEgK5IrXt54yT5VcgxAPTMVBDSfc3X+PXCkk9y2l3dJUCo/tMCti52h0xDIdLV4XQjaQNoIJHnPrXK7tqwr8TPNYdyqZEqkqq0YRZz2QXdG7uO1Drjh7m0SgAmC6dxjzgQAfXNal/U7u4aU29crU2cbJgfIHPzWAAoEiD60oxPFeqjFdkVSYKcWonJn3qKQrnipKiQUiPOpNpGB1q4xgkExPCTPnz1q6ACTzPxSQPCBmTOPPyqYSCBAIPl5VPc82yMiQB6daCcSSM0QTKlFUk9RUTMZ4qCQ3SkRGKjmZnFBwOvzUZz6CrJAfBNQKo4zTUqMmq4JI6VIJBXnU9wIqO3H86RHAHQRQEpMUzIRFIA8CsqzsrvUbpNnY2r11cL/FtlBWo/AquG3hIOShy2X7ugoTEx51AFOI60pKcxJrnO0ktQT+SgBEyaqP4nyOakvO41CZImTVWWSJoKhnd6irk4mqARuq0HMwaBk1QY2ic8Vjuphtw5/LPvWRuh1JEj2NVOK/8uQlMFSyTn++s16Q7HNY+cGCqY3R6RUZwTzmpwSM8cVBZQhe1skp8zzXoQhTBBjFWJ/AE8/0qoKGMxVoKSggkZHXpUlZFiZB3RAMAQeKkpQTEjNKSSCZHp5VFRzJEmhTgFLERwRUZJ60iBtjpHHlSB2q+OKIDznJpZnpFQKjuKUiIqRCUgqWUoAiVKx+v99auRnHciRK+JNSSlR4Ga2Wi9n9c7Q3TbGgaTcaiorCS4gBLSPMqcUQnAzAJPpXs3Z/6Eq2Ie7RauG1H8rewSfD/APYrn/8AIrqr0ttnZHDdr6aeJPk8KUEIVtcdSjgZMV1+g/TftZ2iCXLDSltW6k7k3N5LLR8iJBUQfMJIr6L0D6b9juzlw3dafozKrxskpunx3rqSRBhSsjrxHNdaBHFaVe2xXM3kxbt4m+Klg8k7O/Q3QtO/i65duaq7u3BtI7psehAJKv1HtXp2naTpekW322l6fb2TMyUMNhAJ8zHJrOoNaVdUK/BYMa2+y15slk+HpI4GBRukSZEV7vrH/h17KvJU52Y1G+7PO5IbbcLzEkf/ABq/oRXmOufS36hdmGpXpbev2qcfc6cqFBM8rbV4uP8ALPFfM27ddWsrk+40+86a3iT6X7nKqJ4kjrzUZ486QWlQUEqBKcKAP4nyPkaX4mfKstprhm5HEllEwSeufar2zA3c1jjIE8VanJ5mmCGXTCc8RGcVXcDahRBJJjPAIk5H6fvTB8e6AYz81S8qQcAE8weg4/rXtDg5bE8mMVyInNVqIielInI/lUCsDk8YAq5AyZIECrmnyBhRHSsVRnkz80grxdakhoyVLCiQMic+L+/IVLcRkDrHFK3s726cDdrZv3LqsBthouKPoAMmvQ+z30Y7a6zsevrVvRGJibtwFZSYlQQgn9FFJ9q9oaey1/sRy26mmhfvkkeeGVJyDjJHlWRptu5qt0mz01td5cOeFLNukuKJkdB5dTX0Zo/0H7I2QCtWcutYXuCil5ZQ2SBEbE8j0JINejaPoOjaBZJstG023sLdJkNsNhCQfYVp17a3zNmHfvMe1UTwLsx9ENd1AJutfeTo7REpZw697EDwpx6nnjFemaJ9G+w2kWrTVzp69ZcbAHeamvv5iIJSfDOBmJ9a9Dp1p1aaqvxRiXay67ykVtMtMNhtltLaBwlIgCpxFOiuk4wooooAooooB8UiKZpUByXaX6ddke1ZU9qmkoTeEQLy3JafT5eNMEj0Mj0rx7tF9DO0enFy67Oai1rTAJV9vcAMPgeSVDwK+Qj3r6OpVz26aq3zR2afW36d/wCOX09D4mvLC/0y6Nlqlk/p92nJZuUbFfHRQ9RIrHUITIST7V9qano+lazZ/aarp9vesTOx9sLAPQieD615Zr/0J0i5l3s3qLuluZhh+X2viTuH6kDyrFu2uS5qeT6XT79CXF6w/ij5+zmf3qh4lIBVIJ6HpXdar9K+3elXIR/gStQaIkv2LyVoHpCilf6JrXNfTTt7qjrTNr2aeZAMrdu/4KAPLPiPTgGuKOkuTw4s056/TNdSmjjDM+pqBDgaccDa1hAmEJKlHEwAMk+le29n/oBq7yg52n1e2tG5wzYbnVkf61BIB/5TXsHZ76f9k+zCEHS9JaD6SVfcPfxHSSIJ3Kkjk4ED0rtq26yTzPhGZfvNUFivlnzLon007X6222tjQ7u3SqNyrxtTARPXxgEx6A16f2Y+grbK03HajUQ9wftrQFABjguEyoewScCvdIorUr0NMOcZMK7dNRbxnC9jWaNoWlaBp7dhpNk3a27aQkBOSY81HKj6kk1s6KK7UkuxmNtvLCiijpUkBRRRQBRRRQBSnIEU6KAKKKKAZpU6OsUAUuadIUAUUc0UAUUUdKAKKOlOgFRQKdAKnSoNAFFOKDxQCoooFAGKKKIoAoxRTigFRRTigFRmnRQCop0UAviinRQCop0UAvij4p0UAqdFFAGaM0UUAfFHxRRQC+KfxRRQCop0UAvin8UUUAqfxRRQH//Z
         avatar_hash: 919a5c004fc9ad5875218c4d1489c2eb6aae6c17

Wojciech Kapcia (Tigase) commented 3 years ago

But this would not set the id nor will it remove the room from the cache of rooms and #issue #145 most likely is caused by the same issue.

I'm aware of that but as I said - there wasn't any other error/exception and it would definitely result in WARNING so there should be notification.

Just a wild guess, didn't someone try to use emoji in localpart of the MUC room?

From the data - it seems not.
Andrzej Wójcik (Tigase) commented 3 years ago

I do not see a way to get RoomWithId with id set to null if the room is stored in the database. It looks like something that should not happen.
Andrzej Wójcik (Tigase) commented 3 years ago

The weird thing is that creation of a RoomWithId with id set to null is possible only by creating a room. Due to that I think that it was possible that we have an exception here https://github.com/tigase/tigase-muc/blob/31b80bd3f6bd93e27224cc391d96a6d992b1cc4f/src/main/java/tigase/muc/repository/inmemory/InMemoryMucRepository.java#L316

This should leave a trace, but it is the only reason I can think of that would lead to allowing the creation of a room (which would cause an instance of a room with id set to null but creation would fail) but at the same time, it would still have an old room in the database.
Wojciech Kapcia (Tigase) commented 3 years ago

Another alternative already mentioned before: concurrency / clustering?
Andrzej Wójcik (Tigase) commented 3 years ago

I do not think that it has anything to do with clustering as, according to timestamps, the room was created hours before its avatar is being set. If so, then it was created and id for it was generated and assigned. Moreover, even avatar was already set for it at least once.

Now, after a few hours, in the database, the room is still there but in the memory, we have a room without an avatar and without an id and that can only happen if the room is created (probably created again?).

If the room was in fact created again, then it would require our method to create a room to fail to check if the room already exists and this is only possible if the loading of all rooms would fail.

Another possibility would be that room was created simultaneously on more than one cluster node, but as single XMPP client connection packets are processed on the local cluster node would require 2 different connections to 2 different cluster nodes to create the same room at the same time... (I do no think this is possible..)
Wojciech Kapcia (Tigase) commented 3 years ago

OK, so for now we have no idea what happened. From the discussion we had it was agreed to re-work database (#issue #149). Closing for now.
Login to comment

Type	Bug
Priority	Normal
Assignee	Andrzej Wójcik (Tigase)
Version	tigase-server-8.3.0

Issue Votes (0)

Watchers (0)

Reference

tigase/_server/tigase-muc#148