4 Commits (1f5e6805bfb6c32371e53b375412514afc7a5b63)

Author	SHA1	Message	Date
George Joseph	ca3c22c5f1	Scope Tracing: A new facility for tracing scope enter/exit ... What's wrong with ast_debug? ast_debug is fine for general purpose debug output but it's not really geared for scope tracing since it doesn't present its output in a way that makes capturing and analyzing flow through Asterisk easy. How is scope tracing better? Scope tracing uses the same "cleanup" attribute that RAII_VAR uses to print messages to a separate "trace" log level. Even better, the messages are indented and unindented based on a thread-local call depth counter. When output to a separate log file, the output is uncluttered and easy to follow. Here's an example of the output. The leading timestamps and thread ids are removed and the output cut off at 68 columns for commit message restrictions but you get the idea. --> res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001 --> res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173 --> res_pjsip_session.c:3669 handle_incoming_response PJSIP/ --> chan_pjsip.c:3265 chan_pjsip_incoming_response_after --> chan_pjsip.c:3194 chan_pjsip_incoming_response P chan_pjsip.c:3245 chan_pjsip_incoming_respon <-- chan_pjsip.c:3194 chan_pjsip_incoming_response P <-- chan_pjsip.c:3265 chan_pjsip_incoming_response_after <-- res_pjsip_session.c:3669 handle_incoming_response PJSIP/ <-- res_pjsip_session.c:3661 handle_incoming_response PJSIP/1173 <-- res_pjsip_session.c:3680 handle_incoming PJSIP/1173-00000001 The messages with the "-->" or "<--" were produced by including the following at the top of each function: SCOPE_TRACE(1, "%s\n", ast_sip_session_get_name(session)); Scope isn't limited to functions any more than RAII_VAR is. You can also see entry and exit from "if", "for", "while", etc blocks. There is also an ast_trace() macro that doesn't track entry or exit but simply outputs a message to the trace log using the current indent level. The deepest message in the sample (chan_pjsip.c:3245) was used to indicate which "case" in a "select" was executed. How do you use it? More documentation is available in logger.h but here's an overview: * Configure with --enable-dev-mode. Like debug, scope tracing is #ifdef'd out if devmode isn't enabled. * Add a SCOPE_TRACE() call to the top of your function. * Set a logger channel in logger.conf to output the "trace" level. * Use the CLI (or cli.conf) to set a trace level similar to setting debug level... CLI> core set trace 2 res_pjsip.so Summary Of Changes: * Added LOG_TRACE logger level. Actually it occupies the slot formerly occupied by the now defunct "event" level. * Added core asterisk option "trace" similar to debug. Includes ability to specify global trace level in asterisk.conf and CLI commands to turn on/off and set levels. Levels can be set globally (probably not a good idea), or by module/source file. * Updated sample asterisk.conf and logger.conf. Tracing is disabled by default in both. * Added __ast_trace() to logger.c which keeps track of the indent level using TLS. It's #ifdef'd out if devmode isn't enabled. * Added ast_trace() and SCOPE_TRACE() macros to logger.h. These are all #ifdef'd out if devmode isn't enabled. Why not use gcc's -finstrument-functions capability? gcc's facility doesn't allow access to local data and doesn't operate on non-function scopes. Known Issues: The only know issue is that we currently don't know the line number where the scope exited. It's reported as the same place the scope was entered. There's probably a way to get around it but it might involve looking at the stack and doing an 'addr2line' to get the line number. Kind of like ast_backtrace() does. Not sure if it's worth it. Change-Id: Ic5ebb859883f9c10a08c5630802de33500cad027	5 years ago
George Joseph	201346fb7d	logger: Added logger_queue_limit to the configuration options. ... All log messages go to a queue serviced by a single thread which does all the IO. This setting controls how big that queue can get (and therefore how much memory is allocated) before new messages are discarded. The default is 1000. Should something go bezerk and log tons of messages in a tight loop, this will prevent memory escalation. When the limit is reached, a WARNING is logged to that effect and messages are discarded until the queue is empty again. At that time another WARNING will be logged with the count of discarded messages. There's no "low water mark" for this queue because the logger thread empties the entire queue and processes it in 1 batch before going back and waiting on the queue again. Implementing a low water mark would mean additional locking as the thread processes each message and it's not worth it. A "test" was added to test_logger.c but since the outcome is non-deterministic, it's really just a cli command, not a unit test. Change-Id: Ib4520c95e1ca5325dbf584c7989ce391649836d1	9 years ago
Matt Jordan	2d7a4a3357	main/logger: Add log formatters and JSON structured logs ... When Asterisk is part of a larger distributed system, log files are often gathered using tools (such as logstash) that prefer to consume information and have it rendered using other tools (such as Kibana) that prefer a structured format, e.g., JSON. This patch adds support for JSON formatted logs by adding support for an optional log format specifier in Asterisk's logging subsystem. By adding a format specifier of '[json]': full => [json]debug,verbose,notice,warning,error Log messages will be output to the 'full' channel in the following format: { "hostname": Hostname or name specified in asterisk.conf "timestamp": Date/Time "identifiers": { "lwp": Thread ID, "callid": Call Identifier } "logmsg": { "location": { "filename": Name of the file that generated the log statement "function": Function that generated the log statement "line": Line number that called the logging function } "level": Log level, e.g., DEBUG, VERBOSE, etc. "message": Actual text of the log message } } ASTERISK-25425 #close Change-Id: I8649bfedf3fb7bf3138008cc11565553209cc238	10 years ago
Matthew Jordan	fc0fecb476	configs: Move sample config files into a subdirectory of configs ... This moves all samples configs from configs/ to configs/samples. This allows for additional sets of sample configuration files to be added in the future. Review: https://reviewboard.asterisk.org/r/3804/ git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@418870 65c4cc65-6c06-0410-ace0-fbb531ad65f3	11 years ago