[asterisk-users] How to tell if a dropped call is my fault

2010-06-21 Thread Douglas Mortensen
I just had a user report that they called out to someone on a cell phone this 
morning, and after a short conversation, the call was dropped/lost. The person 
on the cell phone says that this is very rare, and would not suspect the 
dropped/lost call to be on their side. I have looked at the asterisk/full log 
as thoroughly as I can, and have pasted the lines which seem relevant to that 
call below. From what I can tell, only the last 26 lines of the log really 
pertain to the actual call being connected, then hung up. The preceding lines 
are just setting the caller id, and other related call-setup logging.

Is it common to have a dropped call being caused by asterisk? How would it show 
up in the log? The only possible thing I can see in the logs, is the exited 
non-zero, which I've pasted here:

[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Dialing '15053203372'
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Deferring dialing...
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Called g1/15053203372
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Sent deferred digit string: 
T15053203372w
[Jun 21 08:53:32] VERBOSE[21559] logger.c: -- Zap/25-1 answered 
SIP/611-b7b9ae38
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Hungup 'Zap/25-1'
[Jun 21 08:53:56] VERBOSE[21559] logger.c:   == Spawn extension 
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' in macro 
'dialout-trunk'
[Jun 21 08:53:56] VERBOSE[21559] logger.c:   == Spawn extension 
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38'

My experience is that with most programs, if they exit with a non-zero status, 
that means that there was some kind of error. If that is the case, I cannot 
tell what that would have been, based on the log.

As far a the log/verbose level is concerned, asterisk was started as 
/usr/sbin/asterisk -vvvg

Here's the complete asterisk/full as it pertains to the given time period. I do 
think that there are a few lines below that are relating to a different call, 
which we're not concerned with.

[Jun 21 08:53:28] VERBOSE[22157] logger.c:  Extension Changed 611[ext-local] 
new state InUse for Notify User 610
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[5053203...@from-internal-ntc-custom:1] Macro(SIP/611-b7b9ae38, 
user-callerid|SKIPTTL|) in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:1] Set(SIP/611-b7b9ae38, AMPUSER=611) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:2] GotoIf(SIP/611-b7b9ae38, 0?report) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:3] ExecIf(SIP/611-b7b9ae38, 
1|Set|REALCALLERIDNUM=611) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:4] Set(SIP/611-b7b9ae38, AMPUSER=611) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:5] Set(SIP/611-b7b9ae38, AMPUSERCIDNAME=Kurt) in 
new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:6] GotoIf(SIP/611-b7b9ae38, 0?report) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:7] Set(SIP/611-b7b9ae38, AMPUSERCID=611) in new 
stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:8] Set(SIP/611-b7b9ae38, CALLERID(all)=Kurt 
611) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:9] Set(SIP/611-b7b9ae38, REALCALLERIDNUM=611) in 
new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:10] ExecIf(SIP/611-b7b9ae38, 
0|Set|CHANNEL(language)=) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:11] GotoIf(SIP/611-b7b9ae38, 1?continue) in new 
stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Goto 
(macro-user-callerid,s,20)
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing 
[...@macro-user-callerid:20] NoOp(SIP/611-b7b9ae38, Using CallerID Kurt 
611) in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Noop
[Jun 21 

Re: [asterisk-users] How to tell if a dropped call is my fault

2010-06-21 Thread dotnetdub
On Monday, June 21, 2010, Douglas Mortensen d...@impalanetworks.com wrote:
 I just had a user report that they called out to someone on a cell phone this 
 morning, and after a short conversation, the call was dropped/lost. The 
 person on the cell phone says that this is very rare.


Snip


I really would suspect the cell phone.








/611-b7b9ae38' in macro 'dialout-trunk'
 [Jun 21 08:53:56] VERBOSE[21559] logger.c:   == Spawn extension 
 (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38'

 My experience is that with most programs, if they exit with a non-zero 
 status, that means that there was some kind of error. If that is the case, I 
 cannot tell what that would have been, based on the log.

 As far a the log/verbose level is concerned, asterisk was started as 
 /usr/sbin/asterisk -vvvg

 Here's the complete asterisk/full as it pertains to the given time period. I 
 do think that there are a few lines below that are relating to a different 
 call, which we're not concerned with.

 [Jun 21 08:53:28] VERBOSE[22157] logger.c:  Extension Changed 611[ext-local] 
 new state InUse for Notify User 610
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [5053203...@from-internal-ntc-custom:1] Macro(SIP/611-b7b9ae38, 
 user-callerid|SKIPTTL|) in new stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:1] Set(SIP/611-b7b9ae38, AMPUSER=611) in new 
 stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:2] GotoIf(SIP/611-b7b9ae38, 0?report) in new 
 stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:3] ExecIf(SIP/611-b7b9ae38, 
 1|Set|REALCALLERIDNUM=611) in new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:4] Set(SIP/611-b7b9ae38, AMPUSER=611) in new 
 stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:5] Set(SIP/611-b7b9ae38, AMPUSERCIDNAME=Kurt) in 
 new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:6] GotoIf(SIP/611-b7b9ae38, 0?report) in new 
 stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:7] Set(SIP/611-b7b9ae38, AMPUSERCID=611) in new 
 stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:8] Set(SIP/611-b7b9ae38, CALLERID(all)=Kurt 
 611) in new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:9] Set(SIP/611-b7b9ae38, REALCALLERIDNUM=611) in 
 new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:10] ExecIf(SIP/611-b7b9ae38, 
 0|Set|CHANNEL(language)=) in new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:11] GotoIf(SIP/611-b7b9ae38, 1?continue) in new 
 stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Goto 
 (macro-user-callerid,s,20)
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-user-callerid:20] NoOp(SIP/611-b7b9ae38, Using CallerID Kurt 
 611) in new stack
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Noop
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [5053203...@from-internal-ntc-custom:2] Set(SIP/611-b7b9ae38, _NODEST=) 
 in new stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [5053203...@from-internal-ntc-custom:3] Macro(SIP/611-b7b9ae38, 
 record-enable|611|OUT|) in new stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-record-enable:1] GotoIf(SIP/611-b7b9ae38, 1?check) in new stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Goto 
 (macro-record-enable,s,4)
 [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Executing 
 [...@macro-record-enable:4] AGI(SIP/611-b7b9ae38, 
 recordingcheck|20100621-085328|1277132008.6419) in new stack
 [Jun 21 08:53:28] VERBOSE[21559] logger.c:     -- Launched AGI Script 
 /var/lib/asterisk/agi-bin/recordingcheck
 [Jun 21 08:53:29] VERBOSE[21559] logger.c: