Jump to content
Sign in to follow this  
Bobele23

Benutzer ist laut GSE "Busy" auf Datenbank aber "Avaibale" - Anruf wird nicht zugestellt

Recommended Posts

Hallo,

 

Ich habe ein komisches Phenomen bei einer Call-Id, die ich im Trace-Log des Severs nachverfolgt habe.

 

Das bekomme ich angezeigt, bevor mein GSE Script auf dem User startet. Laut diesem ist der Benutzer "Busy" für den Server. Jetzt habe ich den Status des Benutzers auf der Datenbank des Servers nachgeschaut ( Wir loggen den Statuswechsel der einzelnen Benutzer auf der Datenbank mit). Laut Datenbank war der Benutzer Im Zeitraum von 09:42:51 Uhr bis 10:38:01 Uhr im Status "Avaibale" also erreichbar.  

28 10:37:29.256 001cb4 Inf3 SrvPBXCtl  0F670430 0000054a SScrServer::GetPreviousScripts          () NO script found
28 10:37:29.256 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () rule PreProcessing started...
28 10:37:29.256 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () User-defined PreProcessing (dummy)
28 10:37:29.257 001cb4 Inf3 SrvPBXCtl  0F670430 0000054a SScrServer::UserIsBusyReq               (198, 198 ): Busy
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::UserUncondRedirReq          () returning no

 

Das GSE startet und ermittelt, dass der Benutzer "Busy" ist und aufgrund meiner Regel zur Voicemail übergeben wird.

28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () Begin GSE Script (Rule: ruleUserRoutingVertriebRAOS215DE)
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () GSEVersion: 10.30.0.5
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 ()   case [Start0]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> gseStart()
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () <-- gseStart, rc = 1 [gseStateStarted]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 ()   case [DayOfWeek7]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> gseDayOfWeekEx()
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::UserGetUTCBiasReq           () returning 60 minutes
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::CallIsOriginatorDiscdReq    () returning no
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () <-- gseDayOfWeekEx, rc = 25 [gseStateMonday]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 ()   case [Time8]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> WithinTheTimeOfEx(03.12.2013, 07:30:00, 03.12.2013, 17:15:59, True, False)
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::UserGetUTCBiasReq           () returning 60 minutes
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::UserGetUTCBiasReq           () returning 60 minutes
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () <-- WithinTheTimeOfEx, rc = True [Unknown]
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> gseTimes(True)
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () <-- gseTimes, rc = 2 [gseStateTrue]
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::CallIsOriginatorDiscdReq    () returning no
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 ()   case [Situation5]
28 10:37:29.257 001cb4 Inf3 SrvPBXCtl  0F670430 0000054a SScrServer::UserIsBusyReq               (198, 198 ): Busy
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () IsBusy, rc = True
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> gseSituation(True)
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () <-- gseSituation, rc = 2 [gseStateTrue]
28 10:37:29.257 001cb4 Info SrvPBXCtl  0F670430 0000054a SScrServer::CallIsOriginatorDiscdReq    () returning no
28 10:37:29.257 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 ()   case [PlaySound19]
28 10:37:29.258 001cb4 Info SrvScript  06832A58 0000054a SPBXScript::OutputTrace                 () --> gsePlaySoundEx2(Ansage_Voicemail_[DE]_Musik_Ia_Begrüßung.wav, , False, , True, False, , False)

Laut Status der Datenbank, hätte der User aber "Erreichbar" sein und der Anruf zugestellt werden müssen.

 

Ich habe dann im Phonemanager Log nachgeschaut, ob der User die Lines gesperrt hat oder ähnliches. Aber laut Log war auf dem Telefon tote Hose - "Phone Inactive" - bis es die Info über den verpassten Anruf vom Server erhält.

28 10:36:52.123 001d58 Info MenuMgr    080E2B90 a138a106 SMenuMgr::SetMenuState                  () 0=PhoneInactive
28 10:36:52.123 001d58 Info MenuMgr    080E2B90 a138a106 SMenuMgr::GoToSubMenu                   () old depth=0
28 10:36:52.123 001d58 Info MenuMgr    08999818 a138a106 SMenuStackEntry::SMenuStackEntry        ()
28 10:36:52.123 001d58 Info MenuMgr    080E2B90 a138a106 SMenuStackEntry::InitializeCursorPosition()
28 10:36:52.123 001d58 Info MenuMgr    080E2B90 a138a106 SMenuStackEntry::SearchForFirstVisibleItem() return value= 0

28 10:37:32.781 003750 Info CorNetCon  0784A460 a138a106 SCorNetCon::HdlTcTestTimeout            () TC-TEST : 1
28 10:37:32.781 003750 Info CorNetCon  0784A460 a138a106 SCorNetCon::HdlTcTestTimeout            () send <TC_TEST>
28 10:37:32.795 0014e8 Info FrameWork  02A18570 a138a106 STcpListener::ProcessIOCPQueue          (4061) ulAvailableBytes=90 on TCP connection 0x07864A50 packetCount=100
28 10:37:32.795 0014e8 Info EventQueue 073ED5B8 00000000 SEventQueue::QueueEvent                 () pEvent=0D2CF220 type=0 name=e_DecodeMessageEvent
28 10:37:32.795 0040e8 Info EventQueue 0784A4A4 00000000 SSubEventQueue::ProcessEvent            () pEvent=0D2CF220 type=0 name=e_DecodeMessageEvent
28 10:37:32.795 0040e8 Info CorNetCon  0784A460 a138a106 SCorNetCon::On_TC_TEST_CON              () received <TC_TEST_CON>
28 10:37:32.813 000f94 Info EventQueue 0767AB68 00000000 SEventQueue::QueueEvent                 () pEvent=0EE2DF40 type=4294967294 name=SEventEQTimeout
28 10:37:32.813 003690 Info EventQueue 0767AB68 00000000 SEventQueue::Process                    () pEvent=0EE2DF40 type=4294967294 name=SEventEQTimeout
28 10:37:32.813 003690 Info EventQueue 0767AB68 00000000 SEventQueue::Process                    () call timeout function for timer 08023F30


28 10:37:46.022 003e74 Info LineMgr    07588B40 a138a106 CLineMgr::OnInfoMessage                 () pDevice: 07588B40, pInfoMsg: 0E1DBDE8
28 10:37:46.022 003e74 Info LineMgr    07588B40 a138a106 CLineMgr::OnReceivedUserDataChangedEvent() lUserDataChangedContext=20
28 10:37:46.022 003e74 Info EventQueue 073ED5B8 00000000 SEventQueue::QueueEvent                 () pEvent=0829B088 type=5 name=SUserDataChangedEvent
28 10:37:46.022 001fe8 Info EventQueue 07588BB8 00000000 SSubEventQueue::ProcessEvent            () pEvent=0829B088 type=5 name=SUserDataChangedEvent
28 10:37:46.022 001fe8 Info LineMgr    07588B40 a138a106 CLineMgr::HandleOnUserDataChanged       () changed: 20  cumulated changes: 20
28 10:37:46.022 003e74 Info SwSIPSub   0D9A7BA8 00000000 SwSIPActSubscr::Send200Ok               () SEND SIP 200 OK
28 10:37:46.022 003e74 Info SwSIPSub   0D9A7BA8 00000000 SFsm::OnProcessEvent                    () Subscribed	evtNotify	Result: 0	NewSt: Subscribed
28 10:37:46.118 003a9c Info LineMgr    07588B40 a138a106 CLineMgr::OnDelayUserDataChangedTimeout () cumulated changes: 20
28 10:37:46.118 003a9c Info LineMgr    07588B40 a138a106 CLineMgr::ReloadUserData                () cumulated changes: 20
28 10:37:46.118 003a9c Info SCNEndpnt  080E2B80 a138a106 SCorNetEndpoint::OnUserDataChanged      (20)
28 10:37:46.120 003a9c Info PMConfig   0291FF30 00000000 PhoneMgrConfig::GetCallerListStatistics () user id=373 iNormalCallsNew=1 iNormalCallsTotal=20 iCallbackReqsNew=0 iCallbackReqsTotal=0 iVoiceMails=0 iRedialListEntries=20
28 10:37:46.120 003a9c Info SCNEndpnt  080E2B80 a138a106 SCorNetEndpoint::RefreshValuesDerivedFromCallerList() caller list=(1/20) callback list=(0/0)
28 10:37:46.120 003a9c Info SCNEndpnt  080E2B80 a138a106 SCorNetEndpoint::RefreshDisplay         ()
28 10:37:46.120 003a9c Info MenuMgr    080E2B90 a138a106 SMenuStackEntry::GetHeadLinesForDisplay ()

 

Ich bin dann auf den Hinweis gestossen, dass die API PBXUser.IsBusy in einem Cache zwischenspeichert. Macht das dann der builtin GSE Block auch so ? Und wenn ja, wo bekommt der Cache die Daten her und wo werden diese zwischengespeichert ?

 

Ich hoffe jemand kennt sich damit aus oder hat noch eine andere Idee woran es liegen könnte.

Bin für Ideen offen.

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
Sign in to follow this  

×