I noticed a problem this morning with our cdr logging. We have a cron
job that places a call file into the spool directory having asterisk
call itself to check to make sure its still handling incoming calls
correctly, then queries the CDR database in mysql and makes sure that
appropriate records exist.
I can confirm that the call is happening correctly, but I'm missing
records in the database:
select calldate, disposition, lastapp, channel from cdr where clid =
"xxxxxxxxxx" order by calldate desc limit 45;
| 2005-02-14 11:34:04 | ANSWERED | Hangup | Zap/2-1 |
| 2005-02-14 11:34:03 | ANSWERED | BackGround | Zap/3-1 |
| 2005-02-14 11:32:03 | ANSWERED | Hangup | Zap/1-1 |
| 2005-02-14 11:30:04 | ANSWERED | Hangup | Zap/3-1 |
| 2005-02-14 11:30:02 | ANSWERED | BackGround | Zap/4-1 |
Notice the missing BackGround entry from the 11:32 call.
The asterisk console logs for this same duration:
^M -- Attempting call on Zap/g1/2144680768 for 6501@neospire:1 (Retry 1)
Using channel 1
Urgent handler
Urgent handler
^M -- Remote UNIX connection disconnected
^M -- Accepting call from '' to '2144680768' on channel 0/3,
span 1
Enabled echo cancellation on channel 3
Launching 'Goto'
^M -- Executing Goto("Zap/3-1", "neospire|s|1") in new
stack
^M -- Goto (neospire,s,1)
Launching 'Wait'
^M -- Executing Wait("Zap/3-1", "1") in new stack
Difference is 1120, ms is 160
Write returned -1 (Resource temporarily unavailable) on channel 2
Write returned -1 (Resource temporarily unavailable) on channel 2
Write returned -1 (Resource temporarily unavailable) on channel 2
Write returned -1 (Resource temporarily unavailable) on channel 2
Launching 'Answer'
^M -- Executing Answer("Zap/3-1", "") in new stack
Urgent handler
Launching 'Wait'
^M -- Executing Wait("Zap/3-1", "1") in new stack
Enabled echo cancellation on channel 1
Dropping duplicate answer!
^M > Channel Zap/1-1 was answered.
Launching 'StopMonitor'
^M -- Executing StopMonitor("Zap/1-1", "") in new stack
Launching 'Answer'
^M -- Executing Answer("Zap/1-1", "") in new stack
Launching 'Playback'
^M -- Executing Playback("Zap/1-1", "30seconds") in new
stack
Set channel Zap/1-1 to write format gsm
Scheduling timer at 160 sample intervals
^M -- Playing '30seconds' (language 'en')
Launching 'DigitTimeout'
^M -- Executing DigitTimeout("Zap/3-1", "5") in new stack
^M -- Set Digit Timeout to 5
Launching 'ResponseTimeout'
^M -- Executing ResponseTimeout("Zap/3-1", "10") in new
stack
^M -- Set Response Timeout to 10
Launching 'BackGround'
^M -- Executing BackGround("Zap/3-1",
"neo-welcome-options") in new stack
Set channel Zap/3-1 to write format gsm
Scheduling timer at 160 sample intervals
^M -- Playing 'neo-welcome-options' (language 'en')
Scheduling timer at 0 sample intervals
Scheduling timer at 0 sample intervals
Set channel Zap/3-1 to write format ulaw
Scheduling timer at 0 sample intervals
Scheduling timer at 0 sample intervals
Set channel Zap/1-1 to write format ulaw
Launching 'Hangup'
^M -- Executing Hangup("Zap/1-1", "") in new stack
Spawn extension (neospire,6501,4) exited non-zero on 'Zap/1-1'
cdr_mysql: inserting a CDR record.
cdr_mysql: SQL command as follows: INSERT INTO cdr
(calldate,clid,src,dst,dcont
ext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,ac
countcode,uniqueid,userfield) VALUES ('2005-02-14
11:32:03','2147201442','214720
1442','6501','neospire',
'Zap/1-1','','Hangup','',16,16,'ANSWERED',3,'','1108402
321.10557','')
Hanging up channel 'Zap/1-1'
zt_hangup(Zap/1-1)
Set option AUDIO MODE, value: ON(1) on Zap/1-1
Hangup: channel: 1 index = 0, normal = 13, callwait = -1, thirdcall = -1
Not yet hungup... Calling hangup once with icause, and clearing call
Urgent handler
disabled echo cancellation on channel 1
Set option TDD MODE, value: OFF(0) on Zap/1-1
Updated conferencing on 1, with 0 conference users
Set option AUDIO MODE, value: OFF(0) on Zap/1-1
disabled echo cancellation on channel 1
^M -- Hungup 'Zap/1-1'
Urgent handler
Call completed to Zap/g1/2144680768
^M -- Channel 0/3, span 1 got hangup
cdr_mysql: inserting a CDR record.
cdr_mysql: SQL command as follows: INSERT INTO cdr
(calldate,clid,src,dst,dcont
ext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,ac
countcode,uniqueid,userfield) VALUES ('2005-02-14
11:32:01','','','s','neospire'
,
'Zap/3-1','','BackGround','neo-welcome-options',18,17,'ANSWERED',3,'','1108402
321.10558','')
Hanging up channel 'Zap/3-1'
zt_hangup(Zap/3-1)
Set option AUDIO MODE, value: ON(1) on Zap/3-1
Hangup: channel: 3 index = 0, normal = 15, callwait = -1, thirdcall = -1
Not yet hungup... Calling hangup once with icause, and clearing call
Urgent handler
disabled echo cancellation on channel 3
Set option TDD MODE, value: OFF(0) on Zap/3-1
Updated conferencing on 3, with 0 conference users
Set option AUDIO MODE, value: OFF(0) on Zap/3-1
disabled echo cancellation on channel 3
^M -- Hungup 'Zap/3-1'
Notice that there are two inserts in the above logs, yet only one is
actually inserted into the db.
It should also be noted that we're running the latest asterisk versions
on all applicable software. (ast 1.0.5, ast-extras 1.0.1, etc).
Has anyone seen anything similar?
Paul
