да не очерняю я!
Просто по описанию топикстартера астериск ведет себя нормально. И линксис гудок дает. Значит дело в "канале", его и нада дебажить. Гольдштейна в зубы и алга.

А по мне астериск себя ненормально ведет, почему-то после стирания и повторного прописывания в sip.conf телефон начинает звонить. При этом перезагрузка самого шлюза не помогает.

Все таки я думаю что это проблема не линксиса, а астериска, т.к. при входящем звонке судя по всему просто проверяется параметр Call-limit(на пире стоит 1), потом отвечает что все линии заняты и идет отбой по занято, при этом если смотреть tshark трафик в сторону линксиса при входящем звонке вообще не идет(т.е. отбивает не линксис). У меня стоит limitonpeers=yes, но даже если убираю с подвисшей линией ситуация не меняется, хотя вроде бы как должна, хотя бы в одну сторону звонок по логике должен проходить, т.к. call-limit должен ограничивать только исходящие звонки на сколько я понимаю.

Asterisk 1.4.18-attr-r1848

А как практический использовать ztmonitor в этом случая я че то не понял...

Вот опять сегодня такая же бодяга только на другой линии, шлюз также Linksys SPA2102, но уже совсем в другом месте, выкладываю дебаг(Входящий звонок на izhlen1_line2):

[Jul 13 09:25:11] DEBUG[722] pbx.c: Launching 'Macro'
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Executing [600581@sip-input:1] Macro("SIP/test_test1-b451a270",
"voipuser|on|izhlen1_line2"
) in new stack
[Jul 13 09:25:11] DEBUG[722] pbx.c: Expression result is '1'
[Jul 13 09:25:11] DEBUG[722] pbx.c: Launching 'GotoIf'
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Executing [s@macro-voipuser:1] GotoIf("SIP/test_test1-b451a270",
"1?:switchoffinput|1|1") i
n new stack
[Jul 13 09:25:11] DEBUG[722] pbx.c: Not taking any branch
[Jul 13 09:25:11] DEBUG[722] app_macro.c: Executed application: GotoIf
[Jul 13 09:25:11] DEBUG[722] pbx.c: Launching 'Dial'
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Executing [s@macro-voipuser:2] Dial("SIP/test_test1-b451a270", "SIP/izhlen1_line2")
in new
stack
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Asked to create a SIP channel with formats: 0x2 (gsm)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Our T38 capability (3872)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Setting NAT on RTP to Off
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Setting NAT on UDPTL to Off
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** Our native formats are 0x100 (g729)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** Joint capabilities are 0x0 (nothing)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** Our capabilities are 0x10c (ulaw|alaw|g729)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** Our preferred formats from the incoming channel are 0x2 (gsm)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: This channel will not be able to handle video.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable MACRO_DEPTH.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable ARG2.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable ARG1.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable MACRO_PRIORITY.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable MACRO_CONTEXT.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable MACRO_EXTEN.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable SIPCALLID.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable SIPUSERAGENT.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable SIPDOMAIN.
[Jul 13 09:25:11] DEBUG[722] channel.c: Not copying variable SIPURI.
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Outgoing Call for izhlen1_line2
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Updating call counter for outgoing call
[Jul 13 09:25:11] ERROR[722] chan_sip.c: Call to peer 'izhlen1_line2' rejected due to usage limit of 1
[Jul 13 09:25:11] DEBUG[722] app_dial.c: ast call on peer returned -1
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Couldn't call izhlen1_line2
[Jul 13 09:25:11] DEBUG[722] channel.c: Hanging up channel 'SIP/izhlen1_line2-0855d850'
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Hangup call SIP/izhlen1_line2-0855d850, SIP callid
10d3db2479f42b92683d1cbf38c569af@172.18.0.2)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Hanging up channel in state Down (not UP)
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] VERBOSE[722] logger.c: Scheduling destruction of SIP dialog '10d3db2479f42b92683d1cbf38c569af@172.18.0.2' in 6400
ms (Met
hod: INVITE)
[Jul 13 09:25:11] DEBUG[722] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2-0855d850
[Jul 13 09:25:11] DEBUG[722] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2
[Jul 13 09:25:11] DEBUG[722] cdr_pgsql.c: cdr_pgsql: inserting a CDR record.
[Jul 13 09:25:11] DEBUG[722] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO astboxcdr
(calldate,clid,src,dst,dcontext,channel,d
stchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2009-07-13
09:25:11','','','s','s
ip-input-cisco', 'SIP/izhlen1_line2-0855d850','','','',0,0,'NO ANSWER',3,'','1247459111.997085','')
[Jul 13 09:25:11] VERBOSE[722] logger.c: == Everyone is busy/congested at this time (0:0/0/0)
[Jul 13 09:25:11] DEBUG[722] rtp.c: Channel '<unspecified>' has no RTP, not doing anything
[Jul 13 09:25:11] DEBUG[722] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
[Jul 13 09:25:11] DEBUG[722] app_macro.c: Executed application: Dial
[Jul 13 09:25:11] DEBUG[722] pbx.c: Expression result is '0'
[Jul 13 09:25:11] DEBUG[722] pbx.c: Launching 'GotoIf'
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Executing [s@macro-voipuser:3] GotoIf("SIP/test_test1-b451a270", "0?999:") in new
stack
[Jul 13 09:25:11] DEBUG[722] pbx.c: Not taking any branch
[Jul 13 09:25:11] DEBUG[722] app_macro.c: Executed application: GotoIf
[Jul 13 09:25:11] DEBUG[722] pbx.c: Launching 'Hangup'
[Jul 13 09:25:11] VERBOSE[722] logger.c: -- Executing [s@macro-voipuser:4] Hangup("SIP/test_test1-b451a270", "") in new stack
[Jul 13 09:25:11] DEBUG[722] app_macro.c: Spawn extension (macro-voipuser,s,4) exited non-zero on 'SIP/test_test1-b451a270' in
macro 'voipu
ser'
[Jul 13 09:25:11] DEBUG[722] pbx.c: Spawn extension (macro-voipuser,s,4) exited non-zero on 'SIP/test_test1-b451a270'
[Jul 13 09:25:11] VERBOSE[722] logger.c: == Spawn extension (macro-voipuser, s, 4) exited non-zero on 'SIP/test_test1-b451a270'
[Jul 13 09:25:11] DEBUG[722] channel.c: Soft-Hanging up channel 'SIP/test_test1-b451a270'
[Jul 13 09:25:11] DEBUG[722] channel.c: Hanging up channel 'SIP/test_test1-b451a270'
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Hangup call SIP/test_test1-b451a270, SIP callid
ODA5NjI3ZGNhNTRjZmFhOGM0YmI1Y2MxNTAxZTI3OWQ.)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: update_call_counter(test_test1) - decrement call limit counter on hangup
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Updating call counter for incoming call
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Call from peer 'test_test1' removed from call limit 2
[Jul 13 09:25:11] DEBUG[722] devicestate.c: Notification of state change to be queued on device/channel SIP/test_test1
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: Hanging up channel in state Ring (not UP)
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: AST hangup cause 16 (no match found in SIP)
[Jul 13 09:25:11] DEBUG[722] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0
[Jul 13 09:25:11] DEBUG[722] devicestate.c: Notification of state change to be queued on device/channel SIP/test_test1-b451a270
[Jul 13 09:25:11] DEBUG[722] devicestate.c: Notification of state change to be queued on device/channel SIP/test_test1
[Jul 13 09:25:11] DEBUG[722] cdr_pgsql.c: cdr_pgsql: inserting a CDR record.

В sip show channels и core shoq channels его нет, выкладывать вывод не буду, там куча всякого, но этой линии нет, в zap show channels входящего номера к izhlen1_line2 нет(600581), звоню я SIP->SIP, так что здесь даже не задействован ZAP интерфейс, как видите отбивает по причине превышения линий. sip debug ни че не выводит потому что посылки sip пакетов соответственно не происходит.

Вот результат после того как я убрал пользователя из sip.conf и добавил обратно, звонок проходит нормально:

[Jul 13 10:04:20] DEBUG[1982] pbx.c: Launching 'Macro'
[Jul 13 10:04:20] VERBOSE[1982] logger.c: -- Executing [600581@sip-input:1] Macro("SIP/test_test1-b61548b8", "voipuser|on|izhlen1_line2
|goelse") in new stack
[Jul 13 10:04:20] DEBUG[1982] pbx.c: Expression result is '1'
[Jul 13 10:04:20] DEBUG[1982] pbx.c: Launching 'GotoIf'
[Jul 13 10:04:20] VERBOSE[1982] logger.c: -- Executing [s@macro-voipuser:1] GotoIf("SIP/test_test1-b61548b8", "1?:switchoffinput|1|1")
in new stack
[Jul 13 10:04:20] DEBUG[1982] pbx.c: Not taking any branch
[Jul 13 10:04:20] DEBUG[1982] app_macro.c: Executed application: GotoIf
[Jul 13 10:04:20] DEBUG[1982] pbx.c: Launching 'Dial'
[Jul 13 10:04:20] VERBOSE[1982] logger.c: -- Executing [s@macro-voipuser:2] Dial("SIP/test_test1-b61548b8", "SIP/izhlen1_line2") in new
stack
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Asked to create a SIP channel with formats: 0x2 (gsm)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Our T38 capability (3872)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Setting NAT on RTP to Off
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Setting NAT on UDPTL to Off
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** Our native formats are 0x100 (g729)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** Joint capabilities are 0x0 (nothing)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** Our capabilities are 0x10c (ulaw|alaw|g729)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** Our preferred formats from the incoming channel are 0x2 (gsm)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: This channel will not be able to handle video.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable MACRO_DEPTH.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable ARG3.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable ARG2.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable ARG1.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable MACRO_PRIORITY.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable MACRO_CONTEXT.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable MACRO_EXTEN.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable SIPCALLID.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable SIPUSERAGENT.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable SIPDOMAIN.
[Jul 13 10:04:20] DEBUG[1982] channel.c: Not copying variable SIPURI.
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Outgoing Call for izhlen1_line2
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Updating call counter for outgoing call
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Call to peer 'izhlen1_line2' is 1 out of 1
[Jul 13 10:04:20] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Our T38 capability (3872), joint T38 capability (3872)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: ** Our capability: 0x10c (ulaw|alaw|g729) Video flag: False
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: ** Our prefcodec: 0x2 (gsm)
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Audio is at 172.18.0.2 port 14680
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Adding codec 0x100 (g729) to SDP
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Adding codec 0x4 (ulaw) to SDP
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Adding codec 0x8 (alaw) to SDP
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: -- Done with adding codecs to SDP
[Jul 13 10:04:20] DEBUG[1982] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=216)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Done building SDP. Settling with this capability: 0x10c (ulaw|alaw|g729)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 0: INVITE sip:izhlen1_line2@172.20.139.105:5061 SIP/2.0 (52)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 1: Via: SIP/2.0/UDP 172.18.0.2:5060;branch=z9hG4bK0adae56d;rport (61)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 2: From: "3412600502" <sip:3412600502@172.18.0.2>;tag=as5abbf881 (61)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 3: To: <sip:izhlen1_line2@172.20.139.105:5061> (43)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 4: Contact: <sip:3412600502@172.18.0.2> (36)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 5: Call-ID: 4f154dd6684e4e214a8453a77c7fb41c@172.18.0.2 (52)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 8: Max-Forwards: 70 (16)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 9: Date: Mon, 13 Jul 2009 05:04:20 GMT (35)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 11: Supported: replaces (19)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 12: Content-Type: application/sdp (29)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 13: Content-Length: 305 (19)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Header 14: (0)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: v=0 (3)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: o=root 6479 6479 IN IP4 172.18.0.2 (34)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: s=session (9)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: c=IN IP4 172.18.0.2 (19)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: t=0 0 (5)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: m=audio 14680 RTP/AVP 18 0 8 101 (32)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=fmtp:18 annexb=no (19)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=fmtp:101 0-16 (15)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=silenceSupp:off - - - - (25)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=ptime:20 (10)
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: Line: a=sendrecv (10)
[Jul 13 10:04:20] VERBOSE[1982] logger.c: Reliably Transmitting (no NAT) to 172.20.139.105:5061:
[Jul 13 10:04:20] DEBUG[1982] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0
[Jul 13 10:04:20] VERBOSE[1982] logger.c: -- Called izhlen1_line2
[Jul 13 10:04:20] DEBUG[1982] channel.c: Set channel SIP/izhlen1_line2-083687d0 to read format slin
[Jul 13 10:04:20] DEBUG[1982] channel.c: Set channel SIP/test_test1-b61548b8 to write format slin
[Jul 13 10:04:20] DEBUG[1982] channel.c: Set channel SIP/test_test1-b61548b8 to read format slin
[Jul 13 10:04:20] DEBUG[1982] channel.c: Set channel SIP/izhlen1_line2-083687d0 to write format slin
[Jul 13 10:04:20] VERBOSE[1982] logger.c: -- SIP/izhlen1_line2-083687d0 is ringing
[Jul 13 10:04:24] DEBUG[1982] rtp.c: Channel '<unspecified>' has no RTP, not doing anything
[Jul 13 10:04:24] DEBUG[1982] channel.c: Hanging up channel 'SIP/izhlen1_line2-083687d0'
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Hangup call SIP/izhlen1_line2-083687d0, SIP callid 4f154dd6684e4e214a8453a77c7fb41c@172.18.0.2)
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: update_call_counter(izhlen1_line2) - decrement call limit counter on hangup
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Updating call counter for outgoing call
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Call to peer 'izhlen1_line2' removed from call limit 1
[Jul 13 10:04:24] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Hanging up channel in state Ringing (not UP)
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] DEBUG[1982] sched.c: Attempted to delete nonexistent schedule entry 0!
[Jul 13 10:04:24] VERBOSE[1982] logger.c: Scheduling destruction of SIP dialog '4f154dd6684e4e214a8453a77c7fb41c@172.18.0.2' in 6400 ms (Me
thod: INVITE)
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Acked pending invite 102
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Stopping retransmission on '4f154dd6684e4e214a8453a77c7fb41c@172.18.0.2' of Request 102: Match No
t Found
[Jul 13 10:04:24] VERBOSE[1982] logger.c: Reliably Transmitting (no NAT) to 172.20.139.105:5061:
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #0
[Jul 13 10:04:24] VERBOSE[1982] logger.c: Scheduling destruction of SIP dialog '4f154dd6684e4e214a8453a77c7fb41c@172.18.0.2' in 6400 ms (Me
thod: INVITE)
[Jul 13 10:04:24] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2-083687d0
[Jul 13 10:04:24] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/izhlen1_line2
[Jul 13 10:04:24] DEBUG[1982] cdr_pgsql.c: cdr_pgsql: inserting a CDR record.
[Jul 13 10:04:24] DEBUG[1982] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO astboxcdr (calldate,clid,src,dst,dcontext,channel,
dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2009-07-13 10:04:20','3412600502
','3412600502','s','sip-input-cisco', 'SIP/izhlen1_line2-083687d0','','','',4,0,'NO ANSWER',3,'','1247461460.998064','')
[Jul 13 10:04:24] DEBUG[1982] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[Jul 13 10:04:24] DEBUG[1982] app_macro.c: Spawn extension (macro-voipuser,s,2) exited non-zero on 'SIP/test_test1-b61548b8' in macro 'voip
user'
[Jul 13 10:04:24] DEBUG[1982] pbx.c: Spawn extension (macro-voipuser,s,2) exited non-zero on 'SIP/test_test1-b61548b8'
[Jul 13 10:04:24] VERBOSE[1982] logger.c: == Spawn extension (macro-voipuser, s, 2) exited non-zero on 'SIP/test_test1-b61548b8'
[Jul 13 10:04:24] DEBUG[1982] channel.c: Soft-Hanging up channel 'SIP/test_test1-b61548b8'
[Jul 13 10:04:24] DEBUG[1982] channel.c: Hanging up channel 'SIP/test_test1-b61548b8'
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Hangup call SIP/test_test1-b61548b8, SIP callid NjUzYWIwNjI1NGFhOTEyZjAyZTdjOWY2NzM4NTkzMzk.)
[Jul 13 10:04:24] DEBUG[1982] chan_sip.c: Hanging up channel in state Ring (not UP)
[Jul 13 10:04:24] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/test_test1-b61548b8
[Jul 13 10:04:24] DEBUG[1982] devicestate.c: Notification of state change to be queued on device/channel SIP/test_test1
[Jul 13 10:04:24] DEBUG[1982] cdr_pgsql.c: cdr_pgsql: inserting a CDR record.
[Jul 13 10:04:24] DEBUG[1982] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO astboxcdr (calldate,clid,src,dst,dcontext,channel,
dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2009-07-13 10:04:20','3412600502
','3412600502','600581','sip-input', 'SIP/test_test1-b61548b8','SIP/izhlen1_line2-083687d0','Dial','SIP/izhlen1_line2',4,0,'NO ANSWER',3,''
,'1247461460.998063','')

Да и в HANGUPCAUSE было 0.