Помогите разобраться с событиями.
На договоре есть подписка, денег на продление хватает. Происходит в 00 часов окончание подписки и тут же её продление.
Вот что вижу server.mq.log:
Код:
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGScheduler Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013004
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013014
08-25/00:00:13 DEBUG [job-subscription-p-4-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedTopicEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013014
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013011
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013011
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.inet.api.server.event.InetAccountingPeriodModifiedEvent] moduleId: 13; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013018
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGBillingServer Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013014
08-25/00:00:13 INFO [event-proc-p-2-t-1] BalanceEventProcessor - Process event cid:21922; event:Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013014
08-25/00:00:13 INFO [event-proc-p-2-t-1] Module - Sending state disable to inetServ[id: 1]
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateModifyEvent] moduleId: 13; pluginId: no; cid: 21922; scid: -1; userId: 0; deviceId: 2; inetServId: 1; connectionId: 0; state: 0; accessCod
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGScheduler Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013408
08-25/00:00:13 DEBUG [job-subscription-p-4-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013983
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:14 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedTopicEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:14 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:14 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:14 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGBillingServer Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407
08-25/00:00:14 DEBUG [ActiveMQ Session Task] Consumer - Caught from BGBillingServer Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:14 INFO [ActiveMQ Session Task] ContractRuntimeMap - Taked event: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusModifiedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013985
08-25/00:00:16 DEBUG [event-proc-p-2-t-1] EventProcessor - Publish: Event[ru.bitel.bgbilling.kernel.event.events.ContractStatusChangedEvent] moduleId: 0; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040016237
Вот что вижу в scripts.log:
Код:
08-25/00:00:13 INFO [event-proc-p-2-t-1] ScriptEventListener - Caught event: ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[57]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013004 on cid=21922 subscriptionId=1
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[74]: set Close contract status on cid=21922
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[93]: lastRegistrationPeriod=24.08.2016 00:00:13 - 25.08.2016 00:00:13 fromDate=2016-08-24 00:00:13.0 toDate=2016-08-25 00:00:13.0
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[103]: found inet accounting period id=3911, trying to close it at 2016-08-25 00:00:13.0 on cid=21922
08-25/00:00:13 INFO [event-proc-p-2-t-1] ScriptEventListener - Process time => 11
08-25/00:00:13 INFO [event-proc-p-2-t-1] ScriptEventListener - Caught event: ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[58]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013408 on cid=21922 subscriptionId=1
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[68]: current contract cid=21922 status=3
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[76]: set Active contract status on cid=21922
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[83]: subscription.getId()=1
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[94]: lastRegistrationPeriod=25.08.2016 00:00:23 - 26.08.2016 00:00:23 fromDate=2016-08-25 00:00:23.0 toDate=2016-08-26 00:00:23.0
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[102]: prevSubscription.getId()=1 prevSubscription.isActive()=false
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[109]: prevRegistrationPeriodList.size() = 1
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[102]: prevSubscription.getId()=2 prevSubscription.isActive()=false
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[106]: prevRegistrationPeriodList is null
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[147]: periodList=[]
08-25/00:00:13 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[174]: account period for cid=21922 is created with id=4172 and fromDate=2016-08-25 00:00:23.0 and toDate=Fri Aug 26 00:00:22 PETT 2016
08-25/00:00:13 INFO [event-proc-p-2-t-1] ScriptEventListener - Process time => 5
08-25/00:00:14 INFO [event-proc-p-2-t-1] ScriptEventListener - Caught event: ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent
08-25/00:00:14 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[57]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407 on cid=21922 subscriptionId=1
08-25/00:00:14 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[74]: set Close contract status on cid=21922
08-25/00:00:16 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[93]: lastRegistrationPeriod=25.08.2016 00:00:23 - 26.08.2016 00:00:23 fromDate=2016-08-25 00:00:23.0 toDate=2016-08-26 00:00:23.0
08-25/00:00:16 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[103]: found inet accounting period id=4172, trying to close it at 2016-08-26 00:00:23.0 on cid=21922
08-25/00:00:16 INFO [event-proc-p-2-t-1] ScriptEventListener - Process time => 2009
08-25/00:00:17 INFO [event-proc-p-2-t-1] ScriptEventListener - Caught event: ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent
08-25/00:00:17 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[58]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013983 on cid=21922 subscriptionId=1
08-25/00:00:17 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[68]: current contract cid=21922 status=3
08-25/00:00:17 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[76]: set Active contract status on cid=21922
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[83]: subscription.getId()=1
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[94]: lastRegistrationPeriod=25.08.2016 00:00:23 - 26.08.2016 00:00:23 fromDate=2016-08-25 00:00:23.0 toDate=2016-08-26 00:00:23.0
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[102]: prevSubscription.getId()=1 prevSubscription.isActive()=false
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[109]: prevRegistrationPeriodList.size() = 1
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[102]: prevSubscription.getId()=2 prevSubscription.isActive()=false
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[106]: prevRegistrationPeriodList is null
08-25/00:00:17 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[147]: periodList=[4172: 25.08.2016 00:00:23 - 26.08.2016 00:00:22]
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[154]: found accounting period, trying to close it on cid=21922 by closeDate=Thu Aug 25 00:00:22 PETT 2016
08-25/00:00:17 DEBUG [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[174]: account period for cid=21922 is created with id=4173 and fromDate=2016-08-25 00:00:23.0 and toDate=Fri Aug 26 00:00:22 PETT 2016
Почему-то происходит двойной вызов события по закрытию периода и по открытию:
Код:
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGScheduler Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013004
08-25/00:00:13 DEBUG [job-subscription-p-4-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407
08-25/00:00:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGScheduler Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013408
08-25/00:00:13 DEBUG [job-subscription-p-4-t-11] EventProcessor - Publish: Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013983
08-25/00:00:14 DEBUG [event-proc-p-2-t-1] Consumer - Caught from BGBillingServer Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407
Код:
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[57]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013004 on cid=21922 subscriptionId=1
08-25/00:00:13 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[58]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013408 on cid=21922 subscriptionId=1
08-25/00:00:14 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionRegistrationPeriodEndEvent - onEvent[57]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionRegistrationPeriodEndEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: -1; timestamp: 1472040013407 on cid=21922 subscriptionId=1
08-25/00:00:17 INFO [dyn-clss-evnt-lstnr-p-5-t-190] mySubscriptionActivateEvent - onEvent[58]: event=Event[ru.bitel.bgbilling.modules.subscription.server.event.SubscriptionActivateEvent] moduleId: 14; pluginId: no; cid: 21922; scid: -1; userId: 0; timestamp: 1472040013983 on cid=21922 subscriptionId=1
В mySubscriptionRegistrationPeriodEndEvent я изменяю статус договора на Закрыт, ставлю окончание учётного inet-периода равным дате окончания подписки.
Вызываю context.publishAfterCommit(new InetAccountingPeriodModifiedEvent(INET_MID, cid, USER_ID, currentAccountingPeriod, changedAccountingPeriod));
С самой подпиской ничего не делаю.
В mySubscriptionActivateEvent я изменяю статус договора на Активный и создаю новый учётный inet-период с периодом, равным новой подписке.
Почему могут дублироваться события?