Re: [Ekiga-list] Dropped call after approximately 30s, "Failed to receive ACK!"

From: Felix Lechner <felix lechner gmail com>
To: ekiga-list gnome org
Subject: Re: [Ekiga-list] Dropped call after approximately 30s, "Failed to receive ACK!"
Date: Sun, 28 Nov 2010 21:31:47 -0800

Hi Ian,

Thank you for the pointer. Indeed it looks like Siproxd never forwards the ACK to Ekiga. Instead it seems to respond with a 408 Timeout (twice). Perhaps you can confirm this reading from the logs below?

While probably insignificant to my problem, I also noticed that Ekiga does not route PUBLISH requests to Siproxd but directly to the Sipphone server (198.65.166.131). Isn't that supposed to go through the proxy, too?

The PUBLISH requests then get swallowed because the packages did not originate on my gateway.

Thank you for your help,

Felix

* * * Between Ekiga and my gateway running Siproxd:

No. Time Source Destination Protocol Info

1 0.000000 192.168.11.1 192.168.11.177 SIP/SDP Request: INVITE sip:17476686228 192 168 11 177, with session description

2 0.004324 192.168.11.177 192.168.11.1 SIP Status: 100 Trying

3 0.011226 192.168.11.177 192.168.11.1 SIP Status: 180 Ringing

4 1.221986 192.168.11.177 192.168.11.1 SIP Request: REGISTER sip:proxy01.sipphone.com

5 1.668841 192.168.11.1 192.168.11.177 SIP Status: 200 OK (1 bindings)

6 1.676359 192.168.11.177 192.168.11.1 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

7 2.116070 192.168.11.1 192.168.11.177 SIP Request: SUBSCRIBE sip:17476686228 192 168 11 177

8 2.119343 192.168.11.177 192.168.11.1 SIP Status: 405 Method Not Allowed

9 2.178203 192.168.11.177 192.168.11.1 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

10 2.208363 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

11 2.598451 192.168.11.1 192.168.11.177 SIP Status: 405 Method Not Allowed

12 2.638144 192.168.11.1 192.168.11.177 SIP Status: 405 Method Not Allowed

13 2.709676 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

14 3.674083 192.168.11.177 192.168.11.1 SIP/SDP Status: 200 OK, with session description

15 3.710301 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

16 4.174685 192.168.11.177 192.168.11.1 SIP/SDP Status: 200 OK, with session description

17 5.710938 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

18 31.680208 192.168.11.177 192.168.11.1 SIP Request: REGISTER sip:proxy01.sipphone.com

19 32.181097 192.168.11.177 192.168.11.1 SIP Request: REGISTER sip:proxy01.sipphone.com

20 32.814627 192.168.11.1 192.168.11.177 SIP Status: 200 OK (1 bindings)

21 32.822995 192.168.11.177 192.168.11.1 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

22 32.829732 192.168.11.1 192.168.11.177 SIP Status: 200 OK (1 bindings)

23 33.328976 192.168.11.1 192.168.11.177 SIP Request: SUBSCRIBE sip:17476686228 192 168 11 177

24 33.331561 192.168.11.177 192.168.11.1 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

25 33.333971 192.168.11.177 192.168.11.1 SIP Status: 405 Method Not Allowed

26 33.448979 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

27 33.733403 192.168.11.1 192.168.11.177 SIP Request: SUBSCRIBE sip:17476686228 192 168 11 177

28 33.738981 192.168.11.177 192.168.11.1 SIP Status: 405 Method Not Allowed

29 33.761589 192.168.11.1 192.168.11.177 SIP Status: 405 Method Not Allowed

30 33.950697 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

31 34.951540 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

32 35.745194 192.168.11.177 192.168.11.1 SIP Request: BYE sip:+16172295005 74 125 46 80:24000

33 36.246353 192.168.11.177 192.168.11.1 SIP Request: BYE sip:+16172295005 74 125 46 80:24000

34 36.266313 192.168.11.1 192.168.11.177 SIP Status: 404 Not here

35 36.715199 192.168.11.1 192.168.11.177 SIP Status: 404 Not here

36 36.951550 192.168.11.177 198.65.166.131 SIP/XML Request: PUBLISH sip:17476686228 proxy01 sipphone com

* * * Between Siproxd and the outside world:

No. Time Source Destination Protocol Info

1 0.000000 198.65.166.131 10.11.39.174 SIP/SDP Request: INVITE sip:17476686228 72 254 95 107, with session description

2 0.017487 10.11.39.174 198.65.166.131 SIP Status: 100 Trying

3 0.024133 10.11.39.174 198.65.166.131 SIP Status: 180 Ringing

4 1.234185 10.11.39.174 198.65.166.131 SIP Request: REGISTER sip:proxy01.sipphone.com

5 1.673553 198.65.166.131 10.11.39.174 SIP Status: 200 OK (1 bindings)

6 1.688100 10.11.39.174 198.65.166.131 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

7 2.120416 198.65.166.131 10.11.39.174 SIP Request: SUBSCRIBE sip:17476686228 72 254 95 107

8 2.131477 10.11.39.174 198.65.166.131 SIP Status: 405 Method Not Allowed

9 2.189953 10.11.39.174 198.65.166.131 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

10 2.603282 198.65.166.131 10.11.39.174 SIP Status: 405 Method Not Allowed

11 2.643286 198.65.166.131 10.11.39.174 SIP Status: 405 Method Not Allowed

12 3.689478 10.11.39.174 198.65.166.131 SIP/SDP Status: 200 OK, with session description

13 4.188695 10.11.39.174 198.65.166.131 SIP/SDP Status: 200 OK, with session description

14 4.289813 198.65.166.131 10.11.39.174 SIP Request: ACK sip:7476686228 72 254 95 107:5060

15 4.297488 10.11.39.174 198.65.166.131 SIP Status: 408 Request Timeout

16 4.797679 198.65.166.131 10.11.39.174 SIP Request: ACK sip:7476686228 72 254 95 107:5060

17 4.804459 10.11.39.174 198.65.166.131 SIP Status: 408 Request Timeout

18 32.231665 10.11.39.174 198.65.166.131 SIP Request: REGISTER sip:proxy01.sipphone.com

19 32.236893 10.11.39.174 198.65.166.131 SIP Request: REGISTER sip:proxy01.sipphone.com

20 32.819967 198.65.166.131 10.11.39.174 SIP Status: 200 OK (1 bindings)

21 32.831952 198.65.166.131 10.11.39.174 SIP Status: 200 OK (1 bindings)

22 32.834899 10.11.39.174 198.65.166.131 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

23 33.332820 198.65.166.131 10.11.39.174 SIP Request: SUBSCRIBE sip:17476686228 72 254 95 107

24 33.343388 10.11.39.174 198.65.166.131 SIP Request: SUBSCRIBE sip:17476686228 proxy01 sipphone com

25 33.347591 10.11.39.174 198.65.166.131 SIP Status: 405 Method Not Allowed

26 33.736708 198.65.166.131 10.11.39.174 SIP Request: SUBSCRIBE sip:17476686228 72 254 95 107

27 33.752125 10.11.39.174 198.65.166.131 SIP Status: 405 Method Not Allowed

28 33.765718 198.65.166.131 10.11.39.174 SIP Status: 405 Method Not Allowed

29 35.063947 10.11.39.174 198.65.166.165 STUN Message: Binding Request

30 35.543214 198.65.166.165 10.11.39.174 STUN Message: Binding Response

31 35.759343 10.11.39.174 74.125.46.80 SIP Request: BYE sip:+16172295005 74 125 46 80:24000

32 36.257008 74.125.46.80 10.11.39.174 SIP Status: 404 Not here

33 36.271817 10.11.39.174 74.125.46.80 SIP Request: BYE sip:+16172295005 74 125 46 80:24000

34 36.720896 74.125.46.80 10.11.39.174 SIP Status: 404 Not here

---------- Forwarded message ----------
From: "Jānis Rukšāns" <thedogfarted gmail com>
To: Ekiga mailing list <ekiga-list gnome org>
Date: Sun, 28 Nov 2010 17:53:03 +0200
Subject: Re: [Ekiga-list] Dropped call after approximately 30s, "Failed to receive ACK!"
Hi,

On Sat, Nov 27, 2010 at 9:34 AM, Felix Lechner <felix lechner gmail com> wrote:
> A short log of 'siproxd' is included below.
> Nov 25 07:41:54 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120
> INFO:Incoming Call: +16172295005 10 176 159 3 -> 7476686228@
> Nov 25 07:41:56 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120
> INFO:ACK Call: +16172295005 10 176 159 3 -> 7476686228 74 125 46 80
> Nov 25 07:41:56 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120
> INFO:ACK Call: +16172295005 10 176 159 3 -> 7476686228 74 125 46 80
> Nov 25 07:42:28 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120
> INFO:Ending Call: 7476686228 74 125 46 80 -> +16172295005 10 176 159 3
> Can anyone tell from the attached Ekiga log what is causing the dropped
> calls? Looks like the clue is in the line
> 2010/11/25 07:42:29.780 0:44.681 Housekeeper:0xb6cdbb70 SIP Failed to
> receive ACK!
> Opal then ends the call due to a temporary failure.
> Any help would be very much appreciated.

Judging from the logs, I suspect the siproxd is the point of failure -
Ekiga never reiceives an ACK to it's 200 OK and therefore terminates
the call after 32 seconds. A wireshark/tcpdump capture of SIP from
your gateway (Ekiga <-> siproxd and siproxd <-> provider) could shed
some light onto what's going on here.

Cheers
--
Ian

---------- Forwarded message ----------
From: Felix Lechner <felix lechner gmail com>
Date: Fri, Nov 26, 2010 at 11:34 PM
Subject: Dropped call after approximately 30s, "Failed to receive ACK!"
To: ekiga-list gnome org

Hello,

Ekiga drops all my incoming calls after about 30 seconds. Other clients don't. My hope is someone can help me figure out why.

Approximately 30 seconds into every call (always more, never less) Ekiga disconnects after stating "Failed to receive ACK!".

The log was posted to http://pastebin.com/AtYaNBf1.

My setup is challenging---and probably prone to errors. First of all, I am behind a NAT router that works for SIP and RTP traffic when using STUN. Unfortunately, the router also only allows traffic from one MAC address. Since I have several computers, I installed a gateway of my own. That gateway runs 'dnsmasq' and 'squid' for browsing the web. That all works fine.

To facilitate phone traffic I tried several approaches. The best one has been to use 'siproxd', a relatively simple SIP and RTP proxy. I contemplated 'ser' and 'mediaproxy' for standards compliance, but there hasn't been any evidence that 'siproxd' is not working right. The latest version of 'siproxd' has a STUN module to determine the provider's public IP address (74.125.46.80).

My SIP provider is Sipphone/Gizmo5. Looks they use YATE. The incoming call is a Google Voice call. I am pointing that out because it is causing some other quirks. (For example, they stopped supporting iLBC on incoming GV calls.)

Here is more information for the logs: My endpoint is 192.168.11.177. The internal address of my gateway with 'siproxd' is 192.168.11.1 (external address 10.11.39.174). The internal address of the provider's restrictive router is 10.176.159.3.

A short log of 'siproxd' is included below.

Nov 25 07:41:54 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120 INFO:Incoming Call: +16172295005 10 176 159 3 -> 7476686228@

Nov 25 07:41:56 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120 INFO:ACK Call: +16172295005 10 176 159 3 -> 7476686228 74 125 46 80

Nov 25 07:42:28 buffalo-linkstation siproxd[1482]: plugin_logcall.c:120 INFO:Ending Call: 7476686228 74 125 46 80 -> +16172295005 10 176 159 3

Can anyone tell from the attached Ekiga log what is causing the dropped calls? Looks like the clue is in the line

2010/11/25 07:42:29.780 0:44.681 Housekeeper:0xb6cdbb70 SIP Failed to receive ACK!

Opal then ends the call due to a temporary failure.

Any help would be very much appreciated.

Sincerely,
Felix

Follow-Ups:
- Re: [Ekiga-list] Dropped call after approximately 30s, "Failed to receive ACK!"
  - From: =?UTF-8?B?SsSBbmlzIFJ1a8WhxIFucw==?=

References:
- [Ekiga-list] Dropped call after approximately 30s, "Failed to receive ACK!"
  - From: Felix Lechner

[Date Prev][Date Next] [Thread Prev][Thread Next] [Thread Index] [Date Index] [Author Index]