[Spce-user] No ACK from Sipwise after 200 OK

Wed Jun 22 18:43:08 EDT 2016

The subject and the first line of the message are a bit different, let me
rephrase. The problem is it seems the one leg sends a ACK in response to a
200 OK to the sipwise, but the sipwise never sends the ACK to the other
leg, therefore the other leg keeps retrying sending the 200 OK.

Thanks!

On Wed, Jun 22, 2016 at 6:34 PM, Abel Alejandro <
aalejandro at alliedtechnologygrouppr.com> wrote:

> Hello,
>
> My calls are working however I just want to clarify something. When a call
> comes thru, after the endpoint sends a 200 OK to sipwise (192.254.110.41),
> it seems sipwise doesnt forward this to the other leg of the call, is this
> normal?
>
> Pictures of both legs:
>
> https://dl.dropboxusercontent.com/u/41014173/lega.PNG
> https://dl.dropboxusercontent.com/u/41014173/legb.png
>
> SIPWise info:
>
> root at sip:/var/log/ngcp# cat /etc/sipwise_ngcp_version
> System installed. NGCP version mr3.4.2 on 2014-11-20 02:35:58
> System installed. NGCP version mr3.5.1 - upgraded on 2014-11-20 03:26:29
> System installed. NGCP version mr3.6.1 - upgraded on 2014-11-20 03:42:49
> System installed. NGCP version mr3.7.1 - upgraded on 2015-02-01 11:38:34
> System installed. NGCP version mr3.8.2 - upgraded on 2015-07-27 01:06:25
> System installed. NGCP version mr3.8.3 - upgraded on 2015-10-06 23:44:13
> System installed. NGCP version mr4.0.1 - upgraded on 2015-10-07 00:12:10
> System installed. NGCP version mr4.1.1 - upgraded on 2015-11-20 00:25:40
> System installed. NGCP version mr4.1.2 - upgraded on 2016-06-12 02:16:40
> System installed. NGCP version mr4.2.1 - upgraded on 2016-06-12 05:47:53
> System installed. NGCP version mr4.2.2 - upgraded on 2016-06-22 01:53:41
> System installed. NGCP version mr4.3.1 - upgraded on 2016-06-22 02:38:38
> System installed. NGCP version mr4.4.1 - upgraded on 2016-06-22 02:59:33
>
> root at sip:/var/log/ngcp# grep C5A0749D at 10.246.9.8 kamailio-lb.log
> Jun 22 18:20:05 sip lb[2914]: NOTICE: <script>: New request on lb -
> M=INVITE R=sip:7877050555 at 192.254.110.41:5060;transport=udp F=
> sip:7875868313 at 196.12.170.244:5060 T=sip:7877050555 at 192.254.110.41:5060
> IP=udp:196.12.170.244:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip lb[2914]: NOTICE: <script>: Relaying request, du='sip:
> 127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:7877050555
> @192.254.110.41:5060;transport=udp ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip lb[2922]: NOTICE: <script>: Reply from Inbound - S=100
> - Trying M=INVITE IP=udp:127.0.0.1:5062 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip lb[2922]: NOTICE: <script>: Sending reply, fs='udp:
> 192.254.110.41:5060' - ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip lb[2919]: NOTICE: <script>: New request on lb -
> M=INVITE R=sip:17877050555 at 196.12.166.251:5060 F=
> sip:17875868313 at sip.fusetelecom.com T=sip:17877050555 at sip.fusetelecom.com
> IP=udp:127.0.0.1:5080 ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:05 sip lb[2919]: NOTICE: <script>: Relaying request,
> du='<null>', fs='udp:192.254.110.41:5060' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8_b2b-1
> UA='<null>'
> Jun 22 18:20:05 sip lb[2907]: NOTICE: <script>: Reply from Outbound -
> S=100 - Trying M=INVITE IP=udp:196.12.166.251:5060
> ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:05 sip lb[2907]: NOTICE: <script>: Sending reply, fs='udp:
> 127.0.0.1:5060' - ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2909]: NOTICE: <script>: Reply from Outbound -
> S=200 - OK M=INVITE IP=udp:196.12.166.251:5060
> ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2909]: NOTICE: <script>: Sending reply, fs='udp:
> 127.0.0.1:5060' - ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2907]: NOTICE: <script>: Reply from Outbound -
> S=200 - OK M=INVITE IP=udp:196.12.166.251:5060
> ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2907]: NOTICE: <script>: Sending reply, fs='udp:
> 127.0.0.1:5060' - ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2912]: NOTICE: <script>: Reply from Outbound -
> S=200 - OK M=INVITE IP=udp:196.12.166.251:5060
> ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2912]: NOTICE: <script>: Sending reply, fs='udp:
> 127.0.0.1:5060' - ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2920]: NOTICE: <script>: Reply from Inbound - S=200
> - OK M=INVITE IP=udp:127.0.0.1:5062 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2920]: NOTICE: <script>: Sending reply, fs='udp:
> 192.254.110.41:5060' - ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2910]: NOTICE: <script>: New request on lb - M=ACK
> R=sip:ngcp-lb at 192.254.110.41:5060;ngcpct=7369703a3132372e302e302e313a353038303b707278726f7574653d31
> F=sip:7875868313 at 196.12.170.244:5060 T=sip:7877050555 at 192.254.110.41:5060
> IP=udp:196.12.170.244:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2910]: NOTICE: <script>: Relaying request,
> du='sip:127.0.0.1:5062;lr=on;ftag=10.246.9.8+1+4e9d19+990c8790;did=dce.2ea;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=cmVrY3ZlX1B+RDpvbXsmFyMHHWomPikxNCEOAyQfbHo6Jjg-',
> fs='udp:127.0.0.1:5060' - R=sip:127.0.0.1:5080;prxroute=1 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2922]: NOTICE: <script>: New request on lb - M=ACK
> R=sip:17877050555 at 196.12.166.251:5060 F=
> sip:17875868313 at sip.fusetelecom.com T=sip:17877050555 at sip.fusetelecom.com
> IP=udp:127.0.0.1:5080 ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:06 sip lb[2922]: NOTICE: <script>: Relaying request,
> du='<null>', fs='udp:192.254.110.41:5060' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8_b2b-1
> UA='<null>'
> Jun 22 18:20:06 sip lb[2919]: NOTICE: <script>: Reply from Inbound - S=200
> - OK M=INVITE IP=udp:127.0.0.1:5062 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2919]: NOTICE: <script>: Sending reply, fs='udp:
> 192.254.110.41:5060' - ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2908]: NOTICE: <script>: New request on lb - M=ACK
> R=sip:ngcp-lb at 192.254.110.41:5060;ngcpct=7369703a3132372e302e302e313a353038303b707278726f7574653d31
> F=sip:7875868313 at 196.12.170.244:5060 T=sip:7877050555 at 192.254.110.41:5060
> IP=udp:196.12.170.244:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip lb[2908]: NOTICE: <script>: Relaying request,
> du='sip:127.0.0.1:5062;lr=on;ftag=10.246.9.8+1+4e9d19+990c8790;did=dce.2ea;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=cmVrY3ZlX1B+RDpvbXsmFyMHHWomPikxNCEOAyQfbHo6Jjg-',
> fs='udp:127.0.0.1:5060' - R=sip:127.0.0.1:5080;prxroute=1 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2912]: NOTICE: <script>: New request on lb - M=BYE
> R=sip:ngcp-lb at 192.254.110.41:5060;ngcpct=7369703a3132372e302e302e313a353038303b707278726f7574653d31
> F=sip:7875868313 at 196.12.170.244:5060 T=sip:7877050555 at 192.254.110.41:5060
> IP=udp:196.12.170.244:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2912]: NOTICE: <script>: Relaying request,
> du='sip:127.0.0.1:5062;lr=on;ftag=10.246.9.8+1+4e9d19+990c8790;did=dce.2ea;ice_caller=strip;ice_callee=strip;aset=50;rtpprx=yes;vsf=cmVrY3ZlX1B+RDpvbXsmFyMHHWomPikxNCEOAyQfbHo6Jjg-',
> fs='udp:127.0.0.1:5060' - R=sip:127.0.0.1:5080;prxroute=1 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2921]: NOTICE: <script>: Reply from Inbound - S=100
> - Trying M=BYE IP=udp:127.0.0.1:5062 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2921]: NOTICE: <script>: Sending reply, fs='udp:
> 192.254.110.41:5060' - ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2915]: NOTICE: <script>: New request on lb - M=BYE
> R=sip:17877050555 at 196.12.166.251:5060 F=
> sip:17875868313 at sip.fusetelecom.com T=sip:17877050555 at sip.fusetelecom.com
> IP=udp:127.0.0.1:5080 ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:12 sip lb[2915]: NOTICE: <script>: Relaying request,
> du='<null>', fs='udp:192.254.110.41:5060' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8_b2b-1
> UA='<null>'
> Jun 22 18:20:12 sip lb[2910]: NOTICE: <script>: Reply from Outbound -
> S=200 - OK M=BYE IP=udp:196.12.166.251:5060 ID=C5A0749D at 10.246.9.8_b2b-1
> UA='<null>'
> Jun 22 18:20:12 sip lb[2910]: NOTICE: <script>: Sending reply, fs='udp:
> 127.0.0.1:5060' - ID=C5A0749D at 10.246.9.8_b2b-1 UA='<null>'
> Jun 22 18:20:12 sip lb[2918]: NOTICE: <script>: Reply from Inbound - S=200
> - OK M=BYE IP=udp:127.0.0.1:5062 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip lb[2918]: NOTICE: <script>: Sending reply, fs='udp:
> 192.254.110.41:5060' - ID=C5A0749D at 10.246.9.8 UA='<null>'
> root at sip:/var/log/ngcp#
>
> root at sip:/var/log/ngcp# grep C5A0749D at 10.246.9.8 kamailio-proxy.log
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: New request on proxy -
> M=INVITE R=sip:7877050555 at 192.254.110.41:5060;transport=udp F=
> sip:7875868313 at 196.12.170.244:5060 T=sip:7877050555 at 192.254.110.41:5060
> IP=196.12.170.244:5060 (127.0.0.1:5060) ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Call from PSTN - R=sip:
> 7877050555 at 192.254.110.41:5060;transport=udp ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: User-Provided CLI '
> 7875868313' taken from From-User - R=sip:7877050555 at 192.254.110.41:5060;transport=udp
> ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Network-Provided CLI '
> 7875868313' taken from From-User - R=sip:7877050555 at 192.254.110.41:5060;transport=udp
> ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Rewriting user-provided
> CLI '7875868313' to '17875868313' - R=sip:7877050555 at 192.254.110.41:5060;transport=udp
> ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Rewriting
> network-provided CLI '7875868313' to '17875868313' -
> R=sip:7877050555 at 192.254.110.41:5060;transport=udp ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting '
> 17875868313 at 196.12.170.244' as initiating user-provided CLI - R=sip:
> 7877050555 at 192.254.110.41:5060;transport=udp ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting '
> 17875868313 at 196.12.170.244' as initiating network-provided CLI - R=sip:
> 7877050555 at 192.254.110.41:5060;transport=udp ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Rewriting called party '
> 7877050555' to '17877050555' - R=sip:7877050555 at 192.254.110.41:5060;transport=udp
> ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Callee was aliased with
> base '17877050555' - R=sip:fusetelecompbx at sip.fusetelecom.com:5060;transport=udp
> ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Callee is local,
> uuid='f6005efc-9972-4d05-931d-d7b9680274ed' -
> R=sip:fusetelecompbx at sip.fusetelecom.com:5060;transport=udp ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting acc source-leg
> for uuid '0': '0|7875868313|196.12.170.244|17875868313|||0|||0|call|196.12.170.244|1466634005.561546||||||||||||'
> - R=sip:fusetelecompbx at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting acc
> destination-leg for uuid 'f6005efc-9972-4d05-931d-d7b9680274ed':
> '0|17877054150|Fusetelecom
> PBX|124|7877050555|f6005efc-9972-4d05-931d-d7b9680274ed|fusetelecompbx|
> sip.fusetelecom.com|17877050555|192.254.110.41|1||||||||||||' - R=
> sip:fusetelecompbx at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Local user online,
> using alias as user - R=sip:17877050555 at 196.12.166.251:5060 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting
> caller_cli_userprov/caller_domain_userprov '
> 17875868313 at sip.fusetelecom.com' for upn - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting From to '<
> sip:17875868313 at sip.fusetelecom.com>' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting
> caller_cli_netprov/caller_domain_netprov '17875868313 at sip.fusetelecom.com'
> for npn - R=sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting PAI to '<
> sip:17875868313 at sip.fusetelecom.com>' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Setting
> P-Called-Party-ID '<sip:17877050555 at sip.fusetelecom.com>' - R=
> sip:17877050555 at 196.12.166.251:5060 ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Appending P-D-URI
> 'sip:127.0.0.1:5060;lr' - R=sip:17877050555 at 196.12.166.251:5060 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Forcing request via
> B2BUA 'sip:127.0.0.1:5080' - R=sip:17877050555 at 196.12.166.251:5060 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3785]: NOTICE: <script>: Request leaving server,
> D-URI='sip:127.0.0.1:5080' - R=sip:17877050555 at 196.12.166.251:5060 ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:05 sip proxy[3777]: NOTICE: <script>: NAT-Reply - S=100 -
> Connecting M=INVITE IP=196.12.170.244:5060 (127.0.0.1:5080) ID=
> C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip proxy[3797]: NOTICE: <script>: NAT-Reply - S=200 - OK
> M=INVITE IP=196.12.170.244:5060 (127.0.0.1:5080) ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:06 sip proxy[3788]: NOTICE: <script>: New request on proxy -
> M=ACK R=sip:127.0.0.1:5080;prxroute=1 F=sip:7875868313 at 196.12.170.244:5060
> T=sip:7877050555 at 192.254.110.41:5060 IP=196.12.170.244:5060 (
> 127.0.0.1:5060) ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:06 sip proxy[3779]: NOTICE: <script>: NAT-Reply - S=200 - OK
> M=INVITE IP=196.12.170.244:5060 (127.0.0.1:5080) ID=C5A0749D at 10.246.9.8
> UA='<null>'
> Jun 22 18:20:06 sip proxy[3794]: NOTICE: <script>: New request on proxy -
> M=ACK R=sip:127.0.0.1:5080;prxroute=1 F=sip:7875868313 at 196.12.170.244:5060
> T=sip:7877050555 at 192.254.110.41:5060 IP=196.12.170.244:5060 (
> 127.0.0.1:5060) ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip proxy[3788]: NOTICE: <script>: New request on proxy -
> M=BYE R=sip:127.0.0.1:5080;prxroute=1 F=sip:7875868313 at 196.12.170.244:5060
> T=sip:7877050555 at 192.254.110.41:5060 IP=196.12.170.244:5060 (
> 127.0.0.1:5060) ID=C5A0749D at 10.246.9.8 UA='<null>'
> Jun 22 18:20:12 sip proxy[3779]: NOTICE: <script>: NAT-Reply - S=200 - OK
> M=BYE IP=196.12.170.244:5060 (127.0.0.1:5080) ID=C5A0749D at 10.246.9.8
> UA='<null>'
> root at sip:/var/log/ngcp#
>
> --
> *Abel Alejandro*
>
> 787 586 8313 | 787 705 0555
> <joquendo at alliedtechnologygrouppr.com>
>
> 400 Calle Calaf 477
> San Juan, PR 00918
> aalejandro at alliedtechnologygrouppr.com
>

-- 
*Abel Alejandro*

787 586 8313 | 787 705 0555
<joquendo at alliedtechnologygrouppr.com>

400 Calle Calaf 477
San Juan, PR 00918
aalejandro at alliedtechnologygrouppr.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20160622/e160bc6e/attachment-0001.html>