[cisco-voip] Fax dialing issue (FXS direct to PRI, no CUCM involved)

Thu Jun 21 09:40:19 EDT 2012

My customer has a fax machine, connected to a 2911 via FXS. PSTN is via PRI
on the same router.

They receive faxes without issue. We have found that for outbound calls, as
soon as they dial '8' (outbound dial code), the call goes to reorder/fast
busy. Trying to figure out where this is going wrong.

Here is some (hopefully) relevant config:

voice service pots
 fax rate disable
!
<...>
voice translation-rule 4
 rule 1 /^\+\(.*\)/ /\1/
!
!
voice translation-profile ANI
 translate calling 4
!
<...>
!
dial-peer voice 12 pots
 trunkgroup PRI-PSTN
 description Local 7-digit
 destination-pattern 8[2-9]......
 forward-digits 7
!
dial-peer voice 100 voip
 description Default Inbound and DID to CUPS
 destination-pattern +1T
 session protocol sipv2
 session target sip-server
 incoming called-number .
 voice-class codec 1
 dtmf-relay rtp-nte sip-notify
 no vad
!
dial-peer voice 9549 pots
 destination-pattern +1XXXYYYZZZZ
 port 0/2/0
!

'debug voip dialpeer inout' result (AAABBBB is the dialed number,
+1XXXYYYZZZZ is the number of the fax machine):

027441: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=8AAABBBB, Called Number=8AAABBBB, Peer Info
Type=DIALPEER_INFO_SPEECH
027442: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8AAABBBB
027443: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=8AAABBBB, Expanded String=8AAABBBB, Calling Number=8AAABBBBT
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
027444: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=12 Is Matched
027445: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
027446: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=8AAABBBB, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
027447: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=12
027448: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search
Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
027449: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
027450: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
027451: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit at 6520
027452: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8AAABBBB, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search
Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
027453: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ANSWER; Calling Number=8AAABBBB
027454: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027455: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=8AAABBBBT
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027456: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Result=-1
027457: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027458: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ORIGINATE; Calling Number=8AAABBBB
027459: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027460: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=8AAABBBBT
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027461: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Incoming Dial-peer=12 Is Matched
027462: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027463: Jun 19 15:55:13.138:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
027464: Jun 19 15:55:13.138: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
027465: Jun 19 15:55:13.142:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit at 6520
027466: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8AAABBBB, Peer Info
Type=DIALPEER_INFO_SPEECH
027467: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8AAABBBB
027468: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=8AAABBBB, Expanded String=8AAABBBB, Calling Number=
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
027469: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=12 Is Matched
027470: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
027471: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=8AAABBBB, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
027472: Jun 19 15:55:13.142: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=12
027473: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8AAABBBB, Peer Info
Type=DIALPEER_INFO_SPEECH
027474: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8AAABBBB
027475: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchCore:
   Dial String=8AAABBBB, Expanded String=8AAABBBB, Calling Number=
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
027476: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=12 Is Matched
027477: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
027478: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchSafModulePlugin:
   dialstring=8AAABBBB, saf_enabled=1, saf_dndb_lookup=1, dp_result=0
027479: Jun 19 15:55:13.142: //-1/211DB3058ECD/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=12
027480: Jun 19 15:55:13.218: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=+1XXXYYYZZZZ, Peer Info
Type=DIALPEER_INFO_SPEECH
027481: Jun 19 15:55:13.218: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=+1XXXYYYZZZZ
027482: Jun 19 15:55:13.218: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=+1XXXYYYZZZZ, Expanded String=+1XXXYYYZZZZ, Calling Number=
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
027483: Jun 19 15:55:13.218: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=100 Is Matched
027484: Jun 19 15:55:13.218: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=9549 Is Matched
027485: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
027486: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
027487: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=9549
     2: Dial-peer Tag=100
027488: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=8AAABBBB, Peer Info
Type=DIALPEER_INFO_SPEECH
027489: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=8AAABBBB
027490: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=8AAABBBB, Expanded String=8AAABBBB, Calling Number=
   Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
027491: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Outgoing Dial-peer=12 Is Matched
027492: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
027493: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
027494: Jun 19 15:55:13.222: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=12
027495: Jun 19 15:55:16.882:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=+1XXXYYYZZZZ, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search
Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
027496: Jun 19 15:55:16.882:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ANSWER; Calling Number=+1XXXYYYZZZZ
027497: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027498: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=+1XXXYYYZZZZT
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027499: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Result=-1
027500: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027501: Jun 19 15:55:16.882:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ORIGINATE; Calling Number=+1XXXYYYZZZZ
027502: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027503: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=+1XXXYYYZZZZT
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027504: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Incoming Dial-peer=100 Is Matched
027505: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
   Result=Success(0); Incoming Dial-peer=9549 Is Matched
027506: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027507: Jun 19 15:55:16.882:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=100
027508: Jun 19 15:55:16.882: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
027509: Jun 19 15:55:16.882:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit at 6520
027510: Jun 19 15:55:16.914:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=8[2-9]......, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search
Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
027511: Jun 19 15:55:16.914:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ANSWER; Calling Number=8[2-9]......
027512: Jun 19 15:55:16.914: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027513: Jun 19 15:55:16.914: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=8[2-9]......T
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027514: Jun 19 15:55:16.914: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Result=-1
027515: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027516: Jun 19 15:55:16.918:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Match Rule=DP_MATCH_ORIGINATE; Calling Number=8[2-9]......
027517: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
   Is Incoming=TRUE, Number Expansion=FALSE
027518: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Dial String=, Expanded String=, Calling Number=8[2-9]......T
   Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
027519: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
   Result=-1
027520: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit at 5908

027521: Jun 19 15:55:16.918:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=NO_MATCH(-1) After All Match Rules Attempt
027522: Jun 19 15:55:16.918: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
027523: Jun 19 15:55:16.918:
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit at 6520

-- 
Dave Wolgast
Livonia, NY
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20120621/3fdbe530/attachment.html>