Непонятное поведение IVR (автосекретаря)

[anonymous]

Здравствуйте уважаемые форумчане,
может кто-нибудь сталкивался с подобной проблемой:

3CX Phone System версия 10.0.24018.2322
Лицензия - Professional 16 коммутаций, без модуля CallCenter
ОС - Windows2008Server R2 SP1

Ситуация следующая - при входящих звонках с SIP-провайдера указан маршрут на IVR (Автосекретаря), но очень часто бывает что я даже не слышу сообщения автосекретаря, мне сразу сообщают "подождите идет переадресация" и переключают на очередь (по умолчанию стоит другая очередь), причем на одну и ту же, как будто я нажимаю цифру "2" в IVR, в логах видно что выбрано направление 816, но кто его выбрал и где это можно исправить, и вообще кто определил что переключаться именно туда...
Если сообщение IVR воспроизводится, то все работает ОК.

Ниже приведен лог такого звонка, где 800 - IVR, 816 - очередь на которую по непонятной причине переадресовываются звонки, 268268 - voip провайдер (VOIP Trunk):


15:32:23.944|.CallLeg.cpp(143)|Log5||CallLeg:nNewCall:[CM500002]: Info on incoming INVITE:
INVITE sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.20.16.20:5060;branch=z9hG4bK-lr97m-ax4qq
Max-Forwards: 69
Contact: "84852243218"
To: "268268"
From: "84852243218";tag=kh71e7lbkn
Call-ID: [email protected]
CSeq: 369 INVITE
Subject: Call from CS6111
Expires: 3600
Accept: application/sdp;q=0.3, application/ISUP;q=0.2, multipart/mixed;q=0.1
Allow: INVITE, ACK, CANCEL, BYE, INFO, PRACK, UPDATE, OPTIONS, REGISTER, REFER, SUBSCRIBE, MESSAGE, PUBLISH
Organization: IskraTel
Supported: 100rel
User-Agent: SI3000
Content-Length: 0


15:32:23.946|.Line.cpp(301)|Log5||LineCfg::getInboundTarget:Looking for inbound target: called=268268; caller=84852243218
15:32:23.946|.Line.cpp(352)|Log2||LineCfg::getInboundTarget:[CM503012]: Inbound office hours rule (TENSOR_268268) for 10000 forwards to DN:800
15:32:23.960|.CallCtrl.cpp(346)|Log2||CallCtrl:nIncomingCall:[CM503001]: Call(3373): Incoming call from 84852243218@(Ln.10000@TT268268) to
15:32:23.965|.Line.cpp(1455)|Log2||Line:rintEndpointInfo:[CM505003]: Provider:[TT268268] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [SI3000] PBX contact: [sip:[email protected]:5060]
15:32:23.965|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.1
15:32:23.966|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:3373.1:Offer received. RTP connection: 172.20.16.206:23544(23545)
15:32:23.966|.CallCtrl.cpp(529)|Log3||CallCtrl:nSelectRouteReq:[CM503010]: Making route(s) to
15:32:23.967|.CallCtrl.cpp(708)|Log2||CallCtrl:nSelectRouteReq:[CM503004]: Call(3373): Route 1: Ext:Ext.800@[Dev:sip:[email protected]:40600;rinstance=6d2ab635101ee3a5]
15:32:23.999|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210002] C:3373.2:Offer provided. Connection(transcoding mode): 127.0.0.1:7450(7451)
15:32:24.000|.Target.cpp(441)|Log2||Target::makeOneInvite:[CM503025]: Call(3373): Calling Ext:Ext.800@[Dev:sip:[email protected]:40600;rinstance=6d2ab635101ee3a5]
15:32:24.151|.CallLeg.cpp(315)|Log3||CallLeg:nAnswer:[CM503002]: Call(3373): Alerting sip:[email protected]:40600;rinstance=6d2ab635101ee3a5
15:32:24.151|.Extension.cpp(1407)|Log3||Extension:rintEndpointInfo:[CM505001]: Ext.800: Device info: Device Identified: [Man: 3CX Ltd.;Mod: 3CX IVR;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX IVR] PBX contact: [sip:[email protected]:5060]
15:32:24.153|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.2
15:32:24.155|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210001] C:3373.2:Answer received. RTP connection[unsecure]: 127.0.0.1:40694(40695)
15:32:24.157|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210003] C:3373.1:Answer provided. Connection(transcoding mode[unsecure]):172.20.18.231:7448(7449)
15:32:24.158|.CallCtrl.cpp(885)|Log2||CallCtrl:nLegConnected:[CM503007]: Call(3373): Device joined: sip:[email protected]:5060
15:32:24.159|.CallCtrl.cpp(885)|Log2||CallCtrl:nLegConnected:[CM503007]: Call(3373): Device joined: sip:[email protected]:40600;rinstance=6d2ab635101ee3a5
15:32:24.257|.CallLeg.cpp(594)|Log5||CallLeg:nConfirmed:Session 522144 of leg C:3373.1 is confirmed
15:32:24.901|.SLServer.cpp(868)|Log2|MediaServer|MediaServerReporting:TMFhandler:[MS211000] C:3373.1: 172.20.16.206:23544 is delivering DTMF using RTP payload (RFC2833). In-Band DTMF tone detection is disabled for this call segment.
15:32:31.158|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.2
15:32:31.159|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:3373.2:Offer received. RTP connection: 127.0.0.1:40694(40695)
15:32:31.160|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210002] C:3373.1:Offer provided. Connection(transcoding mode): 172.20.18.231:7448(7449)
15:32:31.269|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.1
15:32:31.270|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210001] C:3373.1:Answer received. RTP connection[unsecure]: 172.20.16.206:23544(23545)
15:32:31.270|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210003] C:3373.2:Answer provided. Connection(transcoding mode[unsecure]):127.0.0.1:7450(7451)
15:32:31.481|.CallLeg.cpp(605)|Log5||CallLeg:nRefer:Refer: from=;tag=d22dda1b; to="TENSOR_268268:84852243218";tag=ca33be06; RefTo=
15:32:31.482|.CallCtrl.cpp(529)|Log3||CallCtrl:nSelectRouteReq:[CM503010]: Making route(s) to
15:32:31.482|.CallCtrl.cpp(708)|Log2||CallCtrl:nSelectRouteReq:[CM503004]: Call(3373): Route 1: Ext:Ext.816@[Dev:sip:[email protected]:5488]
15:32:31.537|.Target.cpp(441)|Log2||Target::makeOneInvite:[CM503025]: Call(3373): Calling Ext:Ext.816@[Dev:sip:[email protected]:5488]
15:32:31.696|.CallLeg.cpp(315)|Log3||CallLeg:nAnswer:[CM503002]: Call(3373): Alerting sip:[email protected]:5488
15:32:31.696|.Extension.cpp(1407)|Log3||Extension:rintEndpointInfo:[CM505001]: Ext.816: Device info: Device Identified: [Man: 3CX Ltd.;Mod: 3CX Queue;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Queue Manager (q=816)] PBX contact: [sip:[email protected]:5060]
15:32:31.697|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.3
15:32:31.698|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:3373.3:Offer received. RTP connection: 127.0.0.1:32336(32337)
15:32:31.699|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210002] C:3373.1:Offer provided. Connection(transcoding mode): 172.20.18.231:7448(7449)
15:32:31.703|.CallCtrl.cpp(885)|Log2||CallCtrl:nLegConnected:[CM503007]: Call(3373): Device joined: sip:[email protected]:5488
15:32:31.807|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3373.1
15:32:31.809|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210001] C:3373.1:Answer received. RTP connection[unsecure]: 172.20.16.206:23544(23545)
15:32:31.809|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210003] C:3373.3:Answer provided. Connection(transcoding mode[unsecure]):127.0.0.1:7452(7453)
15:32:32.529|.CallLeg.cpp(143)|Log5||CallLeg:nNewCall:[CM500002]: Info on incoming INVITE:
INVITE sip:[email protected]:5060;nofwd=1;tag3cx=2570-RKUXXILKRD SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5488;branch=z9hG4bK-d8754z-de5d0d48af61fa1c-1---d8754z-;rport=5488
Max-Forwards: 70
Contact:
To:
From: "816Polygraphy:TENSOR_268268:84852243218";tag=db18d45a
Call-ID: NTkwNGU4MzZmZmIxMDExNzk0ZjRjMzJmYmU5MGRlZGQ.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE
Proxy-Authorization: Digest username="816",realm="3CXPhoneSystem",nonce="414d535c05bedb5058:23b901e67aaf861ec06e510da5e71d00",uri="sip:[email protected]:5060;nofwd=1;tag3cx=2570-RKUXXILKRD",response="0d451ea99bd97671ca8855a7dcd000fa",algorithm=MD5
Supported: replaces
User-Agent: 3CX Queue Manager (q=816)
Content-Length: 0


15:32:32.534|.CallCtrl.cpp(346)|Log2||CallCtrl:nIncomingCall:[CM503001]: Call(3374): Incoming call from Ext.816 to
15:32:32.538|.Extension.cpp(1407)|Log3||Extension:rintEndpointInfo:[CM505001]: Ext.816: Device info: Device Identified: [Man: 3CX Ltd.;Mod: 3CX Queue;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Queue Manager (q=816)] PBX contact: [sip:[email protected]:5060]
15:32:32.538|.CallLeg.cpp(1194)|Log5||CallLeg::setRemoteSdp:Remote SDP is set for legC:3374.1
15:32:32.539|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210000] C:3374.1:Offer received. RTP connection: 127.0.0.1:32338(32339)
15:32:32.540|.CallCtrl.cpp(529)|Log3||CallCtrl:nSelectRouteReq:[CM503010]: Making route(s) to
15:32:32.540|.CallCtrl.cpp(708)|Log2||CallCtrl:nSelectRouteReq:[CM503004]: Call(3374): Route 1: Ext:Ext.108@[Dev:sip:[email protected]:5064;user=phone]
15:32:32.584|.SLServer.cpp(861)|Log5|MediaServer|MediaServerReporting::SetRemoteParty:[MS210004] C:3374.2:Offer provided. Connection(proxy mode): 192.168.0.71:7456(7457)
15:32:32.585|.Target.cpp(441)|Log2||Target::makeOneInvite:[CM503025]: Call(3374): Calling Ext:Ext.108@[Dev:sip:[email protected]:5064;user=phone]
15:32:32.670|.CallLeg.cpp(315)|Log3||CallLeg:nAnswer:[CM503002]: Call(3374): Alerting sip:[email protected]:5064;user=phone
15:32:32.670|.Extension.cpp(1407)|Log3||Extension:rintEndpointInfo:[CM505001]: Ext.108: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [Grandstream GXW-4008 V1.5A 1.0.6.8 chip V2.2] PBX contact: [sip:[email protected]:5060]
15:32:33.539|.Call.cpp(1396)|Log2||Call::Terminate:[CM503008]: Call(3373): Call is terminated
15:32:33.676|.Call.cpp(1396)|Log2||Call::Terminate:[CM503008]: Call(3374): Call is terminated
15:32:33.789|.CallLeg.cpp(326)|Log2||CallLeg:nFailure:[CM503003]: Call(3374): Call to sip:[email protected] has failed; Cause: 487 Request Cancelled; from IP:192.168.0.78:5064
15:32:45.003|.Call.cpp(48)|Log5||??:Currently active calls [none]


Я не понял вот эту строку:
15:32:31.481|.CallLeg.cpp(605)|Log5||CallLeg:nRefer:Refer: from=;tag=d22dda1b; to="TENSOR_268268:84852243218";tag=ca33be06; RefTo= я же ничего не нажимал...

С исходящими звонками через этого провайдера никаких проблем.
Есть еще один провайдер (General VOIP) и проводные линии через шлюзы, то же самое поведение с IVR...

Заранее благодарю за любую помощь в этом вопросе.
Иван.

 

[misstake2012]

логи похоже не в подробном уровне логирования.
Настройки - Дополнительно - Подробный уровень.
Похоже, что в звуке приходят какие-то команды DTMF, АТС их принимает и делает переадресацию.
Попробуйте подключить тестовый аккаунт sipnet.ru, у них точно все работает как надо и протестируйте с ним.

 

[anonymous]

@yarvan wrote:Я не понял вот эту строку:
15:32:31.481|.CallLeg.cpp(605)|Log5||CallLeg:nRefer:Refer: from=;tag=d22dda1b; to="TENSOR_268268:84852243218";tag=ca33be06; RefTo= я же ничего не нажимал...
Тут как раз и указывается причина проблемы. Технически - явно "бибикали" и "бибикали" именно 2-кой
Приведите полный лог звонка. Он начинается с распечатки запроса INVITE

Спасибо
P.S. Пожалуйста, следуйте рекоммендациям изложенным в http: //www.3cx.com/forums/pravila-foruma-kak-sokratit-vremja-mezhdu-voprosom-i-otvetom-18715.html
Это действительно сокращает затраты нашего (включая и Вас!) времени

 

[anonymous]

Отредактировал исходное сообщение, теперь полный лог звонка... так же могу запостить логи МедиаСервера и отладочные (trace) логи... прошу прощения pravila-foruma-kak-sokratit-vremja-mezhdu-voprosom-i-otvetom-18715.html внимательно прочел, думал что остальная часть лога излишня.

Технически - явно "бибикали" и "бибикали" именно 2-кой
Тоже пришел к такому выводу, просматривая логи, но в том то и дело что "бибикается" как-то не систематично? стихийно... но почему именно только 2-кой?
Сейчас добавил предварительное IVR-меню с нулевым звуковым файлом, которое на все действия будет переводить на исходное IVR-меню... эдакий фильтр DTMF мусора... если проблема в этом, то она самоустранится... надеюсь...
Вообще похоже с этой проблемой проще искать обходные пути, чем искать причину.

С уважением, Иван.

 

[anonymous]

В предыдущем сообщении я не добавил ещё одну цитату

15:32:24.901|.SLServer.cpp(868)|Log2|MediaServer|MediaServerReporting:TMFhandler:[MS211000] C:3373.1: 172.20.16.206:23544 is delivering DTMF using RTP payload (RFC2833). In-Band DTMF tone detection is disabled for this call segment.
Это сообщение возникает именно тогда, когда передающая сторона явно высылает DTMF.
Откуда этот звонок пришёл на PBX? с мобильного? с обычного городского? или с SIP телефона?

 

[anonymous]

Откуда этот звонок пришёл на PBX? с мобильного? с обычного городского? или с SIP телефона?
Звонок с проводного городского телефона на номер 268268 SIP-провайдера (который в сою очередь связан SIP Trunk-ом с 3CX).
Но подобные сообщения вылезают и при звонках с некоторых мобильных номеров (или операторов, не прослеживал, с моего сотового все ОК, что затрудняет поиск причины).

Пробовал играть параметрами "re-INVITE", "Replace", "Голос через АТС" SIP-провайдера в разных сочетаниях, эффект остается... Сейчас стоит только "re-INVITE".

 

[anonymous]

Надо к провайдеру обратиться. Если звонки со стационарных и/или мобильных телефонов так себя ведут, то эти DTMF'ы генерируются оборудованием провайдера и только он может указать/найти реальную причину.

 

[anonymous]

Надо к провайдеру обратиться.
Я кажись нашел причину: при входящих звонках с некоторых направлений (в основном со старых городских линий, на обычных телефонах это хорошо слышно) при подъеме трубки идет такой проигрыш "траляля-траляля" типа служебного сигнала АТС "определение направления".
Файл прикладываю, каково ваше мнение уважаемый SY могут эти звуки ввести в заблуждение Автосекретаря?

 

[anonymous]

Теоретически, если там DTMF сигналы, то может и запутать. Хотя, если в логе пишется
172.20.16.206:23544 is delivering DTMF using RTP payload (RFC2833)
то похоже, что "запуталось" оборудование провайдера, а не автосекретарь.
Попробуйте "поймать" примеры таких звонков wireshark'ом (и от провайдера, и от GoIP, у которого, как Вы говорили, тоже наблюдается проблема). Это прольёт свет на степень "вины" автосекретаря.

Думаю, что эта часть сигнала вообще не должна попадать "в эфир", а обрабатываться (и вырезаться) оборудованием, которому она адресована.

 

[anonymous]

Прошло чуть больше недели, описанная проблема более не наблюдается.
2-х секундное голосовое меню с пустым звуковым файлом и с переадресацией для всех действий IVR на основное рабочее IVR, нивелирует все звуки передаваемые со стороны провайдера при "подъеме трубки"...
Иногда это проще придумать обходной маневр, чем выяснять с каждым провайдером, что такое и почему это от него приходит.

Благодарю всех участников темы за ваши мысли и знания, именно в процессе диалога с вами пришло это решение.
С уважением, Иван.