Node and item manipulation using PubSub procotol - #4229

Test duration: 217.424s

Failed Configuration
tigase.tests.pubsub.TestPubSub
tearDownClass 30.005s Method arguments: org.testng.TestRunner@3e43f049
2020-08-03 05:49:54 | [Mutex] waiting for: [deleted:node:Node abc755d4-470b-434c-aa90-9020abe4ca64]

2020-08-03 05:50:24 | [Mutex] timeout. Not received [deleted:node:Node abc755d4-470b-434c-aa90-9020abe4ca64]

2020-08-03 05:50:24 | [Mutex] isItemNotified: deleted:node:Node abc755d4-470b-434c-aa90-9020abe4ca64 :: false

java.lang.AssertionError: Removal of node Node abc755d4-470b-434c-aa90-9020abe4ca64 on localhost failed
org.testng.AssertJUnit.fail(AssertJUnit.java:59)
org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24)
tigase.tests.utils.PubSubManager.deleteNode(PubSubManager.java:91)
tigase.tests.utils.PubSubManager.deleteNode(PubSubManager.java:67)
tigase.tests.utils.PubSubManager.lambda$scopeFinished$2(PubSubManager.java:128)
java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:804)
java.base/java.util.concurrent.CopyOnWriteArraySet.forEach(CopyOnWriteArraySet.java:425)
tigase.tests.utils.PubSubManager.scopeFinished(PubSubManager.java:126)
tigase.tests.utils.AbstractManager.scopeFinished(AbstractManager.java:36)
tigase.tests.AbstractTest.tearDownClass(AbstractTest.java:806)
jdk.internal.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.base/java.lang.reflect.Method.invoke(Method.java:566)
org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
org.testng.internal.MethodInvocationHelper.invokeMethodConsideringTimeout(MethodInvocationHelper.java:59)
org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:458)
org.testng.internal.Invoker.invokeConfigurations(Invoker.java:222)
org.testng.internal.Invoker.invokeConfigurations(Invoker.java:142)
org.testng.internal.TestMethodWorker.invokeAfterClassMethods(TestMethodWorker.java:214)
org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
org.testng.TestRunner.privateRun(TestRunner.java:648)
org.testng.TestRunner.run(TestRunner.java:505)
org.testng.SuiteRunner.runTest(SuiteRunner.java:455)
org.testng.SuiteRunner.runSequentially(SuiteRunner.java:450)
org.testng.SuiteRunner.privateRun(SuiteRunner.java:415)
org.testng.SuiteRunner.run(SuiteRunner.java:364)
org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:84)
org.testng.TestNG.runSuitesSequentially(TestNG.java:1208)
org.testng.TestNG.runSuitesLocally(TestNG.java:1137)
org.testng.TestNG.runSuites(TestNG.java:1049)
org.testng.TestNG.run(TestNG.java:1017)
org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:283)
org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:75)
org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:120)
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Failed Tests
tigase.tests.pubsub.TestPubSub
deleteSubnodes 1.035s
2020-08-03 05:49:53 |

2020-08-03 05:49:53 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:49:53 | ------------------------------------

2020-08-03 05:49:53 | [Mutex] waiting for: [deleted:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75]

2020-08-03 05:49:53 | [Mutex] received everything.

2020-08-03 05:49:53 | [Mutex] isItemNotified: deleted:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75 :: true

2020-08-03 05:49:54 | [Mutex] waiting for: [received:nodes:61cf8eee-b333-4c58-bb93-00fb3fcda9ad:localhost]

2020-08-03 05:49:54 | [Mutex] received everything.

2020-08-03 05:49:54 | [Mutex] isItemNotified: received:node:61cf8eee-b333-4c58-bb93-00fb3fcda9ad:localhost:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: false

2020-08-03 05:49:54 | [Mutex] waiting for: [received:nodes:c11299bc-c4cc-49d9-ba1e-d136a940b07a:localhost]

2020-08-03 05:49:54 | [Mutex] received everything.

2020-08-03 05:49:54 | [Mutex] isItemNotified: received:node:c11299bc-c4cc-49d9-ba1e-d136a940b07a:localhost:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: true

java.lang.AssertionError: Found node node-48e4ac9a-68c2-4bd6-9610-48789a133a75 on cluster node localhost expected:<false> but was:<true>
org.testng.AssertJUnit.fail(AssertJUnit.java:59)
org.testng.AssertJUnit.failNotEquals(AssertJUnit.java:364)
org.testng.AssertJUnit.assertEquals(AssertJUnit.java:80)
org.testng.AssertJUnit.assertEquals(AssertJUnit.java:185)
tigase.tests.pubsub.TestPubSubAbstract.ensureNodeItemExists(TestPubSubAbstract.java:338)
tigase.tests.pubsub.TestPubSubAbstract.deleteSubnodes(TestPubSubAbstract.java:141)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.base/java.lang.reflect.Method.invoke(Method.java:566)
org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
org.testng.internal.Invoker.invokeMethod(Invoker.java:583)
org.testng.internal.Invoker.invokeTestMethod(Invoker.java:719)
org.testng.internal.Invoker.invokeTestMethods(Invoker.java:989)
org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
org.testng.TestRunner.privateRun(TestRunner.java:648)
org.testng.TestRunner.run(TestRunner.java:505)
org.testng.SuiteRunner.runTest(SuiteRunner.java:455)
org.testng.SuiteRunner.runSequentially(SuiteRunner.java:450)
org.testng.SuiteRunner.privateRun(SuiteRunner.java:415)
org.testng.SuiteRunner.run(SuiteRunner.java:364)
org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:84)
org.testng.TestNG.runSuitesSequentially(TestNG.java:1208)
org.testng.TestNG.runSuitesLocally(TestNG.java:1137)
org.testng.TestNG.runSuites(TestNG.java:1049)
org.testng.TestNG.run(TestNG.java:1017)
org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:283)
org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:75)
org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:120)
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Skipped Tests
tigase.tests.pubsub.TestPubSub
deleteNodes 0.000s Depends on method(s): tigase.tests.pubsub.TestPubSubAbstract.deleteSubnodes
Passed Tests
tigase.tests.pubsub.TestPubSub
configureNodes 1.030s
2020-08-03 05:46:49 |

2020-08-03 05:46:49 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:49 | ------------------------------------

2020-08-03 05:46:49 | [Mutex] waiting for: [configured:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:node-abc755d4-470b-434c-aa90-9020abe4ca64]

2020-08-03 05:46:49 | [Mutex] received everything.

2020-08-03 05:46:49 | [Mutex] isItemNotified: configured:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:node-abc755d4-470b-434c-aa90-9020abe4ca64 :: true

2020-08-03 05:46:50 | [Mutex] waiting for: [received:nodes:6405bdb7-3d83-4a91-a461-2bbbeb0eaf49:localhost]

2020-08-03 05:46:50 | [Mutex] received everything.

2020-08-03 05:46:50 | [Mutex] isItemNotified: received:node:6405bdb7-3d83-4a91-a461-2bbbeb0eaf49:localhost:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: true

2020-08-03 05:46:50 | [Mutex] waiting for: [received:nodes:023c98ef-4d6e-4767-8b36-1b42832e915d:localhost]

2020-08-03 05:46:50 | [Mutex] received everything.

2020-08-03 05:46:50 | [Mutex] isItemNotified: received:node:023c98ef-4d6e-4767-8b36-1b42832e915d:localhost:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: false
createNodes 1.026s
2020-08-03 05:46:47 |

2020-08-03 05:46:47 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:47 | ------------------------------------

2020-08-03 05:46:47 | [Mutex] waiting for: [created:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75]

2020-08-03 05:46:47 | [Mutex] received everything.

2020-08-03 05:46:47 | [Mutex] isItemNotified: created:node:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: true

2020-08-03 05:46:48 | [Mutex] waiting for: [received:nodes:63d899f1-6c27-4e6a-9828-fdd9f135636a:localhost]

2020-08-03 05:46:48 | [Mutex] received everything.

2020-08-03 05:46:48 | [Mutex] isItemNotified: received:node:63d899f1-6c27-4e6a-9828-fdd9f135636a:localhost:node-48e4ac9a-68c2-4bd6-9610-48789a133a75:Node 48e4ac9a-68c2-4bd6-9610-48789a133a75 :: true
createSubnodes 1.030s
2020-08-03 05:46:48 |

2020-08-03 05:46:48 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:48 | ------------------------------------

2020-08-03 05:46:48 | [Mutex] waiting for: [created:node:node-abc755d4-470b-434c-aa90-9020abe4ca64:Node abc755d4-470b-434c-aa90-9020abe4ca64]

2020-08-03 05:46:48 | [Mutex] received everything.

2020-08-03 05:46:48 | [Mutex] isItemNotified: created:node:node-abc755d4-470b-434c-aa90-9020abe4ca64:Node abc755d4-470b-434c-aa90-9020abe4ca64 :: true

2020-08-03 05:46:49 | [Mutex] waiting for: [received:nodes:22977019-b794-4a89-b775-e749a21f1203:localhost]

2020-08-03 05:46:49 | [Mutex] received everything.

2020-08-03 05:46:49 | [Mutex] isItemNotified: received:node:22977019-b794-4a89-b775-e749a21f1203:localhost:node-abc755d4-470b-434c-aa90-9020abe4ca64:Node abc755d4-470b-434c-aa90-9020abe4ca64 :: true
publishItemsToNodes 0.086s
2020-08-03 05:46:51 |

2020-08-03 05:46:51 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:51 | ------------------------------------

2020-08-03 05:46:51 | [Mutex] waiting for: [published:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com]

2020-08-03 05:46:51 | [Mutex] waiting for: [published:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com]

2020-08-03 05:46:51 | [Mutex] received everything.

2020-08-03 05:46:51 | [Mutex] isItemNotified: published:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com :: true

2020-08-03 05:46:51 | [Mutex] received everything.

2020-08-03 05:46:51 | [Mutex] isItemNotified: published:item:notifieditem-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com :: true
retractItemsFromNodes 0.099s
2020-08-03 05:49:51 |

2020-08-03 05:49:51 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:49:51 | ------------------------------------

2020-08-03 05:49:51 | [Mutex] waiting for: [retracted:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com]

2020-08-03 05:49:52 | [Mutex] waiting for: [retracted:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com]

2020-08-03 05:49:52 | [Mutex] waiting for: [retracted:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com]

2020-08-03 05:49:52 | [Mutex] received everything.

2020-08-03 05:49:52 | [Mutex] isItemNotified: retracted:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com :: true

2020-08-03 05:49:52 | [Mutex] received everything.

2020-08-03 05:49:52 | [Mutex] isItemNotified: retracted:item:notifieditem-64d610ee-3f7d-44fa-9f92-e98ba95b108a:admin@test-domain.com :: true
retrieveItemsFromNodes 0.058s
2020-08-03 05:46:51 |

2020-08-03 05:46:51 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:51 | ------------------------------------

2020-08-03 05:46:51 | [Mutex] waiting for: [retrieved:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:payload-matches:true:localhost]

2020-08-03 05:46:51 | [Mutex] received everything.

2020-08-03 05:46:51 | [Mutex] isItemNotified: retrieved:item:item-64d610ee-3f7d-44fa-9f92-e98ba95b108a:payload-matches:true:localhost :: true
retrieveUserSubscriptions 90.004s
2020-08-03 05:46:51 |

2020-08-03 05:46:51 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:51 | ------------------------------------

2020-08-03 05:46:51 | [Mutex] waiting for: [iq:hyeerb0188]

2020-08-03 05:48:21 | [Mutex] timeout. Not received [iq:hyeerb0188]

2020-08-03 05:48:21 | [Mutex] isItemNotified: success :: false
retrieveUserSubscriptionsWithRegex 90.002s
2020-08-03 05:48:21 |

2020-08-03 05:48:21 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:48:21 | ------------------------------------

2020-08-03 05:48:21 | [Mutex] waiting for: [iq:uxyxdo0189]

2020-08-03 05:49:51 | [Mutex] timeout. Not received [iq:uxyxdo0189]

2020-08-03 05:49:51 | [Mutex] isItemNotified: success :: false
subscribeNodes 1.013s
2020-08-03 05:46:50 |

2020-08-03 05:46:50 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:50 | ------------------------------------

2020-08-03 05:46:50 | [Mutex] waiting for: [subscribed:nodes:baeacb49-3c23-4eae-884f-c24e8d1fcc47:admin@test-domain.com]

2020-08-03 05:46:50 | [Mutex] received everything.

2020-08-03 05:46:50 | [Mutex] isItemNotified: subscribed:nodes:baeacb49-3c23-4eae-884f-c24e8d1fcc47:admin@test-domain.com :: true
testSupportAdvertisement 0.013s
2020-08-03 05:46:47 |

2020-08-03 05:46:47 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:46:47 | ------------------------------------

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] waiting for: [discovery:completed]

2020-08-03 05:46:47 | [Mutex] received everything.

2020-08-03 05:46:47 | [Mutex] isItemNotified: discovery:completed:success :: true

2020-08-03 05:46:47 | [Mutex] isItemNotified: discovery:identity:pubsub:service :: true

2020-08-03 05:46:47 | [Mutex] isItemNotified: discovery:feature:http://jabber.org/protocol/pubsub#publish :: true

2020-08-03 05:46:47 | [Mutex] isItemNotified: discovery:feature:http://jabber.org/protocol/pubsub#subscribe :: true
unsubscribeNodes 1.212s
2020-08-03 05:49:52 |

2020-08-03 05:49:52 | null / [TestClass name=class tigase.tests.pubsub.TestPubSub]

2020-08-03 05:49:52 | ------------------------------------

2020-08-03 05:49:52 | [Mutex] waiting for: [unsubscribed:nodes:654e484f-0cc3-4b8e-b1d2-f8569323dfc0:admin@test-domain.com]

2020-08-03 05:49:52 | [Mutex] received everything.

2020-08-03 05:49:52 | [Mutex] isItemNotified: unsubscribed:nodes:654e484f-0cc3-4b8e-b1d2-f8569323dfc0:admin@test-domain.com :: true