Сброс звонка при переадресации исходящего вызова

[R3Xser]

Сброс звонка при переадресации исходящего вызова на внутренний номер

Здравствуйте уважаемые гуру,

Имеется Настроенный * (Астерикс) trixbox !

входящие / исходящие вызовы - (как внутренние, так и внешние ) работают почти исправно...

Есть пару номеров, при дозвоне на которые - оператор снимает трубку, и делает переадресацию на внутренний номер - после чего звонок сбрасывается.

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: Дамп звонка:

<--- SIP read from UDP://192.168.2.104:5060 --->
ACK sip:XXXXXXXXXX@192.168.2.103:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.104:5060;branch=z9hG4bK3987865462
From: "302" <sip:302@192.168.2.103>;tag=23996866
To: <sip:XXXXXXXXXX@192.168.2.103:5060>;tag=as2cc83280
Call-ID: 4025946357@192.168.2.104
CSeq: 2 ACK
Contact: <sip:302@192.168.2.104>
Authorization: Digest username="302", realm="asterisk", nonce="0646bbe3", uri="sip:XXXXXXXXXX@192.168.2.103:5060", response="fe5b613e0a289d75d8b69439e8dbf5e1, algorithm=MD5
max-forwards: 70
user-agent: sipagent MAC-00-15-7C-26-5F-17 V-12202.26.1.05-SIP
Content-Length: 0


<------------->
--- (11 headers 0 lines) ---
-- Started music on hold, class 'default', on SIP/302-00000159
-- Executing [h@macro-dialout-trunk:1] Macro("SIP/302-00000159", "hangupcall,") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-00000159", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-00000159", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,7)
-- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-00000159", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [s@macro-hangupcall:9] Hangup("SIP/302-00000159", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-00000159' in macro 'hangupcall'
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/302-00000159'
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/302-00000159' in macro 'dialout-trunk'
== Spawn extension (from-internal, XXXXXXXXXX, 4) exited non-zero on 'SIP/302-00000159'
-- Executing [h@from-internal:1] Macro("SIP/302-00000159", "hangupcall") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-00000159", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-00000159", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,7)
-- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-00000159", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [s@macro-hangupcall:9] Hangup("SIP/302-00000159", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-00000159' in macro 'hangupcall'
== Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/302-00000159'
-- Stopped music on hold on SIP/302-00000159
Scheduling destruction of SIP dialog '4025946357@192.168.2.104' in 32000 ms (Method: ACK)
set_destination: Parsing <sip:302@192.168.2.104> for address/port to send to
set_destination: set destination to 192.168.2.104, port 5060
Reliably Transmitting (NAT) to 192.168.2.104:5060:
BYE sip:302@192.168.2.104 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK3e5c93d3;rport
Max-Forwards: 70
From: <sip:XXXXXXXXXX@192.168.2.103:5060>;tag=as2cc83280
To: "302" <sip:302@192.168.2.103>;tag=23996866
Call-ID: 4025946357@192.168.2.104
CSeq: 102 BYE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
trixbox1*CLI>
<--- SIP read from UDP://192.168.2.104:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK3e5c93d3;rport=5060
From: <sip:XXXXXXXXXX@192.168.2.103:5060>;tag=as2cc83280
To: "302" <sip:302@192.168.2.103>;tag=23996866
Call-ID: 4025946357@192.168.2.104
CSeq: 102 BYE
supported: replaces
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog '4025946357@192.168.2.104' Method: ACK
Really destroying SIP dialog '2997074529@192.168.2.104' Method: REGISTER
trixbox1*CLI>
Disconnected from Asterisk server
Executing last minute cleanups

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: Лог CLI

== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Using SIP VRTP TOS bits 136
== Using SIP VRTP CoS mark 6
-- Executing [XXXXXXXXXX@from-internal:1] Macro("SIP/302-000000ca", "user-callerid,SKIPTTL,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/302-000000ca", "AMPUSER=302") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/302-000000ca", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/302-000000ca", "1?Set(REALCALLERIDNUM=302)") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/302-000000ca", "AMPUSER=302") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/302-000000ca", "AMPUSERCIDNAME=302") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/302-000000ca", "0?report") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/302-000000ca", "AMPUSERCID=302") in new stack
-- Executing [s@macro-user-callerid:8] Set("SIP/302-000000ca", "CALLERID(all)="302" <302>") in new stack
-- Executing [s@macro-user-callerid:9] ExecIf("SIP/302-000000ca", "1?Set(CHANNEL(language)=de)") in new stack
-- Executing [s@macro-user-callerid:10] GotoIf("SIP/302-000000ca", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] NoOp("SIP/302-000000ca", "Using CallerID "302" <302>") in new stack
-- Executing [XXXXXXXXXX@from-internal:2] Set("SIP/302-000000ca", "_NODEST=") in new stack
-- Executing [XXXXXXXXXX@from-internal:3] Macro("SIP/302-000000ca", "record-enable,302,OUT,") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("SIP/302-000000ca", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] AGI("SIP/302-000000ca", "recordingcheck,20120427-123051,1335522651.202") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck,20120427-123051,1335522651.202: Outbound recording not enabled
-- <SIP/302-000000ca>AGI Script recordingcheck completed, returning 0
-- Executing [s@macro-record-enable:5] MacroExit("SIP/302-000000ca", "") in new stack
-- Executing [XXXXXXXXXX@from-internal:4] Macro("SIP/302-000000ca", "dialout-trunk,2,XXXXXXXXXX,,") in new stack
-- Executing [s@macro-dialout-trunk:1] Set("SIP/302-000000ca", "DIAL_TRUNK=2") in new stack
-- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/302-000000ca", "0?sub-pincheck,s,1") in new stack
-- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/302-000000ca", "0?disabletrunk,1") in new stack
-- Executing [s@macro-dialout-trunk:4] Set("SIP/302-000000ca", "DIAL_NUMBER=XXXXXXXXXX") in new stack
-- Executing [s@macro-dialout-trunk:5] Set("SIP/302-000000ca", "DIAL_TRUNK_OPTIONS=tr") in new stack
-- Executing [s@macro-dialout-trunk:6] Set("SIP/302-000000ca", "OUTBOUND_GROUP=OUT_2") in new stack
-- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/302-000000ca", "1?nomax") in new stack
-- Goto (macro-dialout-trunk,s,9)
-- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/302-000000ca", "0?skipoutcid") in new stack
-- Executing [s@macro-dialout-trunk:10] Set("SIP/302-000000ca", "DIAL_TRUNK_OPTIONS=") in new stack
-- Executing [s@macro-dialout-trunk:11] Macro("SIP/302-000000ca", "outbound-callerid,2") in new stack
-- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/302-000000ca", "0?Set(CALLERPRES()=)") in new stack
-- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/302-000000ca", "0?Set(REALCALLERIDNUM=302)") in new stack
-- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/302-000000ca", "1?normcid") in new stack
-- Goto (macro-outbound-callerid,s,6)
-- Executing [s@macro-outbound-callerid:6] Set("SIP/302-000000ca", "USEROUTCID=") in new stack
-- Executing [s@macro-outbound-callerid:7] Set("SIP/302-000000ca", "EMERGENCYCID=") in new stack
-- Executing [s@macro-outbound-callerid:8] Set("SIP/302-000000ca", "TRUNKOUTCID=YYYYYYYYYY") in new stack
-- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/302-000000ca", "1?trunkcid") in new stack
-- Goto (macro-outbound-callerid,s,12)
-- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/302-000000ca", "1?Set(CALLERID(all)=YYYYYYYYYY)") in new stack
-- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/302-000000ca", "0?Set(CALLERID(all)=)") in new stack
-- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/302-000000ca", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
-- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/302-000000ca", "1?AGI(fixlocalprefix)") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
== fixlocalprefix: Dialpattern . matched. XXXXXXXXXX -> XXXXXXXXXX
-- <SIP/302-000000ca>AGI Script fixlocalprefix completed, returning 0
-- Executing [s@macro-dialout-trunk:13] Set("SIP/302-000000ca", "OUTNUM=XXXXXXXXXX") in new stack
-- Executing [s@macro-dialout-trunk:14] Set("SIP/302-000000ca", "custom=SIP/YYYYYYYYYY") in new stack
-- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/302-000000ca", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^))") in new stack
-- Executing [s@macro-dialout-trunk:16] Macro("SIP/302-000000ca", "dialout-trunk-predial-hook,") in new stack
-- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/302-000000ca", "") in new stack
-- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/302-000000ca", "0?bypass,1") in new stack
-- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/302-000000ca", "0?customtrunk") in new stack
-- Executing [s@macro-dialout-trunk:19] Dial("SIP/302-000000ca", "SIP/YYYYYYYYYY/XXXXXXXXXX,300,") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Using SIP VRTP TOS bits 136
== Using SIP VRTP CoS mark 6
-- Called YYYYYYYYYY/XXXXXXXXXX
-- SIP/YYYYYYYYYY-000000cb is making progress passing it to SIP/302-000000ca
-- SIP/YYYYYYYYYY-000000cb is making progress passing it to SIP/302-000000ca
-- SIP/YYYYYYYYYY-000000cb is ringing
-- SIP/YYYYYYYYYY-000000cb is making progress passing it to SIP/302-000000ca
-- SIP/YYYYYYYYYY-000000cb answered SIP/302-000000ca
-- Started music on hold, class 'default', on SIP/302-000000ca
-- Executing [h@macro-dialout-trunk:1] Macro("SIP/302-000000ca", "hangupcall,") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-000000ca", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-000000ca", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,7)
-- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-000000ca", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [s@macro-hangupcall:9] Hangup("SIP/302-000000ca", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-000000ca' in macro 'hangupcall'
== Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/302-000000ca'
== Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/302-000000ca' in macro 'dialout-trunk'
== Spawn extension (from-internal, XXXXXXXXXX, 4) exited non-zero on 'SIP/302-000000ca'
-- Executing [h@from-internal:1] Macro("SIP/302-000000ca", "hangupcall") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-000000ca", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-000000ca", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,7)
-- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-000000ca", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [s@macro-hangupcall:9] Hangup("SIP/302-000000ca", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-000000ca' in macro 'hangupcall'
== Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/302-000000ca'
-- Stopped music on hold on SIP/302-000000ca

Подскажите пожалуйста! куда рыть? Где искать проблему? - При том что выше описанная ситуация действительна только для некоторых номеров..- в иных ситуациях - переадресация срабатывает корректно.

P.S. Интересовался на другом ресурсе, решений пока не найдено (
Гоогл не помогает, моск кипит. Яй нид хелп..

С уважением.

[ded]

А что такое SIP/YYYYYYYYYY ? Это ваш (ГСМ, аналоговый, цифровой?) шлюз, или транк к провайдеру?
Ну и шифруетесь Вы по полной, типа хакнут в телефонный номер что ли?
Когда читаешь
Dialpattern . matched. XXXXXXXXXX -> XXXXXXXXXX
-- Executing [s@macro-dialout-trunk:13] Set("SIP/302-000000ca", "OUTNUM=XXXXXXXXXX")
то все иксы и игреки сильно рвут мозг, учитывая то, что иксы являются шаблонами цифр в диалплане Астериска.
Уж можно было поизобретательней - например:
SIP/супершлюз-1
OUTNUM=0123456789

[R3Xser]

А что такое SIP/YYYYYYYYYY ? Это ваш (ГСМ, аналоговый, цифровой?) шлюз, или транк к провайдеру?

YYYYYYYYYY - это транк к провайдеру (SIP аккаунт)
XXXXXXXXXX - набераемый номер
...
P.S. Да нет, не шифруюсь) ...просто привычка...
В будущем учту..... я новичек, в работе с * Астером )

[ded]

Непонятно - почему после того, как вызываемый номер ответил 302-му
-- SIP/YYYYYYYYYY-000000cb answered SIP/302-000000ca
почему включается Music-on-hold?
-- Started music on hold, class 'default', on SIP/302-000000ca
на это и срабатывает Hangup - h
-- Executing [h@macro-dialout-trunk:1]
Вам бы задампить sip set debug peer YYYYYYYYYY когда идёт INVITE к провайдеру и ответ от него. В дебаге уже конец этого диалога - BYE, поэтому причину трудно поймать.

[R3Xser]

почему включается Music-on-hold?
-- Started music on hold, class 'default', on SIP/302-000000ca

Может быть это как раз тот момент - когда вызываемый номер (по моей просьбе перевести на другого человека), делает переадресацию на (свой) внутренний номер ?
Можно ли как то отключить сие творение? (закоменнтировав) для тестирование? если да то где? в extensions.conf?
Самой мызыки не слышно, слышно лишь обрыв связи.. и чередование гудков...

Вам бы задампить sip set debug peer YYYYYYYYYY когда идёт INVITE к провайдеру и ответ от него. В дебаге уже конец этого диалога - BYE, поэтому причину трудно поймать

Позже попробую.... YYYYYYYYY - в моем случае вызываемый номер..
Благодарю... за ответ.. хоть что то уже... буду рыть землю....

[ded]

Может быть это как раз тот момент - когда вызываемый номер

-302?

(по моей просьбе перевести на другого человека), делает переадресацию на (свой) внутренний номер ?

- SIP/YYYYYYYYYY/ХХХХХХХХХХХ это не внутренний номер, по всем признакам - это внешний.

[R3Xser]

- SIP/YYYYYYYYYY/ХХХХХХХХХХХ это не внутренний номер, по всем признакам - это внешний.

Совершенно верно...
Я предполагаю, что это выгледит примерно так [302 (Мой внутренний) > YYYYYYYYYY (Мой Trunk) ] ---> Звонок [ХХХХХХХХХХХ (успешное Сеодинение) > переадресация на внутренний чужой атс (Обрыв связи) ]
Выход конечно есть *(Звонить сразу на прямой номер)... но удивляет тот момент , что сие происходит не со всеми, а лишь с некоторыми атс...
Но если присоеденится к SIP аккаунту напрямую (SIP устройством), минуя Asteriks, .... то соеденение + перенаправление происходит успешно....

[Vlad1983]

нужно снимать полный дамп по всем интерфейсам
tcpdump -i any -A -s0 -w full.cap
с вашими склонностями к шифрованию разбирайтесь в нем сами

возможно частичное проскакивание DTMF по голосу и если встречная АТС "слишком умная", то может по этим сигналам что-то подумать своё и рубануть.
часто случается при встречной RTU от mera.

[R3Xser]

Всех отозвашихся, благодарю за помощь.
Прикладываю более детальный лог звонка.

0123456789 - Вызываемый абонент
9876543210 - Мой SIP транк

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: Лог звонка

[May 4 18:09:27] VERBOSE[2380] logger.c: == Using SIP RTP TOS bits 184
[May 4 18:09:27] VERBOSE[2380] logger.c: == Using SIP RTP CoS mark 5
[May 4 18:09:27] VERBOSE[2380] logger.c: == Using SIP VRTP TOS bits 136
[May 4 18:09:27] VERBOSE[2380] logger.c: == Using SIP VRTP CoS mark 6
[May 4 18:09:27] DEBUG[2350] pbx.c: FONALITY: This thread has already held the conlock, skip locking
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [0123456789@from-internal:1] Macro("SIP/302-00000066", "user-callerid,SKIPTTL,") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/302-00000066", "AMPUSER=302") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/302-00000066", "0?report") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/302-00000066", "1?Set(REALCALLERIDNUM=302)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/302-00000066", "AMPUSER=302") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/302-00000066", "AMPUSERCIDNAME=302") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/302-00000066", "0?report") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/302-00000066", "AMPUSERCID=302") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/302-00000066", "CALLERID(all)="302" <302>") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:9] ExecIf("SIP/302-00000066", "1?Set(CHANNEL(language)=de)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/302-00000066", "1?continue") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Goto (macro-user-callerid,s,19)
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-user-callerid:19] NoOp("SIP/302-00000066", "Using CallerID "302" <302>") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [0123456789@from-internal:2] Set("SIP/302-00000066", "_NODEST=") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [0123456789@from-internal:3] Macro("SIP/302-00000066", "record-enable,302,OUT,") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/302-00000066", "1?check") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Goto (macro-record-enable,s,4)
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/302-00000066", "recordingcheck,20120504-180927,1336147767.102") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[May 4 18:09:27] VERBOSE[7812] logger.c: recordingcheck,20120504-180927,1336147767.102: Outbound recording not enabled
[May 4 18:09:27] VERBOSE[7812] logger.c: -- <SIP/302-00000066>AGI Script recordingcheck completed, returning 0
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/302-00000066", "") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [0123456789@from-internal:4] Macro("SIP/302-00000066", "dialout-trunk,2,0123456789,,") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/302-00000066", "DIAL_TRUNK=2") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/302-00000066", "0?sub-pincheck,s,1") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/302-00000066", "0?disabletrunk,1") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/302-00000066", "DIAL_NUMBER=0123456789") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/302-00000066", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/302-00000066", "OUTBOUND_GROUP=OUT_2") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/302-00000066", "1?nomax") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Goto (macro-dialout-trunk,s,9)
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/302-00000066", "0?skipoutcid") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/302-00000066", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/302-00000066", "outbound-callerid,2") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/302-00000066", "0?Set(CALLERPRES()=)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/302-00000066", "0?Set(REALCALLERIDNUM=302)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/302-00000066", "1?normcid") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Goto (macro-outbound-callerid,s,6)
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/302-00000066", "USEROUTCID=") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/302-00000066", "EMERGENCYCID=") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/302-00000066", "TRUNKOUTCID=9876543210") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/302-00000066", "1?trunkcid") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Goto (macro-outbound-callerid,s,12)
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/302-00000066", "1?Set(CALLERID(all)=9876543210)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/302-00000066", "0?Set(CALLERID(all)=)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/302-00000066", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/302-00000066", "1?AGI(fixlocalprefix)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[May 4 18:09:27] VERBOSE[7812] logger.c: == fixlocalprefix: Dialpattern . matched. 0123456789 -> 0123456789
[May 4 18:09:27] VERBOSE[7812] logger.c: -- <SIP/302-00000066>AGI Script fixlocalprefix completed, returning 0
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/302-00000066", "OUTNUM=0123456789") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/302-00000066", "custom=SIP/9876543210") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/302-00000066", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^)Tt)") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/302-00000066", "dialout-trunk-predial-hook,") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/302-00000066", "") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/302-00000066", "0?bypass,1") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/302-00000066", "0?customtrunk") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Executing [s@macro-dialout-trunk:19] Dial("SIP/302-00000066", "SIP/9876543210/0123456789,300,Tt") in new stack
[May 4 18:09:27] VERBOSE[7812] logger.c: == Using SIP RTP TOS bits 184
[May 4 18:09:27] VERBOSE[7812] logger.c: == Using SIP RTP CoS mark 5
[May 4 18:09:27] VERBOSE[7812] logger.c: == Using SIP VRTP TOS bits 136
[May 4 18:09:27] VERBOSE[7812] logger.c: == Using SIP VRTP CoS mark 6
[May 4 18:09:27] VERBOSE[7812] logger.c: Audio is at 192.168.2.103 port 18678
[May 4 18:09:27] VERBOSE[7812] logger.c: Video is at 192.168.2.103 port 14414
[May 4 18:09:27] VERBOSE[7812] logger.c: Adding codec 0x4 (ulaw) to SDP
[May 4 18:09:27] VERBOSE[7812] logger.c: Adding codec 0x8 (alaw) to SDP
[May 4 18:09:27] VERBOSE[7812] logger.c: Adding video codec 0x80000 (h263) to SDP
[May 4 18:09:27] VERBOSE[7812] logger.c: Adding video codec 0x200000 (h264) to SDP
[May 4 18:09:27] VERBOSE[7812] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[May 4 18:09:27] VERBOSE[7812] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
INVITE sip:0123456789@sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK694bd9bb;rport
Max-Forwards: 70
From: "9876543210" <sip:9876543210@sip.de>;tag=as7e241820
To: <sip:0123456789@sip.de>
Contact: <sip:9876543210@192.168.2.103>
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 401

v=0
o=root 1367758607 1367758607 IN IP4 192.168.2.103
s=Asterisk PBX 1.6.0.26-FONCORE-r78
c=IN IP4 192.168.2.103
b=CT:384
t=0 0
m=audio 18678 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
m=video 14414 RTP/AVP 34 99
a=rtpmap:34 H263/90000
a=rtpmap:99 H264/90000
a=sendrecv

---
[May 4 18:09:27] VERBOSE[7812] logger.c: -- Called 9876543210/0123456789
[May 4 18:09:27] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK694bd9bb
To: <sip:0123456789@sip.de>;tag=77e9f836
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 102 INVITE
WWW-Authenticate: Digest algorithm=MD5, nonce="9f1663539f166353d0b59c64e89cd10b09414c383863d88d4526c28a47ca0324fb53be0e", realm="sip.de"
Content-Length: 0


<------------->
[May 4 18:09:27] VERBOSE[2380] logger.c: --- (8 headers 0 lines) ---
[May 4 18:09:27] VERBOSE[2380] logger.c: Transmitting (NAT) to 123.123.123.123:5060:
ACK sip:0123456789@sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK694bd9bb;rport
Max-Forwards: 70
From: "9876543210" <sip:9876543210@sip.de>;tag=as7e241820
To: <sip:0123456789@sip.de>;tag=77e9f836
Contact: <sip:9876543210@192.168.2.103>
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Content-Length: 0


---
[May 4 18:09:27] VERBOSE[2380] logger.c: Audio is at 192.168.2.103 port 18678
[May 4 18:09:27] VERBOSE[2380] logger.c: Video is at 192.168.2.103 port 14414
[May 4 18:09:27] VERBOSE[2380] logger.c: Adding codec 0x4 (ulaw) to SDP
[May 4 18:09:27] VERBOSE[2380] logger.c: Adding codec 0x8 (alaw) to SDP
[May 4 18:09:27] VERBOSE[2380] logger.c: Adding video codec 0x80000 (h263) to SDP
[May 4 18:09:27] VERBOSE[2380] logger.c: Adding video codec 0x200000 (h264) to SDP
[May 4 18:09:27] VERBOSE[2380] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[May 4 18:09:27] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
INVITE sip:0123456789@sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK35fceaed;rport
Max-Forwards: 70
From: "9876543210" <sip:9876543210@sip.de>;tag=as7e241820
To: <sip:0123456789@sip.de>
Contact: <sip:9876543210@192.168.2.103>
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 103 INVITE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Authorization: Digest username="9876543210", realm="sip.de", algorithm=MD5, uri="sip:0123456789@sip.de", nonce="9f1663539f166353d0b59c64e89cd10b09414c383863d88d4526c28a47ca0324fb53be0e", response="fd4f8954cbac3b69dffa358def2431d0"
Date: Fri, 04 May 2012 16:09:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 401

v=0
o=root 1367758607 1367758608 IN IP4 192.168.2.103
s=Asterisk PBX 1.6.0.26-FONCORE-r78
c=IN IP4 192.168.2.103
b=CT:384
t=0 0
m=audio 18678 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
m=video 14414 RTP/AVP 34 99
a=rtpmap:34 H263/90000
a=rtpmap:99 H264/90000
a=sendrecv

---
[May 4 18:09:27] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 100 Rufaufbau
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK35fceaed
To: <sip:0123456789@sip.de>
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 103 INVITE
Content-Length: 0


<------------->
[May 4 18:09:27] VERBOSE[2380] logger.c: --- (7 headers 0 lines) ---
[May 4 18:09:28] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 183 Verbindung wird aufgebaut (0)
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK35fceaed
To: <sip:0123456789@sip.de>;tag=4fca928f
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
Supported: early-session
CSeq: 103 INVITE
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 386

v=0
o=hiQ9200 6482520120404180928 1799225402 IN IP4 123.123.123.123
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 122.122.122.122
t=0 0
m=audio 10850 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=fmtp:0 vad=no
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sqn: 0
a=sendrecv
a=ptime:20
m=video 0 RTP/AVP 34
c=IN IP4 0.0.0.0
a=rtpmap:34 H263/90000

<------------->
[May 4 18:09:28] VERBOSE[2380] logger.c: --- (12 headers 18 lines) ---
[May 4 18:09:28] VERBOSE[2380] logger.c: Found RTP audio format 0
[May 4 18:09:28] VERBOSE[2380] logger.c: Found RTP audio format 8
[May 4 18:09:28] VERBOSE[2380] logger.c: Found RTP audio format 101
[May 4 18:09:28] VERBOSE[2380] logger.c: Found audio description format PCMU for ID 0
[May 4 18:09:28] VERBOSE[2380] logger.c: Found audio description format PCMA for ID 8
[May 4 18:09:28] VERBOSE[2380] logger.c: Found audio description format telephone-event for ID 101
[May 4 18:09:28] VERBOSE[2380] logger.c: Found RTP video format 34
[May 4 18:09:28] VERBOSE[2380] logger.c: Found video description format H263 for ID 34
[May 4 18:09:28] VERBOSE[2380] logger.c: Capabilities: us - 0x28000c (ulaw|alaw|h263|h264), peer - audio=0xc (ulaw|alaw)/video=0x80000 (h263)/text=0x0 (nothing), combined - 0x8000c (ulaw|alaw|h263)
[May 4 18:09:28] VERBOSE[2380] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[May 4 18:09:28] VERBOSE[2380] logger.c: Peer audio RTP is at port 122.122.122.122:10850
[May 4 18:09:28] VERBOSE[2380] logger.c: Peer doesn't provide video
[May 4 18:09:28] VERBOSE[7812] logger.c: -- SIP/9876543210-00000067 is making progress passing it to SIP/302-00000066
[May 4 18:09:28] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 181 Ruf wird gesendet. (0)
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK35fceaed
To: <sip:0123456789@sip.de>;tag=4fca928f
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
Supported: early-session
CSeq: 103 INVITE
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 386

v=0
o=hiQ9200 6482520120404180928 1799225402 IN IP4 123.123.123.123
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 122.122.122.122
t=0 0
m=audio 10850 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=fmtp:0 vad=no
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sqn: 0
a=sendrecv
a=ptime:20
m=video 0 RTP/AVP 34
c=IN IP4 0.0.0.0
a=rtpmap:34 H263/90000

<------------->
[May 4 18:09:28] VERBOSE[2380] logger.c: --- (12 headers 18 lines) ---
[May 4 18:09:28] VERBOSE[7812] logger.c: -- SIP/9876543210-00000067 is making progress passing it to SIP/302-00000066
[May 4 18:09:29] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 180 Klingeln
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK35fceaed
To: <sip:0123456789@sip.de>;tag=4fca928f
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
Supported: early-session
CSeq: 103 INVITE
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Call-Info: <sip:+49337084400@dtag.de>;purpose=call-completion;m=NR
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 386

v=0
o=hiQ9200 6482520120404180928 1799225402 IN IP4 123.123.123.123
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 122.122.122.122
t=0 0
m=audio 10850 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=fmtp:0 vad=no
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sqn: 0
a=sendrecv
a=ptime:20
m=video 0 RTP/AVP 34
c=IN IP4 0.0.0.0
a=rtpmap:34 H263/90000

<------------->
[May 4 18:09:29] VERBOSE[2380] logger.c: --- (13 headers 18 lines) ---
[May 4 18:09:29] VERBOSE[7812] logger.c: -- SIP/9876543210-00000067 is ringing
[May 4 18:09:29] VERBOSE[7812] logger.c: -- SIP/9876543210-00000067 is making progress passing it to SIP/302-00000066
[May 4 18:09:33] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK7e52e105;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as10cadec1
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 510b596973096ad66ee5ff1e5a0e83ef@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK7111882e;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as4df74a76
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 3d9fe1dc57505da611c14a1123a5fb07@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK30dc79bf;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as0abe713f
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 4a75740b114df18a6112d5eb2e84b3fc@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK5f3b37e5;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as22363515
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 7e7f8bb6239bdfbe289b1de03bc14785@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK28da9116;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as0db39599
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 0146d9cc0ab89ff94009610128610418@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK7e52e105
To: <sip:sip.de>;tag=494c373f
From: Unknown <sip:Unknown@192.168.2.103>;tag=as10cadec1
Call-ID: 510b596973096ad66ee5ff1e5a0e83ef@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: Really destroying SIP dialog '510b596973096ad66ee5ff1e5a0e83ef@192.168.2.103' Method: OPTIONS
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK7111882e
To: <sip:sip.de>;tag=65d0125a
From: Unknown <sip:Unknown@192.168.2.103>;tag=as4df74a76
Call-ID: 3d9fe1dc57505da611c14a1123a5fb07@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: Really destroying SIP dialog '3d9fe1dc57505da611c14a1123a5fb07@192.168.2.103' Method: OPTIONS
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK30dc79bf
To: <sip:sip.de>;tag=0de22ba9
From: Unknown <sip:Unknown@192.168.2.103>;tag=as0abe713f
Call-ID: 4a75740b114df18a6112d5eb2e84b3fc@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: Really destroying SIP dialog '4a75740b114df18a6112d5eb2e84b3fc@192.168.2.103' Method: OPTIONS
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK5f3b37e5
To: <sip:sip.de>;tag=c9fe746a
From: Unknown <sip:Unknown@192.168.2.103>;tag=as22363515
Call-ID: 7e7f8bb6239bdfbe289b1de03bc14785@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: Really destroying SIP dialog '7e7f8bb6239bdfbe289b1de03bc14785@192.168.2.103' Method: OPTIONS
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK28da9116
To: <sip:sip.de>;tag=1293c2d6
From: Unknown <sip:Unknown@192.168.2.103>;tag=as0db39599
Call-ID: 0146d9cc0ab89ff94009610128610418@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: Really destroying SIP dialog '0146d9cc0ab89ff94009610128610418@192.168.2.103' Method: OPTIONS
[May 4 18:09:33] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK35fceaed
To: <sip:0123456789@sip.de>;tag=4fca928f
From: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
Supported: early-session
CSeq: 103 INVITE
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 386

v=0
o=hiQ9200 6482520120404180928 1799225402 IN IP4 123.123.123.123
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 122.122.122.122
t=0 0
m=audio 10850 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=fmtp:0 vad=no
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sqn: 0
a=sendrecv
a=ptime:20
m=video 0 RTP/AVP 34
c=IN IP4 0.0.0.0
a=rtpmap:34 H263/90000

<------------->
[May 4 18:09:33] VERBOSE[2380] logger.c: --- (12 headers 18 lines) ---
[May 4 18:09:33] VERBOSE[2380] logger.c: list_route: hop: <sip:LEITASP01@123.123.123.123:5060>
[May 4 18:09:33] VERBOSE[2380] logger.c: set_destination: Parsing <sip:LEITASP01@123.123.123.123:5060> for address/port to send to
[May 4 18:09:33] VERBOSE[2380] logger.c: set_destination: set destination to 123.123.123.123, port 5060
[May 4 18:09:33] VERBOSE[2380] logger.c: Transmitting (NAT) to 123.123.123.123:5060:
ACK sip:LEITASP01@123.123.123.123:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK38f12659;rport
Max-Forwards: 70
From: "9876543210" <sip:9876543210@sip.de>;tag=as7e241820
To: <sip:0123456789@sip.de>;tag=4fca928f
Contact: <sip:9876543210@192.168.2.103>
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 103 ACK
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Content-Length: 0


---
[May 4 18:09:33] VERBOSE[7812] logger.c: -- SIP/9876543210-00000067 answered SIP/302-00000066
[May 4 18:09:34] VERBOSE[2380] logger.c: Reliably Transmitting (NAT) to 123.123.123.123:5060:
OPTIONS sip:sip.de SIP/2.0
Via: SIP/2.0/UDP 192.168.2.103:5060;branch=z9hG4bK5f4d2d80;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@192.168.2.103>;tag=as6f090cbf
To: <sip:sip.de>
Contact: <sip:Unknown@192.168.2.103>
Call-ID: 2bd09c194953d8eb0649128038c598a3@192.168.2.103
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Date: Fri, 04 May 2012 16:09:34 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


---
[May 4 18:09:34] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.103:5060;rport=5061;branch=z9hG4bK5f4d2d80
To: <sip:sip.de>;tag=7cca658e
From: Unknown <sip:Unknown@192.168.2.103>;tag=as6f090cbf
Call-ID: 2bd09c194953d8eb0649128038c598a3@192.168.2.103
Supported: 100rel,path
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Encoding: identity
Accept-Language: en
Allow: ACK, BYE, CANCEL, INFO, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:34] VERBOSE[2380] logger.c: --- (12 headers 0 lines) ---
[May 4 18:09:34] VERBOSE[2380] logger.c: Really destroying SIP dialog '2bd09c194953d8eb0649128038c598a3@192.168.2.103' Method: OPTIONS
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
INVITE sip:9876543210@192.168.2.103:5060 SIP/2.0
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK3695aa285838c91dfb5883a09e5deff1.d3d75c3e
Max-Forwards: 67
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
From: <sip:0123456789@sip.de>;tag=4fca928f
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
Supported: histinfo,early-session
CSeq: 12726914 INVITE
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 352

v=0
o=hiQ9200 6482520120404180928 1799225403 IN IP4 123.123.123.123
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 122.122.122.122
t=0 0
m=audio 10850 RTP/AVP 0 8 101
a=ptime:20
a=rtpmap:0 PCMU/8000
a=fmtp:0 vad=no
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly
m=video 0 RTP/AVP 34
c=IN IP4 0.0.0.0

<------------->
[May 4 18:09:40] VERBOSE[2380] logger.c: --- (13 headers 16 lines) ---
[May 4 18:09:40] VERBOSE[2380] logger.c: Sending to 123.123.123.123 : 5060 (NAT)
[May 4 18:09:40] VERBOSE[2380] logger.c: Found RTP audio format 0
[May 4 18:09:40] VERBOSE[2380] logger.c: Found RTP audio format 8
[May 4 18:09:40] VERBOSE[2380] logger.c: Found RTP audio format 101
[May 4 18:09:40] VERBOSE[2380] logger.c: Found audio description format PCMU for ID 0
[May 4 18:09:40] VERBOSE[2380] logger.c: Found audio description format PCMA for ID 8
[May 4 18:09:40] VERBOSE[2380] logger.c: Found audio description format telephone-event for ID 101
[May 4 18:09:40] VERBOSE[2380] logger.c: Found RTP video format 34
[May 4 18:09:40] VERBOSE[2380] logger.c: Capabilities: us - 0x28000c (ulaw|alaw|h263|h264), peer - audio=0xc (ulaw|alaw)/video=0x80000 (h263)/text=0x0 (nothing), combined - 0x8000c (ulaw|alaw|h263)
[May 4 18:09:40] VERBOSE[2380] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[May 4 18:09:40] VERBOSE[2380] logger.c: Peer audio RTP is at port 122.122.122.122:10850
[May 4 18:09:40] VERBOSE[2380] logger.c: Peer doesn't provide video
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- Transmitting (NAT) to 123.123.123.123:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK3695aa285838c91dfb5883a09e5deff1.d3d75c3e;received=123.123.123.123
From: <sip:0123456789@sip.de>;tag=4fca928f
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 12726914 INVITE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:9876543210@192.168.2.103>
Content-Length: 0


<------------>
[May 4 18:09:40] VERBOSE[2380] logger.c: Audio is at 192.168.2.103 port 18678
[May 4 18:09:40] VERBOSE[2380] logger.c: Video is at 192.168.2.103 port 14414
[May 4 18:09:40] VERBOSE[2380] logger.c: Adding codec 0x4 (ulaw) to SDP
[May 4 18:09:40] VERBOSE[2380] logger.c: Adding codec 0x8 (alaw) to SDP
[May 4 18:09:40] VERBOSE[2380] logger.c: Adding video codec 0x80000 (h263) to SDP
[May 4 18:09:40] VERBOSE[2380] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- Reliably Transmitting (NAT) to 123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK3695aa285838c91dfb5883a09e5deff1.d3d75c3e;received=123.123.123.123
From: <sip:0123456789@sip.de>;tag=4fca928f
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 12726914 INVITE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:9876543210@192.168.2.103>
Content-Type: application/sdp
Content-Length: 374

v=0
o=root 1367758607 1367758609 IN IP4 192.168.2.103
s=Asterisk PBX 1.6.0.26-FONCORE-r78
c=IN IP4 192.168.2.103
b=CT:384
t=0 0
m=audio 18678 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=recvonly
m=video 14414 RTP/AVP 34
a=rtpmap:34 H263/90000
a=recvonly

<------------>
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Started music on hold, class 'default', on SIP/302-00000066
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
ACK sip:9876543210@192.168.2.103:5060 SIP/2.0
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK53f1758a24e64797ae4a1bbe9b250772.e9961615
Max-Forwards: 67
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
From: <sip:0123456789@sip.de>;tag=4fca928f
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
CSeq: 12726914 ACK
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, OPTIONS, PRACK, PUBLISH, REFER, REGISTER, SUBSCRIBE, UPDATE
Content-Length: 0


<------------->
[May 4 18:09:40] VERBOSE[2380] logger.c: --- (10 headers 0 lines) ---
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- SIP read from UDP://123.123.123.123:5060 --->
BYE sip:9876543210@192.168.2.103:5060 SIP/2.0
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK117c1ce84d01bc3d65fe75a11967cda2.0d21e48b
Max-Forwards: 67
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
From: <sip:0123456789@sip.de>;tag=4fca928f
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
Contact: <sip:LEITASP01@123.123.123.123:5060>
CSeq: 12726915 BYE
Content-Length: 0


<------------->
[May 4 18:09:40] VERBOSE[2380] logger.c: --- (9 headers 0 lines) ---
[May 4 18:09:40] VERBOSE[2380] logger.c: Sending to 123.123.123.123 : 5060 (NAT)
[May 4 18:09:40] VERBOSE[2380] logger.c:
<--- Transmitting (NAT) to 123.123.123.123:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 123.123.123.123:5060;branch=z9hG4bK117c1ce84d01bc3d65fe75a11967cda2.0d21e48b;received=123.123.123.123
From: <sip:0123456789@sip.de>;tag=4fca928f
To: 9876543210 <sip:9876543210@sip.de>;tag=as7e241820
Call-ID: 43002c1d4c7277882c231ea405fea393@sip.de
CSeq: 12726915 BYE
User-Agent: Asterisk PBX 1.6.0.26-FONCORE-r78
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


<------------>
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/302-00000066", "hangupcall,") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-00000066", "1?skiprg") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,4)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-00000066", "1?skipblkvm") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,7)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-00000066", "1?theend") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,9)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/302-00000066", "") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-00000066' in macro 'hangupcall'
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/302-00000066'
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/302-00000066' in macro 'dialout-trunk'
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (from-internal, 0123456789, 4) exited non-zero on 'SIP/302-00000066'
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [h@from-internal:1] Macro("SIP/302-00000066", "hangupcall") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/302-00000066", "1?skiprg") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,4)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/302-00000066", "1?skipblkvm") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,7)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/302-00000066", "1?theend") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Goto (macro-hangupcall,s,9)
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/302-00000066", "") in new stack
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/302-00000066' in macro 'hangupcall'
[May 4 18:09:40] VERBOSE[7812] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/302-00000066'
[May 4 18:09:40] VERBOSE[7812] logger.c: -- Stopped music on hold on SIP/302-00000066
[May 4 18:09:40] DEBUG[2350] pbx.c: FONALITY: This thread has already held the conlock, skip locking
[May 4 18:09:40] VERBOSE[2380] logger.c: Really destroying SIP dialog '43002c1d4c7277882c231ea405fea393@sip.de' Method: BYE

P.S. ситуация очень схожа с вот этой

[R3Xser]

Проблема решилась, заменой параметра canreinvite=update, в транке на canreinvite=no.
Всем спасибо.