Logging: Difference between revisions

From VoIPmonitor.org
Jump to navigation Jump to search
No edit summary
No edit summary
 
(29 intermediate revisions by the same user not shown)
Line 2: Line 2:
=Messages from GNU GPL sniffer sensor service=
=Messages from GNU GPL sniffer sensor service=


'''Voipmonitor''' by default uses 'daemon' facility of syslog to store status messages.
'''Voipmonitor''' by default uses 'daemon' facility of a syslog to store status messages.
By default it is stored to **/var/log/syslog**(debian/ubuntu) or to **/var/log/messages**(centos/rh)
==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:
You can find useful to store status info from voipmonitor to different file:
For '''rsyslog''' use this in /etc/rsyslog.conf
For '''rsyslog''' use this in /etc/rsyslog.conf
Line 11: Line 17:
  & ~
  & ~


=== disable storing of logs for voipmonitor binary===
if ($programname == 'voipmonitor') and ($syslogseverity <= '7') then {stop}


==Description of a status line==
=Status line details=
t2CPU[
pb:10.5/ - packetbuffer - out of the buffer
d:39.2/ - structs create for processing in t2
s:24.6/ - SIP - parse
e:17.3/ - SIP - calls/messages search, struct creation
c:6.8/               - process_packets - calls/messages
g:6.4/                      - process_packets - registers
r:7.3/               - process_packets - RTP


rm:24.6/ - packets shift, prepare for processing
rh:16.7/ - RTP - search hash
rd:19.3/ - RTP - move to read queue


**Addding new thread is automatic**


==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,
  'd' is running after pb,
  if 'd' > 50%, new thread 's' (reasembles, sip parse)  
  if 'd' > 50%, new thread 's' (reasembles, sip parse)  
  if 's' > 50%, new thread 'e' (callid seach + structs create for calls),  
  if 's' > 50%, new thread 'e' (callid search + structs create for calls),  
  if 'e' > 50%, new thread 'c' (calls)
  if 'e' > 50%, new thread 'c' (calls)
  if 'c' > 50%, new thread 'g' (registers)
  if 'c' > 50%, new thread 'g' (registers)
  if 'g' > 50%, new thread 'r' (rtp)
  if 'g' > 50%, new thread 'r' (rtp)


ubírání
===Threads removing===
  if 'e' < N zruší se 'r'
  if thread 'r|g|c|e|s' consuming < N% remove it.
if 'e' < N zruší se 'g'
if 'e' < N zruší se 'c'
if 'e' < N zruší se 'e'
if 's' < N zruší se 's'


SQLq[
=== t2_cpu overloaded ===
C=CDR_queue
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.
M=Message_queue
R=Register_queue
L=LiveSniffer_queue
Cl=Cleanspool queue


tarQ
==tsslCPU==
number of files in a queue
'''[1.5%|8288l]'''
load of ssl thread and count of ssl connections kept
 
==tsip_tcpCPU==
'''[1064l|10/7s|24/9p'''
1064l - connections count per ip:port
10/7s - unfinished streams (ACK) count Total / max (per connections)
24/9p - unfinished packets in streamech - count Total / (max per streams)
 
==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


tarB
==RSS/VSZ==
MBs in tar buffer
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.


tarCPU
==LA==
threads used for taring - its consumption
[11.90 10.93 10.71/8h] Load averages in last 1,5,10 minutes/count of CPUs, h=when hyperthreading enabled

Latest revision as of 17:50, 28 April 2023

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.

tsslCPU

[1.5%|8288l]

load of ssl thread and count of ssl connections kept

tsip_tcpCPU

[1064l|10/7s|24/9p

1064l - connections count per ip:port
10/7s - unfinished streams (ACK) count Total / max (per connections)
24/9p - unfinished packets in streamech - count Total / (max per streams)

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