[Asterisk-Users] 500 "Internal Server Error"
Stephen Malenshek
stephen at valuelinx.net
Tue Dec 28 20:04:15 MST 2004
I am working with implementing Asterisk between four different AS5400's
located in multiple sites with different PSTN gateways. I can get two
of them to work without a problem, but I am getting the following on the
others when I make a SIP call to the other two sites.
Got SIP response 500 "Internal Server Error" back from 10.1.3.28
SIP/alma-1b77 is circuit-busy
Everyone is busy/congested at this time (1:0/1/0)
The strange thing is that one of the access servers is working fine with
the exact same configs in every way. I have moved both routers to the
same IOS version which is:
IOS (tm) 5400 Software (C5400-JS-M), Version 12.2(2)XB15
I have included a copy of the dial-peers that are specified on the
non-functional access server, and I have double checked the configs
against the circuitassignments and they are correct.
!
dial-peer voice 63201 pots
destination-pattern 632....
no digit-strip
port 1/0:0
!
dial-peer voice 63202 pots
destination-pattern 632....
no digit-strip
port 1/2:0
!
dial-peer voice 63203 pots
destination-pattern 632....
no digit-strip
port 1/3:0
!
dial-peer voice 63204 pots
destination-pattern 632....
no digit-strip
port 1/4:0
!
dial-peer voice 63401 pots
destination-pattern 634....
no digit-strip
port 1/5:0
!
dial-peer voice 63402 pots
destination-pattern 634....
no digit-strip
port 1/6:0
!
dial-peer voice 99701 pots
destination-pattern 997....
no digit-strip
port 1/0:0
!
dial-peer voice 99702 pots
destination-pattern 997....
no digit-strip
port 1/2:0
!
dial-peer voice 99703 pots
destination-pattern 997....
no digit-strip
port 1/3:0
!
dial-peer voice 99704 pots
destination-pattern 997....
no digit-strip
port 1/4:0
!
dial-peer voice 43001 pots
destination-pattern 430....
no digit-strip
port 1/0:0
!
dial-peer voice 43002 pots
destination-pattern 430....
no digit-strip
port 1/2:0
!
dial-peer voice 43003 pots
destination-pattern 430....
no digit-strip
port 1/3:0
!
dial-peer voice 43004 pots
destination-pattern 430....
no digit-strip
port 1/4:0
!
dial-peer voice 67001 pots
destination-pattern 670....
no digit-strip
port 1/0:0
!
dial-peer voice 67002 pots
destination-pattern 670....
no digit-strip
port 1/2:0
!
dial-peer voice 67003 pots
destination-pattern 670....
no digit-strip
port 1/3:0
!
dial-peer voice 67004 pots
destination-pattern 670....
no digit-strip
port 1/4:0
!
sip-ua
max-forwards 15
retry invite 10
timers trying 1000
timers expires 300000
sip-server ipv4:XXX.XXX.XXX.XXX:5060
no transport tcp
!
The following is the debugs I collected from the access server with the
problem:
6936: 006932: Dec 29 01:48:05.075: Received:
6937: INVITE sip:6329900 at 10.1.3.28 SIP/2.0
6938: Via: SIP/2.0/UDP 65.67.76.41:5060;branch=z9hG4bK72629db3
6939: From: "5462000" <sip:5462000 at 65.67.76.41>;tag=as3e9b26ba
6940: To: <sip:6329900 at 10.1.3.28>
6941: Contact: <sip:5462000 at 65.67.76.41>
6942: Call-ID: 023bbbe91f61ad7529d14ffb2be36b0d at 65.67.76.41
6943: CSeq: 102 INVITE
6944: User-Agent: Asterisk PBX
6945: Date: Wed, 29 Dec 2004 01:47:54 GMT
6946: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
6947: Content-Type: application/sdp
6948: Content-Length: 179
6949:
6950: v=0
6951: o=root 9671 9671 IN IP4 65.67.76.41
6952: s=session
6953: c=IN IP4 65.67.76.41
6954: t=0 0
6955: m=audio 11980 RTP/AVP 0 3
6956: a=rtpmap:0 PCMU/8000
6957: a=rtpmap:3 GSM/8000
6958: a=silenceSupp:off - - - -
6959:
6960: 006933: Dec 29 01:48:05.075: HandleUdpSocketReads :Msg enqueued
for SPI with IPaddr: 65.67.76.41:5060
6961: 006934: Dec 29 01:48:05.075: CCSIP-SPI-CONTROL:
sipSPISipIncomingCall
6962: 006935: Dec 29 01:48:05.075: 0x63CEA7B8 : State change from
(STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
6963: 006936: Dec 29 01:48:05.075: CCSIP-SPI-CONTROL:
act_idle_new_message
6964: 006937: Dec 29 01:48:05.075: CCSIP-SPI-CONTROL: Converting
TimeZone CST to SIP default timezone = GMT
6965: 006938: Dec 29 01:48:05.075: CCSIP-SPI-CONTROL:
sact_idle_new_message_invite
6966: 006939: Dec 29 01:48:05.075: CCSIP-SPI-CONTROL: sip_stats_method
6967: 006940: Dec 29 01:48:05.075: sipSPIGetSdpBody : Parse incoming
session description
6968: 006941: Dec 29 01:48:05.079: Info: Media ip address/domain name
in c line: 65.67.76.41
6969:
6970: 006942: Dec 29 01:48:05.079: sact_idle_new_message_invite: non
dial peer leg - using RTP Supported Codecs
6971:
6972: 006943: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 18
6973:
6974: 006944: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 0
6975:
6976: 006945: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 8
6977:
6978: 006946: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 4
6979:
6980: 006947: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 2
6981:
6982: 006948: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 15
6983:
6984: 006949: Dec 29 01:48:05.079: sact_idle_new_message_invite: RTP
Preferred Codecs supported by GW 3
6985:
6986: 006950: Dec 29 01:48:05.079: sipSPIDoFaxMediaNegotiation()
6987: 006951: Dec 29 01:48:05.079: sipSPIDoMediaNegotiation: Codec
Negotiation Successful
6988:
6989: 006952: Dec 29 01:48:05.079: sipSPIDoMediaNegotiation: DTMF Relay
mode : Inband Voice
6990:
6991: 006953: Dec 29 01:48:05.079: sipSPIUpdCcbWithSdpInfo: SDP Media
Information:
6992: Negotiated Codec : g711ulaw , bytes :160
6993: Early Media : 0
6994: Delayed Media : 0
6995: Bridge Done : 0
6996: New Media : 0
6997: DSP DNLD Reqd : 0
6998: Media Dest addr/Port : 65.67.76.41:11980
6999:
7000: 006954: Dec 29 01:48:05.079: sipSPIHandleInviteMedia:
7001: Negotiated Codec : g711ulaw, bytes :160
7002: Preferred Codec : g729r8, bytes :20
7003: Preferred DTMF relay : 0
7004: Negotiated DTMF relay : 0
7005: Preferred and Negotiated NTE payloads: 101 0
7006:
7007: 006955: Dec 29 01:48:05.079: sipSPIDoQoSNegotiation - SDP body
with media description
7008: 006956: Dec 29 01:48:05.079: sipSPIDoQoSNegotiation: Best effort
call
7009: 006957: Dec 29 01:48:05.079: sipSPIAddBillingInfoToCcb: sipCallId
for billing records = 023bbbe91f61ad7529d14ffb2be36b0d at 65.67.76.41
7010: 006958: Dec 29 01:48:05.079: ****Adding to UAS Request table
7011:
7012: 006959: Dec 29 01:48:05.079: adding call id B to table
7013:
7014: 006960: Dec 29 01:48:05.079: Queued event from SIP SPI :
SIPSPI_EV_SEND_MESSAGE
7015: 006961: Dec 29 01:48:05.079: CCSIP-SPI-CONTROL:
sip_stats_status_code
7016: 006962: Dec 29 01:48:05.079: ****Adding to UAS Response table
7017:
7018: 006963: Dec 29 01:48:05.079: Previous Hop 65.67.76.41:5060
7019:
7020: 006964: Dec 29 01:48:05.079: 0x63CEA7B8 : State change from
(STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
7021: 006965: Dec 29 01:48:05.083: Sent:
7022: SIP/2.0 100 Trying
7024: From: "5462000" <sip:5462000 at 65.67.76.41>;tag=as3e9b26ba
7025: To: <sip:6329900 at 10.1.3.28>;tag=6231D0-207E
7027: Call-ID: 023bbbe91f61ad7529d14ffb2be36b0d at 65.67.76.41
7028: Server: Cisco-SIPGateway/IOS-12.x
7030: Content-Length: 0
7032:
7034: 006966: Dec 29 01:48:05.083: Queued event From SIP SPI to
CCAPI/DNS : SIPSPI_EV_CC_CALL_PROCEEDING
7035: 006967: Dec 29 01:48:05.083: ccsip_report_digit_control: enable=0:
7036: 006968: Dec 29 01:48:05.083: ccsip_report_digit_control:
disabled.
7038: 006970: Dec 29 01:48:05.083: ccsip_report_digit_control: enable=0:
7040: 006972: Dec 29 01:48:05.083: CCSIP-SPI-CONTROL:
act_recdinvite_proceeding
7041: 006973: Dec 29 01:48:05.083: CCSIP-SPI-CONTROL:
act_recdinvite_proceeding
7042: 006974: Dec 29 01:48:05.083: Queued event From SIP SPI to
CCAPI/DNS : SIPSPI_EV_CC_CALL_PROCEEDING
7044: 006976: Dec 29 01:48:05.083: ccsip_report_digit_control:
disabled.
7045: 006977: Dec 29 01:48:05.083: Queued event From SIP SPI to
CCAPI/DNS : SIPSPI_EV_CC_CALL_PROCEEDING
7046: 006978: Dec 29 01:48:05.083: ccsip_report_digit_control: enable=0:
7050: 006982: Dec 29 01:48:05.087: Queued event From SIP SPI to
CCAPI/DNS : SIPSPI_EV_CC_CALL_DISCONNECT
7052: 006984: Dec 29 01:48:05.087: Queued event from SIP SPI :
SIPSPI_EV_SEND_MESSAGE
7053: 006985: Dec 29 01:48:05.087: CCSIP-SPI-CONTROL:
sip_stats_status_code
7055: 006987: Dec 29 01:48:05.087: Sent:
7056: SIP/2.0 500 Internal Server Error
7057: Via: SIP/2.0/UDP 65.67.76.41:5060;branch=z9hG4bK72629db3
7058: From: "5462000" <sip:5462000 at 65.67.76.41>;tag=as3e9b26ba
7059: To: <sip:6329900 at 10.1.3.28>;tag=6231D0-207E
7060: Date: Wed, 29 Dec 2004 01:48:05 GMT
7061: Call-ID: 023bbbe91f61ad7529d14ffb2be36b0d at 65.67.76.41
7062: Server: Cisco-SIPGateway/IOS-12.x
7063: CSeq: 102 INVITE
7064: Content-Length: 0
7065:
7066:
7067:
7068: 006988: Dec 29 01:48:05.119: Received:
7069: ACK sip:6329900 at 10.1.3.28 SIP/2.0
7070: Via: SIP/2.0/UDP 65.67.76.41:5060;branch=z9hG4bK72629db3
7071: From: "5462000" <sip:5462000 at 65.67.76.41>;tag=as3e9b26ba
7072: To: <sip:6329900 at 10.1.3.28>;tag=6231D0-207E
7073: Contact: <sip:5462000 at 65.67.76.41>
7074: Call-ID: 023bbbe91f61ad7529d14ffb2be36b0d at 65.67.76.41
7076: User-Agent: Asterisk PBX
7078:
7080:
7081: 006989: Dec 29 01:48:05.119: HandleUdpSocketReads :Msg enqueued
for SPI with IPaddr: 65.67.76.41:5060
7083:
7084: 006991: Dec 29 01:48:05.119: CCSIP-SPI-CONTROL:
act_disconnecting_new_message
7087: 006994: Dec 29 01:48:05.119: CCSIP-SPI-CONTROL: sip_stats_method
7089: 006996: Dec 29 01:48:05.119: sipSPIIcpifUpdate :CallState: 2
Playout: 0 DiscTime:643532 ConnTime 0
7090:
7092: 006998: Dec 29 01:48:05.119: The Call Setup Information is :
7094: State of The Call : STATE_DEAD
7096: Calling Number : 5462000
7097: Called Number : 6329900
7098: Negotiated Codec : g711ulaw
7099: Negotiated Codec Bytes : 160
7102:
7103: 006999: Dec 29 01:48:05.119:
7104: Source IP Address (Sig ): 10.1.3.28
7105: Source IP Address (Media): 0.0.0.0
7106: Source IP Port (Media): 0
7107: Destn IP Address (Media): 65.67.76.41
7108: Destn IP Port (Media): 11980
7109: Destn SIP Req Addr:Port : 65.67.76.41:0
7110: Destn SIP Resp Addr:Port : 65.67.76.41:5060
7111: Destination Name : 65.67.76.41
7112:
7113: 007000: Dec 29 01:48:05.119:
7114: Disconnect Cause (CC) : 63
7115: Disconnect Cause (SIP) : 500
7116:
7117: 007001: Dec 29 01:48:05.119: ****Deleting from UAS Request table
7118:
7119: 007002: Dec 29 01:48:05.119: ****Deleting from UAS Response table
7120:
7121: 007003: Dec 29 01:48:05.119: Removing call id B
7122:
7123: 007004: Dec 29 01:48:05.123: freeing ccb 63CEA7B8
7124:
The only difference that I can see is that the non-functional access
server is 3 hops from the VoIP server and the ones that are functional
are only 2 hops.... I do not think this makes any difference, but I
thought I would include it.
Thanks for all your assistance in advance.
Stephen
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20041228/393aed60/attachment.htm
More information about the asterisk-users
mailing list