Asterisk SIP Debugging

Trying to learn about asterisk SIP debugging. Is there a somewhat definitive guide, wiki, or howto for debugging and understanding what the info in /var/log/asterisk/full actually means? I know a lot of the gurus will ask the user to post the asterisk log file and they seem to be able to pick issues out pretty easily. I’m not trying to be lazy…figured the more I know about debugging the easier it will be to troubleshoot. :slight_smile:

The “full” log is the list of every action the server took, marked with INFO through OMMYGAWDWEAREALLGOINGTODIE (or whatever the worst error is).

Reading the log is pretty straightforward. For example:

[2016-05-20 16:35:16] NOTICE[4636] chan_sip.c: Peer ‘154’ is now Reachable. (16ms / 2000ms)
[2016-05-20 16:35:31] VERBOSE[4636][C-00000000] netsock2.c: Using SIP RTP TOS bits 184
[2016-05-20 16:35:31] VERBOSE[4636][C-00000000] netsock2.c: Using SIP RTP CoS mark 5
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [7022867825@from-internal:1] Macro(“SIP/201-00000000”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/201-00000000”, “TOUCH_MONITOR=146378373 1.0”) in new stack
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/201-00000000”, “AMPUSER=201”) in new st ack
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:3] GotoIf(“SIP/201-00000000”, “0?report”) in new stack
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/201-00000000”, “1?Set(REALCALLERIDNU M=201)”) in new stack
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/201-00000000”, “AMPUSER=201”) in new stack

The first line is a notice from “chan_sip”
[2016-05-20 16:35:16] NOTICE[4636] chan_sip.c: Peer ‘154’ is now Reachable. (16ms / 2000ms)

It tells us that one of the Peers what wasn’t previous there is now reachable and the SIP Transit time is 16ms.

Another line:
[2016-05-20 16:35:31] VERBOSE[4714][C-00000000] pbx.c: Executing [s@macro-user-callerid:4] ExecIf(“SIP/201-00000000”, “1?Set(REALCALLERIDNUM=201)”) in new stack

This is a Verbose message from the PBX code. We are going to run the fourth line in the ‘s’ part of the context “macro-user-callerid”. This particular line conditionally sets “REALCALLERIDNUM” to 201 because the test for “SIP/201-00000000” is 1 (or TRUE).

Basically, it just walks through how the server decided what to do. For example, if the poster of the original log file was asking "Why is my caller ID getting set to “201”, we would point him at this code and say “Because it’s supposed to be at this point in the process.”

That’s kind of the ‘101’ version. As you get more and more used to looking at the logs, you start to spot things that are out of the ordinary, and can easily see that there are ERRORS and WARNINGS that are flags to “Look Here!”.

The big thing that the full log does for us is to tell us what contexts are being executed and what the various values are (especially for conditionals). It’s not particularly obtuse. Every line is “time - type - program - context - message”. It just takes a little practice to get to where you can read through it quickly.

Thanks Dave!! Those few tidbits are a HUGE help! I know I can try and google “asterisk sip debugging” but sometimes it makes sense to actually ask a question :wink: