[2025-05-12 09:55:44,524] INFO - *** Eap8PersistentDistributedTimersTests#testPersistenceServiceBasicFailOver() is starting ***
[2025-05-12 09:55:52,852] DEBUG- Waiting up to 10 minutes. Reason: Wait for infinispan resource to be ready
[2025-05-12 09:55:59,926] DEBUG- Waiting up to 10 minutes. Reason: Waiting for exactly 1 pods with label deploymentconfig=eap-distributed-ejb-timers to be ready.
[2025-05-12 09:56:21,114] DEBUG- Waiting up to 10 minutes. Reason: Wait until the service has all endpoints.
[2025-05-12 09:56:21,119] INFO - generateHostname returns namespace: eap-distributed-ejb-timers-appsint-yg6q.apps.xap418-6yzf.eapqe.psi.redhat.com
[2025-05-12 09:56:21,119] DEBUG- Waiting up to 10 minutes. Reason: Wait until the route is ready to serve.
[2025-05-12 09:56:21,220] DEBUG- Waiting up to 10 minutes. Reason: Waiting for exactly 2 pods with label deploymentconfig=eap-distributed-ejb-timers to be ready.
[2025-05-12 09:56:42,395] DEBUG- Waiting up to 10 minutes. Reason: Wait until the service has all endpoints.
[2025-05-12 09:56:42,400] INFO - generateHostname returns namespace: eap-distributed-ejb-timers-appsint-yg6q.apps.xap418-6yzf.eapqe.psi.redhat.com
[2025-05-12 09:56:42,400] DEBUG- Waiting up to 10 minutes. Reason: Wait until the route is ready to serve.
[2025-05-12 09:56:42,515] INFO - About to CREATE a timer by calling: http://eap-distributed-ejb-timers-appsint-yg6q.apps.xap418-6yzf.eapqe.psi.redhat.com
[2025-05-12 09:56:42,720] INFO - Waiting up to 20 seconds. Reason: Waiting for at least one timer expiration to be recorded
[2025-05-12 09:56:43,803] DEBUG- Retrieving current timer executor pod name, the following 1 expirations were collected so far:
---
TimerExpiration{id=null, executor='eap-distributed-ejb-timers-1-flwp6/10.129.4.64', name='org.jboss.qa.appsint.tests.deployments.ejb.distributed.timers.TransactionalRecurringTimerService', info='Eap8PersistentDistributedTimersTests:testPersistenceServiceBasicFailOver', timestamp=2025-05-12T09:56:42.726186Z}
[2025-05-12 09:56:43,809] DEBUG- Current timer executor is eap-distributed-ejb-timers-1-flwp6
[2025-05-12 09:56:43,822] DEBUG- Current RHDG Pod designated for deletion is rhdg-0
[2025-05-12 09:56:43,823] DEBUG- Started observing timer expirations for 80000 milliseconds:
[2025-05-12 09:56:43,823] DEBUG- Injecting a failure by stopping pod rhdg-0 in 20000 milliseconds
[2025-05-12 09:56:43,823] DEBUG- ---> Observing time window from 2025-05-12T09:56:43.823404036Z to 2025-05-12T09:58:03.823404036Z (http://ejb-timer-expiration-store-appsint-yg6q.apps.xap418-6yzf.eapqe.psi.redhat.com/timer/range?from=2025-05-12T09:56:43.823404036Z&to=2025-05-12T09:58:03.823404036Z)
[2025-05-12 09:56:43,843] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:44,869] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:45,890] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:46,908] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:47,926] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:48,943] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:49,963] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:50,980] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:52,001] DEBUG- ---> There are currently 0 expirations in the monitored time window
[2025-05-12 09:56:53,022] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:54,044] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:55,064] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:56,085] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:57,106] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:58,124] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:56:59,143] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:57:00,161] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:57:01,179] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:57:02,197] DEBUG- ---> There are currently 1 expirations in the monitored time window
[2025-05-12 09:57:03,219] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:03,823] DEBUG- Pod rhdg-0 is being stopped!
[2025-05-12 09:57:04,238] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:04,842] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:05,261] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:05,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:06,286] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:06,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:07,306] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:07,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:08,327] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:08,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:09,347] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:09,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:10,379] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:10,843] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:11,398] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:11,844] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:12,416] DEBUG- ---> There are currently 2 expirations in the monitored time window
[2025-05-12 09:57:12,844] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:13,439] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:13,844] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:14,463] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:14,844] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:15,482] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:15,844] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:16,501] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:16,845] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:17,518] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:17,845] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:18,536] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:18,845] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:19,554] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:19,845] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:20,575] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:20,845] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:21,595] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:21,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:22,613] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:22,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:23,634] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:23,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:24,653] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:24,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:25,672] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:25,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:26,698] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:26,846] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:27,723] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:27,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:28,750] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:28,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:29,771] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:29,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:30,790] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:30,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:31,807] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:31,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:32,826] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:32,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:33,843] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:33,847] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:34,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:34,864] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:35,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:35,882] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:36,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:36,899] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:37,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:37,919] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:38,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:38,940] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:39,848] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:39,956] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:40,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:40,975] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:41,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:41,994] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:42,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:43,016] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:43,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:44,039] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:44,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:45,057] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:45,849] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:46,076] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:46,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:47,093] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:47,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:48,110] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:48,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:49,128] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:49,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:50,148] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:50,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:51,165] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:51,850] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:52,183] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:52,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:53,205] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:53,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:54,223] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:54,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:55,243] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:55,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:56,262] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:56,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:57,278] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:57,851] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:58,302] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:58,852] DEBUG- Still observing timer expirations...
[2025-05-12 09:57:59,323] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:57:59,852] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:00,344] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:58:00,852] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:01,367] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:58:01,852] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:02,383] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:58:02,853] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:03,400] DEBUG- ---> There are currently 3 expirations in the monitored time window
[2025-05-12 09:58:03,853] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:04,418] DEBUG- ---> There are finally 3 expirations in the monitored time window
[2025-05-12 09:58:04,853] DEBUG- Still observing timer expirations...
[2025-05-12 09:58:04,853] DEBUG- Finished observing timer expirations for 80000 milliseconds.
[2025-05-12 09:58:04,854] DEBUG- The following 3 expirations were collected in the monitored time interval having "applicationInfo" set to Eap8PersistentDistributedTimersTests:testPersistenceServiceBasicFailOver:
TimerExpiration{id=null, executor='eap-distributed-ejb-timers-1-flwp6/10.129.4.64', name='org.jboss.qa.appsint.tests.deployments.ejb.distributed.timers.TransactionalRecurringTimerService', info='Eap8PersistentDistributedTimersTests:testPersistenceServiceBasicFailOver', timestamp=2025-05-12T09:57:12.612843Z}
---
TimerExpiration{id=null, executor='eap-distributed-ejb-timers-1-flwp6/10.129.4.64', name='org.jboss.qa.appsint.tests.deployments.ejb.distributed.timers.TransactionalRecurringTimerService', info='Eap8PersistentDistributedTimersTests:testPersistenceServiceBasicFailOver', timestamp=2025-05-12T09:57:02.612397Z}
---
TimerExpiration{id=null, executor='eap-distributed-ejb-timers-1-flwp6/10.129.4.64', name='org.jboss.qa.appsint.tests.deployments.ejb.distributed.timers.TransactionalRecurringTimerService', info='Eap8PersistentDistributedTimersTests:testPersistenceServiceBasicFailOver', timestamp=2025-05-12T09:56:52.614443Z}
[2025-05-12 09:58:04,854] INFO - Expected expirations: 8, missed during pause: 1, pause: 10000, interval: 10000, actual: 3