[asterisk-users] Tips & best practices for asterisk troubleshooting & parsing logs

Thu Oct 27 09:26:39 CDT 2011

Capture pcap with tshark or tcpdump for the future analysis with wireshark.
Ngrep is also handy tool for captaring, say, INVITE. You can use grep like
this: tail -f /var/log/asterisk/full | egrep --color -w
'chan_sip.*SIP/911|pbx.*SIP/911'
Interesting technique from Astresk Cookbook, "Debugging dialplan with
Verbose()
http://ofps.oreilly.com/titles/9781449303822/DialplanFundamentals.html

2011/10/27 Sammy Govind <govoiper at gmail.com>

> It was a challenge to read through all the interesting experience you've
> shared over here. I don't know what others may be using for parsing the logs
> beautifully and make them usable. What I would recommend you at the very
> beginning ,since you mentioned using egrep, is figure out the Channel
> identifier string from the logs for a particular call. That's underlined
> below for you.
>
> [Oct 26 17:58:01] VERBOSE[14274] logger.c:     -- Executing [s at tc-maint:3]
>> System("*Local/s at tc-maint-2496,2*","/var/lib/asterisk/bin/schedtc.php 60
>> /var/spool/asterisk/outgoing 0") in new stack
>
>
> Once you Figure out this part use egrep tool and you'll end up seeing only
> the data related to this particular call.
>
> More advanced tool or techniques may involve setting up a central logging
> server where all the other servers deposit their logs and use monitoring
> tools like swatch, splunk, zabbix etc etc etc to parse the logs for you and
> generate alerts.
>
> I haven't came across any Asterisk-specific log parser utility so far.
> Honestly, I never needed one.
>
> On Thu, Oct 27, 2011 at 5:16 AM, Douglas Mortensen <
> doug at impalanetworks.com> wrote:
>
>> Hello all,
>>
>> I have been running asterisk systems since summer of 2008. I do not claim
>> to be an expert. But I have worked through many issues during this period. I
>> have setup & manage 5 systems, which serve 6 companies total (and of course
>> process calls for all of the people they do business with).
>>
>> I have always been happy with asterisk (well, obviously less happy during
>> the problem times... :-). And I continue to prefer to us it. However, if I
>> could name the one largest struggle that I have with asterisk, it is the
>> facilities that it provides for troubleshooting issues & parsing logs.
>>
>> I am hoping that someone on this mailing list can help me to realize how
>> ignorant I really am, and how much time I have wasted parsing, "grep"ping &
>> "less"ing logs manually. I am hoping that one of you can help me "see the
>> light". If so, I would be most grateful.
>>
>> Specifically, here are the challenges I encounter, which I would
>> desperately appreciate help with:
>>
>> Here's an example scenario:
>>
>> A customer calls me & says that a call just came in & some of their
>> wireless DECT phones (I know, trouble already.... :-) didn't ring, while
>> others did. I tell the customer that I'll start looking into the problem
>> immediately.
>>
>> I am using AsteriskNOW with asterisk 1.6. So I SSH into the system & cd to
>> /var/log/asterisk & start looking at the "full" log via "less". We have
>> configured the bulk of our system via FreePBX 2.9. Inbound calls are routed
>> first to a time condition which checks whether it is after hours. If it is
>> not afterhours, then are then routed to a queue, which rings all phones (4
>> wireless DECT phones on 1 DECT wireless server that registers the SIP
>> extensions on behalf of its 4 phones, and 4 more wireless DECT phones on
>> their own wireless server configured the same, and an ATA connected to a
>> paging amp that rings a loud speaker). From there, someone typically will
>> answer the call. Often times they then transfer the call to another
>> extension. However, sometimes no one answers the call, and it winds up going
>> to VM.
>>
>> From the logging aspect of asterisk, it has usually felt like I am
>> trudging through a swampy marsh trying to put the bits & pieces together.
>> The challenge I've seen is that the above scenario can actually consist of
>> multiple SIP calls w/ different legs. I *think* (but am not 100% sure) that
>> often times a call can be handed off from 1 asterisk process to another. The
>> result is that "grep"ping by the asterisk process ID shown after the VERBOSE
>> (or NOTICE or DEBUG section [see below]), I don't actually get to see the
>> full sequence of events in following  all logging that is relevant to that
>> phone call.
>>
>> [Oct 26 17:58:01] VERBOSE[14274] logger.c:     -- Executing [s at tc-maint:3]
>> System("Local/s at tc-maint-2496,2","/var/lib/asterisk/bin/schedtc.php 60
>> /var/spool/asterisk/outgoing 0") in new stack
>>
>> Then on a busy asterisk system, if I filter by the process id, the one
>> process that starts handling the call originally, may wind up immediately
>> taking on another totally unrelated call after handing the initial call off
>> to another process. If I am not extremely careful, I may wind up mistaking
>> the log lines for the 2nd call, as being a part of the 1st call, and then
>> I'm totally barking up the wrong tree.... :-)
>>
>> Another option I've tried is to enable SIP debugging. Generally, I do like
>> this. And one nice thing is that asterisk seems to usually add the SIP
>> "Date:" parameter with its SIP invites, etc. The result is that I can grep
>> the asterisk log like this `egrep -v ^"\[" full` (SIP debug lines don't have
>> the standard timestamp at the beginning) and then I'm only seeing the SIP
>> debugging, in a pretty clean output. Still, there can be a LOT of SIP
>> traffic going on, when I'm ringing 9 different extensions from a queue.
>> Trying to parse it all can make me go cross-eyed. :-) And doing so can take
>> a LONG time (30+ minutes). The SIP debug lines don't necessarily tell me
>> which call they correspond with. So if there are multiple calls going on or
>> ringing at the same time, this can really get hairy.
>>
>> So more or less, I think I've sort of established the type of experience I
>> have with parsing the asterisk logging in troubleshooting issues.
>> Ultimately, I usually can get to the bottom of it, but it literally probably
>> takes 45-60+ minutes of just parsing through the log files before I even get
>> to the point, of being able to answer some seemingly simple questions.
>>
>> Am I going about this the wrong way? Please say yes. Because this is
>> literally probably the only challenge (& sometimes frustration) I have with
>> asterisk. Are there [much] better ways to go about this?
>>
>> I did a bit of searching online, and it seems that some people have
>> attempted to create tools to parse & display the asterisk full log in a more
>> structured simplified manner. But my initial impression was that these were
>> more of "good ideas" that people started on, but they haven't really matured
>> to the point of being really helpful with these types of situations.
>>
>> A part of me just thinks that it just shouldn't be so hard to be able to
>> tell whether a certain extension did actually get a SIP INVITE sent to it,
>> or whether it responded, or to simply just follow the chain of the route
>> that a call took through asterisk prior to running into trouble (or just
>> where it ended up).
>>
>> It seems to me that there should be some powerful tool that does the hard
>> work of parsing the related log lines for us, so that we can just *quickly*
>> review its output & see the sequence of events to determine exactly what
>> happened.
>>
>> Only when we find out what happened, can we even start working on the
>> solution.
>>
>> If you have some insight into reviewing, filtering & parsing asterisk logs
>> in the process of troubleshooting issues, I would GREATLY appreciate it.
>>
>> What approach would you take? What are the best practices, tips & secrets
>> that you've developed?
>>
>> Thanks all!
>> -
>> Doug Mortensen
>> Network Consultant
>> Impala Networks Inc
>> CCNA, MCSA, Security+, A+
>> Linux+, Network+, Server+
>> A.A.S. Information Technology
>> .
>> www.impalanetworks.com
>> P: (505) 327-7300
>> F: (505) 327-7545
>>
>>
>> --
>> _____________________________________________________________________
>> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
>> New to Asterisk? Join us for a live introductory webinar every Thurs:
>>               http://www.asterisk.org/hello
>>
>> asterisk-users mailing list
>> To UNSUBSCRIBE or update options visit:
>>   http://lists.digium.com/mailman/listinfo/asterisk-users
>>
>
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
> New to Asterisk? Join us for a live introductory webinar every Thurs:
>               http://www.asterisk.org/hello
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>   http://lists.digium.com/mailman/listinfo/asterisk-users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20111027/89347c23/attachment-0001.htm>