" /> PlayAnnouncementAndDigits ignoring timeouts - Genesys CTI User Forum
« previous next »
Pages: [1]   Go Down

Author Topic: PlayAnnouncementAndDigits ignoring timeouts  (Read 8395 times)

Offline vma

  • Sr. Member
  • ****
  • Posts: 255
  • Karma: 0
PlayAnnouncementAndDigits ignoring timeouts
« on: April 04, 2013, 08:45:43 PM »
Advertisement
Hi,
I'm having a Genesys Express environment purely IP with SIPServer and no PBX. I'm trying to use the PlayAnnouncementAndDigits block from routing to collect some digits but the timeouts are ignored. Right after announcement is played the routing jumps to next block.

22:26:14.866_T_I_00700224fcae0062 [14:28] TApplyTreatment (type PlayAnnouncementAndDigits) is being called
request to 65200(TServerSIP) message RequestApplyTreatment
AttributeReferenceID 783
AttributeTreatmentParms [209] 00 05 01 00..
'MAX_DIGITS' 4
'START_TIMEOUT' 10
'DIGIT_TIMEOUT' 10
'TOTAL_TIMEOUT' 10
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
                        'TEXT' 'http://localhost/audiofiles/nita/digit_collection/en_collectdigits'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeConnID 00700224fcae0062
AttributeThisDN '8110'
..sent to nita_cc1:3210(fd=720)
    _B_I_00700224fcae0062 [14:28] treatment===========>TREATMENT_REQUEST
22:26:14.867_A_I_00700224fcae0062 [0E:0c] ----------->TMESSAGE
22:26:14.867_I_I_00700224fcae0062 [09:04] <<<<<<<<<<<<suspend interpretator(WAIT_PLAY_TREATMENT), func:TreatmentPlayAnnouncementAndDigits timers:00000
received from 65200(TServerSIP)nita_cc1:3210(fd=) message EventTreatmentApplied
AttributeCallState 0
AttributeCallType 1
AttributePropagatedCallType 1
AttributeCallID 100
AttributeConnID 00700224fcae0062
AttributeCallUUID '141UVMT0P90FD4O91JGUKKO8OC000034'
AttributeUserData [604] 00 1b 00 00..
'language' 'en'
'service' 'antivirus'
'agency' 'nita'
'customer' 'normal'
'RVQID' ''
'RVQDBID' ''
'LBR_ORIG' '101:108'
'LBR_TS' '139574845'
'LBR_SNUM' '39'
'RTargetTypeSelected' '4'
'RTargetRuleSelected' ''
'RTargetObjectSelected' 'nita_antivirus'
'RTargetObjSelDBID' '143'
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'Entry-Agency'
'RStrategyDBID' '109'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeDNIS '8100'
AttributeThisDN '8110'
AttributeThisDNRole 2
AttributeThisQueue '8110'
AttributeOtherQueue '8100'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeReferenceID 783
AttributeExtensions [23] 00 01 01 00..
'BusinessCall' 1
AttributeTimeinSecs 1365139575 (22:26:15)
AttributeTimeinuSecs 314000
AttributeEventSequenceNumber 00000000000009df
22:26:15.315_T_I_00700224fcae0062 [14:0c] EventTreatmentApplied is received for tserver TServerSIP[SwitchSIPCS] (this dn=8110)
    _B_I_00700224fcae0062 [14:21] treatment applied===========>TREATMENT_APPLIED
22:26:15.315_M_I_00700224fcae0062 [10:1f] pulse for one call
received from 65200(TServerSIP)nita_cc1:3210(fd=) message EventTreatmentEnd
AttributeCallState 0
AttributeCallType 1
AttributePropagatedCallType 1
AttributeCallID 100
AttributeConnID 00700224fcae0062
AttributeCallUUID '141UVMT0P90FD4O91JGUKKO8OC000034'
AttributeUserData [604] 00 1b 00 00..
'language' 'en'
'service' 'antivirus'
'agency' 'nita'
'customer' 'normal'
'RVQID' ''
'RVQDBID' ''
'LBR_ORIG' '101:108'
'LBR_TS' '139574845'
'LBR_SNUM' '39'
'RTargetTypeSelected' '4'
'RTargetRuleSelected' ''
'RTargetObjectSelected' 'nita_antivirus'
'RTargetObjSelDBID' '143'
'RTargetAgentSelected' ''
'RTargetPlaceSelected' ''
'RTenant' 'Resources'
'RStrategyName' 'Entry-Agency'
'RStrategyDBID' '109'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
AttributeDNIS '8100'
AttributeThisDN '8110'
AttributeThisDNRole 2
AttributeCollectedDigits '2'
AttributeThisQueue '8110'
AttributeOtherQueue '8100'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeLastDigit 50
AttributeReferenceID 783
AttributeExtensions [230] 00 06 01 00..
'BusinessCall' 1
'MAX_DIGITS' 4
[color=red] 'START_TIMEOUT' 10
'DIGIT_TIMEOUT' 10
'TOTAL_TIMEOUT' 10[/color]
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
                        'TEXT' 'http://localhost/audiofiles/nita/digit_collection/en_collectdigits'
AttributeTimeinSecs 1365139575 (22:26:15)
AttributeTimeinuSecs 982000
AttributeEventSequenceNumber 00000000000009e0
22:26:15.984_T_I_00700224fcae0062 [14:0c] EventTreatmentEnd is received for tserver TServerSIP[SwitchSIPCS] (this dn=8110)
22:26:15.984_A_I_00700224fcae0062 [14:0d] <-----------TMESSAGE
    _B_I_00700224fcae0062 [07:1a] play treatment end===========>TREATMENT_NONE
[color=red]22:26:15.984[/color]_I_I_00700224fcae0062 [09:05] >>>>>>>>>>>>resume interpretator(0), func:TreatmentPlayAnnouncementAndDigits

[color=red]22:26:15.984 [/color]Int 22000 *ROUTING*Digits entered: 2

as you can see it doesn't wait for 10 seconds. It just jumps right to the print statement that I have after. Is there something I'm doing wrong?

regards,
Mihai
Logged

Offline kubikle

  • Full Member
  • ***
  • Posts: 140
  • Karma: 7
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #1 on: April 04, 2013, 09:27:28 PM »
Not sure but I've heard that SIP server have limited support for PlayAnnouncementAndDigits in those cases when  announcement is specified as TEXT and specifically it ignores timeouts. Was told that either instead of TEXT to use something like ID or (workaround) to use 2 separate treatments - PlayAnnouncement and CollectDigits.
Logged

Offline cavagnaro

  • Administrator
  • Hero Member
  • *****
  • Posts: 7641
  • Karma: 56330
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #2 on: April 05, 2013, 12:18:20 AM »
Your audio file has a lenght, which is considered on the Timout, so if your audio is 30secs long you must put the Total Timeout as 40
Logged

Offline vma

  • Sr. Member
  • ****
  • Posts: 255
  • Karma: 0
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #3 on: April 05, 2013, 07:01:20 AM »
My audio file is 2 secs. I did what kubikle said and it works, with two treatments.
BTW I used TEXT exactly to get rid of IDs and the stupid rule that you have to use only digits in the name of the file + create voice prompts + keep a list as a dictionary for those digits.

Anyway if anyone knows an official document where it is said that timeouts are intentionally ignored when using TEXT please let me know.

Thank you very much,
Mihai

Logged

Offline Timur Karimov

  • Sr. Member
  • ****
  • Posts: 415
  • Karma: 2
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #4 on: April 05, 2013, 08:55:03 AM »
Show version of you SIP server
Logged

Offline Fra

  • Hero Member
  • *****
  • Posts: 856
  • Karma: -3
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #5 on: April 05, 2013, 09:03:45 AM »
SIP Server 8.x is severely bugged on PlayAnnouncement & Collect digits - check its release notes, as I've spotted loads of corrections and limitations.

Fra
Logged

Offline vma

  • Sr. Member
  • ****
  • Posts: 255
  • Karma: 0
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #6 on: April 05, 2013, 09:34:45 AM »
The SIP Server version is 8.0.400.25. Is the one that comes with last version of Genesys Express but I guess you are right, I will try to upgrade to last version and I will check again.

Regards,
Mihai
Logged

Offline Kubig

  • Hero Member
  • *****
  • Posts: 2755
  • Karma: 44
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #7 on: April 05, 2013, 10:03:14 AM »
Are you using DTMF in RTP? Did you try change this settings by the way?
Logged

Offline vma

  • Sr. Member
  • ****
  • Posts: 255
  • Karma: 0
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #8 on: April 05, 2013, 10:40:03 AM »
I don't even get to input any DTMF. The timeout is 0 so I don't have time to press anything :)
Logged

Offline Timur Karimov

  • Sr. Member
  • ****
  • Posts: 415
  • Karma: 2
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #9 on: April 05, 2013, 11:29:02 AM »
Upgrade on latest 8.1.x and forget about problem with PACD object.
Logged

Offline Fra

  • Hero Member
  • *****
  • Posts: 856
  • Karma: -3
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #10 on: April 18, 2013, 04:04:59 PM »
Did you manage to sort this out?
I'm using SIP Server 8.1.001.11 + Stream Manager 7.6 with NETANN and  PlayTreatmentAndDigits: the goal is collecting 6 digits and makes the announcement interruptible, so that the customer can stop the announcement whilst they enter those digits. What it happens is that as soon as the first digit is entered, the treatment ends, which prevents from collecting the further 5 digits. Although I'm using the TEXT parameters, I believe this is not a problem of timeouts, as SIP Server is clearly cutting itself out after the first digit has been received:
===
16:30:26.022 SIPMS(CW_TRT5): TRTMSVC: << DTMF SIGNAL(3)
16:30:26.022 SIPMS(CW_TRT5): TRTMSVC: digits_timeout timer set {id=1059061794,timeout=5000}
16:30:26.022 SIPMS(CW_TRT5): ANNC("sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1") - INTERRUPTED
===

[code]16:30:20.210: Sending  [0,UDP] 688 bytes to 172.24.206.15:5090 >>>>>
INVITE sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1 SIP/2.0
From: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
To: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 1 INVITE
Content-Length: 0
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-207
Contact: <sip:**********785@172.24.206.112:5060>
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Max-Forwards: 18
X-Genesys-CallUUID: 7RDRJKPS513M32ONFB7LOJPKMG00000G
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: uui,timer


16:30:20.210: SipDialog: event SEND_INVITE, t=3835, s=2, r=6, m=09acbb74
16:30:20.210 SIPCONN(CW_TRT5): HandleSipDialogEvent(SEND_INVITE) - filtered
16:30:20.210 SIPCONN(CW_TRT5): sdp state SDP_STATE_NULL, event SDP_OFFER_REQUESTED
16:30:20.210 SIPCONN(CW_TRT5): new sdp state SDP_OFFER_REQUESTED, event SDP_OFFER_REQUESTED
16:30:20.210: $-CTI:SIP:APPLY_TREATMENT:171:555

16:30:20.210: HA:MESSAGE:TYPE[callSyncAck]:RECEIVED
16:30:20.210: $+NET:SIP::0:0
16:30:20.210: SIPTR: Received [0,UDP] 732 bytes from 172.24.206.15:3413 <<<<<
SIP/2.0 200 OK
From: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
To: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 1 INVITE
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-207;received=172.24.206.112
Contact: <sip:172.24.206.15:5090>
Content-Type: application/sdp
Content-Length: 233

v=0
o=Genesys 4313 4313 IN IP4 172.24.206.15
s=StreamManager 7.6.005.01 play
c=IN IP4 172.24.206.15
t=0 0
m=audio 27500 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:8 pcma/8000
a=x-media-op:play

16:30:20.210: SipDialog: event CALLING_RESOK, t=3835, s=7, r=5, m=09acbb74
16:30:20.210 SIPCONN(CW_TRT5): HandleSipDialogEvent(CALLING_RESOK)
16:30:20.210 SIPCONN(CW_TRT5): Capabilities 60013f
16:30:20.210 SIPCONN(CW_TRT5): store remote content
16:30:20.210 SIPCONN(CW_TRT5): sdp state SDP_OFFER_REQUESTED, event SDP_RECEIVED
16:30:20.210 SIPCONN(CW_TRT5): new sdp state SDP_OFFER_RECEIVED, event SDP_RECEIVED
16:30:20.210 SIPCONN(CW_TRT5): Connect(1,4)
16:30:20.210 SIPCONN(CW_TRT5): NotifyOnOffer
16:30:20.210 SIPCONN(**********785): SendOffer
16:30:20.210: GetRegistration::Unable to resolve number for DN:dummy
16:30:20.210 SIPCONN(**********785): re-invite-connected
16:30:20.210 SIPCONN(**********785): SendOffer::ReInvite
Session value of the SDP is [4313]
Version values of the SDP is [4313]
16:30:20.210: add party info '**********785' state 1.
16:30:20.210: SIPDLG[68]: register TRN[3836]
16:30:20.210: SIPDLG[68]: TRN[3836] flags set to 0x6
16:30:20.210: Sending  [0,UDP] 912 bytes to 10.255.137.250:5060 >>>>>
INVITE sip:10.255.137.250:5060;transport=udp SIP/2.0
From: <sip:######474@tbk.cs5.com;user=phone>;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1153
To: <sip:**********785@tbk.cs5.com;user=phone>;tag=36617
Call-ID: ed2f8f9_13e1dc483a6@CHTSTRTSSL0
CSeq: 1 INVITE
Content-Length: 236
Content-Type: application/sdp
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-208
Contact: <sip:172.24.206.112:5060>
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, UPDATE, MESSAGE, NOTIFY, OPTIONS
X-Genesys-CallUUID: 7RDRJKPS513M32ONFB7LOJPKMG00000G
Max-Forwards: 19
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: 100rel,timer

v=0
o=Genesys 1366294389 2 IN IP4 172.24.206.15
s=StreamManager 7.6.005.01 play
c=IN IP4 172.24.206.15
t=0 0
m=audio 27500 RTP/AVP 8 101
a=x-media-op:play
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:8 pcma/8000

16:30:20.210: SipDialog: event CONNECTED_SEND_REINVITE, t=3836, s=7, r=5, m=099ff594
16:30:20.210 SIPCONN(**********785): HandleSipDialogEvent(CONNECTED_SEND_REINVITE) - filtered
16:30:20.210 SIPCONN(**********785): sdp state SDP_STATE_NULL, event SDP_OFFER_SENT
16:30:20.210 SIPCONN(**********785): new sdp state SDP_OFFER_SENT, event SDP_OFFER_SENT
16:30:20.210: $-NET:SIP::0:454

16:30:20.225: $+NET:SIP::0:0
16:30:20.225: SIPTR: Received [0,UDP] 865 bytes from 10.255.137.250:5060 <<<<<
SIP/2.0 200 OK
From: <sip:######474@tbk.cs5.com;user=phone>;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1153
To: <sip:**********785@tbk.cs5.com;user=phone>;tag=36617
Call-ID: ed2f8f9_13e1dc483a6@CHTSTRTSSL0
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-208
CSeq: 1 INVITE
Content-Type: application/sdp
Contact: <sip:**********785@10.255.137.250:5060;user=phone;transport=udp>
User-Agent: Nortel SESM 12.0.12.4
Supported: com.nortelnetworks.firewall,p-3rdpartycontrol,nosec,join,x-nortel-sipvc
x-nt-location: -1
Require: timer
Session-Expires: 1800;refresher=uac
Content-Length: 233

v=0
o=PVG 1366295662840 1366295662840 IN IP4 10.255.137.250
s=-
p=+1 6135555555
c=IN IP4 10.255.137.250
t=0 0
m=audio 21966 RTP/AVP 18 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=fmtp:18 annexb=no

16:30:20.225: SipDialog: event CONNECTED_RESOK, t=3836, s=7, r=5, m=099ff594
16:30:20.225 SIPCONN(**********785): HandleSipDialogEvent(CONNECTED_RESOK)
16:30:20.225 SIPCONN(**********785): store remote content
16:30:20.225 SIPCONN(**********785): sdp state SDP_OFFER_SENT, event SDP_RECEIVED
16:30:20.225 SIPCONN(**********785): new sdp state SDP_STATE_NULL, event SDP_RECEIVED
16:30:20.225 SIPCONN(**********785): Connect(2,33)
16:30:20.225 SIPCONN(**********785): NotifyResponseOnAnswer
16:30:20.225 SIPCONN(CW_TRT5): SendAnswer
Session value of the SDP is [710181334]
Version values of the SDP is [710181334]
16:30:20.225 SIPCONN(CW_TRT5): SendAnswer::Ack
16:30:20.225 SIPCONN(CW_TRT5): SendAck(3835)
16:30:20.225: Sending  [0,UDP] 780 bytes to 172.24.206.15:5090 >>>>>
ACK sip:172.24.206.15:5090 SIP/2.0
From: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
To: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 1 ACK
Content-Length: 218
Content-Type: application/sdp
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-209
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, UPDATE, MESSAGE, NOTIFY, OPTIONS
Max-Forwards: 18

v=0
o=PVG 1366294404 1 IN IP4 10.255.137.250
s=-
p=+1 6135555555
c=IN IP4 10.255.137.250
t=0 0
m=audio 21966 RTP/AVP 18 8 101
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no

16:30:20.225: $*:SIP:CTI:HA_SEND_SYNC_MESSAGE:800
16:30:20.225: SipDialog: event CONNECTED_SEND_ACK, t=3835, s=7, r=5, m=09acbb74
16:30:20.225 SIPCONN(CW_TRT5): HandleSipDialogEvent(CONNECTED_SEND_ACK) - filtered
16:30:20.225 SIPCONN(CW_TRT5): sdp state SDP_OFFER_RECEIVED, event SDP_ANSWER_SENT
16:30:20.225 SIPCONN(CW_TRT5): new sdp state SDP_STATE_NULL, event SDP_ANSWER_SENT
16:30:20.225 SIPCONN(CW_TRT5): TRCLR(0)
16:30:20.225 SIPCONN(CW_TRT5): state e:3,p:0,s:3,c:0,rc:0,m:1
16:30:20.225: $*:SIP:CTI:MEDIA_SERVICE_EVENT:801
16:30:20.225 SIPMS(CW_TRT5): total_timeout timer set {id=41943076,timeout=20s}
16:30:20.225 SIPMS(CW_TRT5): total_timeout timer set {id=90177541,timeout=20s}
16:30:20.225 SIPCONN(CW_TRT5): NotifyOnComplete
16:30:20.225 SIPCONN(**********785): NotifyOnComplete
16:30:20.225 SIPCONN(**********785): Connect complete, other device 'CW_TRT5',(099ff520,09acbb00)
16:30:20.225 SIPCONN(**********785): SendAck(3836)
16:30:20.225: Sending  [0,UDP] 495 bytes to 10.255.137.250:5060 >>>>>
ACK sip:**********785@10.255.137.250:5060;user=phone;transport=udp SIP/2.0
From: <sip:######474@tbk.cs5.com;user=phone>;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1153
To: <sip:**********785@tbk.cs5.com;user=phone>;tag=36617
Call-ID: ed2f8f9_13e1dc483a6@CHTSTRTSSL0
CSeq: 1 ACK
Content-Length: 0
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-210
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, UPDATE, MESSAGE, NOTIFY, OPTIONS
Max-Forwards: 19


16:30:20.225: $*:SIP:CTI:HA_SEND_SYNC_MESSAGE:802
16:30:20.225: SipDialog: event CONNECTED_SEND_ACK, t=3836, s=7, r=8, m=099ff594
16:30:20.225 SIPCONN(**********785): HandleSipDialogEvent(CONNECTED_SEND_ACK) - filtered
16:30:20.225: $*:SIP:CTI:RTP_INFO:803
16:30:20.225 SIPCONN(CW_TRT5): Connect complete, other device '**********785',(09acbb00,099ff520)
16:30:20.225: SIPTR(301): complete
16:30:20.225: SIPTR(300): Step 0 - SipTransactionConnectMediaService(301) complete
16:30:20.225: SIPTR(300): complete
16:30:20.225: SIPCM: transaction SipScenario(300) complete
16:30:20.225: GetRegistration::Unable to resolve number for DN:dummy
16:30:20.225: PI: 00 S[IN]D[**********785]C[*D[**********785]]P[CW_TRT5]
16:30:20.225: PI: 00 S[QN]D[######474]E[-]MS[C[*D[CW_TRT5]]]P[**********785]
16:30:20.225: GetRegistration::Unable to resolve number for DN:dummy
16:30:20.225: -----------------------------------------------------------
16:30:20.225: C[16778232]:CF[D[[0]]:SC[300]
16:30:20.225: P[16778251]:D[**********785[2703]]:LID[0]:D2[######474[2705]]:
16:30:20.225 SIPCONN(**********785):  endPoint :CON[16778283]:PEER[16778285]:D[**********785[2703]]:DLG[68 STATE[7]]:D2[[0]:TD[0[IM[no]]]:LCRC
16:30:20.225: P[16778252]:D[######474[2705]]:LID[0]:D2[**********785[2703]]:
16:30:20.225: MS Type SIP_MEDIA_SERVICE_TREATMENT
16:30:20.225 SIPCONN(CW_TRT5):  mediaServiceConnection :CON[16778285]:PEER[16778283]:D[CW_TRT5[2708]]:DLG[70 STATE[7]]:D2[**********785[2703]:TD[0[IM[no]]]:LCRC
16:30:20.225: HA: BEGIN SYNC: CALL[16778232] SYNCTYPE[2]: SECOND CALL[0] SYNCTYPE[-1]
16:30:20.225: HA: END SYNC: CALL[16778232] SYNCTYPE[2]: SECOND CALL[0] SYNCTYPE[-1]
16:30:20.225: $*:SIP:CTI:HA_SEND_SYNC_MESSAGE:804
16:30:20.225: $*:SIP:CTI:REQUEST_COMPLETE:805
16:30:20.225: call1 16778232 idle
16:30:20.225: $-NET:SIP::0:1330

16:30:20.241: HA:MESSAGE:TYPE[callSyncAck]:RECEIVED
16:30:21.147: $+NET:SIP::0:0
16:30:21.147: SIPTR: Received [0,UDP] 374 bytes from 10.255.137.250:5060 <<<<<
OPTIONS sip:TBKN021C0SIP-VIP:5060 SIP/2.0
Via: SIP/2.0/UDP 10.255.137.250:5060;branch=z9hG4bK0gj1nj206gj13jktr620
To: sip:ping@TBKN021C0SIP-VIP
From: <sip:ping@10.255.137.250>;tag=h000000mj5000-k2ch200
Call-ID: h000000mj5000a98bij03p4632c6l41adpkqi0d83ah6l9ha2qis4o86hpg0j959gabcl41a-k2ch200@10.255.137.250
CSeq: 2666580 OPTIONS
Max-Forwards: 70
Content-Length: 0


16:30:21.147: Unable to resolve number for DN:ping
16:30:21.147: trunk ip addr 10.255.137.250
16:30:21.147: gateway 'CW_BRKNL' associated with address '10.255.137.250'
16:30:21.147: Sending  [0,UDP] 353 bytes to 10.255.137.250:5060 >>>>>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.255.137.250:5060;branch=z9hG4bK0gj1nj206gj13jktr620;received=10.255.137.250
To: sip:ping@TBKN021C0SIP-VIP
From: <sip:ping@10.255.137.250>;tag=h000000mj5000-k2ch200
Call-ID: h000000mj5000a98bij03p4632c6l41adpkqi0d83ah6l9ha2qis4o86hpg0j959gabcl41a-k2ch200@10.255.137.250
CSeq: 2666580 OPTIONS
Content-Length: 0


16:30:21.147: $-NET:SIP::0:193

16:30:22.788: $+NET:SIP::0:0
16:30:22.788: SIPTR: Received [0,UDP] 374 bytes from 10.255.137.244:5060 <<<<<
OPTIONS sip:TBKN012C0SIP-VIP:5060 SIP/2.0
Via: SIP/2.0/UDP 10.255.137.244:5060;branch=z9hG4bK0gj1nk201oj0fkovt140
To: sip:ping@TBKN012C0SIP-VIP
From: <sip:ping@10.255.137.244>;tag=h000000mj5000-mefd200
Call-ID: h000000mj5000a98bij0jo8632c6l41adpkqi0d83ah6l9ha2qis4o46ipg0j959gabcl41a-mefd200@10.255.137.244
CSeq: 2538966 OPTIONS
Max-Forwards: 70
Content-Length: 0


16:30:22.788: Unable to resolve number for DN:ping
16:30:22.788: trunk ip addr 10.255.137.244
16:30:22.788: gateway 'CW_BRKNL_OUT2' associated with address '10.255.137.244'
16:30:22.788: Sending  [0,UDP] 353 bytes to 10.255.137.244:5060 >>>>>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.255.137.244:5060;branch=z9hG4bK0gj1nk201oj0fkovt140;received=10.255.137.244
To: sip:ping@TBKN012C0SIP-VIP
From: <sip:ping@10.255.137.244>;tag=h000000mj5000-mefd200
Call-ID: h000000mj5000a98bij0jo8632c6l41adpkqi0d83ah6l9ha2qis4o46ipg0j959gabcl41a-mefd200@10.255.137.244
CSeq: 2538966 OPTIONS
Content-Length: 0


16:30:22.788: $-NET:SIP::0:209

16:30:26.022: $+NET:SIP::0:0
16:30:26.022: SIPTR: Received [0,UDP] 535 bytes from 172.24.206.15:3413 <<<<<
INFO sip:**********785@172.24.206.112:5060 SIP/2.0
From: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
To: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 1 INFO
Content-Length: 23
Content-Type: application/dtmf-relay
Via: SIP/2.0/UDP 172.24.206.15:5090;branch=z9hG4bK0409B0EF-73E7-4BEF-9AEA-7926DC73B655-2242
Contact: <sip:172.24.206.15:5090>

Signal=3
Duration=30

16:30:26.022: SIPDLG[70]: register TRN[3839]
16:30:26.022: SipDialog: event CONNECTED_REQUEST, t=3839, s=7, r=5, m=09acbb74
16:30:26.022 SIPCONN(CW_TRT5): HandleSipDialogEvent(CONNECTED_REQUEST)
16:30:26.022 SIPCONN(CW_TRT5): new transaction
16:30:26.022 SIPCONN(CW_TRT5): 1pcc event CONNECTED_REQUEST
16:30:26.022 SIPCONN(CW_TRT5): Handle INFO
16:30:26.022 SIPCONN(CW_TRT5): SendResponse(200,3839)
16:30:26.022: Sending  [0,UDP] 632 bytes to 172.24.206.15:5090 >>>>>
SIP/2.0 200 OK
From: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
To: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 1 INFO
Via: SIP/2.0/UDP 172.24.206.15:5090;branch=z9hG4bK0409B0EF-73E7-4BEF-9AEA-7926DC73B655-2242;received=172.24.206.15
Contact: <sip:**********785@172.24.206.112:5060>
X-Genesys-CallUUID: 7RDRJKPS513M32ONFB7LOJPKMG00000G
Allow: INVITE, ACK, PRACK, CANCEL, BYE, REFER, INFO, UPDATE, MESSAGE, NOTIFY, OPTIONS
Supported: uui
Content-Length: 0


16:30:26.022: SipDialog: event CONNECTED_SEND_RESOK, t=3839, s=7, r=8, m=09acbb74
16:30:26.022 SIPCONN(CW_TRT5): HandleSipDialogEvent(CONNECTED_SEND_RESOK) - filtered
16:30:26.022 SIPMS(CW_TRT5): handle 1pcc event 9
16:30:26.022: handle info message
16:30:26.022 SIPMS(CW_TRT5): TRTMSVC: << DTMF SIGNAL(3)
16:30:26.022 SIPMS(CW_TRT5): TRTMSVC: digits_timeout timer set {id=1059061794,timeout=5000}
16:30:26.022 SIPMS(CW_TRT5): ANNC("sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1") - INTERRUPTED
16:30:26.022 SIPMS(CW_TRT5): process next prompt
16:30:26.022: $*:SIP:CTI:MEDIA_SERVICE_EVENT:806
16:30:26.022 SIPMS(CW_TRT5): terminate media service
16:30:26.022: SIPTR(302): Begin step 0 - SipTransactionDetachMediaService(303)
16:30:26.022 SIPCONN(CW_TRT5): DetachMediaPeer
16:30:26.022 SIPCONN(**********785): ClrMediaPeer
16:30:26.022 SIPCONN(CW_TRT5): state e:1,p:3,s:0,c:0,rc:0,m:1
16:30:26.022: SipDialog: ClearCall(phone=0,state=7)
16:30:26.022: SipDialog::Terminate(state=7,reason=0)
16:30:26.022: SIPDLG[70]: register TRN[3840]
16:30:26.022: Sending  [0,UDP] 442 bytes to 172.24.206.15:5090 >>>>>
BYE sip:172.24.206.15:5090 SIP/2.0
From: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
To: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 2 BYE
Content-Length: 0
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-211
Max-Forwards: 18


16:30:26.022: SipDialog: event SEND_BYE, t=3840, s=8, r=8, m=09acbb74
16:30:26.022 SIPCONN(CW_TRT5): HandleSipDialogEvent(SEND_BYE) - filtered
16:30:26.022: SipDialog: set monitor 00000000
16:30:26.022 SIPCONN(CW_TRT5): DetachMediaPeer
16:30:26.022: SIPTR(303): complete
16:30:26.022: SIPTR(302): Step 0 - SipTransactionDetachMediaService(303) complete
16:30:26.022: SIPTR(302): complete
16:30:26.022: SIPCM: transaction SipScenario(302) complete
16:30:26.022: GetRegistration::Unable to resolve number for DN:dummy
16:30:26.022: PI: 00 S[IN]D[**********785]C[*D[**********785]]P[-]
16:30:26.022: PI: 00 S[QN]D[######474]E[-]
16:30:26.022: GetRegistration::Unable to resolve number for DN:dummy
16:30:26.022: -----------------------------------------------------------
16:30:26.022: C[16778232]:CF[D[[0]]:SC[302]
16:30:26.022: P[16778251]:D[**********785[2703]]:LID[0]:D2[######474[2705]]:
16:30:26.022 SIPCONN(**********785):  endPoint :CON[16778283]:PEER[0]:D[**********785[2703]]:DLG[68 STATE[7]]:D2[[0]:TD[0[IM[no]]]:LCRC
16:30:26.022: P[16778252]:D[######474[2705]]:LID[0]:D2[**********785[2703]]:
16:30:26.022: HA: BEGIN SYNC: CALL[16778232] SYNCTYPE[2]: SECOND CALL[0] SYNCTYPE[-1]
16:30:26.022: HA: END SYNC: CALL[16778232] SYNCTYPE[2]: SECOND CALL[0] SYNCTYPE[-1]
16:30:26.022: $*:SIP:CTI:HA_SEND_SYNC_MESSAGE:807
16:30:26.022: call1 16778232 idle
16:30:26.022: free_dcr 09ad6350
16:30:26.022: $-NET:SIP::0:781

16:30:26.022: $+NET:SIP::0:0
16:30:26.022: SIPTR: Received [0,UDP] 463 bytes from 172.24.206.15:3413 <<<<<
SIP/2.0 200 OK
From: sip:**********785@tbk.cs5.com;user=phone;tag=F49AC8EC-F65A-4808-964D-982CCECA66D1-1155
To: <sip:annc@172.24.206.15:5090;play=TB/3251;repeat=1>;tag=D949D7B1-0513-4E9E-8F50-A2E429EDBCD4-2772
Call-ID: A5828E5F-38C8-4D25-A253-FD18F986543C-1136@172.24.206.112
CSeq: 2 BYE
Via: SIP/2.0/UDP 172.24.206.112:5060;branch=z9hG4bK6DC579C9-0491-4EC7-B888-9A1B54895048-211;received=172.24.206.112
Contact: <sip:172.24.206.15:5090>
Content-Length: 0


16:30:26.022: SipDialog: event TERMINATING_BYE_RES, t=3840, s=9, r=4, m=00000000
16:30:26.022: SipDialog: event DESTROY, t=0, s=10, r=4, m=00000000
16:30:26.022: SipDialog[70]:<< Abort ALL <<
16:30:26.022: $*:SIP:CTI:HA_SEND_SYNC_MESSAGE:808
16:30:26.022: $-NET:SIP::0:155[/code]

Thanks

Fra
Logged

Offline cavagnaro

  • Administrator
  • Hero Member
  • *****
  • Posts: 7641
  • Karma: 56330
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #11 on: April 18, 2013, 04:25:13 PM »
Can you post the URS logs too Fra?
Logged

Offline Fra

  • Hero Member
  • *****
  • Posts: 856
  • Karma: -3
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #12 on: April 18, 2013, 04:47:32 PM »
Mh, yeah, but you can't seen anything, as it's SIP Server notifying URS that the treatment is over:

[code]18 04 13 16:30:20.263_T_I_00bf022699c28010 [14:28] TApplyTreatment (type PlayAnnouncementAndDigits) is being called
request to 65203(SIP_Server_1_PRI/SIP_Server_1_BAK) message RequestApplyTreatment
AttributeReferenceID 41561
AttributeTreatmentParms [150] 00 05 01 00..
'MAX_DIGITS' 6
'START_TIMEOUT' 10
'DIGIT_TIMEOUT' 5
'TOTAL_TIMEOUT' 20
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
                        'TEXT' 'TB/3251'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeConnID 00bf022699c28010
AttributeThisDN '######474'
..sent to TBUAT-PRL-G10:3000(fd=808)
    _B_I_00bf022699c28010 [14:28] treatment===========>TREATMENT_REQUEST
18 04 13 16:30:20.263_A_I_00bf022699c28010 [0E:0c] ----------->TMESSAGE
18 04 13 16:30:20.263_I_I_00bf022699c28010 [09:04] <<<<<<<<<<<<suspend interpretator(WAIT_PLAY_TREATMENT), timers:00000
received from 65203(SIP_Server_1_PRI)TBUAT-PRL-G10:3000(fd=) message EventTreatmentApplied
AttributeCallState 0
AttributeCallType 2
attr_#152 2
AttributeCallID 16778232
AttributeConnID 00bf022699c28010
AttributeCallUUID '7RDRJKPS513M32ONFB7LOJPKMG00000G'
AttributeUserData [340] 00 0C 00 00..
'Call-ID' 'ed2f8f9_13e1dc483a6@CHTSTRTSSL0'
'Contact' '<sip:10.255.137.250:5060;transport=udp>'
'initconnid' '00bf022699c28010'
'IP_PHONE_DISPLAY'(list) 'TEXT' 'From: ************785'
                        'TITLE' 'NGN: 0######474'
'dnis' '######474'
'CustomerSegment' 'TB'
'productcode' 'test'
'delivery_env' 'SIT6'
'oohflag' '0'
'cr_open' '0'
'RETRY' '0'
'prd_hist' 'test'
AttributeDNIS '######474'
AttributeANI '**********785'
AttributeThisDN '######474'
AttributeThisDNRole 2
AttributeCollectedDigits ''
AttributeThisQueue '######474'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeReferenceID 41561
AttributeExtensions [50] 00 02 00 00..
'OtherTrunkName' 'CW_BRKNL'
'BusinessCall' 1
AttributeTimeinSecs 1366299020 (16:30:20)
AttributeTimeinuSecs 225000
AttributeEventSequenceNumber 000000000001bb81
18 04 13 16:30:20.295_T_I_00bf022699c28010 [14:0c] EventTreatmentApplied is received for tserver SIP_Server_1_PRI[SIP_Switch_1] (this dn=######474)
    _B_I_00bf022699c28010 [14:21] treatment applied===========>TREATMENT_APPLIED
18 04 13 16:30:20.295_M_I_00bf022699c28010 [10:1f] pulse for one call
18 04 13 16:30:22.013_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1366299022, mem=0,482679,38701,260,228,1)
18 04 13 16:30:22.013_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(429 335/1024)
18 04 13 16:30:24.013_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1366299024, mem=0,482679,38701,260,228,1)
18 04 13 16:30:24.013_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(429 335/1024)
18 04 13 16:30:26.013_M_I_ [10:1d] PULSE (calls: 1(1)=1+0-0, targets=0, time=1366299026, mem=0,482679,38701,260,228,1)
18 04 13 16:30:26.013_M_I_ [10:1d] virtual queues allocation pattern: static=(13 256 128) dynamic=(429 335/1024)
received from 65203(SIP_Server_1_PRI)TBUAT-PRL-G10:3000(fd=) message EventTreatmentEnd
AttributeCallState 0
AttributeCallType 2
attr_#152 2
AttributeCallID 16778232
AttributeConnID 00bf022699c28010
AttributeCallUUID '7RDRJKPS513M32ONFB7LOJPKMG00000G'
AttributeUserData [340] 00 0C 00 00..
'Call-ID' 'ed2f8f9_13e1dc483a6@CHTSTRTSSL0'
'Contact' '<sip:10.255.137.250:5060;transport=udp>'
'initconnid' '00bf022699c28010'
'IP_PHONE_DISPLAY'(list) 'TEXT' 'From: ************785'
                        'TITLE' 'NGN: 0######474'
'dnis' '######474'
'CustomerSegment' 'TB'
'productcode' 'test'
'delivery_env' 'SIT6'
'oohflag' '0'
'cr_open' '0'
'RETRY' '0'
'prd_hist' 'test'
AttributeDNIS '######474'
AttributeANI '**********785'
AttributeThisDN '######474'
AttributeThisDNRole 2
AttributeCollectedDigits '3'
AttributeThisQueue '######474'
AttributeTreatmentType 8 (TreatmentPlayAnnouncementAndDigits)
AttributeLastDigit 51
AttributeReferenceID 41561
AttributeExtensions [198] 00 07 00 00..
'OtherTrunkName' 'CW_BRKNL'
'BusinessCall' 1
'MAX_DIGITS' 6
'START_TIMEOUT' 10
'DIGIT_TIMEOUT' 5
'TOTAL_TIMEOUT' 20
'PROMPT'(list) '1'(list) 'INTERRUPTABLE' 1
                        'TEXT' 'TB/3251'
AttributeTimeinSecs 1366299026 (16:30:26)
AttributeTimeinuSecs 22000
AttributeEventSequenceNumber 000000000001bb83
18 04 13 16:30:26.076_T_I_00bf022699c28010 [14:0c] EventTreatmentEnd is received for tserver SIP_Server_1_PRI[SIP_Switch_1] (this dn=######474)[/code]
Logged

Offline cavagnaro

  • Administrator
  • Hero Member
  • *****
  • Posts: 7641
  • Karma: 56330
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #13 on: April 18, 2013, 06:58:12 PM »
Can you check how are you sending DTMF? Info or RTP?
Logged

Offline Fra

  • Hero Member
  • *****
  • Posts: 856
  • Karma: -3
Re: PlayAnnouncementAndDigits ignoring timeouts
« Reply #14 on: April 18, 2013, 07:02:20 PM »
It's in the SIP Server log, Cav, you should see an INFO message with the digit collected, a '3' (get some coffee!  ;D ).
The issue is not in receving DTMF, but in SIP Server, which seems to have this embedded logic, whereby interruptible = the announcement is terminated just right after the first digit.

Fra
Logged
Pages: [1]   Go Up
« previous next »