asterisk 22.5.0 проблемма с исходящими.

[alexander-spiridonov]

Имеем телефон Cisco-CP3905 и asterisk 22.5.0
Проблема: нет исходящим звонков, лог ниже получаем на попытку звонка SIP/2.0 501 Not Implemented хотя телефон нормально регистрируется
и проблем с входящими нет

pbxast*CLI> pjsip set logger host 10.11.2.124
PJSIP Logging Enabled for host: 10.11.2.124
<--- Received SIP request (966 bytes) from UDP:10.11.2.124:5060 --->
NOTIFY sip:201@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjLQPBdfNeAvExqiqjBejdEi3mfD7pbG2K
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=aKxjsH4JuBHlWtmLVaegz7tfPF1a78w-
To: "Филиппов А.А." <sip:201@10.11.2.3>
Call-ID: Nchm.h9eSwX4L.U8LSZPZa0dzHuCzM3s
CSeq: 20295 NOTIFY
Contact: <sip:201@10.11.2.124:5060>
Content-Length: 349
Subscription-State: active
Event: dialog
Content-Disposition: session;handling=required
Content-Type: application/dialog-info+xml

<?xml version="1.0" encoding="UTF-8" ?>
<dialog-info xmlns:call="urn:x-cisco:parmams:xml:ns:dialog-info:dialog:callinfo-dialog" version="0" state="partial" entity="sip:201@10.11.2.124">
<dialog id="2" call-id="d0999f4a-9237-4827-b705-f97e265b7eec" local-tag="c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a">
<state>trying</state></dialog>
</dialog-info>

<--- Transmitting SIP response (663 bytes) to UDP:10.11.2.124:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.11.2.124:5060;rport=5060;received=10.11.2.124;branch=z9hG4bKPjLQPBdfNeAvExqiqjBejdEi3mfD7pbG2K
Call-ID: Nchm.h9eSwX4L.U8LSZPZa0dzHuCzM3s
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=aKxjsH4JuBHlWtmLVaegz7tfPF1a78w-
To: "Филиппов А.А." <sip:201@10.11.2.3>;tag=z9hG4bKPjLQPBdfNeAvExqiqjBejdEi3mfD7pbG2K
CSeq: 20295 NOTIFY
WWW-Authenticate: Digest realm="asterisk",nonce="1763712323/decfa7d2c6b93756981e0c161793cdcf",opaque="0777566c25f176f1",algorithm=MD5,qop="auth"
Server: FPBX-17.0.19.26(22.5.0)
Content-Length: 0


<--- Received SIP request (1260 bytes) from UDP:10.11.2.124:5060 --->
NOTIFY sip:201@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjNhCg.Na3lDQxml0QpYbcpimwPSBjBaNt
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=aKxjsH4JuBHlWtmLVaegz7tfPF1a78w-
To: "Филиппов А.А." <sip:201@10.11.2.3>
Call-ID: Nchm.h9eSwX4L.U8LSZPZa0dzHuCzM3s
CSeq: 20296 NOTIFY
Contact: <sip:201@10.11.2.124:5060>
Content-Length: 349
Subscription-State: active
Event: dialog
Content-Disposition: session;handling=required
Content-Type: application/dialog-info+xml
Authorization: Digest username="201", realm="asterisk", nonce="1763712323/decfa7d2c6b93756981e0c161793cdcf", uri="sip:201@10.11.2.3:5060", response="ef5a255187ab44143bc861a804b0025f", algorithm=MD5, cnonce="HL..UC9jpvqGZFS5ZRF4UawV7VOLQ7Hm", opaque="0777566c25f176f1", qop=auth, nc=00000001

<?xml version="1.0" encoding="UTF-8" ?>
<dialog-info xmlns:call="urn:x-cisco:parmams:xml:ns:dialog-info:dialog:callinfo-dialog" version="0" state="partial" entity="sip:201@10.11.2.124">
<dialog id="2" call-id="d0999f4a-9237-4827-b705-f97e265b7eec" local-tag="c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a">
<state>trying</state></dialog>
</dialog-info>

<--- Transmitting SIP response (520 bytes) to UDP:10.11.2.124:5060 --->
SIP/2.0 501 Not Implemented
Via: SIP/2.0/UDP 10.11.2.124:5060;rport=5060;received=10.11.2.124;branch=z9hG4bKPjNhCg.Na3lDQxml0QpYbcpimwPSBjBaNt
Call-ID: Nchm.h9eSwX4L.U8LSZPZa0dzHuCzM3s
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=aKxjsH4JuBHlWtmLVaegz7tfPF1a78w-
To: "Филиппов А.А." <sip:201@10.11.2.3>;tag=z9hG4bKPjNhCg.Na3lDQxml0QpYbcpimwPSBjBaNt
CSeq: 20296 NOTIFY
Server: FPBX-17.0.19.26(22.5.0)
Content-Length: 0


<--- Received SIP request (1265 bytes) from UDP:10.11.2.124:5060 --->
INVITE sip:127@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjho7Ls9Hx8mqUgT8TqMA745RmWju.yxti
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a
To: sip:127@10.11.2.3
Call-ID: d0999f4a-9237-4827-b705-f97e265b7eec
CSeq: 13031 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
User-Agent: Cisco-CP3905/9.2.1
Contact: <sip:201@10.11.2.124:5060>
Supported: replaces,join,sdp-anat,norefersub,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-monrec,X-cisco-config,X-cisco-sis-5.0.0,X-cisco-xsi-7.0.1
Expires: 180
Accept: application/sdp
Allow-Events: kpml,dialog
Remote-Party-ID: "Филиппов А.А."<sip:201@10.11.2.3:5060>;privacy=off
Content-Type: application/sdp
Content-Length: 290

v=0
o=- 2208988881 2208988881 IN IP4 10.11.2.124
s=FOXPHONE
t=0 0
a=X-nat:0
m=audio 16388 RTP/AVP 0 8 18 101
c=IN IP4 10.11.2.124
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

<--- Transmitting SIP response (612 bytes) to UDP:10.11.2.124:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.11.2.124:5060;rport=5060;received=10.11.2.124;branch=z9hG4bKPjho7Ls9Hx8mqUgT8TqMA745RmWju.yxti
Call-ID: d0999f4a-9237-4827-b705-f97e265b7eec
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a
To: <sip:127@10.11.2.3>;tag=z9hG4bKPjho7Ls9Hx8mqUgT8TqMA745RmWju.yxti
CSeq: 13031 INVITE
WWW-Authenticate: Digest realm="asterisk",nonce="1763712328/91da4325df3729f5b504b78defdbcd88",opaque="73ba9ea158e65c05",algorithm=MD5,qop="auth"
Server: FPBX-17.0.19.26(22.5.0)
Content-Length: 0


<--- Received SIP request (432 bytes) from UDP:10.11.2.124:5060 --->
ACK sip:127@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjho7Ls9Hx8mqUgT8TqMA745RmWju.yxti
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a
To: sip:127@10.11.2.3;tag=z9hG4bKPjho7Ls9Hx8mqUgT8TqMA745RmWju.yxti
Call-ID: d0999f4a-9237-4827-b705-f97e265b7eec
CSeq: 13031 ACK
Content-Length: 0


<--- Received SIP request (969 bytes) from UDP:10.11.2.124:5060 --->
NOTIFY sip:201@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjDJyQ1nvsJ0dPo.9wZixQ6h-AMg2hwoQR
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=TK80Wi.HpmuVHyQWlaBwwRGo1RG1XTFG
To: "Филиппов А.А." <sip:201@10.11.2.3>
Call-ID: 9C1vCmJ9CizocfSg6.C89ER0kCtTOWrn
CSeq: 30500 NOTIFY
Contact: <sip:201@10.11.2.124:5060>
Content-Length: 352
Subscription-State: active
Event: dialog
Content-Disposition: session;handling=required
Content-Type: application/dialog-info+xml

<?xml version="1.0" encoding="UTF-8" ?>
<dialog-info xmlns:call="urn:x-cisco:parmams:xml:ns:dialog-info:dialog:callinfo-dialog" version="1"
state="partial" entity="sip:201@10.11.2.124">
<dialog id="2" call-id="d0999f4a-9237-4827-b705-f97e265b7eec" local-tag="c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a"><state>terminated</state></dialog>
</dialog-info>

<--- Transmitting SIP response (663 bytes) to UDP:10.11.2.124:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.11.2.124:5060;rport=5060;received=10.11.2.124;branch=z9hG4bKPjDJyQ1nvsJ0dPo.9wZixQ6h-AMg2hwoQR
Call-ID: 9C1vCmJ9CizocfSg6.C89ER0kCtTOWrn
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=TK80Wi.HpmuVHyQWlaBwwRGo1RG1XTFG
To: "Филиппов А.А." <sip:201@10.11.2.3>;tag=z9hG4bKPjDJyQ1nvsJ0dPo.9wZixQ6h-AMg2hwoQR
CSeq: 30500 NOTIFY
WWW-Authenticate: Digest realm="asterisk",nonce="1763712334/470af3d82721f7551e2ec4dfd8c769c1",opaque="0d1526db65c685a0",algorithm=MD5,qop="auth"
Server: FPBX-17.0.19.26(22.5.0)
Content-Length: 0


<--- Received SIP request (1263 bytes) from UDP:10.11.2.124:5060 --->
NOTIFY sip:201@10.11.2.3:5060 SIP/2.0
Via: SIP/2.0/UDP 10.11.2.124:5060;rport;branch=z9hG4bKPjlTkS86eu0h-sgKwF9UPUX9E6ygOUe2QO
Max-Forwards: 70
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=TK80Wi.HpmuVHyQWlaBwwRGo1RG1XTFG
To: "Филиппов А.А." <sip:201@10.11.2.3>
Call-ID: 9C1vCmJ9CizocfSg6.C89ER0kCtTOWrn
CSeq: 30501 NOTIFY
Contact: <sip:201@10.11.2.124:5060>
Content-Length: 352
Subscription-State: active
Event: dialog
Content-Disposition: session;handling=required
Content-Type: application/dialog-info+xml
Authorization: Digest username="201", realm="asterisk", nonce="1763712334/470af3d82721f7551e2ec4dfd8c769c1", uri="sip:201@10.11.2.3:5060", response="50ea3226f230f2c34bda50ee40a9b450", algorithm=MD5, cnonce="rk1TEWutWp6DZrkXpuTkWCrXsAoylBTx", opaque="0d1526db65c685a0", qop=auth, nc=00000001

<?xml version="1.0" encoding="UTF-8" ?>
<dialog-info xmlns:call="urn:x-cisco:parmams:xml:ns:dialog-info:dialog:callinfo-dialog" version="1"
state="partial" entity="sip:201@10.11.2.124">
<dialog id="2" call-id="d0999f4a-9237-4827-b705-f97e265b7eec" local-tag="c5af02f5-1dfb-4b6b-b3de-ac1c3abe793a"><state>terminated</state></dialog>
</dialog-info>

<--- Transmitting SIP response (520 bytes) to UDP:10.11.2.124:5060 --->
SIP/2.0 501 Not Implemented
Via: SIP/2.0/UDP 10.11.2.124:5060;rport=5060;received=10.11.2.124;branch=z9hG4bKPjlTkS86eu0h-sgKwF9UPUX9E6ygOUe2QO
Call-ID: 9C1vCmJ9CizocfSg6.C89ER0kCtTOWrn
From: "Филиппов А.А." <sip:201@10.11.2.3>;tag=TK80Wi.HpmuVHyQWlaBwwRGo1RG1XTFG
To: "Филиппов А.А." <sip:201@10.11.2.3>;tag=z9hG4bKPjlTkS86eu0h-sgKwF9UPUX9E6ygOUe2QO
CSeq: 30501 NOTIFY
Server: FPBX-17.0.19.26(22.5.0)
Content-Length: 0

[Glukinho]

SIP/2.0 501 Not Implemented - это ответы на NOTIFY события, они не имеют отношения к звонку.

Ваш телефон присылает INVITE (начало звонка), в ответ на него Астериск присылает 401 Unauthorized (приглашает прислать аутентифицированный звонок, то есть с учетными данными), в ответ на это телефон присылает ACK (как бы говорит "принял и понял").

После этого телефон должен прислать аутентифицированный INVITE, но в вашем логе этого нет - либо лог неполный, либо телефон не посылает, либо посылает, но не доходит.

Установите sngrep (если не установлен) и запустите sngrep -c, будет гораздо понятнее всё.

[alexander-spiridonov]

сейчас попробую

[alexander-spiridonov]

С работы свалили сейчс не проверить
но в конце лога вместо второго регистр он шлет NOTIFY
но с данными авторизации

[alexander-spiridonov]

или это вообще не связные вещи?

[Glukinho]

Это не связанные вещи. Вам нужны сообщения INVITE и ответы на них. Ориентируйтесь на поле Call-ID - все сообщения, имеющие одинаковым это поле, относятся к одному диалогу. Так что вам нужны только сообщения с Call-ID как у самого первого INVITE.

Повторюсь, sngrep сделает весь этот отбор за вас и представит SIP диалоги в удобном виде, запустите лучше его.

[alexander-spiridonov]

окей, с понедельник сделаю. Спасибо за наводку

[ded]

Вы регистрируете Cisco 3905 как будто из-за НАТа. До него не доходит предложение авторизации через дайджест -
WWW-Authenticate: Digest realm="asterisk",nonce="1763712328/91da4325df3729f5b504b78defdbcd88",opaque="73ba9ea158e65c05",algorithm=MD5,qop="auth"
И он будет опять и опять присылать INVITE - типичное поведение неправильно настраиваемого цыскофона. Хотя на первый взгляд 10.11.2.124 и 10.11.2.3 в одной подсети.
sngrep ничего не даст кроме анализа и вот такого же вывода.

P.S. убирайте портянки под спойлер?

[alexander-spiridonov]

Телефон и атс физически находиться в разных сетях, файрволла между ними нет.
Телефон в сети 10.82.6.0/24, атс 10.82.0.0/24 при этом с этой сети сип телефон пашет а вот цыска не хочет, при этом входящая связь до цыски работает.... куда копать уже не знаю
При этом тот же самый цыска с той-же самой конфигурацией в сети 10.82.0.0/24 работает.

[alexander-spiridonov]

при этом логи с телефона
spoiler=12:03:12:627 [sip] 22:52:36.625 pjcu.c pjcuRcvHandler(CONN), ORIGINATE, eid=0, cid=5
12:03:12:632 [sip] 22:52:36.630 pjcu.c [PJCU_ProcConnEvt():2857] case FSIP_CORE_ORIGINATE, PJCU_TASK_ID(0), eid(0)
12:03:12:634 [sip] 22:52:36.632 foxsip_channel [pjcu_makeCall():191] prepare to call pjsua_call_make_call(): eid: 0, cid: 5
12:03:12:636 [sip] 22:52:36.635 pjsua_call.c Making call with acc #0 to sip:127@10.82.0.251:5060
12:03:12:642 [sip] 22:52:36.641 pjcu_media_uti Media index 0 selected for call 0
12:03:12:645 [sip] 22:52:36.643 pjcu_media_uti [pjcu_create_audio_sdp2][226] addrType=0, rtp_port=16386
12:03:12:652 [sip] 22:52:36.651 pjcu_media_uti [328] sdp->origin.addr=10.82.6.124
12:03:12:661 [sip] 22:52:36.660 dlg0x1360670 Sending Request msg INVITE/cseq=25805 (tdta0x1933008)
12:03:12:673 [sip] 22:52:36.671 pjcu.c [pjcu_on_call_state():1012] Call 0 state=CALLING
12:03:12:706 [sip] 22:52:36.704 dlg0x1360670 Sending Request msg INVITE/cseq=25804 (tdta0x1933008)
12:03:12:713 [sip] 22:52:36.711 util Request msg INVITE/cseq=25805 (tdta0x1933008): skipping target resolution because address is already set
12:03:12:717 [sip] 22:52:36.715 util Request msg INVITE/cseq=25805 (tdta0x1933008) exceeds UDP size threshold (1500), sending with TCP
12:03:12:723 [sip] 22:52:36.721 tsx0x1934070 Temporary failure in sending Request msg INVITE/cseq=25805 (tdta0x1933008), will try next server. Err=171064 (Unknown pjsip error 171064)
12:03:12:732 [sip] 22:52:36.730 pjcu.c [pjcu_on_call_state():1012] Call 0 state=CALLING
12:03:18:014 x [LC] lldpDecode(). extra data after lldp end, t=0
12:03:18:732 [sip] 22:52:42.730 pjcu.c [pjcu_on_call_state():1012] Call 0 state=DISCONNCTD
12:03:18:734 [sip] 22:52:42.733 pjcu.c [pjcu_on_call_state():1169] Call disconnected, code staus(408)!
12:03:18:740 [sip] 22:52:42.735 pjcu_pjsip_api [pcu_rptCallRelease():2367]: reason=408, code=0