Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
New Member

incoming call problems with sip pbx

hi,

i can call the pbx but i can not receive call from this pbx.

this is the sip trace i capture from the failed call.

023079: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.10.73.5]:5080, local_address:[ - ]

023080: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

023081: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

023082: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

INVITE sip:181@10.10.8.15;user=phone SIP/2.0

Via: SIP/2.0/UDP 10.10.73.5:5080;branch=z9hG4bK-487eba4134c721cb8df7abafa556bccf;rport

From: "carlos parra" <sip:510@localhost>;tag=1088810056

To: <sip:181@10.10.8.15;user=phone>

Call-ID: 577306b6@pbx

CSeq: 31830 INVITE

Max-Forwards: 70

Contact: <sip:510@10.10.73.5:5080;transport=udp>

Supported: 100rel, replaces, norefersub

Allow-Events: refer

Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE

Accept: application/sdp

User-Agent: pbxnsip-PBX/3.4.0.3201

P-Asserted-Identity: "carlos parra" <sip:510@localhost>

Content-Type: application/sdp

Content-Length: 219

v=0

o=- 163466339 163466339 IN IP4 10.10.73.5

s=-

c=IN IP4 10.10.73.5

t=0 0

m=audio 9330 RTP/AVP 8 0 101

a=rtpmap:8 pcma/8000

a=rtpmap:0 pcmu/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=sendrecv

023083: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

023084: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x882434E8) with key=[59212] to table

023085: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...

023086: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.73.5,Port 5080, Transport 1, SentBy Port 5080

023087: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()

023088: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()

023089: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.10.8.15

023090: //-1/E5358C0EA10D/SIP/State/sipSPIChangeState: 0x882434E8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)

023091: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.73.5,Port 5080, Transport 1, SentBy Port 5060

023092: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone COL to SIP default timezone = GMT

023093: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.73.5,Port 5080, Transport 1, SentBy Port 5080

023094: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()

023095: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()

023096: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.10.8.15

023097: //-1/E5358C0EA10D/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Name to carlos parra

023098: //-1/E5358C0EA10D/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Number to 510

023099: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container

023100: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container

023101: //-1/E5358C0EA10D/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.

023102: //-1/E5358C0EA10D/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x882434E8 key=577306b6@pbx181

023103: //-1/E5358C0EA10D/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id

023104: //-1/E5358C0EA10D/SIP/Info/sipSPIMatchSrcIpGroup: Match found on access list

023105: //-1/E5358C0EA10D/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name carlos parra, number 510, Calling oct3 0x00, oct_3a 0x81, Called number 181

023106: //-1/E5358C0EA10D/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:10.10.73.5:5080, Host:10.10.73.5

023107: //-1/E5358C0EA10D/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 510

023108: //-1/E5358C0EA10D/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found

023109: //-1/E5358C0EA10D/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error

023110: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID

023111: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call

023112: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

023113: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()

023114: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()

023115: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.10.8.15

023116: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header

023117: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetSipProfilesTag: voice class SIP Profiles tag is set : 1000

023118: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE

023119: //-1/E5358C0EA10D/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled

023120: //-1/E5358C0EA10D/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0

023121: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: xcoder high-density disabled

023122: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Flow Mode set to FLOW_THROUGH

023123: //-1/E5358C0EA10D/SIP/Info/sipSPIGetCallConfig: Media forking disabled

023124: //-1/E5358C0EA10D/SIP/Info/sipSPIContinueNewMsgInvite: Calling name carlos parra, number 510, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 181, oct3 0x00

023125: //-1/E5358C0EA10D/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE

023126: //-1/E5358C0EA10D/SIP/Info/sipSPIContinueNewMsgInvite: Requires reliable-provisional support

023127: //-1/E5358C0EA10D/SIP/Info/sipSPIValidateRequestUri: Not Enabled

023128: //-1/E5358C0EA10D/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0

023129: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0

023130: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

023131: //135353/E5358C0EA10D/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ

023132: //135353/E5358C0EA10D/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:8BBA103C

023133: //135353/E5358C0EA10D/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header

023134: //135353/E5358C0EA10D/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ

023135: //135353/E5358C0EA10D/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2000

023136: //135353/E5358C0EA10D/SIP/Info/Session-Timer/sipSTSLMain:

SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4

Configured SE:1800, Configured Min-SE:1800

023137: //135353/E5358C0EA10D/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container

023138: //135353/E5358C0EA10D/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container

023139: //135353/E5358C0EA10D/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found

023140: //135353/E5358C0EA10D/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1

023141: //135353/E5358C0EA10D/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 9330

SIP: (135353) Attribute mid, level 1 instance 1 not found.

023142: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()

023143: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()

023144: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.10.8.15

023145: //135353/E5358C0EA10D/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.10.8.15

023146: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec  

023147: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96

023148: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved

                          as its in use by other codec No Codec  

023149: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is  reserved by another application

023150: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98

023151: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101

023152: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:

023153: //135353/E5358C0EA10D/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711ulaw) Negotiation Successful on Static Payload for m-line 1

023154: //135353/E5358C0EA10D/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled

023155: //135353/E5358C0EA10D/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0

023156: //135353/E5358C0EA10D/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1

023157: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec

023158: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec

023159: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98

023160: //135353/E5358C0EA10D/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE

023161: //135353/E5358C0EA10D/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option

023162: //135353/E5358C0EA10D/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.

023163: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0

023164: //135353/E5358C0EA10D/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay

023165: //135353/E5358C0EA10D/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0

023166: //135353/E5358C0EA10D/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1

payload_type=0, codec_bytes=160, codec=g711ulaw, dtmf_relay=rtp-nte

stream_type=voice+dtmf (1), dest_ip_address=10.10.73.5, dest_port=9330

023167: //135353/E5358C0EA10D/SIP/State/sipSPIChangeStreamState: Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING)

023168: //135353/E5358C0EA10D/SIP/Media/sipSPIUpdCallWithSdpInfo:

Preferred Codec        : g729r8, bytes :20

Preferred  DTMF relay  : rtp-nte

Preferred NTE payload  : 101

Early Media            : No

Delayed Media          : No

Bridge Done            : No

New Media              : No

DSP DNLD Reqd          : No

023169: //135353/E5358C0EA10D/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr

023170: //135353/E5358C0EA10D/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.10.8.15

023171: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 135353 peer 0 flags 0x201 state STATE_IDLE

023172: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.

023173: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call

023174: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

CallID 135353, Peer CallID 0, sdp 0x8BC98AB8 channels 0x88244A3C

023175: //135353/E5358C0EA10D/SIP/Info/copy_channels:

callId 135353 size 0 ptr 0x8ADABE40)

023176: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the  switch..

023177: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 8 mline 1

023178: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw

023179: //135353/E5358C0EA10D/SIP/Info/codec_found:

Codec to be matched: 6

023180: //135353/E5358C0EA10D/SIP/Info/codec_found: No match for the codecs found..

023181: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 0 mline 1

023182: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw

023183: //135353/E5358C0EA10D/SIP/Info/codec_found:

Codec to be matched: 5

023184: //135353/E5358C0EA10D/SIP/Info/codec_found:  codecs[i] = 5 & codec = 5 are same..

023185: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5

023186: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20

023187: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=0,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1

023188: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

failed to update call entry

023189: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Adding codec 5 ptype 0 time 20, bytes 160  as channel 0 mline 1 ss 1 10.10.73.5:9330

023190: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:

Hndl ptype 101 mline 1

023191: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 135353, dtmf = 6

023192: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5

023193: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1

023194: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer:

callId 135353 flags 0x100 state STATE_IDLE

023195: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer:

Report initial call media

023196: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x804000C, ccb->pld.flags_ipip 0x201

023197: //135353/E5358C0EA10D/SIP/Info/copy_channels:

callId 135353 size 240 ptr 0x8A7EAB9C)

023198: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer:

CCSIP: Unable to report channel ind

023199: //135353/E5358C0EA10D/SIP/Info/ccsip_update_srtp_caps:  5798: Posting Remote SRTP caps to other callleg.

023200: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind()

023201: //135353/E5358C0EA10D/SIP/Media/sipSPIUpdCallWithSdpInfo:

  Stream type            : voice+dtmf

  Media line             : 1

  State                  : STREAM_ADDING (2)

  Stream address type    : 1

  Callid                 : -1

  Negotiated Codec       : g711ulaw, bytes :160

  Nego. Codec payload    : 0 (tx), 0 (rx)

  Negotiated DTMF relay  : rtp-nte

  Negotiated NTE payload : 101 (tx), 101 (rx)

  Negotiated CN payload  : 0

  Media Srce Addr/Port   : [10.10.8.15]:0

  Media Dest Addr/Port   : [10.10.73.5]:9330

023202: //135353/E5358C0EA10D/SIP/Info/sipSPIHandleInviteMedia:

Negotiated Codec       : g711ulaw, bytes :160

Preferred Codec        : g729r8, bytes :20

Preferred  DTMF relay 1 : 6

Preferred  DTMF relay 2 : 0

Negotiated DTMF relay   : 6

Preferred and Negotiated NTE payloads: 101 101

Preferred and Negotiated NSE payloads: 100 0

Preferred and Negotiated Modem Relay: 0 0

Preferred and Negotiated V150.1 Modem Passthrough: 0 0

Preferred and Negotiated V150.1 Modem Relay: 0 0

Preferred and Negotiated Modem Relay GwXid: 1 0

023203: //135353/E5358C0EA10D/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1

023204: //135353/E5358C0EA10D/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort

023205: //135353/E5358C0EA10D/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active

023206: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16632 for stream 1

023207: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16632

023208: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1

023209: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16632

023210: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateSrcSdpVariablePart:

SIP update src sdp, negoitated codec 5, payload type 0

023211: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101

023212: //135353/E5358C0EA10D/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 577306b6@pbx

023213: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container

023214: //135353/E5358C0EA10D/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found

023215: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0

023216: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0

023217: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled

023218: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo

023219: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,

023220: //135353/E5358C0EA10D/SIP/Info/sipSPIShrlCall: Check peer: 1000 for Shared-Line call, callid: 135353

023221: //135353/E5358C0EA10D/SIP/Info/ccsip_set_bearer_capability:

   Bearer Capability: Speech (0x00)

023222: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container

023223: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container

023224: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message

023225: //135353/E5358C0EA10D/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_INTERNAL_ERR

023226: //135353/E5358C0EA10D/SIP/Info/sipSPIContinueNewMsgInvite: Application Layer internal request

023227: //135353/E5358C0EA10D/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.

023228: //135353/E5358C0EA10D/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x882434E8 key=577306b6@pbxDA5EFE14-803

023229: //135353/E5358C0EA10D/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP

023230: //135353/E5358C0EA10D/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:500, container:8BBA54A4

023231: //135353/E5358C0EA10D/SIP/Info/Session-Timer/sipSTSLMain:

SE: 0;refresher:none peer refresher:none, flags:0, posted event:E_STSL_INVALID_PEER_EVENT, reason:4

Configured SE:1800, Configured Min-SE:1800

023232: //135353/E5358C0EA10D/SIP/Info/sipSPISendInviteResponse: Associated container=0x8BBA54A4 to Invite Response 500

023233: //135353/E5358C0EA10D/SIP/Transport/sipSPITransportSendMessage: msg=0x8AE62848, addr=10.10.73.5, port=5080, sentBy_port=5080, local_addr=, is_req=0, transport=1, switch=0, callBack=0x8137C6E4

023234: //135353/E5358C0EA10D/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately

023235: //135353/E5358C0EA10D/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0

023236: //135353/E5358C0EA10D/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x8AE62848 to default port=5080

023237: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:10.10.73.5, rport:5080 with laddr:

023238: //135353/E5358C0EA10D/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x8AE62848

023239: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AE62848, addr=10.10.73.5, port=5080, local_addr=, connId=4 for UDP

023240: //135353/E5358C0EA10D/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response

023241: //135353/E5358C0EA10D/SIP/State/sipSPIChangeState: 0x882434E8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_DISCONNECTING, SUBSTATE_NONE)

023242: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Sent:

SIP/2.0 500 Internal Server Error

Via: SIP/2.0/UDP 10.10.73.5:5080;branch=z9hG4bK-487eba4134c721cb8df7abafa556bccf;rport

From: "carlos parra" <sip:510@localhost>;tag=1088810056

To: <sip:181@10.10.8.15;user=phone>;tag=DA5EFE14-803

Date: Tue, 22 Feb 2011 23:04:11 GMT

Call-ID: 577306b6@pbx

CSeq: 31830 INVITE

Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0

023243: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [10.10.73.5]:5080, local_address:[ - ]

023244: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1

023245: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0

023246: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:

Received:

ACK sip:181@10.10.8.15;user=phone SIP/2.0

Via: SIP/2.0/UDP 10.10.73.5:5080;branch=z9hG4bK-487eba4134c721cb8df7abafa556bccf;rport

From: "carlos parra" <sip:510@localhost>;tag=1088810056

To: <sip:181@10.10.8.15;user=phone>;tag=DA5EFE14-803

Call-ID: 577306b6@pbx

CSeq: 31830 ACK

Max-Forwards: 70

Contact: <sip:510@10.10.73.5:5080;transport=udp>

P-Asserted-Identity: "carlos parra" <sip:510@localhost>

Content-Length: 0

023247: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog

023248: //135353/E5358C0EA10D/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x882434E8

023249: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.73.5,Port 5080, Transport 1, SentBy Port 5060

023250: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone COL to SIP default timezone = GMT

023251: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 10.10.73.5,Port 5080, Transport 1, SentBy Port 5080

023252: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Name to carlos parra

023253: //135353/E5358C0EA10D/SIP/Info/sipSPIUpdateIdentity: SIP->PSTN: Setting Calling Number to 510

023254: //135353/E5358C0EA10D/SIP/State/sipSPIChangeState: 0x882434E8 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE)  to (STATE_DEAD, SUBSTATE_NONE)

023255: //135353/E5358C0EA10D/SIP/Call/sipSPICallInfo:

The Call Setup Information is:

Call Control Block (CCB) : 0x882434E8

State of The Call        : STATE_DEAD

TCP Sockets Used         : NO

Calling Number           : 510

Called Number            : 181

Source IP Address (Sig  ): 10.10.8.15

Destn SIP Req Addr:Port  : 10.10.73.5:0

Destn SIP Resp Addr:Port : 10.10.73.5:5080

Destination Name         : 10.10.73.5

023256: //135353/E5358C0EA10D/SIP/Call/sipSPIMediaCallInfo:

Number of Media Streams: 1

Media Stream             : 1

Negotiated Codec         : g711ulaw

Negotiated Codec Bytes   : 160

Nego. Codec payload      : 0 (tx), 0 (rx)

Negotiated Dtmf-relay    : 6

Dtmf-relay Payload       : 101 (tx), 101 (rx)

Source IP Address (Media): 10.10.8.15

Source IP Port    (Media): 16632

Destn  IP Address (Media): 10.10.73.5

Destn  IP Port    (Media): 9330

Orig Destn IP Address:Port (Media): [ - ]:0

023257: //135353/E5358C0EA10D/SIP/Call/sipSPICallInfo:

Disconnect Cause (CC)    : 16

Disconnect Cause (SIP)   : 500

023258: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[59212] removed.

023259: //135353/E5358C0EA10D/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.

023260: //135353/E5358C0EA10D/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x882434E8 key=577306b6@pbx181

023261: //135353/E5358C0EA10D/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.

023262: //135353/E5358C0EA10D/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x882434E8 key=577306b6@pbxDA5EFE14-803

023263: //135353/E5358C0EA10D/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd

023264: //135353/E5358C0EA10D/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed

023265: //135353/E5358C0EA10D/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 882434E8

023266: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[59212]

i can not see what is wrong because i only get a 500 error wich does not tell me much.

i will apreciate any help.

Everyone's tags (3)
2 REPLIES
New Member

Re: incoming call problems with sip pbx

I am not sure what devices you are using, or how they are connected.  Looks like you are using private IP addresses, so I assume that this is not going out over the internet.  Anyway, when receiving a 500 Internal Server Error, the first thing I would look at is the incoming Access-List.  My thought would be that the IP address the call is coming from is not being allowed though the firewall/Access-List.

Thank you,

Darren

New Member

Re: incoming call problems with sip pbx

thank you for your reply.

i have already checked that and i have the sip pbx ip registered on the access list 2 so i think the problem is not that and on the debug i can see that the acl is match the rules.

access-list 2 permit 10.10.8.11

access-list 2 permit 200.13.230.38

access-list 2 permit 10.10.73.5

access-list 2 permit 200.13.235.188

access-list 2 remark CCA_SIP_SOURCE_GROUP_ACL_EXTERNAL

access-list 2 remark SDM_ACL Category=1

access-list 2 permit 200.13.235.189

access-list 2 permit 200.13.234.200

regards.

2771
Views
0
Helpful
2
Replies
CreatePlease to create content