JRE upon anonymous user connection (#734)

Activities

Daniel Wisnewski opened 8 years ago

Due Date
2016-12-15

When connecting to Tigase Server, the following error shows in the logs, however nothing seems to be amiss with server operation, this is likely just a verbose message that anonymous server cannot access database/roster. Although this is not critical, it may cause large logs in servers using anonymous authentication.

Error only occurs on new anonymous user connection.

2016-12-04 19:53:17.529 [in_21-pubsub]     AbstractComponent.processStanzaPacket()  SEVERE: tigase.pubsub.repository.RepositoryException: Getting user roster error when processing from=c2s@birdbox/0:0:0:0:0:0:0:1_5222_0:0:0:0:0:0:0:1_49968, to=pubsub@birdbox, DATA=<iq type="set" id="ebf5506a-6ddc-49fb-8709-bae22fe25d71" xmlns="jabber:client" from="d2a1066e-fcbf-4f78-ada7-c3326f89ea3e@birdbox/Gajim" to="d2a1066e-fcbf-4f78-ada7-c3326f89ea3e@birdbox"><pubsub xmlns="http://jabber.org/protocol/pubsub"><publish node="http://jabber.org/protocol/mood"><item id="0"><mood xmlns="http://jabber.org/protocol/mood"/></item></publish></pubsub></iq>, SIZE=376, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=ANONYM, TYPE=set
java.lang.RuntimeException: tigase.pubsub.repository.RepositoryException: Getting user roster error
	at tigase.pubsub.modules.PublishItemModule.process(PublishItemModule.java:589)
	at tigase.component2.modules.ModulesManager.process(ModulesManager.java:114)
	at tigase.component2.AbstractComponent.processStanzaPacket(AbstractComponent.java:248)
	at tigase.component2.AbstractComponent.processPacket(AbstractComponent.java:236)
	at tigase.pubsub.PubSubComponent.processPacket(PubSubComponent.java:631)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1570)
Caused by: tigase.pubsub.repository.RepositoryException: Getting user roster error
	at tigase.pubsub.repository.PubSubDAO.getUserRoster(PubSubDAO.java:105)
	at tigase.pubsub.repository.cached.CachedPubSubRepository.getUserRoster(CachedPubSubRepository.java:635)
	at tigase.pubsub.repository.PubSubRepositoryWrapper.getUserRoster(PubSubRepositoryWrapper.java:93)
	at tigase.pubsub.modules.PublishItemModule.getValidBuddies(PublishItemModule.java:432)
	at tigase.pubsub.modules.PublishItemModule.pepProcess(PublishItemModule.java:492)
	at tigase.pubsub.modules.PublishItemModule.process(PublishItemModule.java:518)
	at tigase.component2.modules.ModulesManager.process(ModulesManager.java:114)
	at tigase.component2.AbstractComponent.processStanzaPacket(AbstractComponent.java:248)
	at tigase.component2.AbstractComponent.processPacket(AbstractComponent.java:236)
	at tigase.pubsub.PubSubComponent.processPacket(PubSubComponent.java:631)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1570)
Caused by: tigase.db.UserNotFoundException: User does not exist: d2a1066e-fcbf-4f78-ada7-c3326f89ea3e@birdbox
	at tigase.db.jdbc.JDBCRepository.getUserUID(JDBCRepository.java:1232)
	at tigase.db.jdbc.JDBCRepository.getNodeNID(JDBCRepository.java:1202)
	at tigase.db.jdbc.JDBCRepository.getData(JDBCRepository.java:237)
	at tigase.db.jdbc.JDBCRepository.getData(JDBCRepository.java:291)
	at tigase.db.UserRepositoryMDImpl.getData(UserRepositoryMDImpl.java:135)
	at tigase.pubsub.repository.PubSubDAO.getUserRoster(PubSubDAO.java:99)
	at tigase.pubsub.repository.cached.CachedPubSubRepository.getUserRoster(CachedPubSubRepository.java:635)
	at tigase.pubsub.repository.PubSubRepositoryWrapper.getUserRoster(PubSubRepositoryWrapper.java:93)
	at tigase.pubsub.modules.PublishItemModule.getValidBuddies(PublishItemModule.java:432)
	at tigase.pubsub.modules.PublishItemModule.pepProcess(PublishItemModule.java:492)
	at tigase.pubsub.modules.PublishItemModule.process(PublishItemModule.java:518)
	at tigase.component2.modules.ModulesManager.process(ModulesManager.java:114)
	at tigase.component2.AbstractComponent.processStanzaPacket(AbstractComponent.java:248)
	at tigase.component2.AbstractComponent.processPacket(AbstractComponent.java:236)
	at tigase.pubsub.PubSubComponent.processPacket(PubSubComponent.java:631)
	at tigase.server.AbstractMessageReceiver$QueueListener.run(AbstractMessageReceiver.java:1570)

Bartosz Małkowski commented 8 years ago

Fixed in project @tigase-pubsub@.

Daniel Wisnewski commented 8 years ago

Anonymous connections now result in the following message:

2016-12-06 09:15:01.397 [jabber:iq:private Queue Worker 0]  JabberIqPrivate.process()  WARNING: Received privacy request but user session is not authorized yet: from=c2s@birdbox/0:0:0:0:0:0:0:1_5222_0:0:0:0:0:0:0:1_62056, to=sess-man@birdbox, DATA=<iq from="9b4ac926-e9b7-4aed-a66b-738e4499dd43@birdbox/Gajim" xmlns="jabber:client" id="de9b213c-16b6-459c-801d-3786a58f3390" type="set"><query xmlns="jabber:iq:private"><roster xmlns="roster:delimiter">::</roster></query></iq>, SIZE=227, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=ANONYM, TYPE=set

This appears correct, please confirm/close if this is the case.

Artur Hefczyc commented 8 years ago

The exceptions is fixed, this is OK but the warning log entry should not be there. It is misleading as this is not the "not authorized yet" case, instead it is an anonymous user who does not have access to the DB. %bmalkow please improve the code so it is not a WARNING, FINEST level would be more appropriate and log description should be changed to reflect that we are dealing with anonymous user here.

Yes, I know that this is most likely my own, old code.

Bartosz Małkowski commented 8 years ago

Implemented

Daniel Wisnewski commented 8 years ago

Anonymous connections no longer cause associated JRE, closing issue.

Type	Bug
Priority	Major
Assignee	Daniel Wisnewski
RedmineID	4760
Version	tigase-server-7.1.0
Spent time	5h

Issue Votes (0)

Watchers (0)

Reference

tigase/_server/server-core#734