Hi again Scott,
Captured the MP118 log after updating firmware to latest(?) 5.4 version.
I have attached the log. Is there any clue or pointer what may be
causing this internal server error?
Do i need to do specific change after firmware update?
Thanks in advance.
Scott Lawrence wrote:
On Wed, 2009-03-25 at 09:13 +0800, Cuneyt M wrote:
Hi Scott,
I setup the Xlite as per the previous installations which worked
flawlessly.
Enabled Invite All to Proxy too.
Attached are the sshots of xlite config, the internal server error and
the log from MP118 (level 5 debug output).
DNS resolution works OK at client and server side (passed the tests
etc.).
Where do you think the problem would be?
Here's the problem... from the Audiocodes log:
AcSIPParser: Problem in SIP Message Headers [Time:
9:5:40]25d:9h:5m:40s ( sip_stack)(1065 ) ?? [WARNING]
AcSIPParser: Warning. Branch is too long. Truncated to 49 chars [Time:
9:5:40]25d:9h:5m:40s
This is a known bug in some versions of the Audiocodes firmware. You
should be able to get a later version from them that fixes it.
The reason it didn't show up before is that 3.10.3 introduced an
important improvement in proxy loop detection, but the fix makes the Via
headers we generate somewhat longer and went over this ridiculously low
limit that Audiocodes used to have.
Log is Activated 25d:11h:25m:27s ( lgr_flow)(2785 ) ---- Incoming
SIP Message from 192.168.11.2:5060 ---- [Time: 11:25:27]25d:11h:25m:27s INVITE
sip:[email protected];transport=udp SIP/2.0
Record-Route:
<sip:192.168.11.2:5060;lr;sipXecs-rs=%2Afrom%7EZGMxMmVlNzQ%60.400_authrules%2Aauth%7E%21266eb5764b809b477be0be3aa1aad0f1>
Max-Forwards: 18
Contact: <sip:[email protected]:3766;transport=TCP>
To: "72424443"<sip:[email protected]>
From: "251"<sip:[email protected]>;tag=dc12ee74
Call-Id: ZTI1NzBhYTdjYjkwODExNGE4OGVhMGVhMDc4YTgyOWM.
Cseq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE,
INFO
Content-Type: application/sdp
Proxy-Authorization: Digest
username="251",realm="sipx.localdomain.com",nonce="5f21dca545458cf052e73c217474d15c49c9a428",uri="sip:[email protected]",response="47a9c21a5913b40ef80d001bbe301f71",algorithm=MD5
User-Agent: X-Lite release 1100l stamp 47546
Content-Length: 425
Date: Wed, 25 Mar 2009 03:25:28 GMT
Via: SIP/2.0/UDP
192.168.11.2;branch=z9hG4bK-sipXecs-042afbb68438b884e1c3016ec9640dc34d1e
Via: SIP/2.0/TCP
192.168.11.2;branch=z9hG4bK-sipXecs-0427cbe5be07583c8d88db82602f768427ff~fa990603d1253c5cd2492b6f578190e8
Via: SIP/2.0/TCP
192.168.11.50:20084;branch=z9hG4bK-d8754z-d46593113e7c791e-1---d8754z-;rport=3766
[Time: 11:25:27]25d:11h:25m:27s v=0
o=- 4 2 IN IP4 192.168.11.50
s=CounterPath X-Lite 3.0
c=IN IP4 192.168.11.50
t=0 0
m=audio 53866 RTP/AVP 107 119 100 106 0 105 98 8 3 101
a=alt:1 1 : +qdWB1/Q et1mqvkP 192.168.11.50 53866
a=fmtp:101 0-15
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
[Time: 11:25:27]25d:11h:25m:27s ( lgr_flow)(2787 ) | | new
GetNewSIPCall created - #17 [Time: 11:25:27]25d:11h:25m:27s (
sip_stack)(2788 ) new AcSIPCallAPI created - #11 [Time:
11:25:27]25d:11h:25m:27s ( lgr_stk_mngr)(2789 ) Resource StackSession
<#11> Allocated [Time: 11:25:27]25d:11h:25m:27s ( lgr_flow)(2790 ) |
|(SIPTU#17)INVITE State:Idle() [Time: 11:25:27]25d:11h:25m:27s (
sip_stack)(2791 ) SIPCall(#17) changes state from Idle to Invited [Time:
11:25:27]25d:11h:25m:27s ( lgr_callf)(2793 ) new Call created - #11
[Time: 11:25:27]25d:11h:25m:33s ( lgr_psbrdex)(2833 ) InsertBoardEvent-
event 44 inserted channel 0 [Time: 11:25:33]25d:11h:25m:33s (
lgr_flow)(2834 ) #0:TIMER_EXPIRED_EV [Time: 11:25:33]25d:11h:25m:33s (
lgr_flow)(2835 ) | #0:TIMER_EXPIRED_EV [Time:
11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2836 ) #0:cpDigitMapHndlr_Stop
- Stoped (0) [Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2837 )
#0:CloseChannel: ChannelNum=0 [Time: 11:25:33]25d:11h:25m:33s (
lgr_psbrdif)(2838 ) Open channel: IsVoiceOn: 1, IsT38On: 0, IsVbdOn: 0,
IsVideoOn: 0 [Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2839 )
#0:OpenChannel:on Trunk -1 BChannel:0 CID=0 with VoiceCoder: g711Ulaw64k20
VbdCoder: InvalidCoder255 DetectorSide: 0 FaxModemDet NO_FAX_MODEM_DETECTED
[Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2840 ) #0:OpenChannel
VoiceVolume= 0, DTMFVolume = -11, InputGain = 0, RTPRedundancyDepth = 0
FlashHookPeriod = 790 AgcCmd = 0x13180000
[Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2841 ) OpenChannel,
CoderType = 1, Interval = 3, M = 1
[Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2842 )
#0:FAXTransportType = 0 [Time: 11:25:33]25d:11h:25m:33s ( lgr_psbrdif)(2843
) #0:ConfigFaxModemChannelParams NSEMode=0, CNGDetMode=0, FAXTranType=0,
VxxTranType=0, VoiceVol= 0, DTMFVol=-11, InGain=0, RTPRedDepth=0, ECE=1, SCE=1,
ECNlpMode=0, DJBufMinDelay=10, DJBufOptFac=10) [Time: 11:25:33]25d:11h:25m:33s
( lgr_psbrdif)(2844 ) Detectors: Amd:0, Ans:0 En:0 IBScmd:0xa1 [Time:
11:25:33]25d:11h:25m:33s ( lgr_flow)(2845 ) | #0:RELEASE
(send) GWAPP_PROTOCOL_ERROR_UNSPECIFIED :
(ZTI1NzBhYTdjYjkwODExNGE4OGVhMGVhMDc4YTgyOWM.) [Time: 11:25:33]25d:11h:25m:33s
( lgr_flow)(2846 ) | |
#11:RELEASE:(ZTI1NzBhYTdjYjkwODExNGE4OGVhMGVhMDc4YTgyOWM.) [Time:
11:25:33]25d:11h:25m:33s ( lgr_flow)(2847 ) | | #11:Call
changing states from:AlertingState_IP2Tel to:DisconnectingState [Time:
11:25:33]25d:11h:25m:34s ( lgr_psbrdex)(2869 ) InsertBoardEvent- event
116 inserted channel 0 [Time: 11:25:34]25d:11h:25m:35s ( lgr_flow)(2870
) #0:GUARD_TIME_TIMER_EXPIRED_EV [Time: 11:25:35]25d:11h:25m:35s (
lgr_flow)(2871 ) | #0:GUARD_TIME_TIMER_EXPIRED_EV [Time:
11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2872 ) #0:cpDigitMapHndlr_Stop
- Stoped (0) [Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2873 )
#0:CloseChannel: ChannelNum=0 [Time: 11:25:35]25d:11h:25m:35s (
lgr_psbrdif)(2874 ) Open channel: IsVoiceOn: 1, IsT38On: 0, IsVbdOn: 0,
IsVideoOn: 0 [Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2875 )
#0:OpenChannel:on Trunk -1 BChannel:0 CID=0 with VoiceCoder: g711Ulaw64k20
VbdCoder: InvalidCoder255 DetectorSide: 0 FaxModemDet NO_FAX_MODEM_DETECTED
[Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2876 ) #0:OpenChannel
VoiceVolume= 0, DTMFVolume = -11, InputGain = 0, RTPRedundancyDepth = 0
FlashHookPeriod = 790 AgcCmd = 0x13180000
[Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2877 ) OpenChannel,
CoderType = 1, Interval = 3, M = 1
[Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2878 )
#0:FAXTransportType = 0 [Time: 11:25:35]25d:11h:25m:35s ( lgr_psbrdif)(2879
) #0:ConfigFaxModemChannelParams NSEMode=0, CNGDetMode=0, FAXTranType=0,
VxxTranType=0, VoiceVol= 0, DTMFVol=-11, InGain=0, RTPRedDepth=0, ECE=1, SCE=1,
ECNlpMode=0, DJBufMinDelay=10, DJBufOptFac=10) [Time: 11:25:35]25d:11h:25m:35s
( lgr_psbrdif)(2880 ) Detectors: Amd:0, Ans:0 En:0 IBScmd:0xa1 [Time:
11:25:35]25d:11h:25m:39s ( lgr_flow)(2881 ) | |
TransactionUserMngr::ReturnSIPCall - #17 [Time: 11:25:39]25d:11h:25m:39s (
sip_stack)(2882 ) SIPCall(#17) changes state from Disconnected to Idle
[Time: 11:25:39]25d:11h:25m:44s ( lgr_psbrdex)(2883 ) recv <-- DIGIT(2)
Ch:1 OnTime:0 InterTime:3686565 Direction:0 System:1 [Time:
11:25:44]25d:11h:25m:44s ( lgr_flow)(2884 ) #1:DIGIT_EV [Time:
11:25:44]25d:11h:25m:44s ( lgr_flow)(2885 ) | #1:DIGIT_EV
[Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2886 ) Turn ringer OFF
for channel 1 [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2887 ) |
#1:FXO Release Line [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2888
) #1:PSOSBoardInterface::StopPlayTone- Called [Time:
11:25:44]25d:11h:25m:44s ( lgr_psbrdex)(2889 ) recv <-- DIGIT(2) Ch:1
OnTime:80 InterTime:3686565 Direction:0 System:1 [Time:
11:25:44]25d:11h:25m:44s ( lgr_flow)(2890 ) #1:DIGIT_EV [Time:
11:25:44]25d:11h:25m:44s ( lgr_flow)(2891 ) | #1:DIGIT_EV
[Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2892 ) Turn ringer OFF
for channel 1 [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2893 ) |
#1:FXO Release Line [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2894
) #1:PSOSBoardInterface::StopPlayTone- Called [Time:
11:25:44]25d:11h:25m:44s ( lgr_psbrdex)(2895 ) recv <-- DIGIT(4) Ch:1
OnTime:0 InterTime:90 Direction:0 System:1 [Time: 11:25:44]25d:11h:25m:44s (
lgr_flow)(2896 ) #1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s (
lgr_flow)(2897 ) | #1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s (
lgr_psbrdif)(2898 ) Turn ringer OFF for channel 1 [Time:
11:25:44]25d:11h:25m:44s ( lgr_flow)(2899 ) | #1:FXO Release
Line [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2900 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:44]25d:11h:25m:44s (
lgr_psbrdex)(2901 ) recv <-- DIGIT(4) Ch:1 OnTime:80 InterTime:90
Direction:0 System:1 [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2902
) #1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2903 ) |
#1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2904 )
Turn ringer OFF for channel 1 [Time: 11:25:44]25d:11h:25m:44s (
lgr_flow)(2905 ) | #1:FXO Release Line [Time:
11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2906 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:44]25d:11h:25m:44s (
lgr_psbrdex)(2907 ) recv <-- DIGIT(2) Ch:1 OnTime:0 InterTime:90
Direction:0 System:1 [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2908
) #1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2909 ) |
#1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2910 )
Turn ringer OFF for channel 1 [Time: 11:25:44]25d:11h:25m:44s (
lgr_flow)(2911 ) | #1:FXO Release Line [Time:
11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2912 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:44]25d:11h:25m:44s (
lgr_psbrdex)(2913 ) recv <-- DIGIT(2) Ch:1 OnTime:80 InterTime:90
Direction:0 System:1 [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2914
) #1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_flow)(2915 ) |
#1:DIGIT_EV [Time: 11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2916 )
Turn ringer OFF for channel 1 [Time: 11:25:44]25d:11h:25m:44s (
lgr_flow)(2917 ) | #1:FXO Release Line [Time:
11:25:44]25d:11h:25m:44s ( lgr_psbrdif)(2918 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:44]25d:11h:25m:45s (
lgr_psbrdex)(2919 ) recv <-- DIGIT(8) Ch:1 OnTime:0 InterTime:150
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2920
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2921 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2922 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2923 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2924 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2925 ) recv <-- DIGIT(8) Ch:1 OnTime:70 InterTime:150
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2926
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2927 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2928 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2929 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2930 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2931 ) recv <-- DIGIT(3) Ch:1 OnTime:0 InterTime:190
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2932
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2933 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2934 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2935 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2936 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2937 ) recv <-- DIGIT(3) Ch:1 OnTime:80 InterTime:190
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2938
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2939 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2940 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2941 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2942 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2943 ) recv <-- DIGIT(3) Ch:1 OnTime:0 InterTime:110
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2944
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2945 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2946 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2947 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2948 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2949 ) recv <-- DIGIT(3) Ch:1 OnTime:80 InterTime:110
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2950
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2951 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2952 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2953 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2954 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2955 ) recv <-- DIGIT(3) Ch:1 OnTime:0 InterTime:80
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2956
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2957 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2958 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2959 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2960 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]25d:11h:25m:45s (
lgr_psbrdex)(2961 ) recv <-- DIGIT(3) Ch:1 OnTime:90 InterTime:80
Direction:0 System:1 [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2962
) #1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_flow)(2963 ) |
#1:DIGIT_EV [Time: 11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2964 )
Turn ringer OFF for channel 1 [Time: 11:25:45]25d:11h:25m:45s (
lgr_flow)(2965 ) | #1:FXO Release Line [Time:
11:25:45]25d:11h:25m:45s ( lgr_psbrdif)(2966 )
#1:PSOSBoardInterface::StopPlayTone- Called [Time: 11:25:45]
_______________________________________________
sipx-users mailing list
[email protected]
List Archive: http://list.sipfoundry.org/archive/sipx-users
Unsubscribe: http://list.sipfoundry.org/mailman/listinfo/sipx-users
