[Spce-user] Help on SIPWISE an IMS AS

Thu Feb 8 11:03:07 EST 2018

Daniel,

Attached is the file.

Regards

Lanvin

De : Daniel Grotti [mailto:dgrotti at sipwise.com] 
Envoyé : jeudi 8 février 2018 15:46
À : Lanvin ADON <lanvin.adon at kaina-com.fr>; spce-user at lists.sipwise.com
Objet : Re: [Spce-user] Help on SIPWISE an IMS AS

Hi Lanvin,
can you share the kamailio-proxy.log for this call?

Daniel

On 02/08/2018 12:18 PM, Lanvin ADON wrote:

Hi Daniel,

I don’t understand why I’m not having any answer on my request hereafter.

Is it out of the community scope?

My name is Lanvin ADON, telecom engineer.

I've integrated  <SIP:PROVIDER> sipwise CE on our training LAB as IMS-AS.

Third party registration is OK.

UE to UE call through the AS is OK

Call forwarding to VM is OK.

I'm facing issue on diversion (All CF to URIs). The problem is that the AS
is sending the contact header instead of the URI of the FTN set in the GUI.

Almost two weeks trying to debug but no good result and I'm coming to you
for your support.

The case:

1.       Student21 - Student22 & Student23 success 3rd party registration in
<sip:provider> sipwise ce

2.       Student21 forwarded to student22

3.       Student23 calls student21

4.       S-CSCF sent INVITE to sipwise CE

5.        <Sip:provider> sipwise sent back invite but with scscf hostname as
R-URI instead of URI set in the GUI (student22)

6.       IMS cancel the call with user not found. 

Sipwise NGCP platform version 'mr5.4.1'

Could anyone please provide support on this?

Regards

Lanvin ADON

De : Spce-user [mailto:spce-user-bounces at lists.sipwise.com] De la part de
Daniel Grotti
Envoyé : mardi 6 février 2018 14:45
À : spce-user at lists.sipwise.com <mailto:spce-user at lists.sipwise.com> 
Objet : Re: [Spce-user] mail test

Everything look good!  :)

-- 
Daniel Grotti
Head of Customer Support
Sipwise GmbH, Campus 21/Europaring F15
AT-2345 Brunn am Gebirge

Office: +43(0)130120332
Email: dgrotti at sipwise.com <mailto:dgrotti at sipwise.com> 
Website: https://www.sipwise.com

On 02/06/2018 03:34 PM, KAINA-COM wrote:

Hi all,

I’m new in the list. Just to make a test to check no error back to me.

Regards

Lanvin ADON

_______________________________________________
Spce-user mailing list
Spce-user at lists.sipwise.com <mailto:Spce-user at lists.sipwise.com> 
https://lists.sipwise.com/listinfo/spce-user

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20180208/080a8934/attachment-0001.html>
-------------- next part --------------
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: New request on proxy - M=INVITE R=sip:student21 at binobox-ims2.com F=sip:student23 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.146:44389 (10.88.1.50:5060) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Reset initial local route - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Request from IMS Core - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Extracted topmost route host 'sipwise.binobox-ims.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Successfully removed own topmost Route 'sipwise.binobox-ims.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Successfully replaced Route with P-Route - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load domain preferences for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Clean domain preferences for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Extracted caller info from P-Served-User, subscriber=student23 at binobox-ims2.com - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Successfully looked up IMS subscriber student23 at binobox-ims2.com with uuid '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Adding reply P-NGCP-Caller-Info '<sip:<null>@<null>>;ip=10.88.1.146;port=44389;primary=2259910023' - ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: IMS marker, s:ims_role='orig', s:caller_uuid='06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7', s:callee_uuid='<null>', s:acc_caller_user='student23', s:acc_caller_domain='binobox-ims2.com'  - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Clear caller preferences - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load caller preferences for uuid '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7' and domain 'binobox-ims2.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking User-Agent filters - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: User-Agent header found, check filter list - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: UA filter mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: UA filter checks passed - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load caller contract preferences for contract id '4' and ip '10.88.1.146' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Loaded caller contract preferences for location id '<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting network-provided domain 'binobox-ims2.com' as acc_caller_domain - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use lb/rtp set id '50' for local caller - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Fetched dialplan IDs caller_in='<null>', callee_in='<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: CDR IP header 'P-NGCP-Src-Ip' and 'P-NGCP-Src-Ip' not found, use received IP - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Dialog managed, lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: IP authorization for caller not provisioned, allow call - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: User-Provided CLI 'student23' taken from From-User - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking User-provided CLI against allowed CLIs - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: User-provided CLI 'student23' rejected, using network-provided CLI '2259910023' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting '2259910023 at binobox-ims2.com' as initiating user-provided CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting '2259910023 at binobox-ims2.com' as initiating network-provided CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Skip callee search for originating IMS AS leg - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Dialog set total - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7/4' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting acc source-leg for uuid '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7': '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7|student23|binobox-ims2.com|2259910023|||4|||0|call|10.88.1.50|1518105559.619164||||||||||||2259910023|' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting acc destination-leg for uuid '<null>': '0|||0|student21|<null>|student21|binobox-ims2.com|<null>|<null>|0||||||||||||student21|' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Manually set lb 'sip:10.88.1.50:5060' for next hop for call to IMS core - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Relaying request, du='sip:10.88.1.50:5060' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: user, account to '<null>/0' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '<null>/0' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Bridge RTP interfaces ext/ext configured for caller/default - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Remove existing ICE candidates (if any) for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Engaging rtpengine in request for caller did '50' and callee did '50' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:3023]: select_rtpp_node(): script error - no valid set selected
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2539]: rtpp_function_call(): no available proxies
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting P-Caller-UUID to '06eda2bb-23a1-46c9-ad63-f4e6f46ce1e7' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Sessions Timers disabled for caller - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Sessions Timers disabled for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Remove Session-Expires - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting userprovided caller domain - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use first userprov caller domain 'binobox-ims2.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare From display-name setting - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare From username setting - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting From to '<sip:2259910023 at binobox-ims2.com>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare PAI username setting - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare PPI username setting - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare Diversion setting - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare P-Called-Party-ID setting using selector '0' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: WARNING: <core> [rvalue.c:1007]: rval_get_int(): automatic string to int conversion for "orig_callee" failed
Feb  8 16:59:19 sipwise proxy[27698]: WARNING: <core> [rvalue.c:1912]: rval_expr_eval_int(): rval expression conversion to int failed (8788,58-8788,70)
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting P-Called-Party-ID '<sip:student21 at binobox-ims2.com>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Writing sbc parameters  ;calltimer=21600;aleg_sst_enable=no;sst_enable=no - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Adding P-NGCP-Caller-Info '<sip:student23 at binobox-ims2.com>;ip=10.88.1.146;port=44389;primary=2259910023' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Adding P-NGCP-Callee-Info '<sip:<null>@<null>>;ip=10.88.1.50;port=5060' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Appending P-D-URI 'sip:10.88.1.50:5060;imsroute=3c7369703a6f64695f7a644d4f7568736867384031302e38382e312e3134363a353035343b6c723b6f7269673b736572766963653d73637363663e' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Forcing request via B2BUA 'sip:10.88.1.50:5080' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Request leaving server, D-URI='sip:10.88.1.50:5080' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27696]: NOTICE: <script>: NAT-Reply - S=100 - Connecting M=INVITE IP=10.88.1.146:44389 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: New request on proxy - M=INVITE R=sip:student21 at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.146:44389 (10.88.1.50:5060) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Reset initial local route - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Request from IMS Core - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Extracted topmost route host 'sipwise.binobox-ims.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Successfully removed own topmost Route 'sipwise.binobox-ims.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Successfully replaced Route with P-Route - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Load domain preferences for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Clean domain preferences for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Terminating call leg from IMS core - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Extracted caller info from From, subscriber=2259910023 at binobox-ims2.com - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Successfully looked up IMS subscriber 2259910023 at binobox-ims2.com with uuid '0' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding reply P-NGCP-Caller-Info '<sip:<null>@<null>>;ip=10.88.1.146;port=44389' - ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: IMS marker, s:ims_role='term', s:caller_uuid='0', s:callee_uuid='<null>', s:acc_caller_user='2259910023', s:acc_caller_domain='binobox-ims2.com'  - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Clear caller preferences - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Load caller preferences for uuid '0' and domain 'binobox-ims2.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking User-Agent filters - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: User-Agent header found, check filter list - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: UA filter mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: UA filter checks passed - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Setting network-provided domain 'binobox-ims2.com' as acc_caller_domain - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Use lb/rtp set id '50' for local caller - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Fetched dialplan IDs caller_in='<null>', callee_in='<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: CDR IP header 'P-NGCP-Src-Ip' and 'P-NGCP-Src-Ip' not found, use received IP - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Dialog managed, lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: IP authorization for caller not provisioned, allow call - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: User-Provided CLI '2259910023' taken from From-User - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking User-provided CLI against allowed CLIs - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: User-provided CLI '2259910023' rejected, using network-provided CLI '2259910023' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Setting '2259910023 at binobox-ims2.com' as initiating user-provided CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Setting '2259910023 at binobox-ims2.com' as initiating network-provided CLI - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Searching for callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Skipping internal services for unauthenticated call - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Extracted IMS callee info on term leg from P-Served-User, subscriber=student21 at binobox-ims2.com - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Clear callee preferences - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Callee is local, uuid='5c1f0688-8344-420d-8a2a-8fa23349ff58' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Load callee preferences for uuid '5c1f0688-8344-420d-8a2a-8fa23349ff58' domain: 'binobox-ims2.com'- R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Load callee contract preferences for contract id '4 and ip '<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Loaded callee contract preferences for location id '<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Use lb/rtp set id '50' for local callee - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Fetched dialplan IDs caller_out='<null>', callee_out='<null>' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Set callee dialogs: user, account to '5c1f0688-8344-420d-8a2a-8fa23349ff58/4' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '5c1f0688-8344-420d-8a2a-8fa23349ff58/4' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking UPN '2259910023' and NPN '2259910023' against block in lists - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Admin Contract callee block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Admin callee block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Contract callee block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Callee block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Check Administrative Contract NCOS level - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Check Administrative NCOS level - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Check Contract NCOS level - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Check User NCOS level - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking URI 'sip:student21 at binobox-ims2.com' and CLI 'student21' against admin contract block out lists - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Admin Contract caller block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking URI 'sip:student21 at binobox-ims2.com' and CLI 'student21' against block out lists - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Admin caller block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Checking URI 'sip:student21 at binobox-ims2.com' and CLI 'student21' against contract block out lists - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Contract caller block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Caller block mode is 'blacklist' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Ignore 'force_inbound_calls_to_peer' because callee was dialed by 'uri' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: CFU to CF map id '13' found - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: No CF source set for CF map id '13' found, CF is done always - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Loaded CF destination set for CF map id '13': 'sip:student22 at binobox-ims2.com' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Loaded CF timeouts for CF map id '13': '300' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: No CF time destination set for CF map id '13' found, CF is done always - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: No CF source configured, performing call-forward - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Setting acc source-leg for uuid '0': '0|2259910023|binobox-ims2.com|2259910023|||0|||0|call|10.88.1.50|1518105559.648608||||||||||||2259910023|' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Setting acc destination-leg for uuid '5c1f0688-8344-420d-8a2a-8fa23349ff58': '0|||4|student21|5c1f0688-8344-420d-8a2a-8fa23349ff58|student21|binobox-ims2.com|student21|binobox-ims2.com|0||||||||||||student21|' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Dialog set total - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '0/0' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to '0/0' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Trigger CF loop to 'sip:10.88.1.50:5062' for call to 'sip:playcfannounce at binobox-ims2.com' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Setting sbcprofile to cf - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Writing sbc parameters  ;profile=ngcp_cf - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Appending P-D-URI 'sip:10.88.1.50:5062' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Forcing request via B2BUA 'sip:10.88.1.50:5080' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding P-NGCP-Caller-Info '<sip:2259910023 at binobox-ims2.com>;ip=10.88.1.146;port=44389' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding P-NGCP-Forward-Info '<sip:student21 at binobox-ims2.com>;ip=10.88.1.50;port=5080;primary=2259910021' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding P-NGCP-Callee-Info '<sip:playcfannounce at binobox-ims2.com>;ip=10.88.1.50;port=5080' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: New request on proxy - M=INVITE R=sip:playcfannounce at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Load domain preferences for callee - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Clean domain preferences for callee - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: Internal CF loop - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: IMS marker, s:ims_role='<null>', s:caller_uuid='5c1f0688-8344-420d-8a2a-8fa23349ff58', s:callee_uuid='<null>', s:acc_caller_user='student21', s:acc_caller_domain='binobox-ims2.com'  - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Clear caller preferences - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Load caller preferences for uuid '5c1f0688-8344-420d-8a2a-8fa23349ff58' and domain 'binobox-ims2.com' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Checking User-Agent filters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: User-Agent header missing, check for enforced rejection - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: UA filter checks passed - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Load caller contract preferences for contract id '4' and ip '10.88.1.50' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Loaded caller contract preferences for location id '<null>' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Use lb/rtp set id '50' for local caller - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Fetched dialplan IDs caller_in='<null>', callee_in='<null>' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: CDR IP header 'P-NGCP-Src-Ip' and 'P-NGCP-Src-Ip' not found, use received IP - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: IP authorization for caller not provisioned, allow call - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Use NPN '2259910021' as UPN for CF loop - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Checking User-provided CLI against allowed CLIs - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: User-provided CLI '2259910021' accepted (matched user preference) - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Searching for callee - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: Rate check request - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Skip accounting for failed request as flagged - R=sip:playcfannounce at app.local ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: Adding reply P-NGCP-Caller-Info '<sip:student21 at binobox-ims2.com>;ip=10.88.1.50;port=5080;primary=2259910021' - ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: NOTICE: <script>: New request on proxy - M=ACK R=sip:playcfannounce at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Recovered rtpengine caller did '50' from default value - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Recovered rtpengine callee did '50' from caller value - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Not switching caller did and callee did for downstream in-dialog, caller did is '50' and callee did is '50' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27700]: NOTICE: <script>: Failure route for hunt call - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: No rtpengine engaged for this branch, no need for stopping  - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27701]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27701]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Relaying request, du='<null>' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: ++++++++++ incremented History-Info counter, $avp(s:cf_loop_counter)='2' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: ++++++++++ History-Info: (hunt failure) rcv_index='0' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[userout:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totaluserout:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: decreased user profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[accountout:4] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: decreased account profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[location:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[locationout:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totallocation:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totallocationout:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: decrased location profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Trigger CF loop to 'sip:10.88.1.50:5062' for call to 'sip:student22 at binobox-ims2.com' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Setting sbcprofile to cf - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Writing sbc parameters  ;profile=ngcp_cf - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: NOTICE: <script>: Appending P-D-URI 'sip:10.88.1.50:5062' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: NOTICE: <script>: Forcing request via B2BUA 'sip:10.88.1.50:5080' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Adding P-NGCP-Caller-Info '<sip:2259910023 at binobox-ims2.com>;ip=10.88.1.146;port=44389' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Adding P-NGCP-Forward-Info '<sip:student21 at binobox-ims2.com>;ip=10.88.1.50;port=5080;primary=2259910021' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Adding P-NGCP-Callee-Info '<sip:student22 at binobox-ims2.com>;ip=10.88.1.50;port=5080' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27700]: INFO: <script>: Dropping local hunt branch - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: New request on proxy - M=INVITE R=sip:student22 at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load domain preferences for callee - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Clean domain preferences for callee - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Internal CF loop - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: IMS marker, s:ims_role='<null>', s:caller_uuid='5c1f0688-8344-420d-8a2a-8fa23349ff58', s:callee_uuid='<null>', s:acc_caller_user='student21', s:acc_caller_domain='binobox-ims2.com'  - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Clear caller preferences - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load caller preferences for uuid '5c1f0688-8344-420d-8a2a-8fa23349ff58' and domain 'binobox-ims2.com' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking User-Agent filters - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: User-Agent header missing, check for enforced rejection - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: UA filter checks passed - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load caller contract preferences for contract id '4' and ip '10.88.1.50' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Loaded caller contract preferences for location id '<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use lb/rtp set id '50' for local caller - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Fetched dialplan IDs caller_in='<null>', callee_in='<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: CDR IP header 'P-NGCP-Src-Ip' and 'P-NGCP-Src-Ip' not found, use received IP - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: IP authorization for caller not provisioned, allow call - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use NPN '2259910021' as UPN for CF loop - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking User-provided CLI against allowed CLIs - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: User-provided CLI '2259910021' accepted (matched user preference) - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Searching for callee - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Clear callee preferences - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Callee is local, uuid='4e1b6048-c7e3-4164-b8b2-8500a654ea27' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load callee preferences for uuid '4e1b6048-c7e3-4164-b8b2-8500a654ea27' domain: 'binobox-ims2.com'- R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load callee contract preferences for contract id '4 and ip '<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Loaded callee contract preferences for location id '<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use lb/rtp set id '50' for local callee - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Fetched dialplan IDs caller_out='<null>', callee_out='<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: WARNING: <script>: Dialog *NOT* managed - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Dialog managed, lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: user, account to '4e1b6048-c7e3-4164-b8b2-8500a654ea27/4' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '4e1b6048-c7e3-4164-b8b2-8500a654ea27/4' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking UPN '2259910021' and NPN '2259910021' against block in lists - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Admin Contract callee block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Admin callee block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Contract callee block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Callee block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Check Administrative Contract NCOS level - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Check Administrative NCOS level - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Check Contract NCOS level - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Check User NCOS level - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Check Administrative CF NCOS level - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking URI 'sip:student22 at binobox-ims2.com' and CLI 'student22' against admin contract block out lists - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Admin Contract caller block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking URI 'sip:student22 at binobox-ims2.com' and CLI 'student22' against block out lists - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Admin caller block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Checking URI 'sip:student22 at binobox-ims2.com' and CLI 'student22' against contract block out lists - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Contract caller block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Caller block mode is 'blacklist' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Ignore 'force_inbound_calls_to_peer' because callee was dialed by 'uri' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Dialog set mark type to local - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Dialog set total - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set caller dialogs: totaluser, totaluserout, totalaccount, totalaccountout to '5c1f0688-8344-420d-8a2a-8fa23349ff58/4' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set caller dialogs: user, userout, account, accountout to '5c1f0688-8344-420d-8a2a-8fa23349ff58/4' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting acc source-leg for uuid '5c1f0688-8344-420d-8a2a-8fa23349ff58': '5c1f0688-8344-420d-8a2a-8fa23349ff58|student21|binobox-ims2.com|2259910021|||4|||0|cfu|10.88.1.50|1518105559.678220||||||||||||2259910021|' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting acc destination-leg for uuid '4e1b6048-c7e3-4164-b8b2-8500a654ea27': '0|||4|student22|4e1b6048-c7e3-4164-b8b2-8500a654ea27|student22|binobox-ims2.com|student22|binobox-ims2.com|0||||||||||||student22|' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Relaying request, du='sip:lb at 10.88.1.50;lr;socket=sip:10.88.1.50:5060' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Load callee contract preferences for contract id '4 and ip 'scscf.sprout.binobox-ims2.com' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Loaded callee contract preferences for location id '<null>' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: user, account to '4e1b6048-c7e3-4164-b8b2-8500a654ea27/4' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Set callee dialogs: totaluser, totalaccount to '4e1b6048-c7e3-4164-b8b2-8500a654ea27/4' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Bridge RTP interfaces ext/ext configured for original caller/callee - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Usage of rtpengine forced by preference - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Remove existing ICE candidates (if any) for callee - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Try protocol 'transparent' for callee - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Engaging rtpengine in request for caller did '50' and callee did '50' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:3023]: select_rtpp_node(): script error - no valid set selected
Feb  8 16:59:19 sipwise proxy[27698]: ERROR: rtpengine [rtpengine.c:2539]: rtpp_function_call(): no available proxies
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting P-Caller-UUID to '5c1f0688-8344-420d-8a2a-8fa23349ff58' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting P-Callee-UUID to '4e1b6048-c7e3-4164-b8b2-8500a654ea27' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Local user online, using registered contact as user - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Sessions Timers disabled for caller - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Sessions Timers disabled for callee - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Setting userprovided caller domain - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Use first userprov caller domain 'binobox-ims2.com' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare From display-name setting - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare From username setting - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting caller_cli_userprov/caller_domain_userprov '2259910023 at binobox-ims2.com' for upn - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting From to '<sip:2259910023 at binobox-ims2.com>' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare PAI username setting - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting caller_cli_netprov/caller_domain_netprov '2259910023 at binobox-ims2.com' for npn - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting PAI to '<sip:2259910023 at binobox-ims2.com>' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare PPI username setting - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare Diversion setting - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: No selector set, not setting CLI - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Prepare P-Called-Party-ID setting using selector 'orig_callee' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Setting P-Called-Party-ID '<sip:student21 at binobox-ims2.com>' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Writing sbc parameters  ;calltimer=21600;aleg_sst_enable=no;sst_enable=no - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Adding P-NGCP-Caller-Info '<sip:student21 at binobox-ims2.com>;ip=10.88.1.50;port=5080;primary=2259910021' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: INFO: <script>: Adding P-NGCP-Callee-Info '<sip:student22 at binobox-ims2.com>;ip=10.88.1.50;port=5060;primary=2259910022' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Appending P-D-URI 'sip:lb at 10.88.1.50;lr;socket=sip:10.88.1.50:5060' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Forcing request via B2BUA 'sip:10.88.1.50:5080' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27698]: NOTICE: <script>: Request leaving server, D-URI='sip:10.88.1.50:5080' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27696]: NOTICE: <script>: NAT-Reply - S=100 - Connecting M=INVITE IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: NAT-Reply - S=404 - Not Found M=INVITE IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Stop rtpengine for current branch using first Via, caller did is '50' and callee did is '50' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:3023]: select_rtpp_node(): script error - no valid set selected
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2539]: rtpp_function_call(): no available proxies
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: Failure route for local call - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Stop rtpengine for current branch using first Via, caller did is '50' and callee did is '50' - R=sip:scscf.sprout.binobox-ims2.com;transport=TCP ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:3023]: select_rtpp_node(): script error - no valid set selected
Feb  8 16:59:19 sipwise proxy[27699]: ERROR: rtpengine [rtpengine.c:2539]: rtpp_function_call(): no available proxies
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding reply P-NGCP-Caller-Info '<sip:student21 at binobox-ims2.com>;ip=10.88.1.50;port=5080;primary=2259910021' - ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: INFO: <script>: Adding reply P-NGCP-Callee-Info '<sip:student22 at binobox-ims2.com>;ip=scscf.sprout.binobox-ims2.com;port=5060;primary=2259910022' - ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27699]: NOTICE: <script>: [dialog:failed] decreased redis counters lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=sip:you at kamailio.org ID=123 UA='<null>'
Feb  8 16:59:19 sipwise proxy[27703]: NOTICE: <script>: New request on proxy - M=ACK R=sip:student22 at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.50:5080 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27703]: INFO: <script>: Recovered rtpengine caller did '50' from default value - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27703]: INFO: <script>: Recovered rtpengine callee did '50' from caller value - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: Failure route for hunt call - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27703]: INFO: <script>: Not switching caller did and callee did for downstream in-dialog, caller did is '50' and callee did is '50' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: No rtpengine engaged for this branch, no need for stopping  - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27703]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27703]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27703]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27703]: INFO: <script>: Relaying request, du='<null>' - R=sip:student22 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: ++++++++++ incremented History-Info counter, $avp(s:cf_loop_counter)='3' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: ++++++++++ History-Info: (hunt failure) rcv_index='0' - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[user:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[userout:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totaluser:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totaluserout:5c1f0688-8344-420d-8a2a-8fa23349ff58] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: decreased user profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[account:4] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[accountout:4] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totalaccount:4] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totalaccountout:4] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: decreased account profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[location:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[locationout:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totallocation:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: WARNING: app_lua [app_lua_sr.c:98]: lua_sr_log(): central:del[totallocationout:<null>] counter was -1
Feb  8 16:59:19 sipwise proxy[27697]: INFO: <script>: decrased location profile redis counters - R=sip:playcfannounce at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='IM-client/OMA1.0 Boghe-Win32/v2.0.153.836'
Feb  8 16:59:19 sipwise proxy[27697]: NOTICE: <script>: [dialog:failed] decreased redis counters lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=<null> ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: NOTICE: <script>: New request on proxy - M=ACK R=sip:student21 at binobox-ims2.com F=sip:2259910023 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.146:44389 (10.88.1.50:5060) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Recovered rtpengine caller did '50' from default value - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Recovered rtpengine callee did '50' from caller value - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Not switching caller did and callee did for downstream in-dialog, caller did is '50' and callee did is '50' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27701]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27701]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27701]: INFO: <script>: Relaying request, du='sip:sipwise.binobox-ims.com:5060;lr' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27700]: NOTICE: <script>: NAT-Reply - S=404 - Not Found M=INVITE IP=10.88.1.146:44389 (10.88.1.50:5080) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27700]: NOTICE: <script>: [dialog:failed] decreased redis counters lua_dlg_callid:[503f79db-d59f-5975-6742-7e44ef1e3ddf] - R=<null> ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: NOTICE: <script>: New request on proxy - M=ACK R=sip:student21 at binobox-ims2.com F=sip:student23 at binobox-ims2.com T=sip:student21 at binobox-ims2.com IP=10.88.1.146:44389 (10.88.1.50:5060) ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: INFO: <script>: Recovered rtpengine caller did '50' from default value - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: INFO: <script>: Recovered rtpengine callee did '50' from caller value - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: INFO: <script>: Not switching caller did and callee did for downstream in-dialog, caller did is '50' and callee did is '50' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: INFO: <script>: Use rtpengine for forward direction for IPv4/IPv4 - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
Feb  8 16:59:19 sipwise proxy[27702]: ERROR: rtpengine [rtpengine.c:2859]: select_rtpp_set(): no rtpp_set_list->rset_first
Feb  8 16:59:19 sipwise proxy[27702]: ERROR: rtpengine [rtpengine.c:3436]: set_rtpengine_set_n(): could not locate rtpengine set 50
Feb  8 16:59:19 sipwise proxy[27702]: INFO: <script>: Relaying request, du='sip:sipwise.binobox-ims.com:5060;lr' - R=sip:student21 at binobox-ims2.com ID=503f79db-d59f-5975-6742-7e44ef1e3ddf UA='<null>'
^C