Logging

From VoIPmonitor.org
Jump to navigation Jump to search

Messages from GNU GPL sniffer sensor service

Voipmonitor by default uses 'daemon' facility of a syslog to store status messages.

Default location

debian/ubuntu

it is stored to /var/log/syslog

on centos/rh

/var/log/messages

Messages file Change

change log file

You can find useful to store status info from voipmonitor to different file: For rsyslog use this in /etc/rsyslog.conf

if $programname == 'voipmonitor' and $syslogseverity <= '7' then /var/log/voipmon.log
& ~

disable storing of logs for voipmonitor binary

if ($programname == 'voipmonitor') and ($syslogseverity <= '7') then {stop}

Status line details

calls

calls[14527,r:5241][14428,r:5350] Absolute calls counter. This counts structs in memory for INVITEs(call-ids) and r:for REGISTERs. in Second bracket is amount of structs before final packets processing.

PS

PS[C:29/-34(23/23) r:-/- S:2017/1802 SR:- SM:0 R:327512/329972 A:269886]

call/packet counters per second.

C : number of calls / second, X/-Y: X is number of newly created structs for calls, Y is amount of removed structs in the brackets is count of calls before and after filtering in the store function
r : number of registers /second, X/-Y X is number of newly created structs for registers, Y is amount of removed structs
S : X/Y - X is number of valid SIP packets / second on sip ports. Y is number of all packets on sip ports. 
SR: number of SIP register packets,  
SM: number of SIP messages packets,  
R : number of RTP packets / second of registered calls by voipmonitor per second.
A : all packets per second

SQLq/SQLf

SQLq[C1:246 R1:20 i99_1:38 /0.069s / 2q/s / 279i/s] - (i99_1:38 / 0.069s / 2q/s /279i/s]

C=CDR_queue 
M=Message_queue
R=Register_queue
L=LiveSniffer_queue
Cl=Cleanspool queue
i99_1:38 - others = queue size of a sip responses/uas
O99_1:39 - others viz above
2q/s     - count of queries for store operations per sec.
279i/s   - count of inserts per second

SQLf reported when query_cache enabled in sensors config

heap[A|B|C]

A: number of % of used heap memory.If 100 voipmonitor is not able to process packets in realtime due to CPU or I/O. 
B: number of % used memory in packetbuffer. 
C: % used for async write buffers (if 100% I/O is blocking and heap will grow and than ring buffer will get full and then packet loss will occur)

comp

comp[23]

Compression ratio for heap (when packetbuffer_compres enabled)

[Mb/s]

total network throughput

t0i_dag0_CPU

[2614.7Mb/s;24.8%/19.6%] Throughput thru this 'dag0' interface 2614.7Mb/s Usage of reading thread from this interface 24.8% Usage of thread making blocksof packets for processing with t0 thread 19.6% (this stat is printed per sniffing interface where packets were visible)

t0CPU

This is %CPU utilization for thread 0. Thread 0 is process reading from kernel ring buffer. Once it is over 90% it means that the current setup is hitting limit processing packets from network card. Please write to support@voipmonitor.org if you hit this limit.

t1CPU

This is %CPU utilization for thread 1. Thread 1 is process reading packets from thread 0, adding it to the buffer and compress it (if enabled).

tarQ

number of files in a queue

tarB

MBs in tar buffer

tarCPU

tarCPU[3.3|4.8|9.6|5.5|1.6|3.2|1.4|2.2%]

are threads used for taring - its consumption in %

t2CPU

t2CPU[pb:43.8/defrag:17.5/d19.5/s12.9/e5.4/c6.9/g10.1/r1 1.7/o0.3/rm:17.9/rh:31.9/rh:32.9/rd:8.2/rd:9.1/rd:8.5/rd:9.2/rd:8.5/rd:8.8/rd:8.8/rd:9.3/S:263.4%]

its consumption per thread in %
pb:43.8/	- packetbuffer - out of the buffer
defrag:17.5/	- defragmentation of packets
d:19.5/		- structs create for processing in t2
s:12.6/		- SIP - parse
e:5.4/		- SIP - calls/messages search, struct creation
c:6.9/		- process_packets - calls/messages
g:10.1/		- process_packets - registers
r:11.7/		- process_packets - RTP
o:0.3/		- others options,notifies/subscribes
rm:17.9/	- RTP - packets shift, prepare for processing
rh:31.9,32.9/	- RTP - search hash
rd:19.3,.../	- RTP - move to read queue
S		- SUM Total consumption

Adding new thread is automatic

'd' is running after pb,
if 'd' > 50%, new thread 's' (reasembles, sip parse) 
if 's' > 50%, new thread 'e' (callid search + structs create for calls), 
if 'e' > 50%, new thread 'c' (calls)
if 'c' > 50%, new thread 'g' (registers)
if 'g' > 50%, new thread 'r' (rtp)

Threads removing

if thread 'r|g|c|e|s' consuming < N% remove it.

t2_cpu overloaded

when pb:is over 95% make sure t2_boost is enabled in settings - if not helps, try to modify options (decrease values from default) pcap_queue_dequeu_window_length=2000|1000(more interfaces) or pcap_queue_dequeu_need_blocks=0.

tRTP_CPU

[658.8%/46.7m/15t] Means that 15threads processing RTP, peak thread 46.7%, Sum 658.8%

tacCPU

[N0|N1|N...] %CPU utilization when compressing pcap files or when compressing internal memory if tar=yes (which is by default) number of threads grows automatically

RSS/VSZ

RSS: resident size, which is an accurate representation of how much actual physical memory sniffer is consuming. in MB
VSZ: virtual size of a process, which is the sum of memory it is actually using, memory it has mapped into itself (for instance the video card’s RAM for the X server),
     files on disk that have been mapped into it (most notably shared libraries), and memory shared with other processes. VIRT represents how much memory the program is able to access at the present moment.

LA

[11.90 10.93 10.71/8h] Load averages in last 1,5,10 minutes/count of CPUs, h=when hyperthreading enabled