First, my hardware: Wildcard TE405P (3rd Gen) with an Itasic daughterboard, and software: Asterisk version 1.4.22, dahdi-linux-2.1.0.3, dahdi-tools-2.1.0.2
Since upgrading to DAHDI, a strange audio artifact has been noticed by people that receive calls from our switch, via the PRI. SIP-only calls are unaffected, as are IAX trunks. People with SIP accounts on our system cannot hear the artifact, yet the people that they call on the publicly switched telephone network do. What the person at the PSTN end hears is a quiet “vip-vip” sound on occasion. The call is not interrupted, there is no dead air, and it otherwise does not affect the call except by being a little strange and slightly annoying.
This problem can be reproduced reliably by making a SIP->PSTN call (or PSTN->SIP call), then the SIP end placing the call on hold, activating the music-on-hold music. If I do not have some kind of constant noise on the line, then the problem cannot be reliably produced - a dead air call does not generate this noise. However, if you start the music-on-hold at the top of the minute, the noise is generated every minute at exactly :24 and :51 seconds.
I suspect that this is a bug in the DAHDI drivers for this particular card, since the problem did not exist before we upgraded to DAHDI from Zaptel. This is the first version of DAHDI we’ve used.
This is a fairly busy server with client calls being made during my testing, and as such usernames and phone numbers have been protected.
These logs have been created using ‘core set verobse 12’. I’m not about to use ‘set sip debug=anything’ because of the high traffic this host receives. I doubt it would be very helpful anyway as a result.
The changes I have made include:
Removed all (and there were many!) “No matching peer found” messages
Removed all “Wrong Password” messages
Changed phone numbers so that the area code and extension are now the non-existent 123555 area code and extension.
Replaced usernames with USERNAME, but kept the call identification number.
Replaced all IP addresses with Xs.
Replaced the long distance hostname/ip with “longdistancehost”, while keeping the call identification number.
Now, the logs:
-- Executing [1235551192@default:1] Set("SIP/USERNAME-b5ece5d8", "CIDBlock=") in new stack
-- Executing [1235551192@default:2] Dial("SIP/USERNAME-b5ece5d8", "DAHDI/g1/1235551192") in new stack
-- Requested transfer capability: 0x00 - SPEECH
-- Called g1/1235551192
-- DAHDI/1-1 is proceeding passing it to SIP/USERNAME-b5ece5d8
-- Executing [1235551192@local:1] Dial("DAHDI/23-1", "DAHDI/g1/1235550673|150") in new stack
-- Requested transfer capability: 0x00 - SPEECH
-- Called g1/1235550673
-- Accepting call from '1235551190' to '1235551192' on channel 0/23, span 1
-- DAHDI/2-1 is proceeding passing it to DAHDI/23-1
-- DAHDI/2-1 is ringing
-- DAHDI/1-1 is ringing
-- DAHDI/2-1 answered DAHDI/23-1
-- Native bridging DAHDI/23-1 and DAHDI/2-1
Unable to handle return result on switchtype 3!
– DAHDI/1-1 answered SIP/USERNAME-b5ece5d8
– Started music on hold, class ‘default’, on DAHDI/1-1
– Channel 0/14, span 1 got hangup request, cause 16
== Spawn extension (local, 1235550896, 1) exited non-zero on ‘DAHDI/14-1’
– Hungup ‘DAHDI/14-1’
– Executing [1235551192@default:1] Set(“SIP/USERNAME-b5564d00”, “CIDBlock=”) in new stack
– Executing [1235551192@default:2] Dial(“SIP/USERNAME-b5564d00”, “DAHDI/g1/1235551192”) in new stack
– Requested transfer capability: 0x00 - SPEECH
– Called g1/1235551192
– DAHDI/4-1 is proceeding passing it to SIP/USERNAME-b5564d00
– Executing [1235551192@local:1] Dial(“DAHDI/22-1”, “DAHDI/g1/1235550673|150”) in new stack
– Requested transfer capability: 0x00 - SPEECH
– Called g1/1235550673
– Accepting call from ‘1235553912’ to ‘1235551192’ on channel 0/22, span 1
– DAHDI/5-1 is proceeding passing it to DAHDI/22-1
– DAHDI/5-1 is ringing
– DAHDI/4-1 is ringing
– Executing [11235555708@default:1] Set(“SIP/USERNAME-b5e91bf0”, “CIDBlock=”) in new stack
– Executing [11235555708@default:2] NoOp(“SIP/USERNAME-b5e91bf0”, “China motion NORTH AMERICAN LD”) in new stack
– Executing [11235555708@default:3] Dial(“SIP/USERNAME-b5e91bf0”, “SIP/123555XXXX@longdistancehost”) in new stack
– Called 123555XXXX@longdistancehost
– SIP/longdistancehost-08a624b0 is making progress passing it to SIP/USERNAME-b5e91bf0
voip2*CLI>
noise heard in previous second here
voip2CLI>
voip2CLI>
voip2CLI>
voip2CLI>
– DAHDI/5-1 answered DAHDI/22-1
– Native bridging DAHDI/22-1 and DAHDI/5-1
Unable to handle return result on switchtype 3!
– DAHDI/4-1 answered SIP/USERNAME-b5564d00
[Feb 18 12:27:43] NOTICE[19517]: rtp.c:788 process_rfc3389: Comfort noise support incomplete in Asterisk (RFC 3389). Please turn off on client if possible. Client IP: longdistancehost
– Registered SIP ‘USERNAME’ at XXX.XXX.XX.XXX port 5061 expires 3600
– Got SIP response 489 “Bad event” back from XX.XXX.XX.XXX
– Remote UNIX connection
– SIP/longdistancehost-08a624b0 answered SIP/USERNAME-b5e91bf0
– Remote UNIX connection disconnected
– Remote UNIX connection
– Remote UNIX connection disconnected
voip2CLI>
voip2CLI>
voip2*CLI>
It turns out that this was due to a kernel bug that was slowing down the whole system every time the SATA write cache was writing to the drive. The solution was to turn off write caching for all drives like this:
hdparm -W0 /dev/sda
hdparm -W0 /dev/sdb
The kernel bug, including discussion, is available here: