thr3ads.net - asterisk users - [asterisk-users] Problem with callfile and CDR [Aug 2012]

If this information is useful, please help other people find it:
Share via:

Rodrigo Lang

2012-Aug-01 17:45 UTC

[asterisk-users] Problem with callfile and CDR

Good afternoon list.

I am experiencing a problem with the CDR and callfiles. What is happening
is this: When generating a call with a callfile, everything works
perfectly, but the CDR is recorded in the table when they answer the call
destination. The field disposition is being recorded correctly, but the
duration field is marked with the ring time and billsec is marked with 0.
This just happens to connections through callfiles. Yes, the call is
working usually remains. I did several tests with durations from seconds to
20 minutes.

I tested in two servers. With an Asterisk 1.4.44 (debian 5 64bits), and
another with Asterisk 1.8.14.0 (debian 6 64bits). In both occurs the same
problem. AND I tried using ForkCDR and ResetCDR and both did not help.

I'm doing something wrong? Has anyone experienced something similar? Any
tips?


*The callfile:*

Channel: local/21411615 at test_outgoing> CallerID: "ELCO Test" <123456789>
> MaxRetries: 1
> RetryTime: 30
> WaitTime: 25
> Context: test_ivr
> Extension: 21411615
> Priority: 1
> AlwaysDelete: Yes
> Archive: Yes


*The extensions.conf*

[test_outgoingsaida]> exten => _X.,1,Dial(khomp/gpstn/${EXTEN},120,Ttr)
> exten => _X.,2,Hangup()
> [test_ivr]
> exten => _X.,1,Answer()
> exten => _X.,n,Wait(20)
> exten => _X.,n,Hangup()


*Example, console:*

*Log first channel:*
[2012-08-01 14:29:44] DEBUG[6679] pbx.c: Launching 'Dial'
[2012-08-01 14:29:44] VERBOSE[6679] pbx.c:     -- Executing
[21411615 at test_outgoing:1] Dial("Local/21411615 at
test_outgoing-cb92;2",
"khomp/gpstn/21411615,120,Ttr") in new stack
[2012-08-01 14:29:44] DEBUG[6679] devicestate.c: device 'Khomp/B1C0'
state
'1'
[2012-08-01 14:29:44] DEBUG[6679] rtp_engine.c: Can't find native functions
for channel 'Khomp/B1C0-0.0'
[2012-08-01 14:29:44] DEBUG[6679] rtp_engine.c: Seeded SDP of
'Khomp/B1C0-0.0' with that of 'Local/21411615 at
test_outgoing-cb92;2'
[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDTIME.
[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
ANSWEREDTIME.
[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDPEERNAME.
[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDPEERNUMBER.
[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALSTATUS.
[2012-08-01 14:29:44] VERBOSE[6679] app_dial.c:     -- Called
khomp/gpstn/21411615
[2012-08-01 14:29:52] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0 is
ringing
[2012-08-01 14:29:53] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0 is
making progress passing it to Local/21411615 at test_outgoing-cb92;2
[2012-08-01 14:30:02] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0
answered Local/21411615 at test_outgoing-cb92;2
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
write format slin
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
read format slin
[2012-08-01 14:30:02] DEBUG[6679] features.c: Removing dialed interfaces
datastore on Khomp/B1C0-0.0 since we're bridging
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Planning to masquerade channel
Khomp/B1C0-0.0 into the structure of Local/21411615 at test_outgoing-cb92;1
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Done planning to masquerade
channel Khomp/B1C0-0.0 into the structure of
Local/21411615 at test_outgoing-cb92;1
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
write format slin
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
read format slin
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Putting channel Khomp/B1C0-0.0
in slin/slin formats
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Done Masquerading
Khomp/B1C0-0.0 (6)
[2012-08-01 14:30:02] DEBUG[6679] chan_local.c: Not posting to
'Local/21411615 at test_outgoing-cb92;2' queue since already masqueraded
out
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Bridge stops because we're
zombie or need a soft hangup: c0=Local/21411615 at test_outgoing-cb92;2,
c1=Local/21411615 at test_outgoing-cb92;1<ZOMBIE>, flags: No,Yes,Yes,Yes
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Bridge stops bridging channels
Local/21411615 at test_outgoing-cb92;2 and Local/21411615 at test_outgoing-cb92
;1<ZOMBIE>
[2012-08-01 14:30:02] DEBUG[6679] cdr_mysql.c: Inserting a CDR record.
[2012-08-01 14:30:02] DEBUG[6679] cdr_mysql.c: SQL command as follows:
INSERT INTO cdr
(`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`)
VALUES ('2012-08-01 14:29:44','\"ELCO Test\"
<123456789>','123456789','21411615','test_outgoing','Local/21411615
at test_outgoing-cb92
;2','Khomp/B1C0-0.0','Dial','khomp/gpstn/21411615,120,Ttr','18','0','ANSWERED','3','1343842184.19303')
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Hanging up zombie
'Local/21411615 at test_outgoing-cb92;1<ZOMBIE>'
[2012-08-01 14:30:02] DEBUG[6679] app_dial.c: Exiting with
DIALSTATUS=ANSWER.
[2012-08-01 14:30:02] DEBUG[6679] pbx.c: Spawn extension
(test_outgoing,21411615,1) exited non-zero on
'Local/21411615 at test_outgoing-cb92;2'
[2012-08-01 14:30:02] VERBOSE[6679] pbx.c:   == Spawn extension
(test_outgoing, 21411615, 1) exited non-zero on
'Local/21411615 at test_outgoing-cb92;2'
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Soft-Hanging up channel
'Local/21411615 at test_outgoing-cb92;2'
[2012-08-01 14:30:02] DEBUG[6679] channel.c: Hanging up channel
'Local/21411615 at test_outgoing-cb92;2'

*Log second channel:*
[2012-08-01 14:29:44] VERBOSE[6678] pbx_spool.c:     -- Attempting call on
local/21411615 at test_outgoing for 21411615 at test_ivr:1 (Retry 1)
[2012-08-01 14:30:02] DEBUG[6678] pbx.c: Launching 'Answer'
[2012-08-01 14:30:02] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:1] Answer("Local/21411615 at
test_outgoing-cb92;1", "") in
new stack
[2012-08-01 14:30:02] DEBUG[6678] pbx.c: Launching 'Wait'
[2012-08-01 14:30:02] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:2] Wait("Local/21411615 at
test_outgoing-cb92;1", "30") in
new stack
[2012-08-01 14:30:02] DEBUG[6678] channel.c: Scheduling timer at (50
requested / 50 actual) timer ticks per second
[2012-08-01 14:30:02] DEBUG[6678] channel.c: Started silence generator on
'Local/21411615 at test_outgoing-cb92;1'
[2012-08-01 14:30:34] DEBUG[6678] channel.c: Scheduling timer at (0
requested / 0 actual) timer ticks per second
[2012-08-01 14:30:34] DEBUG[6678] channel.c: Stopped silence generator on
'Khomp/B1C0-0.0'
[2012-08-01 14:30:34] DEBUG[6678] pbx.c: Launching 'Hangup'
[2012-08-01 14:30:34] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:3] Hangup("Khomp/B1C0-0.0", "") in new
stack
[2012-08-01 14:30:34] DEBUG[6678] pbx.c: Spawn extension
(test_ivr,21411615,3) exited non-zero on 'Khomp/B1C0-0.0'
[2012-08-01 14:30:34] VERBOSE[6678] pbx.c:   == Spawn extension (test_ivr,
21411615, 3) exited non-zero on 'Khomp/B1C0-0.0'
[2012-08-01 14:30:34] DEBUG[6678] channel.c: Soft-Hanging up channel
'Khomp/B1C0-0.0'
[2012-08-01 14:30:34] DEBUG[6678] channel.c: Hanging up channel
'Khomp/B1C0-0.0'
[2012-08-01 14:30:34] NOTICE[6678] pbx_spool.c: Call completed to
local/21411615 at test_outgoing


*Example, table cdr (MySQL):*

*************************** 46. row ***************************
     calldate: 2012-08-01 14:29:44
         clid: "ELCO Test" <123456789>
          src: 123456789
          dst: 21411615
     dcontext: test_outgoing
      channel: Local/21411615 at test_outgoing-cb92;2
   dstchannel: Khomp/B1C0-0.0
      lastapp: Dial
     lastdata: khomp/gpstn/21411615,120,Ttr
     duration: 18
      billsec: 0
  disposition: ANSWERED
     amaflags: 3
  accountcode:
     uniqueid: 1343842184.19303
    userfield:
          did:
recordingfile:




Best Regards,

-- 
Rodrigo Lang
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20120801/5754a7bf/attachment.htm>

Danny Nicholas

2012-Aug-01 18:08 UTC

head link

[asterisk-users] Problem with callfile and CDR

Just a WAG, but could the "local" channel be causing some kind of
problem?
Perhaps if you  changed local to SIP or DAHDI?

 

From: asterisk-users-bounces at lists.digium.com
[mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Rodrigo Lang
Sent: Wednesday, August 01, 2012 12:45 PM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: [asterisk-users] Problem with callfile and CDR

 

Good afternoon list.

 

I am experiencing a problem with the CDR and callfiles. What is happening is
this: When generating a call with a callfile, everything works perfectly,
but the CDR is recorded in the table when they answer the call destination.
The field disposition is being recorded correctly, but the duration field is
marked with the ring time and billsec is marked with 0. This just happens to
connections through callfiles. Yes, the call is working usually remains. I
did several tests with durations from seconds to 20 minutes.

 

I tested in two servers. With an Asterisk 1.4.44 (debian 5 64bits), and
another with Asterisk 1.8.14.0 (debian 6 64bits). In both occurs the same
problem. AND I tried using ForkCDR and ResetCDR and both did not help.

 

I'm doing something wrong? Has anyone experienced something similar? Any
tips? 

 

 

The callfile:

Channel: local/21411615 at test_outgoing
CallerID: "ELCO Test" <123456789>
MaxRetries: 1
RetryTime: 30
WaitTime: 25
Context: test_ivr
Extension: 21411615
Priority: 1
AlwaysDelete: Yes
Archive: Yes

 

 

The extensions.conf

 

[test_outgoingsaida]
exten => _X.,1,Dial(khomp/gpstn/${EXTEN},120,Ttr)
exten => _X.,2,Hangup()
[test_ivr]
exten => _X.,1,Answer()
exten => _X.,n,Wait(20)
exten => _X.,n,Hangup()

 

 

Example, console:

 

Log first channel:

[2012-08-01 14:29:44] DEBUG[6679] pbx.c: Launching 'Dial'

[2012-08-01 14:29:44] VERBOSE[6679] pbx.c:     -- Executing
[21411615 at test_outgoing:1] Dial("Local/21411615 at
test_outgoing-cb92;2",
"khomp/gpstn/21411615,120,Ttr") in new stack

[2012-08-01 14:29:44] DEBUG[6679] devicestate.c: device 'Khomp/B1C0'
state
'1'

[2012-08-01 14:29:44] DEBUG[6679] rtp_engine.c: Can't find native functions
for channel 'Khomp/B1C0-0.0'

[2012-08-01 14:29:44] DEBUG[6679] rtp_engine.c: Seeded SDP of
'Khomp/B1C0-0.0' with that of 'Local/21411615 at
test_outgoing-cb92;2'

[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDTIME.

[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
ANSWEREDTIME.

[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDPEERNAME.

[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALEDPEERNUMBER.

[2012-08-01 14:29:44] DEBUG[6679] channel.c: Not copying variable
DIALSTATUS.

[2012-08-01 14:29:44] VERBOSE[6679] app_dial.c:     -- Called
khomp/gpstn/21411615

[2012-08-01 14:29:52] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0 is
ringing

[2012-08-01 14:29:53] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0 is
making progress passing it to Local/21411615 at test_outgoing-cb92;2

[2012-08-01 14:30:02] VERBOSE[6679] app_dial.c:     -- Khomp/B1C0-0.0
answered Local/21411615 at test_outgoing-cb92;2

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
write format slin

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
read format slin

[2012-08-01 14:30:02] DEBUG[6679] features.c: Removing dialed interfaces
datastore on Khomp/B1C0-0.0 since we're bridging

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Planning to masquerade channel
Khomp/B1C0-0.0 into the structure of Local/21411615 at test_outgoing-cb92;1

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Done planning to masquerade
channel Khomp/B1C0-0.0 into the structure of
Local/21411615 at test_outgoing-cb92;1

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
write format slin

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Set channel Khomp/B1C0-0.0 to
read format slin

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Putting channel Khomp/B1C0-0.0
in slin/slin formats

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Done Masquerading
Khomp/B1C0-0.0 (6)

[2012-08-01 14:30:02] DEBUG[6679] chan_local.c: Not posting to
'Local/21411615 at test_outgoing-cb92;2' queue since already masqueraded
out

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Bridge stops because we're
zombie or need a soft hangup: c0=Local/21411615 at test_outgoing-cb92;2,
c1=Local/21411615 at test_outgoing-cb92;1<ZOMBIE>, flags: No,Yes,Yes,Yes

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Bridge stops bridging channels
Local/21411615 at test_outgoing-cb92;2 and
Local/21411615 at test_outgoing-cb92;1<ZOMBIE>

[2012-08-01 14:30:02] DEBUG[6679] cdr_mysql.c: Inserting a CDR record.

[2012-08-01 14:30:02] DEBUG[6679] cdr_mysql.c: SQL command as follows:
INSERT INTO cdr
(`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`
lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`) VALUES
('2012-08-01 14:29:44','\"ELCO Test\"
<123456789>','123456789','21411615','test_outgoing','Local/21411615
at test_out
going-cb92;2','Khomp/B1C0-0.0','Dial','khomp/gpstn/21411615,120,Ttr','18','0
','ANSWERED','3','1343842184.19303')

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Hanging up zombie
'Local/21411615 at test_outgoing-cb92;1<ZOMBIE>'

[2012-08-01 14:30:02] DEBUG[6679] app_dial.c: Exiting with
DIALSTATUS=ANSWER.

[2012-08-01 14:30:02] DEBUG[6679] pbx.c: Spawn extension
(test_outgoing,21411615,1) exited non-zero on
'Local/21411615 at test_outgoing-cb92;2'

[2012-08-01 14:30:02] VERBOSE[6679] pbx.c:   == Spawn extension
(test_outgoing, 21411615, 1) exited non-zero on
'Local/21411615 at test_outgoing-cb92;2'

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Soft-Hanging up channel
'Local/21411615 at test_outgoing-cb92;2'

[2012-08-01 14:30:02] DEBUG[6679] channel.c: Hanging up channel
'Local/21411615 at test_outgoing-cb92;2'

 

Log second channel:

[2012-08-01 14:29:44] VERBOSE[6678] pbx_spool.c:     -- Attempting call on
local/21411615 at test_outgoing for 21411615 at test_ivr:1 (Retry 1)

[2012-08-01 14:30:02] DEBUG[6678] pbx.c: Launching 'Answer'

[2012-08-01 14:30:02] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:1] Answer("Local/21411615 at
test_outgoing-cb92;1", "") in
new stack

[2012-08-01 14:30:02] DEBUG[6678] pbx.c: Launching 'Wait'

[2012-08-01 14:30:02] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:2] Wait("Local/21411615 at
test_outgoing-cb92;1", "30") in
new stack

[2012-08-01 14:30:02] DEBUG[6678] channel.c: Scheduling timer at (50
requested / 50 actual) timer ticks per second

[2012-08-01 14:30:02] DEBUG[6678] channel.c: Started silence generator on
'Local/21411615 at test_outgoing-cb92;1'

[2012-08-01 14:30:34] DEBUG[6678] channel.c: Scheduling timer at (0
requested / 0 actual) timer ticks per second

[2012-08-01 14:30:34] DEBUG[6678] channel.c: Stopped silence generator on
'Khomp/B1C0-0.0'

[2012-08-01 14:30:34] DEBUG[6678] pbx.c: Launching 'Hangup'

[2012-08-01 14:30:34] VERBOSE[6678] pbx.c:     -- Executing
[21411615 at test_ivr:3] Hangup("Khomp/B1C0-0.0", "") in new
stack

[2012-08-01 14:30:34] DEBUG[6678] pbx.c: Spawn extension
(test_ivr,21411615,3) exited non-zero on 'Khomp/B1C0-0.0'

[2012-08-01 14:30:34] VERBOSE[6678] pbx.c:   == Spawn extension (test_ivr,
21411615, 3) exited non-zero on 'Khomp/B1C0-0.0'

[2012-08-01 14:30:34] DEBUG[6678] channel.c: Soft-Hanging up channel
'Khomp/B1C0-0.0'

[2012-08-01 14:30:34] DEBUG[6678] channel.c: Hanging up channel
'Khomp/B1C0-0.0'

[2012-08-01 14:30:34] NOTICE[6678] pbx_spool.c: Call completed to
local/21411615 at test_outgoing

 

 

Example, table cdr (MySQL):

 

*************************** 46. row ***************************

     calldate: 2012-08-01 14:29:44

         clid: "ELCO Test" <123456789>

          src: 123456789

          dst: 21411615

     dcontext: test_outgoing

      channel: Local/21411615 at test_outgoing-cb92;2

   dstchannel: Khomp/B1C0-0.0

      lastapp: Dial

     lastdata: khomp/gpstn/21411615,120,Ttr

     duration: 18

      billsec: 0

  disposition: ANSWERED

     amaflags: 3

  accountcode:

     uniqueid: 1343842184.19303

    userfield:

          did:

recordingfile:

 

 

 

 

Best Regards,

 

-- 
Rodrigo Lang

-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20120801/d7850719/attachment.htm>

Rodrigo Lang

2012-Aug-01 19:11 UTC

head link

[asterisk-users] Problem with callfile and CDR

Ow, thanks. Solve the issue!

Adding /n at the end it worked correctly.

Example:
Channel: Local/21411615 at test_outgoing/n


Thanks again!

Best regards,
Rodrigo Lang.


2012/8/1 <isrlgb at gmail.com>
> add a /n at the end of the local channel
> -----Original Message-----
> From: Rodrigo Lang <rodrigoferreiralang at gmail.com>
> Sender: asterisk-users-bounces at lists.digium.com
> Date: Wed, 1 Aug 2012 15:53:44
> To: Asterisk Users Mailing List - Non-Commercial Discussion<
> asterisk-users at lists.digium.com>
> Reply-To: Asterisk Users Mailing List - Non-Commercial Discussion
>         <asterisk-users at lists.digium.com>
> Subject: Re: [asterisk-users] Problem with callfile and CDR
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
> New to Asterisk? Join us for a live introductory webinar every Thurs:
>                http://www.asterisk.org/hello
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
>
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
> New to Asterisk? Join us for a live introductory webinar every Thurs:
>                http://www.asterisk.org/hello
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
>


-- 
Rodrigo Lang
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20120801/9e77ca9c/attachment.htm>

Possibly Parallel Threads

Search for more apparently analagous threads

asterisk users - Aug 2012 - Problem with callfile and CDR

[asterisk-users] Problem with callfile and CDR

[asterisk-users] Problem with callfile and CDR

[asterisk-users] Problem with callfile and CDR

Possibly Parallel Threads