Opened 6 years ago

Last modified 6 years ago

#290 closed баг

Не работает исходящий вызов через TLS на телефон Yealink — at Version 1

Reported by: alx Owned by: alx
Priority: средний Milestone: 2 очередь
Component: any Keywords:
Cc:

Description (last modified by alx)

Телефон Yealink зарегистрирован на плате VE-01 через транспорт TLS, номер 122.
Звонки с телефона проходят нормально. При вызове номера 122 вызывающий немедленно получает ответ "480 Temporarily Unavailable". Лог звонка:

sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Idle: CAS A activity detected, ts=127, flags=0000, data=0
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Idle: CAS event, ts=127, flags=0000, data=7
sip_ua[521]: fxs.cpp:702: ==> ts 127: manual CAS event processing (abcd=13)
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialtone: CAS event, ts=127, flags=0000, data=7
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialtone: DTMF detected, ts=127, flags=0000, data=1
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: Tone completed, ts=127, flags=0000, data=3
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: Tone detected, ts=127, flags=0000, data=255
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: DTMF detected, ts=127, flags=0000, data=2
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: Tone detected, ts=127, flags=0000, data=255
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: DTMF detected, ts=127, flags=0000, data=2
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Dialing: Tone detected, ts=127, flags=0000, data=255
sip_ua[521]: fxs.cpp:241: ts 127: dialing 122
sip_ua[521]: user_agent.cpp:3099: --> ua_dial_out() <sip:111@192.168.1.67> -> sip:122@192.168.1.67 ()...
DEBUG | 20181116-055333.891 | repro | RESIP:TRANSPORT | 44042 | Transport.cxx:392 | incoming from: [ V4 127.0.0.1:6060 UDP flowKey=21 transportKey=1 ]
DEBUG | 20181116-055333.892 | repro | RESIP:TRANSACTION | 43017 | TuSelector.cxx:189 | TuSelector::selectTransactionUser: Checking which TU message belongs to:

INVITE sip:122@192.168.1.67 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.67:6060;rport=6060;branch=z9hG4bK1008681416;received=127.0.0.1
Max-Forwards: 70
Contact: <sip:111@127.0.0.1:6060>
To: <sip:122@192.168.1.67>
From: <sip:111@192.168.1.67>;tag=1421584185
Call-ID: 318460658
CSeq: 20 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: replaces, timer
User-Agent: eXosip/4.1.0
X-Endpoint-Type: FXS
Content-Length: 955

v=0
o=gateway 0 0 IN IP4 192.168.1.67
s=conversation
c=IN IP4 192.168.1.67
t=0 0
m=audio 10254 RTP/SAVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:UNoBOLysHhZNJqdg1T/6cJ9QBoqNQ1MAtrIEupjc
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:jFwyWwVA9GBmjTdPnjdab79TtRFrbegoEHziWuTK
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30
m=audio 10254 RTP/AVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30

DEBUG | 20181116-055333.895 | repro | RESIP:TRANSACTION | 43017 | TransactionUser.cxx:83 | TransactionUser::isForMe: TU=DialogUsageManager, Checking rule... : 
SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055333.896 | repro | RESIP:TRANSACTION | 43017 | MessageFilterRule.cxx:66 |   MessageFilterRule::matches: Method is not in list. Rule does not
 match.
DEBUG | 20181116-055333.897 | repro | RESIP:TRANSACTION | 43017 | TransactionUser.cxx:90 | TransactionUser::isForMe: TU=DialogUsageManager, No matching rule fo
und : SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055333.899 | repro | RESIP:TRANSACTION | 43017 | TransactionUser.cxx:83 | TransactionUser::isForMe: TU=Proxy, Checking rule... : SipReq:  INVI
TE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055333.900 | repro | RESIP:TRANSACTION | 43017 | TransactionUser.cxx:86 | TransactionUser::isForMe: TU=Proxy, Match! : SipReq:  INVITE 122@192
.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055333.902 | repro | RESIP | 43017 | Helper.cxx:374 | Helper::makeResponse(SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE cont
act=111@127.0.0.1:6060 / 20 from(wire) code=100 reason=
DEBUG | 20181116-055333.904 | repro | RESIP:TRANSACTION | 43017 | TimerQueue.cxx:50 | Adding timer: Timer Trying tid=1008681416 ms=80
DEBUG | 20181116-055333.905 | repro | RESIP:TRANSACTION | 43017 | TuSelector.cxx:70 | Send to TU: Proxy size=0 

INVITE sip:122@192.168.1.67 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.67:6060;rport=6060;branch=z9hG4bK1008681416;received=127.0.0.1
Max-Forwards: 70
Contact: <sip:111@127.0.0.1:6060>
To: <sip:122@192.168.1.67>
From: <sip:111@192.168.1.67>;tag=1421584185
Call-ID: 318460658
CSeq: 20 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: replaces, timer
User-Agent: eXosip/4.1.0
X-Endpoint-Type: FXS
Content-Length: 955

v=0
o=gateway 0 0 IN IP4 192.168.1.67
s=conversation
c=IN IP4 192.168.1.67
t=0 0
m=audio 10254 RTP/SAVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:UNoBOLysHhZNJqdg1T/6cJ9QBoqNQ1MAtrIEupjc
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:jFwyWwVA9GBmjTdPnjdab79TtRFrbegoEHziWuTK
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30
m=audio 10254 RTP/AVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30

DEBUG | 20181116-055334.240 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:1075 | Found transport: [ V4 0.0.0.0:5060 UDP flowKey=21 transportKey=1 ]
DEBUG | 20181116-055334.242 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:871 | Looked up source for destination: [ V4 127.0.0.1:6060 UDP flowKey=2
1 transportKey=1 ] -> [ V4 127.0.0.1:0 UDP flowKey=21 transportKey=1 ] sent-by=192.168.1.67 sent-port=6060
DEBUG | 20181116-055334.244 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:1291 | Transmitting to [ V4 127.0.0.1:6060 UDP flowKey=21 transportKey=1 
] tlsDomain= via [ V4 127.0.0.1:5060 UDP flowKey=21 transportKey=1 ]

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.67:6060;rport=6060;branch=z9hG4bK1008681416;received=127.0.0.1
To: <sip:122@192.168.1.67>
From: <sip:111@192.168.1.67>;tag=1421584185
Call-ID: 318460658
CSeq: 20 INVITE
Content-Length: 0

sigcomp id=
DEBUG | 20181116-055334.241 | repro | REPRO:APP | 47117 | Proxy.cxx:167 | Got: INVITE sip:122@192.168.1.67 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.67:6060;rport=6060;branch=z9hG4bK1008681416;received=127.0.0.1
Max-Forwards: 70
Contact: <sip:111@127.0.0.1:6060>
To: <sip:122@192.168.1.67>
From: <sip:111@192.168.1.67>;tag=1421584185
Call-ID: 318460658
CSeq: 20 INVITE
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: replaces, timer
User-Agent: eXosip/4.1.0
X-Endpoint-Type: FXS
Content-Length: 955

v=0
o=gateway 0 0 IN IP4 192.168.1.67
s=conversation
c=IN IP4 192.168.1.67
t=0 0
m=audio 10254 RTP/SAVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:UNoBOLysHhZNJqdg1T/6cJ9QBoqNQ1MAtrIEupjc
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:jFwyWwVA9GBmjTdPnjdab79TtRFrbegoEHziWuTK
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30
m=audio 10254 RTP/AVP 8 0 96 18 101 13 98
a=altc:1 IP6 2a01:540:2f05:7f00:ad:c3ff:fe00:6 10254
a=altc:2 IP4 192.168.1.67 10254
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=rtpmap:98 PCMA/8000
a=gpmd:98 vbd=yes
a=ptime:30

INFO | 20181116-055334.248 | repro | REPRO:APP | 47117 | Proxy.cxx:366 | New RequestContext tid=1008681416 : SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cs
eq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
INFO | 20181116-055334.250 | repro | REPRO:APP | 47117 | Proxy.cxx:376 | Inserting new RequestContext tid=1008681416 -> numtrans=1 final=0
INFO | 20181116-055334.251 | repro | REPRO:APP | 47117 | RequestContext.cxx:92 | RequestContext::process(SipMessage) 1008681416
DEBUG | 20181116-055334.252 | repro | REPRO:APP | 47117 | RequestContext.cxx:152 | Got a request.
DEBUG | 20181116-055334.253 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: StrictRouteFixup
DEBUG | 20181116-055334.254 | repro | REPRO:APP | 47117 | monkeys/StrictRouteFixup.cxx:39 | Monkey handling request: StrictRouteFixup; reqcontext = numtrans=1 
final=0 req=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055334.587 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: IsTrustedNode
DEBUG | 20181116-055334.588 | repro | REPRO:APP | 47117 | monkeys/IsTrustedNode.cxx:36 | Monkey handling request: IsTrustedNode; reqcontext = numtrans=1 final=
0 req=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
sip_ua[548]: user_agent.cpp:1911: ---> transport 0: SIP event 5 (Call is being processed!): cid=1, did=0, tid=6, rid=0, sid=0, nid=0
INFO | 20181116-055334.590 | repro | REPRO:APP | 47117 | AclStore.cxx:553 | AclStore - source address IS trusted: 127.0.0.1:6060 UDP
DEBUG | 20181116-055334.592 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: DigestAuthenticator
DEBUG | 20181116-055334.593 | repro | REPRO:APP | 47117 | monkeys/DigestAuthenticator.cxx:51 | Monkey handling request: DigestAuthenticator; reqcontext = numtr
ans=1 final=0 req=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055334.594 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: AmIResponsible
DEBUG | 20181116-055334.595 | repro | REPRO:APP | 47117 | monkeys/AmIResponsible.cxx:32 | Monkey handling request: AmIResponsible; reqcontext = numtrans=1 fina
l=0 req=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
sip_ua[629]: repro.cpp:439: doSessionAccounting(): Session Created 'branch=z9hG4bK1008681416'
DEBUG | 20181116-055334.599 | repro | REPRO:APP | 47117 | Proxy.cxx:595 | Proxy::isMyUri sip:122@192.168.1.67 1
DEBUG | 20181116-055334.600 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: RequestFilter
DEBUG | 20181116-055334.601 | repro | REPRO:APP | 47117 | monkeys/RequestFilter.cxx:154 | Monkey handling request: RequestFilter; reqcontext = numtrans=1 final
=0 req=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055334.603 | repro | REPRO:APP | 47117 | monkeys/RequestFilter.cxx:147 | Request is accepted
DEBUG | 20181116-055334.604 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: MyStaticRoute
DEBUG | 20181116-055334.605 | repro | REPRO:APP | 47117 | reproStaticRoute.cpp:38 | Monkey handling request: MyStaticRoute; reqcontext = numtrans=1 final=0 req
=SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
DEBUG | 20181116-055334.607 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: MyLocationServer
DEBUG | 20181116-055334.608 | repro | RESIP:DUM | 47117 | InMemorySyncRegDb.cxx:258 | InMemorySyncRegDb::lockRecord:  aor=sip:122@192.168.1.67 threadid=47117
DEBUG | 20181116-055334.609 | repro | RESIP:DUM | 47117 | InMemorySyncRegDb.cxx:279 | InMemorySyncRegDb::unlockRecord:  aor=sip:122@192.168.1.67 threadid=47117
DEBUG | 20181116-055334.613 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:107 | RequestProcessor waiting for async response: MyLocationServer
DEBUG | 20181116-055334.615 | repro | REPRO:APP | 36868 | UserAuthGrabber.cxx:31 | Grabbed user info for 122@192.168.1.67 : 52272286bf32cdd1ed3285f914984c4d
DEBUG | 20181116-055334.616 | repro | RESIP:TRANSACTION | 36868 | TuSelector.cxx:70 | Send to TU: Proxy size=0 

UserInfoMessage(tid=1008681416)
DEBUG | 20181116-055334.617 | repro | REPRO:APP | 47117 | Proxy.cxx:167 | Got: UserInfoMessage(tid=1008681416)
DEBUG | 20181116-055334.619 | repro | REPRO:APP | 47117 | Proxy.cxx:438 | Trying to dispatch : UserInfoMessage(tid=1008681416)
DEBUG | 20181116-055334.620 | repro | REPRO:APP | 47117 | Proxy.cxx:443 | Sending UserInfoMessage(tid=1008681416) to numtrans=1 final=0 req=SipReq:  INVITE 122
@192.168.1.67 tid=1008681416 cseq=20 INVITE contact=111@127.0.0.1:6060 / 20 from(wire)
INFO | 20181116-055334.622 | repro | REPRO:APP | 47117 | RequestContext.cxx:657 | RequestContext::process(ApplicationMessage) UserInfoMessage(tid=1008681416)
DEBUG | 20181116-055334.955 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:95 | Chain invoking RequestProcessor: MyLocationServer
DEBUG | 20181116-055334.956 | repro | RESIP | 47117 | Helper.cxx:374 | Helper::makeResponse(SipReq:  INVITE 122@192.168.1.67 tid=1008681416 cseq=20 INVITE cont
act=111@127.0.0.1:6060 / 20 from(wire) code=480 reason=
DEBUG | 20181116-055334.958 | repro | REPRO:APP | 47117 | RequestContext.cxx:937 | tid of orig req: 1008681416
DEBUG | 20181116-055334.959 | repro | REPRO:APP | 47117 | RequestContext.cxx:972 | Ensuring orig tid matches tid of response: 1008681416 == 1008681416
DEBUG | 20181116-055334.960 | repro | REPRO:APP | 47117 | RequestContext.cxx:979 | Sending final response.
DEBUG | 20181116-055334.962 | repro | RESIP | 47117 | SipStack.cxx:822 | SEND: SipResp: 480 tid=1008681416 cseq=20 INVITE / 20 from(tu)
DEBUG | 20181116-055334.964 | repro | REPRO:APP | 47117 | ProcessorChain.cxx:113 | RequestProcessor skipping current chain: MyLocationServer
DEBUG | 20181116-055334.966 | repro | RESIP:TRANSACTION | 43017 | TimerQueue.cxx:50 | Adding timer: Timer H tid=1008681416 ms=32000
DEBUG | 20181116-055334.967 | repro | RESIP:TRANSACTION | 43017 | TimerQueue.cxx:50 | Adding timer: Timer G tid=1008681416 ms=500
DEBUG | 20181116-055334.968 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:1075 | Found transport: [ V4 0.0.0.0:5060 UDP flowKey=21 transportKey=1 ]
DEBUG | 20181116-055334.969 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:871 | Looked up source for destination: [ V4 127.0.0.1:6060 UDP flowKey=2
1 transportKey=1 ] -> [ V4 127.0.0.1:0 UDP flowKey=21 transportKey=1 ] sent-by=192.168.1.67 sent-port=6060
DEBUG | 20181116-055334.971 | repro | RESIP:TRANSPORT | 43017 | TransportSelector.cxx:1291 | Transmitting to [ V4 127.0.0.1:6060 UDP flowKey=21 transportKey=1 
] tlsDomain= via [ V4 127.0.0.1:5060 UDP flowKey=21 transportKey=1 ]

SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/UDP 192.168.1.67:6060;rport=6060;branch=z9hG4bK1008681416;received=127.0.0.1
To: <sip:122@192.168.1.67>;tag=e7c8bc13
From: <sip:111@192.168.1.67>;tag=1421584185
Call-ID: 318460658
CSeq: 20 INVITE
Server: repro 1.10.2
Content-Length: 0

sigcomp id=
DEBUG | 20181116-055334.979 | repro | RESIP:TRANSPORT | 44042 | Transport.cxx:392 | incoming from: [ V4 127.0.0.1:6060 UDP flowKey=21 transportKey=1 ]
sip_ua[548]: user_agent.cpp:1911: ---> transport 0: SIP event 9 (4xx received for Call!): cid=1, did=0, tid=6, rid=0, sid=0, nid=0
sip_ua[521]: fxs.cpp:419: ---> ts=127, state=Calling: Call disconnected, ts=127, flags=0000, data=1
sip_ua[521]: comcerto.cpp:6475: ts 127: stopping RTP stream
sip_ua[521]: comcerto.cpp:6475: ts 127: stopping RTP stream

repro-1.10.2

Change History (1)

comment:1 by alx, 6 years ago

Description: modified (diff)
Note: See TracTickets for help on using tickets.