Asterisk Wrong Billsec

509 Views Asked by At

The problem is this: I have an Asterisk server, with a custom context to count and set limit call time to the extensions. I see that the Billsec values on the DB, is wrong, because it is counting since the call is ringing, not when the call is answered.
Can you help me please. My server has a SIP trunk to make the calls

Here's the flow of the call

Net Flow

And here's the output of elastix with verbose

-- Executing [XXXXXXXXXX@from-internal:1] Macro("SIP/14105-000000b2", "user-callerid,LIMIT,EXTERNAL,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/14105-000000b2", "TOUCH_MONITOR=1526653901.192") in new stack
-- Executing [s@macro-user-callerid:2] Set("SIP/14105-000000b2", "AMPUSER=14105") in new stack
-- Executing [s@macro-user-callerid:3] GotoIf("SIP/14105-000000b2", "0?report") in new stack
-- Executing [s@macro-user-callerid:4] ExecIf("SIP/14105-000000b2", "1?Set(REALCALLERIDNUM=14105)") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/14105-000000b2", "AMPUSER=14105") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/14105-000000b2", "0?limit") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/14105-000000b2", "AMPUSERCIDNAME=HERE'S_EXTENSION") in new stack
-- Executing [s@macro-user-callerid:8] GotoIf("SIP/14105-000000b2", "0?report") in new stack
-- Executing [s@macro-user-callerid:9] Set("SIP/14105-000000b2", "AMPUSERCID=14105") in new stack
-- Executing [s@macro-user-callerid:10] Set("SIP/14105-000000b2", "__DIAL_OPTIONS=tr") in new stack
-- Executing [s@macro-user-callerid:11] Set("SIP/14105-000000b2", "CALLERID(all)="HERE'S_EXTENSION" <14105>") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("SIP/14105-000000b2", "0?limit") in new stack
-- Executing [s@macro-user-callerid:13] ExecIf("SIP/14105-000000b2", "1?Set(GROUP(concurrency_limit)=14105)") in new stack
-- Executing [s@macro-user-callerid:14] ExecIf("SIP/14105-000000b2", "0?Set(CHANNEL(language)=)") in new stack
-- Executing [s@macro-user-callerid:15] GotoIf("SIP/14105-000000b2", "1?continue") in new stack
-- Goto (macro-user-callerid,s,28)
-- Executing [s@macro-user-callerid:28] Set("SIP/14105-000000b2", "CALLERID(number)=14105") in new stack
-- Executing [s@macro-user-callerid:29] Set("SIP/14105-000000b2", "CALLERID(name)=HERE'S_EXTENSION") in new stack
-- Executing [s@macro-user-callerid:30] Set("SIP/14105-000000b2", "CDR(cnum)=14105") in new stack
-- Executing [s@macro-user-callerid:31] Set("SIP/14105-000000b2", "CDR(cnam)=HERE'S_EXTENSION") in new stack
-- Executing [s@macro-user-callerid:32] Set("SIP/14105-000000b2", "CHANNEL(language)=es") in new stack
-- Executing [XXXXXXXXXX@from-internal:2] Set("SIP/14105-000000b2", "EMERGENCYROUTE=YES") in new stack
-- Executing [XXXXXXXXXX@from-internal:3] Set("SIP/14105-000000b2", "INTRACOMPANYROUTE=YES") in new stack
-- Executing [XXXXXXXXXX@from-internal:4] Set("SIP/14105-000000b2", "MOHCLASS=music-rony") in new stack
-- Executing [XXXXXXXXXX@from-internal:5] Set("SIP/14105-000000b2", "_NODEST=") in new stack
-- Executing [XXXXXXXXXX@from-internal:6] Gosub("SIP/14105-000000b2", "sub-record-check,s,1(out,XXXXXXXXXX,)") in new stack
-- Executing [s@sub-record-check:1] Set("SIP/14105-000000b2", "REC_POLICY_MODE_SAVE=") in new stack
-- Executing [s@sub-record-check:2] GotoIf("SIP/14105-000000b2", "1?check") in new stack
-- Goto (sub-record-check,s,7)
-- Executing [s@sub-record-check:7] Set("SIP/14105-000000b2", "__MON_FMT=wav") in new stack
-- Executing [s@sub-record-check:8] GotoIf("SIP/14105-000000b2", "1?next") in new stack
-- Goto (sub-record-check,s,11)
-- Executing [s@sub-record-check:11] ExecIf("SIP/14105-000000b2", "0?Return()") in new stack
-- Executing [s@sub-record-check:12] ExecIf("SIP/14105-000000b2", "0?Set(__REC_POLICY_MODE=)") in new stack
-- Executing [s@sub-record-check:13] GotoIf("SIP/14105-000000b2", "0?out,1") in new stack
-- Executing [s@sub-record-check:14] Set("SIP/14105-000000b2", "__REC_STATUS=INITIALIZED") in new stack
-- Executing [s@sub-record-check:15] Set("SIP/14105-000000b2", "NOW=1526653901") in new stack
-- Executing [s@sub-record-check:16] Set("SIP/14105-000000b2", "__DAY=18") in new stack
-- Executing [s@sub-record-check:17] Set("SIP/14105-000000b2", "__MONTH=05") in new stack
-- Executing [s@sub-record-check:18] Set("SIP/14105-000000b2", "__YEAR=2018") in new stack
-- Executing [s@sub-record-check:19] Set("SIP/14105-000000b2", "__TIMESTR=20180518-093141") in new stack
-- Executing [s@sub-record-check:20] Set("SIP/14105-000000b2", "__FROMEXTEN=14105") in new stack
-- Executing [s@sub-record-check:21] Set("SIP/14105-000000b2", "__CALLFILENAME=out-XXXXXXXXXX-14105-20180518-093141-1526653901.192") in new stack
-- Executing [s@sub-record-check:22] Goto("SIP/14105-000000b2", "out,1") in new stack
-- Goto (sub-record-check,out,1)
-- Executing [out@sub-record-check:1] ExecIf("SIP/14105-000000b2", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack
-- Executing [out@sub-record-check:2] GosubIf("SIP/14105-000000b2", "0?record,1(exten,XXXXXXXXXX,14105)") in new stack
-- Executing [out@sub-record-check:3] Return("SIP/14105-000000b2", "") in new stack
-- Executing [XXXXXXXXXX@from-internal:7] Macro("SIP/14105-000000b2", "dialout-trunk,2,926984292,,off") in new stack
-- Executing [s@macro-dialout-trunk:1] Set("SIP/14105-000000b2", "DIAL_TRUNK=2") in new stack
-- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/14105-000000b2", "0?sub-pincheck,s,1()") in new stack
-- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/14105-000000b2", "0?disabletrunk,1") in new stack
-- Executing [s@macro-dialout-trunk:4] Set("SIP/14105-000000b2", "DIAL_NUMBER=926984292") in new stack
-- Executing [s@macro-dialout-trunk:5] Set("SIP/14105-000000b2", "DIAL_TRUNK_OPTIONS=tr") in new stack
-- Executing [s@macro-dialout-trunk:6] Set("SIP/14105-000000b2", "OUTBOUND_GROUP=OUT_2") in new stack
-- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/14105-000000b2", "1?nomax") in new stack
-- Goto (macro-dialout-trunk,s,9)
-- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/14105-000000b2", "1?skipoutcid") in new stack
-- Goto (macro-dialout-trunk,s,12)
-- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/14105-000000b2", "1?sub-flp-2,s,1()") in new stack
-- Executing [s@sub-flp-2:1] ExecIf("SIP/14105-000000b2", "1?Set(TARGET_FLP_2=01151926984292)") in new stack
-- Executing [s@sub-flp-2:2] GotoIf("SIP/14105-000000b2", "1?match") in new stack
-- Goto (sub-flp-2,s,6)
-- Executing [s@sub-flp-2:6] Set("SIP/14105-000000b2", "DIAL_NUMBER=01151926984292") in new stack
-- Executing [s@sub-flp-2:7] Return("SIP/14105-000000b2", "") in new stack
-- Executing [s@macro-dialout-trunk:13] Set("SIP/14105-000000b2", "OUTNUM=01151926984292") in new stack
-- Executing [s@macro-dialout-trunk:14] Set("SIP/14105-000000b2", "custom=SIP/IDT") in new stack
-- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/14105-000000b2", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^music-rony)tr)") in new stack
-- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/14105-000000b2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^music-rony)trM(confirm))") in new stack
-- Executing [s@macro-dialout-trunk:17] Macro("SIP/14105-000000b2", "dialout-trunk-predial-hook,") in new stack
-- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/14105-000000b2", "") in new stack
-- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/14105-000000b2", "0?bypass,1") in new stack
-- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/14105-000000b2", "1?Set(CONNECTEDLINE(num,i)=01151926984292)") in new stack
-- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/14105-000000b2", "1?Set(CONNECTEDLINE(name,i)=CID:14105)") in new stack
-- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/14105-000000b2", "0?customtrunk") in new stack
-- Executing [s@macro-dialout-trunk:22] Dial("SIP/14105-000000b2", "SIP/IDT/01151926984292,300,M(setmusic^music-rony)tr") in new stack


  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called SIP/IDT/01151926984292
    -- SIP/IDT-000000b3 answered SIP/14105-000000b2
    -- Executing [s@macro-setmusic:1] Set("SIP/IDT-000000b3", "CHANNEL(musicclass)=music-rony") in new stack
       > 0x2752f70 -- Probation passed - setting RTP source address to XXX.XXX.XXX.XXX:21522
       > 0x29fa6b0 -- Probation passed - setting RTP source address to XXX.XXX.XXX.XXX:36935
       > 0x29fa6b0 -- Probation passed - setting RTP source address to XXX.XXX.XXX.XXX:36935
    -- Executing [h@macro-dialout-trunk:1] Macro("SIP/14105-000000b2", "hangupcall,") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/14105-000000b2", "1?endmixmoncheck") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] NoOp("SIP/14105-000000b2", "End of MIXMON check") in new stack
    -- Executing [s@macro-hangupcall:10] GotoIf("SIP/14105-000000b2", "1?nomeetmemon") in new stack
    -- Goto (macro-hangupcall,s,28)
    -- Executing [s@macro-hangupcall:28] NoOp("SIP/14105-000000b2", "End of MEETME check") in new stack
    -- Executing [s@macro-hangupcall:29] GotoIf("SIP/14105-000000b2", "1?noautomon") in new stack
    -- Goto (macro-hangupcall,s,34)
    -- Executing [s@macro-hangupcall:34] NoOp("SIP/14105-000000b2", "TOUCH_MONITOR_OUTPUT=") in new stack
    -- Executing [s@macro-hangupcall:35] GotoIf("SIP/14105-000000b2", "1?noautomon2") in new stack
    -- Goto (macro-hangupcall,s,41)
    -- Executing [s@macro-hangupcall:41] NoOp("SIP/14105-000000b2", "MONITOR_FILENAME=") in new stack
    -- Executing [s@macro-hangupcall:42] GotoIf("SIP/14105-000000b2", "1?noautomon3") in new stack
    -- Goto (macro-hangupcall,s,48)
    -- Executing [s@macro-hangupcall:48] NoOp("SIP/14105-000000b2", "MIXMONITOR_FILENAME=") in new stack
    -- Executing [s@macro-hangupcall:49] GotoIf("SIP/14105-000000b2", "1?noautomon4") in new stack
    -- Goto (macro-hangupcall,s,51)
    -- Executing [s@macro-hangupcall:51] NoOp("SIP/14105-000000b2", "ONETOUCH_RECFILE=") in new stack
    -- Executing [s@macro-hangupcall:52] GotoIf("SIP/14105-000000b2", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,55)
    -- Executing [s@macro-hangupcall:55] GotoIf("SIP/14105-000000b2", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,58)
    -- Executing [s@macro-hangupcall:58] GotoIf("SIP/14105-000000b2", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,60)
    -- Executing [s@macro-hangupcall:60] AGI("SIP/14105-000000b2", "hangup.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/hangup.agi
    -- <SIP/14105-000000b2>AGI Script hangup.agi completed, returning 0
    -- Executing [s@macro-hangupcall:61] Hangup("SIP/14105-000000b2", "") in new stack
  == Spawn extension (macro-hangupcall, s, 61) exited non-zero on 'SIP/14105-000000b2' in macro 'hangupcall'
  == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/14105-000000b2'
  == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/14105-000000b2' in macro 'dialout-trunk'
  == Spawn extension (from-internal, XXXXXXXXXX, 7) exited non-zero on 'SIP/14105-000000b2'
2

There are 2 best solutions below

1
On

Dump your traffic for sip port and analyse with wireshark than you can see your flow, you need to check all packets, if you give first 200 then ring so it is problem by your provider side.

Example command for dump

tcpdump -i eth0 -n -s 0 port 5060 -vvv -w capture_file_name.cap

After that, download file to your local directory with scp. Open with Wireshark.

0
On

Capture made

This is the capture that i have when a call is made.