====== Debug commands ====== ==== Enable Voximal module traces === Execute : CLI> voximal debug ==== Enable Voximal interpreter traces === Execute : CLI> voximal debug interpreter ==== View the traces flow === Execute : root# tail -f /var/log/voximal/debug.log With colors : root# tail -f /var/log/voximal/debug.log | ccze -A ==== Generate a normal stop ==== Clean stop of the Voximald process : root# /usr/sbin/voximalc -local 2 -distant 1 -mode 2 Command-line arguments : [-key id] [-local id] [-distant id] [-send message] [-mode 0..3] To send one message, set mode to 0 To receive messages in loop, set mode to 1 To work in request/response, set mode to 2 To send messages in loop, set mode to 3 > exit < exit|result=ok ==== Powerful top monitor ==== Use the "htop" tool : htop -p $(pidoff voximald) 1 [ 0.0%] Tasks: 33, 29 thr; 1 running 2 [| 0.7%] Load average: 0.51 0.28 0.30 3 [ 0.0%] Uptime: 3 days, 01:39:39 4 [ 0.0%] Mem[||| 175M/3.91G] Swp[| 31.8M/7.81G] PID USER PRI NI VIRT RES SHR S CPU% MEM% TIME+ Command 1 root 20 0 199M 3316 2208 S 0.0 0.1 0:02.58 /sbin/init 18890 root 20 0 56440 4164 3360 S 0.0 0.1 0:00.02 `- /lib/systemd/s 18891 root 20 0 224M 1316 0 S 0.0 0.0 0:00.00 | `- (sd-pam) 409 root 20 0 81156 1236 1068 S 0.0 0.0 0:00.95 `- /usr/lib/postf 14487 postfix 20 0 83224 5088 4320 S 0.0 0.1 0:00.00 | `- pickup -l - 412 postfix 20 0 83388 1916 1648 S 0.0 0.0 0:00.30 | `- qmgr -l -t 308 root 20 0 350M 24556 19196 S 0.0 0.6 0:05.93 `- /usr/sbin/apac 30788 www-data 20 0 350M 6752 1384 S 0.0 0.2 0:00.00 | `- /usr/sbin/a 30787 www-data 20 0 350M 6752 1384 S 0.0 0.2 0:00.00 | `- /usr/sbin/a 30786 www-data 20 0 350M 6752 1384 S 0.0 0.2 0:00.00 | `- /usr/sbin/a 30785 www-data 20 0 350M 6752 1384 S 0.0 0.2 0:00.00 | `- /usr/sbin/a 30784 www-data 20 0 350M 6752 1384 S 0.0 0.2 0:00.00 | `- /usr/sbin/a 263 mysql 28 8 670M 38608 1668 S 0.0 0.9 1:55.94 `- /usr/sbin/mysq 2808 mysql 20 0 670M 38608 1668 S 0.0 0.9 0:00.00 | `- /usr/sbin/m F1Help F2Setup F3SearchF4FilterF5SortedF6CollapF7Nice -F8Nice +F9Kill F10Quit ==== Powerful SIP traffic monitor ==== Use the "sngrep" tool : sngrep xINVITE sip:0970265644@84.246.228.243:506 128.140.150.200:5060 xuser=phone SIP/2.0 qqqqqqqqqqwqqqqqqqqq xVia: SIP/2.0/UDP 128.140.150.200:5060;br 22:22:36.632419 x INVITE (Sxch=z9hG4bKk5efg100aob0k0be5og0.1 +0.000994 x qqqqqqqqqqqqqqqqxMax-Forwards: 66 22:22:36.633413 x 100 TryixFrom: ;tag=1c1397877903 22:22:36.681724 x 200 OK (SxTo: sip:0970265644@ipdirections.net +0.085629 x 22:22:45.526954 x 200 OKxSupported: sdp-anat x x xContent-Type: application/sdp x xContent-Length: 435 x xP-Early-Media: supported x xP-Access-Network-Info: GSTN;operator-spe x Esc Calls List Enter Raw Space Compare F1 Help F2 SDP F3 RTP F4 Exte ==== Asterisk Manager traffic monitor ==== Use the "ngrep" tool : ngrep ngrep -d lo -s 1500 port 5038 -T ==== Monitor memory/CPU ==== A very simple way to follow the memory and CPU indicators : root# top -b -d 5 -p $(pidof voximald) | awk -v OFS="," '$1+0>0 {print strftime("%Y-%m-%d %H:%M:%S"),$1,$NF,$5,$6,$7,$9,$10; fflush() }' | tee datas.csv ==== Valgrid using ==== The Asterisk module launch the interpreter by defaut, you need to disable it to be able to run the voximald process with Valgrid. To disable the Voximal launch from the Asterisk module edit and add this option in the voximal.conf : [general] ... launcher=no ... Start the voximald process with Valgrid : #root valgrind --tool=memcheck --leak-check=full --log-file="logfile.out" /usr/sbin/voximald -channels 1 -config /etc/openvxi/client.cfg -user asterisk -group asterisk And run the Asterisk. asterisk -cvvvvv -U asterisk -G asterisk -g ==== VoiceXML Log levels ==== Format : Diagnostic date/time | threadID | sessionID or mark | tagID | subtag | text Error date/time | threadID | sessionID or -1 | 0 | severity | modulename | errorID | errorText | appends Event date/time | threadID | sessionID | EVENT | 0|evenID | appends Logging example : ... Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessBegin Locked Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessEnd Unlock Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4000|SBjsiGetVar|exiting: returned 0, 0x7f82daeb34e0 (0x7f82d419a750) Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|8002|fr.ulex.vxi|VXI::assign_element(set value : id=08facd13i9e0q9o1m4vav8ghvn8tbagn21bfcb5) Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|5001|VXIpromptWait|VXIprompt Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|5001|VXIpromptWait|Waiting PROMPT Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|5001|VXIpromptWait|EVT < 1 : prompt|session=1|item=1|result=ok Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|8002|fr.ulex.vxi|VXI::DoInnerJump() Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4000|SBjsiCheckVar|entering: 0x7f82d412af00, '$_internalName_31627' Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4004|JsiContext::CheckVar|Check variable $_internalName_31627, context 0x7f82d41656e0 Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessBegin Lock Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessBegin Locked Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessEnd Unlock Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4000|SBjsiCheckVar|exiting: returned 0 Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4000|SBjsiCheckVar|entering: 0x7f82d412af00, '$_internalName_31628' Oct 23 23:39:12.35|0x7f82daebb700|0_1_1540337949.313|4004|JsiContext::CheckVar|Check variable $_internalName_31628, context 0x7f82d41656e0 Oct 23 23:39:12.35|0x7f82daebb700|-1|4002||AccessBegin Lock ... The default log bases (used to define tagIDs) : client.cache.diagLogBase VXIInteger 2000 client.inet.diagLogBase VXIInteger 3000 client.jsi.diagLogBase VXIInteger 4000 client.prompt.diagLogBase VXIInteger 5000 client.rec.diagLogBase VXIInteger 6000 client.tel.diagLogBase VXIInteger 7000 client.vxi.diagLogBase VXIInteger 8000 client.object.diagLogBase VXIInteger 9000 client.client.diagLogBase VXIInteger 10000 === Interet connector === SBinet: API trace SBinet: Channel diagnostics SBinet: Stream diagnostics SBinet: Cookie diagnostics SBinet: Validator diagnostics SBinet: Cache diagnostics SBinet: Timing diagnostics SBinet: Dump HTTP requests and responses === Cache === SBcache: API trace SBcache: Cache manager diagnostics SBcache: Cache entry diagnostics SBcache: Cache stream diagnostics SBcache: Cache entry table mutex diagnostics SBcache: Cache entry mutex diagnostics === EcmaScript interpreter === SBjsi: API trace SBjsi: JavaScript context diagnostics SBjsi: JavaScript garbage collection trace SBjsi: JavaScript scope diagnostics SBjsi: Native ScriptEase error messages SBjsi: ScriptEase debug log messages === Client main === OSBclient: API trace OSBclient: Component names and versions OSBclient: General diagnostics === Objects === OSBobject: API trace === VoiceXML interpreter (VXI) === VXI: VoiceXML document and application warnings VXI: VoiceXML log element output VXI: VoiceXML element logging VXI: VoiceXML grammar logging VXI: VoiceXML transitions VXI: VoiceXML log Contents (VoiceXML and Data XML/Json) === Telephony === VXItel: Signaling trace === Prompt === VXIprompt: Prompting trace === Recognize === VXIrec: Recognition trace VXIrec: Grammar trace ==== Set the right TimeZone ==== Install the NTP package to synchronize your server to the world's time. #timedatectl set-timezone America/New_York or, for french servers, #timedatectl set-timezone Europe/Paris or automatically, #dpkg-reconfigure tzdata ==== Monitor the file descriptors ==== List the file descriptors used by a process : # ls -l /proc/[PID]/fd ==== Generate a CallStacks or Coredumps ==== Generate the threads stacks or a coredump file for the process (voximald) : gdb -ex "thread apply all bt" --batch /usr/sbin/voximald $(pidof voximald) > /var/log/voximal/backtrace-voximald$(date +%s).txt gdb /usr/sbin/voximald $(pidof voximald) -ex "gcore /tmp/toto.core" --batch