| Author |
|
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 18 2008 at 10:45am | IP Logged
|
|
|
Note from LanScape support:
We received this email from Danny earlier this week and wanted to include it in this thread:
Original Email:
------------------------------
Hey guys,
Our compiled CallBox application is having trouble initiating VOIP calls through our Asterisk box reliably. I am able to get the SingleLinePhone sample app to work time and time again. I assume there is a difference in the way we are registering our CallBox extensions and trying to use them after sitting idle for some time. The asterisk machine has been returning "No such host" and an array of other errors in the logs, but I cannot believe there is a problem in our asterisk configuration since it has been working so reliably recently, and works fine with the SingleLinePhone demo.
(Note: IP addreses have been changed)
I have posted "full.txt" into our support FTP account. It logged the traffic from the CallBox machine (212.18.121.20) to the Asterisk machine (212.183.121.19.) All of my research keeps pointing me into ACK response failure in my softphone and failure to incorporate STUN from my softphone. I think it is all irrelevant, but am stuck nonetheless.
Thanks for any help.
Danny
-------------------------------
Danny then went on to post:
I just found this support post:
Topic: SIP 487 Request Terminated:
http://www.lanscapecorp.com/forum/forum_posts.asp?TID=477&PN =1&TPN=1
It is a little old, but I seem to be having the same problem. I sent an e-mail to LanScape support group yesterday about the same issue, but wanted to give you some more information.
Essentially, I am experiencing the exact same kinds of issues as described by Jalal. There does appear to be some kind of race condition issue.
I have two asterisk machines running version 1.4.17.?. One is attached to the same circuit from our ISP as the machine running the media engine. There is no firewall between the machines, there is just an ethernet cable from the ISP running into a switch which is also connected to both the asterisk box and the media engine pc. They are both configured with an external IP from the ISP.
The other asterisk box is at a location about 90 miles from me and is also connected to an ISP by a small switch. There is no firewall in the path and it is configured with an external IP.
When I placed calls using the media engine to these two machines, I get very different results.
The local asterisk machine exhibits the behavior Jalal described. The CANCEL is sent before an ACK on a retransmitted invite can be received. This causes asterisk to terminate the request and send 487s for quite a while.
The remote asterisk machine (90 miles away) does not exhibit this behavior. Calls place as normal.
Both asterisk machines report 407: Proxy Authentication Required (which seems irrelevant) and both return 401: Unauthorized to my first registration attempt (also seems irrelevant).
I am using version 5.12.8.3 which means the fix for Jalal is not the fix for me.
I am going to post two Wireshark captures to my support FTP account. They should give you a pretty good indication of what is going on. These captures were made on the media engine computer when ran against both the local and remote asterisk box.
Thanks guys
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 18 2008 at 11:01am | IP Logged
|
|
|
I forgot to mention...
(Note: IP addreses have been changed)
The packet capture while connecting to the remote asterisk machine(108.6.40.214) with my local media engine(212.183.121.20) is called:
Remote Asterisk using CallBox.pcap
The packet capture while connecting to the local asterisk machine(212.183.121.19) with my local media engine(212.183.121.20) is called:
Local Asterisk using CallBox.pcap
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 20 2008 at 7:22pm | IP Logged
|
|
|
Hi Danny,
This is Randal. We have been incredibly busy here this week. We thank your group for your patience. I even have to roll up my sleeves late on a Friday night. :)
I took a quick look at your “full.txt” application log. We may have to talk a bit more regarding your local Asterisk box not connecting reliably. However, as far as I can see from your app log, you may be facing a Media Engine – Asterisk only issue that recently came to our attention. It’s a timing dependent issue with the CSeq header value of transmitted INVITE requests. This issue seems to occur only on fast host multi core machines (with equally fast network connections) when the VOIP app (media engine) generates secondary INVITE requests as the result of authentication challenges from Asterisk servers.
I wanted to post tonight because we are in the midst of a possible fix that will remedy the problem and we hate to make your group wait any longer.
We have placed into your support FTP account a temporary test image of the VOIP Media Engine. Please download file image “Image - PhoneTree - Temp v5.12.8.5.zip”.
Simply replace the DLLs in the archive with your current DLLs.
If you would, please make multiple tests to your local and remote Asterisk boxes. Report your finding when you can.
I will be working tomorrow (Saturday). If you are at work tomorrow, a few of us will be manning the support forum and working on other tasks. Feel free to contact us anytime tomorrow if you want.
Thanks,
Randal
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 20 2008 at 7:22pm | IP Logged
|
|
|
Danny,
Please post back with the version of Asterisk you are using.
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 23 2008 at 8:27am | IP Logged
|
|
|
I have tested with 1.4.17 and 1.4.21 with the same results.
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 23 2008 at 8:35am | IP Logged
|
|
|
To clarify...I tested both of those asterisk versions with 5.12.8.3, I am going to try your new engine in just a moment.
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 9:04am | IP Logged
|
|
|
Hi Danny,
What ever we do, we must conduct all testing using the v5.12.8.5 image you have downloaded from your support FTP account.
If you have further info as the results of your testing the v5.12.8.5 image, please post today if you can.
Unfortunately we are not completely clear on what connection problems you are facing. Looking at your wireshark and SIP logs, we made the best possible educated guess as to what the issue may be.
If the problem is due to media engine INVITE retries as the results of Asterisk challenging a previous INVITE request, the v5.12.8.5 image will take care of the media engine/Asterisk SIP inter-op issue that was recently brought to our attention.
If the problem is something else, then we will have to look further.
One thing we can do is have your VOIP app create individual SIP logs for the phone lines it uses. Its easier to manually look through individual phone line SIP logs for the connection problem instead of a single huge SIP log for all the media engine phone lines.
To make the media engine create individual SIP logs for each phone line, have your app call the LogPhoneLineSipMessages() API proc for each phone line. This API is documented in the media engine Software Developer’s Reference.
If you can perform your tests and determine what phone lines experience connectivity errors to your Asterisk box, then we can simply look at the phone lines individual SIP log and get to the bottom of the problem.
The workload here has somewhat lightened up for today so our support forum responses should be much shorter relative to last week.
We received an email from Dave regarding this connectivity issue. The issue most likely is associated with media Engine/Asterisk SIP interoperability. If we can get some testing done today, its possible that we can overcome this problem and scrub the conference call meeting for tomorrow.
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 10:40am | IP Logged
|
|
|
Hey support,
Again to clarify, since I found the connectivity to be unreliable early on, I have been using only a single phone line to do my testing. All logs should show subsequent attempts made in sequence from the same phone line trying to get a connection. I will see if there is a handy spot to add the LogPhoneLineSipMessages call and try to send its output along with the asterisk output for you to compare.
Thanks,
Danny
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 11:13am | IP Logged
|
|
|
Thanks Danny. That was a good clarification.
Conduct exact same single line tests using v5.12.8.5. Please report your test results to this support forum thread.
If the same problems exist using this updated version:
Your code can call the LogPhoneLineSipMessages() API proc anytime after the media engine is started (any time after successful return from the StartSipTelephony() API proc).
If you are testing with a single phone line and that phone line sees the connection errors, that will help to simplify and help us to more quickly locate the problem.
Question:
Is your Asterisk box challenging the INVITE requests coming from the media engine?
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 11:32am | IP Logged
|
|
|
I have tested with 5.12.8.5 over the past day or so. The problem persists.
Typically, I would see many failures, then the same call (keeps getting pushed back into one of our queues) will succeed. There doesn't appear to be any good reason why things succeed sometimes, and fail other times.
Today I tried to clear all stuck SIP transmissions and channels from asterisk by doing a restart. I attempted to add the LogPhoneLineSipMessges API. The first time I tried passing "C:\SipMessages.log" as the char value. I did not find a log file. The second time I tried just passing "SipMessages.log." That also did not seem to produce anything.
Dennis already had place holders for
BOOL LogSipMessages;
char *pSipLogFileName;
in his call to StartSipTelephony. I set those to true and it produced the SipMessages.log file. It seems to have all you would need in it. I am waiting around hoping one of these calls will succeed, so you can see the "before/after" logging to compare. If none of these calls will succeed, I will just stop it in about 10 minutes and send you my SipMessages.log and my Sip log file from asterisk.
Danny
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 12:01pm | IP Logged
|
|
|
Hi Danny,
If you are testing with just a single phone line, then yes, you will not need to call the LogPhoneLineSipMessges() API proc to create individual per phone linen SIP logs. The main SIP log as specified in the startup parameters will be OK.
If you do call the LogPhoneLineSipMessges() API proc for each phone line, make sure you specify a unique log file name that is different for each phone line and different from the startup parameter SIP log file name you set in your startup parameters.
We will wait for your SIP log for the failed call(s) and review. We are making this issue a priority today and tomorrow.
How long do you plan to work today?
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 12:34pm | IP Logged
|
|
|
I just sent up LanscapeSipLog and AsteriskSipLog to my ftp account. They should be over the same time range. It was the same outgoing call that was looping over and over with failed attempts. Let me know how else i can help.
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 12:35pm | IP Logged
|
|
|
I generally work until 5:30 EST, but can accomodate your schedule if we get onto a roll...
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 12:40pm | IP Logged
|
|
|
Great... Looking at logs now....
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 1:44pm | IP Logged
|
|
|
Danny,
Looking at the media engine “LanscapeSipLog.txt” file, here is a summary of call activity:
Code:
Total Calls: 50
Good Calls: 41
Bad Calls: 9
Percentage of calls failing: 18% (way too high)
Reason for ALL bad calls: Asterisk is returning “503 Server error” for the calls.
Reason: Unknown.
All error call flows have the signature:
INVITE -------->
<------- 407 Proxy Authentication Required
ACK -------->
INVITE (with Auth credentials) -------->
<-------------------------------- 503 Server error
ACK -------->
|
|
|
All SIP call flows look good. We do not know why Asterisk is returning “503 Server error” responses back for 9 of the calls. The only way to completely see what Asterisk is doing is to put Asterisk under the debugger and see why he is doing this.
In the mean time, your VOIP app should use the media engine to detect these “503 Server error” responses and retry the outgoing call until successful.
Aditional Steps:
“Turn up” and/or enable verbose and debugger output logging on your asterisk servers so that we may be able to see why he is returning 503 responses for what looks like perfectly good SIP INVITE requests. We may not have to put asterisk under a debugger if we can locate the issue with log output.
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 1:49pm | IP Logged
|
|
|
I will turn on verbose logging. I did want to tell you that your summary of call activity is not valid based on my experience. I had 0 calls place correctly during the logging period today. Eventually I just stopped the attempts and sent the logs. It is interested that you found some patterns to seem "good" and some to seem "bad" given that none of my calls completely successfully. I will crank up the logging and send you some more info in a moment.
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 2:04pm | IP Logged
|
|
|
Danny,
If you disagree about the number of successful vs. failed calls, then we must be looking at different data.
The media engine SIP log you sent to us (“LanscapeSipLog.txt”) shows that 41 calls connected and 9 calls failed due to “503 Server errors”.
Hmmmm…. What gives….. :)
Support
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 2:05pm | IP Logged
|
|
|
Maybe you should describe to us what you are seeing. Was the SIP log you sent us the correct one????
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 2:10pm | IP Logged
|
|
|
Danny,
If you take a look at the SIP log, you will see the following call activiy:
Code:
Number of calls Status
----------------------------------
24 Good
2 "503 Server error"
2 Good
2 "503 Server error"
2 Good
2 "503 Server error"
10 Good
2 "503 Server error"
2 Good
1 "503 Server error"
1 Good
Total calls: 50
|
|
|
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 2:10pm | IP Logged
|
|
|
The SIP log I sent was the correct one. When I say the connect failed, I mean that our CallBox timed out waiting on the aknowledgement of a successful connection from the LME. We are waiting for the RTP data to start flowing, and then ultimately for our Asterisk machine to give us a beep (wait for outgoing phone number) then another beep (wait for outgoing CallerID.) Though I have seen the Asterisk Log claim to register a connection and start playing the beeps for us, the CallBox has never registered a successful attempt from the LME so it sits in a loop with timeouts. Maybe a discussion with Dennis is in order as Dave suggested. It could be possible that our timeout values are not long enough. I seem to recall in the past week changing some of my startup params to use 0 as the timeout value (assuming that means no timeout.) In the Dennis CallBox code, there are some situations in which his phone line threads wait for responses for seemingly arbitrary amounts of time (ex: 8000 ms for successful connection notification.) Where do we go from here?
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 2:29pm | IP Logged
|
|
|
I increased my logging, and I am uploading NewestAsterisk.log and NewestLME.log...
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 2:31pm | IP Logged
|
|
|
Danny,
This is Randal. If you and Dave want to set up a virtual meeting again, I will be free any time on or after 8:30 Eastern Standard time (your time). Getting together tomorrow morning - Not a problem.
You or Dave please send me an email when you want to start tomorrow.
It sounds as if we were looking at two different things. Let us know if you want us to do anything further yet today.
Thanks Danny,
Randal
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 2:43pm | IP Logged
|
|
|
Hi Danny,
From the media engine SIP log (NewestLME.log), all calls connected to Asterisk successfully – no SIP errors whatsoever.
We also do not see any “fatal” or “terminal” errors in the Asterisk SIP log either. Hmmmm... We have to think...
Support
|
| Back to Top |
|
| |
fdfrye
Intermediate
Joined: February 01 2008
Location: United States
Posts: 23
|
| Posted: June 24 2008 at 2:45pm | IP Logged
|
|
|
Hey Randal,
It might be helpful for you to check and see if the latest Asterisk log with more verbose logging answers your questions about the 503 error. Also, getting together tomorrow around 9:00 AM would be great, but I want you to feel confident that we have done anything we can do today to be ready to troubleshoot the LME/CallBox interface with respect to why we would be calling a call attempt failed when the LME thinks it had a perfect SIP round-trip.
I guess it all gets down to timeouts...?
|
| Back to Top |
|
| |
support
Administrator
Joined: January 26 2005
Location: United States
Posts: 1666
|
| Posted: June 24 2008 at 3:19pm | IP Logged
|
|
|
Danny,
Your logs look OK. Nothing there indicates a call problem. I’m not sure what has changed since we last met as a virtual group. If the VOIP Media Engine SIP call flows show proper call setup and tear down, there is not much we can suggest just by guessing. The “503 Server error” responses we see that are sometime being returned by Asterisk seem to be a secondary issue that is not important at this time.
Its probably best if we convene tomorrow morning and discuss this with the rest of the group. Dave sent me an email yesterday afternoon. I agree with Dave, we will need to have Dennis present for meaningful discussions.
You or Dave please email me with the virtual meeting details and time. 9AM your time will work.
As usual , good job.
Thanks,
Randal
|
| Back to Top |
|
| |
Active Topics 
Member List 
Search 
Help 
Register 
Login
LanScape Support Forum -> LanScape VOIP Media Engine™ - Technical Support
Topic: VOIP Timeouts (SipFarEndFailures)
