Cdr duration always return 0

bouthaina · July 28, 2023, 12:05pm

Hii, i use sqlite3 to save asterisk cdr and everything were ok but when i migrate from SIP to PJSIP the duration and billsec always return 0.

thank you for your help

jcolp · July 28, 2023, 12:24pm

There is insufficient information here. What is the call flow? What is the console output? If you save to a file, is the duration and billsec correct?

bouthaina · July 28, 2023, 12:36pm

if i save to a csv file the duration and billsec always get 0. this is an example line from master.csv file:

“”,“8001”,“8002”,“Extension_SipPhone”,“”“paul”" <8001>",“PJSIP/8001-00000000”,“PJSIP/8002-00000001”,“Dial”,“PJSIP/8002,60,kKtT”,“2023-07-28 08:17:08”,“2023-07-28 08:17:08”,“2023-07-28 08:17:08”,0,0,“ANSWERED”,“DOCUMENTATION”,“1690546620.0”,“169054662064c3b1bce3575”

jcolp · July 28, 2023, 12:37pm

And the console output? Is the call actually up? Was it immediately disconnected?

bouthaina · July 28, 2023, 12:43pm

the call up and builded, the problem is that duration get always 0 while the real call duration was not 0.
this is the output:
VERBOSE[11628][C-00000002] bridge_channel.c: Channel PJSIP/8002-00000003 joined ‘simple_bridge’ basic-bridge
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: Bridge Enter message for channel PJSIP/8002-00000003: 1690543803.00233308
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Updating Party A PJSIP/8002-00000003 snapshot
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Processing bridge enter for PJSIP/8002-00000003
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Transitioning CDR for PJSIP/8002-00000003 from state Single to Bridged
[Jul 28 07:30:03] VERBOSE[11563][C-00000002] bridge_channel.c: Channel PJSIP/8001-00000002 joined ‘simple_bridge’ basic-bridge
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: Bridge Enter message for channel PJSIP/8001-00000002: 1690543803.00233968
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Updating Party A PJSIP/8001-00000002 snapshot
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Processing bridge enter for PJSIP/8001-00000002
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state DialedPending to Dial
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state Dial to Bridged
ps: i am using agi scripts for the dialplan

jcolp · July 28, 2023, 12:55pm

That’s PARTIAL output. You need to provide complete console output from the start of the call to the end.

bouthaina · July 28, 2023, 1:10pm

[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Created CDR for channel PJSIP/8001-00000002
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state NONE to Single
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] pbx.c: Executing [8002@internal:1] AGI(“PJSIP/8001-00000002”, “/var/www/html/i-pbx/include/…/agi/Route_Outgoing.php”) in new stack
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: Launched AGI Script /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: Exten_dynamic=
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: extension_s:490
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: caller ext : 8001
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: cid=8001
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: start monitoring
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: AGI Script Executing Application: (MixMonitor) Options: (/var/spool/asterisk/monitor//169054380064c3a6b8b9b1d.wav)
[Jul 28 07:30:00] VERBOSE[11571][C-00000002] app_mixmonitor.c: Begin MixMonitor Recording PJSIP/8001-00000002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: CDR[169054380064c3a6b8b9b1d] DIAL 8002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: test 490
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: rule= 13
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: rule::
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: regex : /^9[0-9]{2,9}$/
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: called_ext : 8002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: preg_match : 0
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: rule::
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: regex : /^[1]{3,5}$/
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: called_ext : 8002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: preg_match : 1
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: SET getNum
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: caller name=paul
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php: CALLING 8002 USING RULE Internal AND INTERNAL DIALPLAN
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: AGI Script Executing Application: (Goto) Options: (Extension_SipPhone,8002,1)
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] pbx_builtins.c: Goto (Extension_SipPhone,8002,1)
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: <PJSIP/8001-00000002>AGI Script /var/www/html/i-pbx/include/…/agi/Route_Outgoing.php completed, returning 0
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] pbx.c: Executing [8002@Extension_SipPhone:1] AGI(“PJSIP/8001-00000002”, “/var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php”) in new stack
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: Launched AGI Script /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php: extension :: 8002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php: CDR[169054380064c3a6b8b9b1d] RING pascal ,8002
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] res_agi.c: AGI Script Executing Application: (Dial) Options: (PJSIP/8002,60,kKtT)
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Created CDR for channel PJSIP/8002-00000003
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Transitioning CDR for PJSIP/8002-00000003 from state NONE to Single
[Jul 28 07:30:00] VERBOSE[11563][C-00000002] app_dial.c: Called PJSIP/8002
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: Dial Begin message for PJSIP/8001-00000002, PJSIP/8002-00000003: 1690543800.00934341
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Processing Dial Begin message for channel PJSIP/8001-00000002, peer PJSIP/8002-00000003
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Updated Party A PJSIP/8001-00000002 snapshot
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Updated Party B PJSIP/8002-00000003 snapshot
[Jul 28 07:30:00] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state Single to Dial
[Jul 28 07:30:01] VERBOSE[11563][C-00000002] app_dial.c: PJSIP/8002-00000003 is ringing
[Jul 28 07:30:01] VERBOSE[6925] cdr.c: Dial End message for PJSIP/8001-00000002, PJSIP/8002-00000003: 1690543801.00128015
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Set answered time to 1690543803.227541
[Jul 28 07:30:03] VERBOSE[11563][C-00000002] app_dial.c: PJSIP/8002-00000003 answered PJSIP/8001-00000002
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: Dial End message for PJSIP/8001-00000002, PJSIP/8002-00000003: 1690543803.00228757
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Processing Dial End message for channel PJSIP/8001-00000002, peer PJSIP/8002-00000003
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state Dial to DialedPending
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Set answered time to 1690543803.229175
[Jul 28 07:30:03] VERBOSE[11628][C-00000002] bridge_channel.c: Channel PJSIP/8002-00000003 joined ‘simple_bridge’ basic-bridge
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: Bridge Enter message for channel PJSIP/8002-00000003: 1690543803.00233308
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Updating Party A PJSIP/8002-00000003 snapshot
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Processing bridge enter for PJSIP/8002-00000003
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Transitioning CDR for PJSIP/8002-00000003 from state Single to Bridged
[Jul 28 07:30:03] VERBOSE[11563][C-00000002] bridge_channel.c: Channel PJSIP/8001-00000002 joined ‘simple_bridge’ basic-bridge
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: Bridge Enter message for channel PJSIP/8001-00000002: 1690543803.00233968
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Updating Party A PJSIP/8001-00000002 snapshot
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Processing bridge enter for PJSIP/8001-00000002
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state DialedPending to Dial
[Jul 28 07:30:03] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state Dial to Bridged
[Jul 28 07:30:20] VERBOSE[11628][C-00000002] bridge_channel.c: Channel PJSIP/8002-00000003 left ‘simple_bridge’ basic-bridge
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: Bridge Leave message for PJSIP/8002-00000003: 1690543820.00824703
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Processing Bridge Leave for PJSIP/8002-00000003
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Transitioning CDR for PJSIP/8002-00000003 from state Bridged to Finalized
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] bridge_channel.c: Channel PJSIP/8001-00000002 left ‘simple_bridge’ basic-bridge
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php: DIALSTATUS ANSWER
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: Bridge Leave message for PJSIP/8001-00000002: 1690543820.00825153
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Processing Bridge Leave for PJSIP/8001-00000002
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Transitioning CDR for PJSIP/8001-00000002 from state Bridged to Finalized
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Beginning finalize/dispatch for PJSIP/8002-00000003
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Dispatching CDR for Party A PJSIP/8002-00000003, Party B
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php: CDR[169054380064c3a6b8b9b1d] DIALSTATUS ANSWER,16
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] res_agi.c: <PJSIP/8001-00000002>AGI Script /var/www/html/i-pbx/include/…/agi/Extension_SipPhone.php completed, returning 0
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] pbx.c: Executing [8002@Extension_SipPhone:2] Hangup(“PJSIP/8001-00000002”, “”) in new stack
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] pbx.c: Spawn extension (Extension_SipPhone, 8002, 2) exited non-zero on ‘PJSIP/8001-00000002’
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Created CDR for channel PJSIP/8001-00000002
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Transitioning CDR for PJSIP/8001-00000002 from state NONE to Single
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] pbx.c: Executing [h@Extension_SipPhone:1] AGI(“PJSIP/8001-00000002”, “/var/www/html/i-pbx/include/…/agi/Hangup.php”) in new stack
[Jul 28 07:30:20] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Set answered time to 1690543820.865451
[Jul 28 07:30:20] VERBOSE[11563][C-00000002] res_agi.c: Launched AGI Script /var/www/html/i-pbx/include/…/agi/Hangup.php
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Hangup.php: unique id i ::: 1690543800.6
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Hangup.php: duration4:
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Hangup.php: CDR[169054380064c3a6b8b9b1d] HANGUP 8002,pascal
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: AGI Script Executing Application: (ResetCDR) Options: (w)
[Jul 28 07:30:21] WARNING[11563][C-00000002] app.c: Unrecognized option: ‘w’
[Jul 28 07:30:21] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Set answered time to 1690543821.071365
[Jul 28 07:30:21] VERBOSE[6925] cdr.c: 0x7f41e80027a0 - Set answered time to 1690543821.071397
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: AGI Script Executing Application: (StopMixMonitor) Options: ()
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] app_mixmonitor.c: MixMonitor close filestream (mixed)
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: /var/www/html/i-pbx/include/…/agi/Hangup.php: caller id : 490
[Jul 28 07:30:21] VERBOSE[11563][C-00000002] res_agi.c: <PJSIP/8001-00000002>AGI Script /var/www/html/i-pbx/include/…/agi/Hangup.php completed, returning 0
[Jul 28 07:30:21] VERBOSE[11571][C-00000002] app_mixmonitor.c: End MixMonitor Recording PJSIP/8001-00000002
[Jul 28 07:30:21] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Beginning finalize/dispatch for PJSIP/8001-00000002
[Jul 28 07:30:21] VERBOSE[6925] cdr.c: 0x7f41e8000a90 - Dispatching CDR for Party A PJSIP/8001-00000002, Party B PJSIP/8002-00000003

0-9 ↩︎

jcolp · July 28, 2023, 1:15pm

You’re calling ResetCDR which will reset the CDR. What happens if you do not do that?

bouthaina · July 28, 2023, 1:28pm

yes the problem is from ResetCDR, when i commented it the values of duration and billsec are correct now.

thank youuuu

system · August 27, 2023, 1:29pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.