Some nightly tests for PubSub fail (#35)

Closed

Activities

Artur Hefczyc opened 10 years ago

Due Date
2014-10-10

There are 2 pubsub tests run by TTS and they fail for some databases.

Artur Hefczyc commented 10 years ago

Any progress on this? Still tests fail for PubSub only.

Bartosz Małkowski commented 10 years ago

Andrzej, I'm almost sure that you changed something there. I'm I right?

Andrzej Wójcik (Tigase) commented 10 years ago

I checked this issue and for me there where cases in which it worked ok and some in which it failed. I reverted changes in JDBCPubSubDAO which might cause issues with MySQL database, but I suppose that this issue might be related to changes in hashCodeForPacket implementation in PubSub component as it allows 2 requests from same user to be processed in same time which in case of TTS might result in subscription retrieval being processed before subscription is processed.

%wojtek could you look at this in TTS if it may execute this requests in same time? I'm not so familiar with TTS to say if it is possible or not.

wojciech.kapcia@tigase.net commented 10 years ago

Actually the TTS executes subsequent stanzas extremely linearly (i.e. it waits for the result from the server before sending anything else). However, after investigation it turns out that component sends out result for the IQ before finalizing updating the data:

2014-11-12 16:54:43.471 [in_1-pubsub]      ModulesManager.process()           FINEST:   Processing packet: from=sess-man@build.xmpp-test.net, to=null, DATA=<iq id="subs1" from="all-xmpp-test@test-d/def-user-resource" to="pubsub.test-d" xmlns="jabber:client" type="set">
<pubsub xmlns="http://jabber.org/protocol/pubsub#owner">
<subscriptions node="princely_musings">
<subscription jid="bard@shakespeare.lit" subscription="subscribed"/></subscriptions></pubsub></iq>, SIZE=309, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=set
2014-11-12 16:54:43.471 [in_1-pubsub]      ModulesManager.process()           FINER:    Handled by module class tigase.pubsub.modules.ManageSubscriptionModule
2014-11-12 16:54:43.476 [in_1-pubsub]      AbstractComponent$1.write()        FINER:    Sent: <iq id="subs1" from="pubsub.test-d" to="all-xmpp-test@test-d/def-user-resource" xmlns="jabber:client" type="result"/>
2014-11-12 16:54:43.476 [in_1-pubsub]      CachedPubSubRepository.update()    FINEST:   Node 'princely_musings' added to lazy write queue (subscriptions)
2014-11-12 16:54:43.477 [in_1-pubsub]      PubSubDAOJDBC.updateNodeSubscription()  FINEST: Updating node subscriptions[1]: princely_musings / UsersSubscription{jid=bard@shakespeare.lit, subid=4ea4pupz86mkbs1btp3, subscription=subscribed}
2014-11-12 16:54:43.481 [in_2-pubsub]      ModulesManager.process()           FINEST:   Processing packet: from=sess-man@build.xmpp-test.net, to=null, DATA=<iq id="subs2" from="all-xmpp-test@test-d/def-user-resource" to="pubsub.test-d" xmlns="jabber:client" type="get">
<pubsub xmlns="http://jabber.org/protocol/pubsub#owner">
<subscriptions node="princely_musings"/></pubsub></iq>, SIZE=225, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=get
2014-11-12 16:54:43.482 [in_2-pubsub]      ModulesManager.process()           FINER:    Handled by module class tigase.pubsub.modules.ManageSubscriptionModule
2014-11-12 16:54:43.482 [in_2-pubsub]      ManageSubscriptionModule.processGet()  FINEST: Node subscriptions: princely_musings / [UsersSubscription{jid=all-xmpp-test@test-d, subid=33yszb1ei7d8u5fa1g1, subscription=subscribed}]
2014-11-12 16:54:43.482 [in_2-pubsub]      AbstractComponent$1.write()        FINER:    Sent: <iq id="subs2" from="pubsub.test-d" to="all-xmpp-test@test-d/def-user-resource" xmlns="jabber:client" type="result"><pubsub xmlns="http://jabber.org/protocol/pubsub#owner"><subscriptions node="princely_musings"><subscription jid="all-xmpp-test@test-d" subscription="subscribed"/></subscriptions></pubsub></iq>
2014-11-12 16:54:43.483 [in_2-pubsub]      ModulesManager.process()           FINEST:   Finished class tigase.pubsub.modules.ManageSubscriptionModule
2014-11-12 16:54:43.483 [in_1-pubsub]      PubSubDAOJDBC.updateNodeSubscription()  FINEST: Updating node subscriptions[2]

In the CachedPubSubRepository there is a comment:

// Prevent node modifications while it is being written to DB

// From 3.0.0 this should not be needed as we keep changes to the node per thread

// synchronized (node) {

so it's not that TTS sends two requests at the same time but nevertheless the second request is processed in different thread hence issues with proper affiliation/subscription/configuration being returned to the client.

Andrzej Wójcik (Tigase) commented 10 years ago

I changed logic in ManageAffiliationsModule and ManageSubscriptionModule to make sure that changes are saved to database before any notification or result is sent by component to user. This should fix this issue.

wojciech.kapcia@tigase.net commented 10 years ago

After last run the issue seems to be resolved. A few tests failed for MongoDB but given that they passed for low-mem I would say this is just typical hickup of TTS.

Type	Bug
Priority	Critical
Assignee	Artur Hefczyc
RedmineID	2328
Spent time	9h 45m

Issue Votes (0)

Watchers (0)

Reference

tigase/_server/tigase-pubsub#35