Summary:	ASTERISK-01614: [patch] Improvement of chan_sip.c debugging
Reporter:	khb (khb)	Labels:
Date Opened:	2004-05-14 00:14:40	Date Closed:	2008-01-15 14:58:37.000-0600
Priority:	Minor	Regression?	No
Status:	Closed/Complete	Components:	Core/General
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) chan_sip.patch_1.txt ( 1) chan_sip.patch_2.txt ( 2) chan_sip.patch_2-a.txt ( 3) chan_sip.patch_3.txt ( 4) new_sip_patch_1.txt ( 5) new_sip_patch_2.txt ( 6) new_sip_patch.2again.txt ( 7) sip.patch_2-a.txt
Description:	In the process of catching up with all the new patches to this module I noticed too many (IMHO) debug messages in my logfiles with no debugging turned on, so I looked a little closer into the new SIP debugging modes. While the extra features in SIP debug are great ideas, I had concerns about implementation and so I created the following patches for your consideration. I ma running them now. Patch 1: =========== In sip_do_debug_peer/ip: You are checking for the same CLI command line syntax across multiple procedures, whereas you should make it orthogonal and only check for syntax in the first and then implement the function in the subsequent procedures without having to recheck. Makes code easier to maintain. Example: In sip_do_debug_ip and sip_do_debug_peer  you are checking for the number of arguments and fail if it isn't 4, although that has already been checked before in sip_do_debug. Fixed: The keywords "peer" and "ip" were case sensitive, whereas the rest of the command line seems not. Patch 2: ========= When the driver is running in production mode, ie. when no debug is enabled, you want it to do as little extra work as possible. But the new debug code calls at least two levels of procedures everytime the test (on IP address/peer name) is performed, even when we have already tested before. This patch reduces the overhead somewhat by inlining function calls and eliminating duplication.  Perhaps the optimizer does this internally too, but it's good to not rely on that with efficient coding. Patch 3: ========== In various places debug messages to the console or logfiles are produced based on the setting of the sipdebug flag or the new ip/peer debug matching.  Since "debug" is used to enable them, I would expect to find them in the 'debug' log and not in the verbose log.  This patch changes that behavior for some cases. What are the design ideas for all the current levels of output? How should they be used?  Guideline would be nice. With so many levels of logging output that can be generated. this needs to be streamlined a bit. LAST NOT LEAST, ================= NO Patch yet, just question: In sip_do_debug_peer you are freeing a peer if temponly is set.  Don't you have to remove the peer from the list, ie unlinking the chain pointers first? I am not up much on this temponly stuff right now, but since you are finding the peer in the chain, you should close the chain after removing the link.  Anyone losing peers this way?  Perhaps this temponly stuff doesn't happen often? ****** ADDITIONAL INFORMATION ****** 3 patches attached Please review.
Comments:	By: Olle Johansson (oej) 2004-05-14 11:49:35 Temponly peers are not in the linked list, they are created by find_peer from a database. Database peers are not kept in-memory. By: Olle Johansson (oej) 2004-05-14 11:55:16 The debug flag is the -d switch on start of asterisk. Sipdebug flag is if you want additional debugging for SIP, beyond the -d level. I don't agree that all debug level messsages should be combined with a requirement for SIP debugging. SIP Debugging adds packet trace and protocol internals. Asterisk debugging is cross-channel debug level messages. So asterisk -vvvv: A lot of verbosity asterisk -d: Debugging of all call setup/teardown within Asterisk asterisk -d: and CLI sip debug: Detailed SIP Protocol debugging (packets) Not very clear, I know... Maybe someone else can clarify. By: khb (khb) 2004-05-14 13:05:41 Thanks, that's a good start.  That's what I am really looking for, clarification and documentation. I don't necessarily expect all debug to be turned on or off with the same flag either, but in absence of documented rules and enforcement, when you don't know the levels of impact of the information, you would want to turn all of them on at once to not miss some useful information, and then you might just have only one flag. So whith that in mind we can review the existing messages and make sure they follow such a model as you stated. By: Mark Spencer (markster) 2004-05-15 19:13:49 the use of LOG_DEBUG doesn't really give us the same visibility in general that verbose does.  Since we've specifically asked for sip debug, some subjective amount of debugging should be printed as verbose to accompany the raw traces.  Therefore, I don't think patch3 is necessary.  In patch1, is it safe to call gethostbyname with the IP and port number?  If you're going to modify it by 0'ing out the : character, then you need to operate on a copy not the original. Other than that first one looks pretty good.   #2 seems a bit complex for what it is (apparently) intended to do.  Why not just inline the functions and be done with it? By: khb (khb) 2004-05-15 22:34:17 yes, it's good to let patches sit for a while to look at them again. I thought I didn't want to zero out in the source as well, but forgot to cut off the port before sending to ghbyn.  The patch will probably seg fault or something. I am attaching a revision with memcopy. I don't feel very strong about patch 3 either, it was just an attempt to streamline a bit, it should be reserved to a separate review and organization of all log messages in the module and in other modules. Since, I had a look at some other modules as well.  I think also there is a bug in the logger code when a verbose message is not finished in one call (no terminating  \n) but I couldn't get it right in the time spent. edited on: 05-15-04 21:32 By: Mark Spencer (markster) 2004-05-16 02:06:05 I don't see a new attachment... By: khb (khb) 2004-05-16 21:03:34 Oops,  I don't know where my mind was.  one moment.... By: khb (khb) 2004-05-16 21:10:59 hmm, for some reason mantis mangles the filename to a.txt it should have been chan_sip.patch_2-a.txt, replacement for patch 2 By: Mark Spencer (markster) 2004-05-16 23:38:38 Doesn't apply...  gets two fails, can you update it for latest cvs? Also, don't bother with the if (option_debug || sipdebug) stuff..  just leave it option_debug... By: khb (khb) 2004-05-17 17:36:03 new patches uploaded By: Mark Spencer (markster) 2004-05-21 01:56:27 Still doesn't apply....  Are you sure you're diffing against asterisk cvs head? By: khb (khb) 2004-05-21 14:01:02 yes. But that was last week. new_sip_patch_1.txt still works ok with cvs this morning. new_sip_patch_2again.txt has been updated. (The capabilities patch caused the conflicts.) By: Mark Spencer (markster) 2004-05-31 12:26:45 Hrm, still doesn't apply..  Lets try once more and I"ll try to get this in as soon as you can get me an updated patch!  sorry for the delay. By: Mark Spencer (markster) 2004-06-18 10:08:05 I updated the patch for latest CVS and applied. By: Digium Subversion (svnbot) 2008-01-15 14:58:37.000-0600 Repository: asterisk Revision: 3240 U   trunk/channels/chan_sip.c ------------------------------------------------------------------------ r3240 | markster | 2008-01-15 14:58:37 -0600 (Tue, 15 Jan 2008) | 2 lines Debugging cleanups (bug ASTERISK-1614) ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=3240