NAT

classic Classic list List threaded Threaded
16 messages Options
leo
Reply | Threaded
Open this post in threaded view
|

NAT

leo
This post was updated on .
CONTENTS DELETED
The author has deleted this message.
Reply | Threaded
Open this post in threaded view
|

Re: NAT

shaheryarkh
You are missing one fundamental fact, that is you have to handle NAT for both signalling and media. From your description it looks signalling is going perfect (NAT is correctly handled), since you are able to establish call between two clients successfully, clients can register, make call, accept call and hangup call with your server. So main goal of NAT Traversal module is achieved. 

However, there is no media on call, so media NAT is not handled. NAT Traversal and / or NAT Helper modules may try to fix media NAT issues as well by manipulating SDP but in so many case they will be simply NOT enough for this purpose. Especially in case of 3g and corporate networks, which may have very very complex network typology with multiple layers of NAT (so called Nested NAT). So rtp / media proxy is the ONLY solution that can handle media across such complex networks.

If you have really good sip clients with support for STUN / TURN / ICE etc. and you somewhat control over client data network environment, them you may fix media NAT issues up to 90% but in about 5-10% cases you will still need a media relay.

Thank you.


On Mon, Feb 25, 2013 at 11:51 PM, leo <[hidden email]> wrote:
Hello,

Unfortunately after reading the forum i've to open a new post about NAT
because i couldn't find a clear solution and information for my problem.
I've also read the NAT Traversal module documentation.

I've an OpenSIPS server (version 1.8.2) on a Debian system (6.0.7 -
2.6.32-5-686).
OpenSIPS was installed by the apt-get install using the apt.opensips.org
repository and configured with osipsconfig (residential script with ALIASES,
AUTH, DBACC, DBUSRLOC and DIALOG).

The UAs can register to the OpenSIPS server. They can place the call but i
've no audio no video.
The OpenSIPS server has a public IP address (so, no natted).
The UAs could be natted or with public ip thru 3G.

I wouldn't like to use rtproxy or mediaproxy cause the rtp traffic would be
passing by those servers (am i correct?) adding jitter and latency.
I would set up the system in the way the the rtp traffic would be P2P. Would
NAT Traversal be the solution? How it should be configured (i've already
enabled the required modules too)?

Thanks a lot.

Leo.



--
View this message in context: http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918.html
Sent from the OpenSIPS - Users mailing list archive at Nabble.com.

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



--
Muhammad Shahzad
-----------------------------------
CISCO Rich Media Communication Specialist (CRMCS)
CISCO Certified Network Associate (CCNA)
Cell: +49 176 99 83 10 85
MSN: [hidden email]
Email: [hidden email]

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Roberto Spadim
humm i got the same problem but didn't found a solution
my solution was connect internet (public ip) directly to voip server, in other words, i removed the opensip proxy and ntpproxy, but if anyone have the solution could be very nice, i googled many examples but they don't work


2013/2/25 Muhammad Shahzad <[hidden email]>
You are missing one fundamental fact, that is you have to handle NAT for both signalling and media. From your description it looks signalling is going perfect (NAT is correctly handled), since you are able to establish call between two clients successfully, clients can register, make call, accept call and hangup call with your server. So main goal of NAT Traversal module is achieved. 

However, there is no media on call, so media NAT is not handled. NAT Traversal and / or NAT Helper modules may try to fix media NAT issues as well by manipulating SDP but in so many case they will be simply NOT enough for this purpose. Especially in case of 3g and corporate networks, which may have very very complex network typology with multiple layers of NAT (so called Nested NAT). So rtp / media proxy is the ONLY solution that can handle media across such complex networks.

If you have really good sip clients with support for STUN / TURN / ICE etc. and you somewhat control over client data network environment, them you may fix media NAT issues up to 90% but in about 5-10% cases you will still need a media relay.

Thank you.


On Mon, Feb 25, 2013 at 11:51 PM, leo <[hidden email]> wrote:
Hello,

Unfortunately after reading the forum i've to open a new post about NAT
because i couldn't find a clear solution and information for my problem.
I've also read the NAT Traversal module documentation.

I've an OpenSIPS server (version 1.8.2) on a Debian system (6.0.7 -
2.6.32-5-686).
OpenSIPS was installed by the apt-get install using the apt.opensips.org
repository and configured with osipsconfig (residential script with ALIASES,
AUTH, DBACC, DBUSRLOC and DIALOG).

The UAs can register to the OpenSIPS server. They can place the call but i
've no audio no video.
The OpenSIPS server has a public IP address (so, no natted).
The UAs could be natted or with public ip thru 3G.

I wouldn't like to use rtproxy or mediaproxy cause the rtp traffic would be
passing by those servers (am i correct?) adding jitter and latency.
I would set up the system in the way the the rtp traffic would be P2P. Would
NAT Traversal be the solution? How it should be configured (i've already
enabled the required modules too)?

Thanks a lot.

Leo.



--
View this message in context: http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918.html
Sent from the OpenSIPS - Users mailing list archive at Nabble.com.

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



--
Muhammad Shahzad
-----------------------------------
CISCO Rich Media Communication Specialist (CRMCS)
CISCO Certified Network Associate (CCNA)
Cell: <a href="tel:%2B49%20176%2099%2083%2010%2085" value="+4917699831085" target="_blank">+49 176 99 83 10 85
MSN: [hidden email]
Email: [hidden email]

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




--
Roberto Spadim
SPAEmpresarial

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Adrian Georgescu
Using a media relay is the solution for your problem. You are asking for a solution to not use the solution which makes no sense.

Adrian
 
On Feb 25, 2013, at 7:24 PM, Roberto Spadim wrote:

humm i got the same problem but didn't found a solution
my solution was connect internet (public ip) directly to voip server, in other words, i removed the opensip proxy and ntpproxy, but if anyone have the solution could be very nice, i googled many examples but they don't work


2013/2/25 Muhammad Shahzad <[hidden email]>
You are missing one fundamental fact, that is you have to handle NAT for both signalling and media. From your description it looks signalling is going perfect (NAT is correctly handled), since you are able to establish call between two clients successfully, clients can register, make call, accept call and hangup call with your server. So main goal of NAT Traversal module is achieved. 

However, there is no media on call, so media NAT is not handled. NAT Traversal and / or NAT Helper modules may try to fix media NAT issues as well by manipulating SDP but in so many case they will be simply NOT enough for this purpose. Especially in case of 3g and corporate networks, which may have very very complex network typology with multiple layers of NAT (so called Nested NAT). So rtp / media proxy is the ONLY solution that can handle media across such complex networks.

If you have really good sip clients with support for STUN / TURN / ICE etc. and you somewhat control over client data network environment, them you may fix media NAT issues up to 90% but in about 5-10% cases you will still need a media relay.

Thank you.


On Mon, Feb 25, 2013 at 11:51 PM, leo <[hidden email]> wrote:
Hello,

Unfortunately after reading the forum i've to open a new post about NAT
because i couldn't find a clear solution and information for my problem.
I've also read the NAT Traversal module documentation.

I've an OpenSIPS server (version 1.8.2) on a Debian system (6.0.7 -
2.6.32-5-686).
OpenSIPS was installed by the apt-get install using the apt.opensips.org
repository and configured with osipsconfig (residential script with ALIASES,
AUTH, DBACC, DBUSRLOC and DIALOG).

The UAs can register to the OpenSIPS server. They can place the call but i
've no audio no video.
The OpenSIPS server has a public IP address (so, no natted).
The UAs could be natted or with public ip thru 3G.

I wouldn't like to use rtproxy or mediaproxy cause the rtp traffic would be
passing by those servers (am i correct?) adding jitter and latency.
I would set up the system in the way the the rtp traffic would be P2P. Would
NAT Traversal be the solution? How it should be configured (i've already
enabled the required modules too)?

Thanks a lot.

Leo.



--
View this message in context: http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918.html
Sent from the OpenSIPS - Users mailing list archive at Nabble.com.

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



--
Muhammad Shahzad
-----------------------------------
CISCO Rich Media Communication Specialist (CRMCS)
CISCO Certified Network Associate (CCNA)
Cell: <a href="tel:%2B49%20176%2099%2083%2010%2085" value="+4917699831085" target="_blank">+49 176 99 83 10 85
MSN: [hidden email]
Email: [hidden email]

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




--
Roberto Spadim
SPAEmpresarial
_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
Thanks Adrian.

There was a sense in my question, having the RTP traffic P2P would be translated in:
1) better user experience, less jitter and latency.
2) saving to install one or more mediaproxies. Considering that all RTP traffic will pass on them, they will need to have high bandwidth (symmetric up/down) and maybe CPU/RAM.
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Saúl Ibarra Corretgé

On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
Gracias Saul.
I'll read about mediaproxy and ICE. Bye for now.
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Adrian Georgescu
In reply to this post by leo

On Feb 28, 2013, at 6:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.

The added latency is in practice irrelevant and you can have jitter with or without media relay.

> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.

You cannot cut corners here, without a media relay your user experience will be horrible, as many calls will have no media at all or will have one way media.

> --
> View this message in context: http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918p7585000.html
> Sent from the OpenSIPS - Users mailing list archive at Nabble.com.
>
> _______________________________________________
> Users mailing list
> [hidden email]
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
This post was updated on .
In reply to this post by Saúl Ibarra Corretgé
Hello Saúl:

I've now running the OpenSIPS server with the Mediaproxy.
Some natted UA are working and others no. Those that can't, thay can call but no audio/video.
I would like to enable the ICE (cause the UA also support it) but i'm really stuck on the wiki page you've recomended. Could you help me on how to enable ICE?
I think i've to add the following lines to the opensips.conf file:

modparam("mediaproxy", "ice_candidate", "low-priority")
modparam("mediaproxy", "ice_candidate_avp", "$avp(ice_candidate)")

but i don't understand what should i do with the followings ones:

route {
    ...
    $avp(s:ice_candidate) := "low-priority";
    ...
}

and

1 if ((ice_candidate != none and ice_candidate_avp != none) 2 and SDP offer contains a=ice-pwd 3 and a=ice-ufrag and a=candidate line(s) then: 4 append to the SDP the following line: 5 a=candidate:R(random string) 1 UDP PRIORITY MP_IP MP_PORT typ relay 6 a=candidate:R(random string) 2 UDP PRIORITY MP_IP MP_RTCP_PORT typ relay
Thanks for your help.
BR,

Leo.


________________________________
 Da: Saúl Ibarra Corretgé <saul@ag-projects.com>
A: OpenSIPS users mailling list <users@lists.opensips.org> 
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT
 

On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: NAT

shaheryarkh
Setting modparam ice_candidate to low-priority will enable ICE for all calls in media proxy with media proxy's own address as TURN service with low-priority. However if you want to control priority on per call basis then then you can define ice_candidate_avp and set priority of media proxy relay ICE candidates at run time on per call basis. You will just need to set specified AVP within route definition in opensips.cfg.

Thank you.


On Fri, Mar 1, 2013 at 3:34 PM, Leonardo Uzcudun <[hidden email]> wrote:
Hello saul:

I've now running the OpenSIPS server with the Mediaproxy.
Some natted UA are working and others no. Those that can't, thay can call but no audio/video.
I would like to enable the ICE (cause the UA also support it) but i'm really stuck on the wiki page you've recomended. Could you help me on how to enable ICE?
I think i've to add the following lines to the opensips.conf file:
modparam("mediaproxy", "ice_candidate", "low-priority")
modparam("mediaproxy", "ice_candidate_avp", "$avp(ice_candidate)")

but i don't understand what should i do with the followings ones:

route { ... $avp(s:ice_candidate) := "low-priority"; ... }

and

1 if ((ice_candidate != none and ice_candidate_avp != none) 2 and SDP offer contains a=ice-pwd 3 and a=ice-ufrag and a=candidate line(s) then: 4 append to the SDP the following line: 5 a=candidate:R(random string) 1 UDP PRIORITY MP_IP MP_PORT typ relay 6 a=candidate:R(random string) 2 UDP PRIORITY MP_IP MP_RTCP_PORT typ relay
Thanks for your help.
BR,

Leo.


Da: Saúl Ibarra Corretgé <[hidden email]>
A: OpenSIPS users mailling list <[hidden email]>
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT


On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users




--
Muhammad Shahzad
-----------------------------------
CISCO Rich Media Communication Specialist (CRMCS)
CISCO Certified Network Associate (CCNA)
Cell: +49 176 99 83 10 85
MSN: [hidden email]
Email: [hidden email]

_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
In reply to this post by Saúl Ibarra Corretgé
Hello Saul:

I'm still trying to configure ICE support.
How could i check if it is working?
Thanks,

Leo.

Da: Saúl Ibarra Corretgé <[hidden email]>
A: OpenSIPS users mailling list <[hidden email]>
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT


On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Adrian Georgescu
You need to use a SIP client that supports ICE and check its logs.

Adrian

On Mar 6, 2013, at 7:20 PM, Leonardo Uzcudun wrote:

Hello Saul:

I'm still trying to configure ICE support.
How could i check if it is working?
Thanks,

Leo.

Da: Saúl Ibarra Corretgé <[hidden email]>
A: OpenSIPS users mailling list <[hidden email]>
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT


On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: NAT

Adrian Georgescu
In reply to this post by leo
Only in the client you can check such thing.

Adrian

On Mar 6, 2013, at 7:20 PM, Leonardo Uzcudun wrote:

Hello Saul:

I'm still trying to configure ICE support.
How could i check if it is working?
Thanks,

Leo.

Da: Saúl Ibarra Corretgé <[hidden email]>
A: OpenSIPS users mailling list <[hidden email]>
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT


On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
Ouch....


Da: Adrian Georgescu [via OpenSIPS (Open SIP Server)] <[hidden email]>
A: leo <[hidden email]>
Inviato: Lunedì 11 Marzo 2013 16:05
Oggetto: Re: NAT

Only in the client you can check such thing.

Adrian

On Mar 6, 2013, at 7:20 PM, Leonardo Uzcudun wrote:

Hello Saul:

I'm still trying to configure ICE support.
How could i check if it is working?
Thanks,

Leo.

Da: Saúl Ibarra Corretgé <[hidden email]>
A: OpenSIPS users mailling list <[hidden email]>
Inviato: Giovedì 28 Febbraio 2013 12:07
Oggetto: Re: [OpenSIPS-Users] NAT


On Feb 28, 2013, at 11:47 AM, leo wrote:

> Thanks Adrian.
>
> There was a sense in my question, having the RTP traffic P2P would be
> translated in:
> 1) better user experience, less jitter and latency.
> 2) saving to install one or more mediaproxies. Considering that all RTP
> traffic will pass on them, they will need to have high bandwidth (symmetric
> up/down) and maybe CPU/RAM.
>

Fixing the signaling is not enough because the media flows through different ports and with symmetric NATs you don't know what ports those will be. To (try to) use P2P media you need your endpoints to use ICE. MediaProxy is ICE aware, so if it detects that media is flowing P2P it will bail out. You can find more information about this here: http://mediaproxy.ag-projects.com/projects/mediaproxy/wiki/ICE


Regards,

--
Saúl Ibarra Corretgé
AG Projects




_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



If you reply to this email, your message will be added to the discussion below:
http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918p7585234.html
To unsubscribe from NAT, click here.
NAML


leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
This post has NOT been accepted by the mailing list yet.
In reply to this post by leo
Hello Guys,

I'm sorry still boring you with this but i can't understand why i'm having the following situation. Still same server/configuration with mediaproxy...

If UA from 3G calls to a natted UA, all is working -> Audio + Video
If UA from nat calls to a 3G UA, the call is established but NO Audio + NO Video

here are the logs when the UA from nat calls to a 3G UA (of course, XXX.XXX.XXX.XXX is the Opensips)

Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  method:  <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  uri:     <sip:ipad@XXX.XXX.XXX.XXX>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1655958442>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1929]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=100
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>#015#012]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <20> <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:uri:has_totag: no totag
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: start searching: hash=6300, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:lg@XXX.XXX.XXX.XXX}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=10000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: content_length=423
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:pre_auth: credentials with given realm not found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:reserve_nonce_index: second= 0, sec_monit= 85,  index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:build_auth_hf: nonce index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="XXX.XXX.XXX.XXX", nonce="514791d6000000580b1d3e612d9691781907d89e667ee42f"#015#012'
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  method:  <ACK>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  uri:     <sip:ipad@XXX.XXX.XXX.XXX>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1655958442>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to_param: tag=5a585dc4c5293a974c43e17233c28b04.c483
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: <To> [68]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  method:  <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  uri:     <sip:ipad@XXX.XXX.XXX.XXX>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=100
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>#015#012]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:uri:has_totag: no totag
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:lg@XXX.XXX.XXX.XXX}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_nonce: comparing [514791d6000000580b1d3e612d9691781907d89e667ee42f] and [514791d6000000580b1d3e612d9691781907d89e667ee42f]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:has_stmt_ctx: ctx found for subscriber
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f79ac (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=2; type=254; is_null=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 1 columns in result
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb71fdaf8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_columns: allocate 16 bytes for result columns at 0xb71f8764
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8768)[0]=[password]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_rows: allocate 28 bytes for result rows and values at 0xb71fa228
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_str2val: converting STRING [PASS]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth_db:get_ha1: HA1 string calculated: ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_response: our result = 'QQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQ'
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_response: authorization is OK
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:post_auth: nonce index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_columns: freeing result columns at 0xb71f8764
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing 1 rows
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_row: freeing row values at 0xb71fa230
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing rows at 0xb71fa228
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_result: freeing result set at 0xb71fdaf8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:uri:check_username: Digest username and URI username match
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: content_length=423
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:find_first_route: No Route headers found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:loose_route: There is no Route HF
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:w_create_dialog2: bye on timeout activated
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:build_new_dlg: new dialog 0xb2fea10c (c=820030190,f=sip:lg@XXX.XXX.XXX.XXX,t=sip:ipad@XXX.XXX.XXX.XXX,ft=1059686875) on hash 1053
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:init_leg_info: route_set , contact sip:lg@82.90.127.126:1024, cseq 21 and bind_addr udp:XXX.XXX.XXX.XXX:5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_add_leg_info: set leg 0 for 0xb2fea10c: tag=<1059686875> rcseq=<0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:link_dlg: ref dlg 0xb2fea10c with 3 -> 3
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:add_rr_param: adding (;did=d14.8a9bc924) 0xb71fa574
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb71fdd80
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_columns: allocate 32 bytes for result columns at 0xb71f8038
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8040)[0]=[username]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8048)[1]=[domain]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:alias_db:alias_db_query: no alias found for R-URI
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_columns: freeing result columns at 0xb71f8038
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing 0 rows
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_result: freeing result set at 0xb71fdd80
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: found a complete match
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: setting as ruri <sip:ipad@37.101.92.163;line=60214e1ea975261>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: looking for branches
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev media-dispatcher[1184]: debug: Issuing "update" command to relay at 127.0.0.1
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Received new SDP offer
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50072
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50073
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50074
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50075
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Added new stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: Unknown, RTCP: Unknown)
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50076
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50077
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50078
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50079
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Added new stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: Unknown, RTCP: Unknown)
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: created new session 820030190: lg@XXX.XXX.XXX.XXX (1059686875) --> ipad@XXX.XXX.XXX.XXX
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_newtran: transaction on entrance=(nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 2 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 1 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onreq: t hash_index = 6301, t label = 163875489
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:get_dlg_timeout: invalid AVP value, use default timeout
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 0 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:_shm_resize: resize(0) called
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:_reply_light: reply sent out. buf=0xb71ff230: SIP/2.0 1..., shmem=0xb31428a8: SIP/2.0 1
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:_reply_light: finished
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: new branch at sip:ipad@37.101.92.163;line=60214e1ea975261
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:clen_builder: content-length: 425 (425)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 500000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [4]: 0xb30ba2e4 (10974800000)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [0]: 0xb30ba300 (10979)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_relay_to: new transaction fwd'ed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:4,tl=0xb30ba2e4 next=(nil), timeout=10974800000
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:retransmission_handler: retransmission_handler : request resending (t=0xb30ba198, INVITE si ... )
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:set_timer: relative timeout is 1000000
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:insert_timer_unsafe: [5]: 0xb30ba2e4 (10975800000)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:retransmission_handler: retransmission_handler : done
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <100>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <Trying>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>#015#012]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=100, new_code=100
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=-1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:set_timer: relative timeout is 30
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [1]: 0xb30ba300 (11004)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  status:  <101>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  reason:  <Dialog Establishement>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_should_relay_response: T_code=100, new_code=101
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:push_reply_in_dialog: new branch with tag <86587959>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:init_leg_info: route_set , contact , cseq 21 and bind_addr udp:XXX.XXX.XXX.XXX:5060
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_add_leg_info: set leg 1 for 0xb2fea10c: tag=<86587959> rcseq=<21>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:build_res_buf_from_sip_res:  old size: 488, new size: 422
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:build_res_buf_from_sip_res: copied size: orig:101, new: 35, rest: 387 msg=#012SIP/2.0 101 Dialog Establishement#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012To: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 1 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:relay_reply: sent buf=0xb71ff4c4: SIP/2.0 1..., shmem=0xb2f81418: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  status:  <101>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  reason:  <Dialog Establishement>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:reply_received: org. status uas=101, uac[0]=101 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_should_relay_response: T_code=101, new_code=101
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:build_res_buf_from_sip_res:  old size: 488, new size: 422
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:build_res_buf_from_sip_res: copied size: orig:101, new: 35, rest: 387 msg=#012SIP/2.0 101 Dialog Establishement#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012To: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:relay_reply: sent buf=0xb71ff258: SIP/2.0 1..., shmem=0xb2f81418: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  status:  <180>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  reason:  <Ringing>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:reply_received: org. status uas=101, uac[0]=101 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_should_relay_response: T_code=101, new_code=180
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:build_res_buf_from_sip_res:  old size: 474, new size: 408
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:build_res_buf_from_sip_res: copied size: orig:87, new: 21, rest: 387 msg=#012SIP/2.0 180 Ringing#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012To: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:relay_reply: sent buf=0xb71ff230: SIP/2.0 1..., shmem=0xb3143550: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 30
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [1]: 0xb30ba300 (11005)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:18 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:5,tl=0xb30ba2e4 next=(nil), timeout=10975800000
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <200>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <OK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:20 sip-dev media-relay[1733]: debug: Got traffic information for stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: 37.101.92.163:7076, RTCP: Unknown)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=180, uac[0]=180 local=0 is_invite=1)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: incoming reply
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=180, new_code=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=80
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: content_length=323
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: current rr is <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: skipping 1 route records
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: out rr []
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: we have 1 records
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:dlg_update_routing: dialog 0xb2fea10c[1]: rr=<> contact=<sip:ipad@37.101.92.163>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res:  old size: 822, new size: 756
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res: copied size: orig:82, new: 16, rest: 740 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012To: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163>#015#012Content-Type: application/sdp#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length:   323#015#012#015#012v=0#015#012o=ipad 2412 2624 IN IP4 37.101.92.163#015#012s=Talk#015#012c=IN IP4 37.101.92.163#015#012b=AS:512#015#012t=0 0#015#012m=audio 7076 RTP/AVP 110 0 8 100 3 101#015#012a=rtpmap:110 speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:100 iLBC/8000#015#012a=fmtp:100 mode=30#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-11#015#012m=video 9078 RTP/AVP 103#015#012a=rtpmap:103 VP8/90000#015#012
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:update_totag_set: new totag
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [2]: 0xb30ba1e0 (10982)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 3, due event 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:dlg_onreply: dialog 0xb2fea10c confirmed
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:insert_dlg_timer_unsafe: inserting 0xb2fea140 for 32577
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:ref_dlg: ref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: sent buf=0xb71ff894: SIP/2.0 2..., shmem=0xb301a79c: SIP/2.0 2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:has_stmt_ctx: ctx found for acc
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f4f68 (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=6; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=10; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=8; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=9; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:20 sip-dev media-relay[1733]: debug: Got traffic information for stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: 37.101.92.163:9078, RTCP: Unknown)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  method:  <ACK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  uri:     <sip:ipad@37.101.92.163>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1750294998>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:sl:sl_filter_ACK: to late to be a local ACK!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=100
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:ipad@XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:ipad@XXX.XXX.XXX.XXX>]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <ACK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:uri:has_totag: totag found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:is_preloaded: is_preloaded: No
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [37.101.92.163] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:check_self: host != me
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:after_loose: Topmost route URI: 'sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924' is me
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: content_length=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:find_next_route: No next Route HF found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:after_loose: No next URI found!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=d14.8a9bc924>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_onroute: route param is 'd14.8a9bc924' (len=12)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:lookup_dlg: ref dlg 0xb2fea10c with 1 -> 4
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:lookup_dlg: dialog id=1117567400 found on entry 1053
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=58
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:lg@XXX.XXX.XXX.XXX}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 3 to state 4, due event 6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_onroute: sequential request successfully processed (dst_leg=1)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:compare_uris: straight-forward URI match
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: Remote contact succesfully validated
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:get_route_set: Route [sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924] has been deleted
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: Route Headers succesfully validated
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=78
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=38
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: e2e proxy ACK found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_newtran: building branch for end2end ACK - flags=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_relay_to: forwarding ACK
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_request: sending:#012ACK sip:ipad@37.101.92.163 SIP/2.0#015#012Via: SIP/2.0/UDP XXX.XXX.XXX.XXX:5060;branch=z9hG4bKd981.1aa84c9.2#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1750294998#015#012From: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012To: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 ACK#015#012Contact: <sip:lg@82.90.127.126:1024>#015#012Proxy-Authorization: Digest username="lg", realm="XXX.XXX.XXX.XXX", nonce="514791d6000000580b1d3e612d9691781907d89e667ee42f", uri="sip:ipad@XXX.XXX.XXX.XXX", response="579f62776dea202242c754f0304634f0", algorithm=MD5#015#012Max-Forwards: 69#015#012User-Agent: LinphoneAndroid/2.0.3 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012.
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_request: orig. len=616, new_len=662, proto=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:22 sip-dev media-relay[1733]: debug: Got traffic information for stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: 37.101.92.163:7076, RTCP: 37.101.92.163:7077)
Mar 18 23:14:22 sip-dev media-relay[1733]: debug: Got traffic information for stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: 37.101.92.163:9078, RTCP: 37.101.92.163:9079)
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:2,tl=0xb30ba1e0 next=(nil), timeout=10982
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: removing 0xb30ba198 from table
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:delete_cell: delete transaction 0xb30ba198
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:next_state_dlg: unref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 4 to state 4, due event 1
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: done
Mar 18 23:14:30 sip-dev /usr/sbin/opensips[1931]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  method:  <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  uri:     <sip:lg@82.90.127.126:1024>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK789486656>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=100
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:lg@XXX.XXX.XXX.XXX}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:lg@XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:lg@XXX.XXX.XXX.XXX>]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:uri:has_totag: totag found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:is_preloaded: is_preloaded: No
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [82.90.127.126] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 1024
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:check_self: host != me
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:after_loose: Topmost route URI: 'sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924' is me
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: content_length=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:find_next_route: No next Route HF found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:after_loose: No next URI found!
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=d14.8a9bc924>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onroute: route param is 'd14.8a9bc924' (len=12)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:lookup_dlg: ref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:lookup_dlg: dialog id=1117567400 found on entry 1053
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=58
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:ipad@XXX.XXX.XXX.XXX}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 4 to state 5, due event 7
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onroute: BYE successfully processed - dst_leg = 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:remove_dialog_from_db: trying to remove a dialog, update_flag is 31
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 2 -> 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:compare_uris: straight-forward URI match
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: Remote contact succesfully validated
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:get_route_set: Route [sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924] has been deleted
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: Route Headers succesfully validated
Mar 18 23:14:45 sip-dev media-dispatcher[1184]: debug: Issuing "remove" command to relay at 127.0.0.1
Mar 18 23:14:45 sip-dev media-relay[1733]: debug: removing session 820030190: lg@XXX.XXX.XXX.XXX (1059686875) --> ipad@XXX.XXX.XXX.XXX
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50072 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50073 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50074 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50075 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50076 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50077 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50078 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50079 Closed)
Mar 18 23:14:45 sip-dev media-dispatcher[1184]: debug: Got statistics: {'from_tag': '1059686875', 'dialog_id': None, 'start_time': None, 'timed_out': False, 'call_id': '820030190', 'to_tag': None, 'streams': [{'status': 'closed', 'caller_codec': 'Unknown', 'post_dial_delay': 4.6322281360626221, 'callee_codec': 'Dynamic(103)', 'start_time': None, 'caller_bytes': 0, 'callee_bytes': 0, 'caller_packets': 0, 'end_time': None, 'callee_remote': '37.101.92.163:9078', 'caller_remote': 'Unknown', 'media_type': 'video', 'callee_local': 'XXX.XXX.XXX.XXX:50078', 'timeout_wait': 0, 'caller_local': 'XXX.XXX.XXX.XXX:50076', 'callee_packets': 0}, {'status': 'closed', 'caller_codec': 'Unknown', 'post_dial_delay': 4.0785679817199707, 'callee_codec': 'Dynamic(110)', 'start_time': None, 'caller_bytes': 0, 'callee_bytes': 0, 'caller_packets': 0, 'end_time': None, 'callee_remote': '37.101.92.163:7076', 'caller_remote': 'Unknown', 'media_type': 'audio', 'callee_local': 'XXX.XXX.XXX.XXX:50074', 'timeout_wait': 0, 'caller_local': 'XXX.XXX.XXX.XXX:50072', 'callee_packets': 0}], 'duration': 0, 'to_uri': 'ipad@XXX.XXX.XXX.XXX', 'from_uri': 'lg@XXX.XXX.XXX.XXX', 'callee_ua': 'Unknown', 'caller_ua': 'LinphoneAndroid/2.0.3 (eXosip2/3.6.0)'}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=58449, isACK=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 2 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:ref_dlg: ref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 0 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 500000
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [4]: 0xb30ba2e4 (11003400000)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [0]: 0xb30ba300 (11007)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_relay_to: new transaction fwd'ed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <200>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <OK>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK154e.c04fd1e5.0>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <37.101.92.163>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK789486656>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:lg@XXX.XXX.XXX.XXX}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:lg@XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:lg@XXX.XXX.XXX.XXX>]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 58449 label 1579021324 branch 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=0, new_code=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res:  old size: 371, new size: 304
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res: copied size: orig:83, new: 16, rest: 288 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 37.101.92.163:5060;received=37.101.92.163;rport=5060;branch=z9hG4bK789486656#015#012From: <sip:ipad@XXX.XXX.XXX.XXX>;tag=86587959#015#012To: <sip:lg@XXX.XXX.XXX.XXX>;tag=1059686875#015#012Call-ID: 820030190#015#012CSeq: 2 BYE#015#012User-Agent: LinphoneAndroid/2.0.3 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:_shm_resize: resize(0) called
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [2]: 0xb30ba1e0 (11008)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: sent buf=0xb71ff328: SIP/2.0 2..., shmem=0xb31410d8: SIP/2.0 2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:has_stmt_ctx: ctx found for acc
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f4f68 (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=3; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=8; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=10; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=9; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:4,tl=0xb30ba2e4 next=(nil), timeout=11003400000
Mar 18 23:14:48 sip-dev /usr/sbin/opensips[1930]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:49 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:0,tl=0xb30ba300 next=(nil), timeout=11007
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:2,tl=0xb30ba1e0 next=(nil), timeout=11008
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: removing 0xb30ba198 from table
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:delete_cell: delete transaction 0xb30ba198
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 4096, id 0 entered
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 0
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:unref_dlg: ref <=0 for dialog 0xb2fea10c
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:destroy_dlg: destroing dialog 0xb2fea10c
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:destroy_dlg: dlg expired or not in list - dlg 0xb2fea10c [1053:1117567400] with clid '820030190' and tags '1059686875' '86587959'
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: done

 
leo
Reply | Threaded
Open this post in threaded view
|

Re: NAT

leo
This post has NOT been accepted by the mailing list yet.
Any clue on this?


Da: leo [via OpenSIPS (Open SIP Server)] <[hidden email]>
A: leo <[hidden email]>
Inviato: Lunedì 18 Marzo 2013 23:27
Oggetto: Re: NAT

Hello Guys,

I'm sorry still boring you with this but i can't understand why i'm having the following situation. Still same server/configuration with mediaproxy...

If UA from 3G calls to a natted UA, all is working -> Audio + Video
If UA from nat calls to a 3G UA, the call is established but NO Audio + NO Video

here are the logs when the UA from nat calls to a 3G UA (of course, XXX.XXX.XXX.XXX is the Opensips)

Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  method:  <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  uri:     <sip:[hidden email]>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1655958442>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1929]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=100
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:[hidden email]]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>#015#012]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <20> <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:uri:has_totag: no totag
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: start searching: hash=6300, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=10000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: content_length=423
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:pre_auth: credentials with given realm not found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:reserve_nonce_index: second= 0, sec_monit= 85,  index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:build_auth_hf: nonce index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="XXX.XXX.XXX.XXX", nonce="514791d6000000580b1d3e612d9691781907d89e667ee42f"#015#012'
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  method:  <ACK>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  uri:     <sip:[hidden email]>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1655958442>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to_param: tag=5a585dc4c5293a974c43e17233c28b04.c483
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: <To> [68]; uri=[sip:[hidden email]]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  method:  <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  uri:     <sip:[hidden email]>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=100
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:[hidden email]]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>#015#012]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:uri:has_totag: no totag
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_nonce: comparing [514791d6000000580b1d3e612d9691781907d89e667ee42f] and [514791d6000000580b1d3e612d9691781907d89e667ee42f]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:has_stmt_ctx: ctx found for subscriber
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f79ac (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=2; type=254; is_null=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 1 columns in result
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb71fdaf8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_columns: allocate 16 bytes for result columns at 0xb71f8764
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8768)[0]=[password]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_rows: allocate 28 bytes for result rows and values at 0xb71fa228
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_str2val: converting STRING [PASS]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth_db:get_ha1: HA1 string calculated: ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_response: our result = 'QQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQ'
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:check_response: authorization is OK
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:auth:post_auth: nonce index= 88
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_columns: freeing result columns at 0xb71f8764
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing 1 rows
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_row: freeing row values at 0xb71fa230
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing rows at 0xb71fa228
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_result: freeing result set at 0xb71fdaf8
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:uri:check_username: Digest username and URI username match
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: content_length=423
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:find_first_route: No Route headers found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:loose_route: There is no Route HF
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:w_create_dialog2: bye on timeout activated
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:build_new_dlg: new dialog 0xb2fea10c (c=820030190,f=sip:[hidden email],t=sip:[hidden email],ft=1059686875) on hash 1053
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:init_leg_info: route_set , contact sip:lg@82.90.127.126:1024, cseq 21 and bind_addr udp:XXX.XXX.XXX.XXX:5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_add_leg_info: set leg 0 for 0xb2fea10c: tag=<1059686875> rcseq=<0>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:link_dlg: ref dlg 0xb2fea10c with 3 -> 3
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:rr:add_rr_param: adding (;did=d14.8a9bc924) 0xb71fa574
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb71fdd80
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_allocate_columns: allocate 32 bytes for result columns at 0xb71f8038
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8040)[0]=[username]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb71f8048)[1]=[domain]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:alias_db:alias_db_query: no alias found for R-URI
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_columns: freeing result columns at 0xb71f8038
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_rows: freeing 0 rows
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:db_free_result: freeing result set at 0xb71fdd80
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: found a complete match
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: setting as ruri <sip:ipad@37.101.92.163;line=60214e1ea975261>
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:registrar:lookup: looking for branches
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8000000
Mar 18 23:14:16 sip-dev media-dispatcher[1184]: debug: Issuing "update" command to relay at 127.0.0.1
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Received new SDP offer
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50072
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50073
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50074
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50075
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Added new stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: Unknown, RTCP: Unknown)
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50076
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50077
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50078
Mar 18 23:14:16 sip-dev media-relay[1733]: mediaproxy.mediacontrol.StreamListenerProtocol starting on 50079
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: Added new stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: Unknown, RTCP: Unknown)
Mar 18 23:14:16 sip-dev media-relay[1733]: debug: created new session 820030190: [hidden email] (1059686875) --> [hidden email]
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_newtran: transaction on entrance=(nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 2 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 1 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onreq: t hash_index = 6301, t label = 163875489
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:get_dlg_timeout: invalid AVP value, use default timeout
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 0 entered
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:_shm_resize: resize(0) called
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:_reply_light: reply sent out. buf=0xb71ff230: SIP/2.0 1..., shmem=0xb31428a8: SIP/2.0 1
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:_reply_light: finished
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: new branch at sip:ipad@37.101.92.163;line=60214e1ea975261
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:clen_builder: content-length: 425 (425)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 500000
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [4]: 0xb30ba2e4 (10974800000)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 5
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [0]: 0xb30ba300 (10979)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_relay_to: new transaction fwd'ed
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:16 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:4,tl=0xb30ba2e4 next=(nil), timeout=10974800000
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:retransmission_handler: retransmission_handler : request resending (t=0xb30ba198, INVITE si ... )
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:set_timer: relative timeout is 1000000
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:insert_timer_unsafe: [5]: 0xb30ba2e4 (10975800000)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1933]: DBG:tm:retransmission_handler: retransmission_handler : done
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <100>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <Trying>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=10
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:[hidden email]]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>#015#012]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=100, new_code=100
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=-1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:set_timer: relative timeout is 30
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [1]: 0xb30ba300 (11004)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  status:  <101>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  reason:  <Dialog Establishement>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_should_relay_response: T_code=100, new_code=101
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:push_reply_in_dialog: new branch with tag <86587959>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:init_leg_info: route_set , contact , cseq 21 and bind_addr udp:XXX.XXX.XXX.XXX:5060
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_add_leg_info: set leg 1 for 0xb2fea10c: tag=<86587959> rcseq=<21>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:build_res_buf_from_sip_res:  old size: 488, new size: 422
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:build_res_buf_from_sip_res: copied size: orig:101, new: 35, rest: 387 msg=#012SIP/2.0 101 Dialog Establishement#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:[hidden email]>;tag=1059686875#015#012To: <sip:[hidden email]>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 1 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:relay_reply: sent buf=0xb71ff4c4: SIP/2.0 1..., shmem=0xb2f81418: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  status:  <101>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_msg:  reason:  <Dialog Establishement>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:reply_received: org. status uas=101, uac[0]=101 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_should_relay_response: T_code=101, new_code=101
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:build_res_buf_from_sip_res:  old size: 488, new size: 422
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:build_res_buf_from_sip_res: copied size: orig:101, new: 35, rest: 387 msg=#012SIP/2.0 101 Dialog Establishement#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:[hidden email]>;tag=1059686875#015#012To: <sip:[hidden email]>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:relay_reply: sent buf=0xb71ff258: SIP/2.0 1..., shmem=0xb2f81418: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1931]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  status:  <180>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  reason:  <Ringing>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=8
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:reply_received: org. status uas=101, uac[0]=101 local=0 is_invite=1)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: incoming reply
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_should_relay_response: T_code=101, new_code=180
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:build_res_buf_from_sip_res:  old size: 474, new size: 408
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:build_res_buf_from_sip_res: copied size: orig:87, new: 21, rest: 387 msg=#012SIP/2.0 180 Ringing#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:[hidden email]>;tag=1059686875#015#012To: <sip:[hidden email]>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163:5060>#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 2, due event 2
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:relay_reply: sent buf=0xb71ff230: SIP/2.0 1..., shmem=0xb3143550: SIP/2.0 1
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 30
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [1]: 0xb30ba300 (11005)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:17 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:18 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:5,tl=0xb30ba2e4 next=(nil), timeout=10975800000
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <200>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <OK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKd981.1aa84c9.0>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <82.90.127.126>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <1024>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1186108331>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 6301 label 163875489 branch 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:20 sip-dev media-relay[1733]: debug: Got traffic information for stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: 37.101.92.163:7076, RTCP: Unknown)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=180, uac[0]=180 local=0 is_invite=1)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: incoming reply
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=180, new_code=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 8, id 0 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:push_reply_in_dialog: 0xb2fea10c totag in rpl is <86587959> (8)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:push_reply_in_dialog: branch with tag <86587959> already exists
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=80
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: content_length=323
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: current rr is <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: skipping 1 route records
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: out rr []
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:print_rr_body: we have 1 records
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:dlg_update_routing: dialog 0xb2fea10c[1]: rr=<> contact=<sip:ipad@37.101.92.163>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res:  old size: 822, new size: 756
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res: copied size: orig:82, new: 16, rest: 740 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1186108331#015#012Record-Route: <sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924>#015#012From: <sip:[hidden email]>;tag=1059686875#015#012To: <sip:[hidden email]>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 INVITE#015#012Contact: <sip:ipad@37.101.92.163>#015#012Content-Type: application/sdp#015#012User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0)#015#012Content-Length:   323#015#012#015#012v=0#015#012o=ipad 2412 2624 IN IP4 37.101.92.163#015#012s=Talk#015#012c=IN IP4 37.101.92.163#015#012b=AS:512#015#012t=0 0#015#012m=audio 7076 RTP/AVP 110 0 8 100 3 101#015#012a=rtpmap:110 speex/8000#015#012a=fmtp:110 vbr=on#015#012a=rtpmap:100 iLBC/8000#015#012a=fmtp:100 mode=30#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-11#015#012m=video 9078 RTP/AVP 103#015#012a=rtpmap:103 VP8/90000#015#012
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:update_totag_set: new totag
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [2]: 0xb30ba1e0 (10982)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 64, id 0 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 2 to state 3, due event 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:dlg_onreply: dialog 0xb2fea10c confirmed
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:insert_dlg_timer_unsafe: inserting 0xb2fea140 for 32577
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:dialog:ref_dlg: ref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: sent buf=0xb71ff894: SIP/2.0 2..., shmem=0xb301a79c: SIP/2.0 2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:has_stmt_ctx: ctx found for acc
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f4f68 (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=6; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=10; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=8; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=9; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:20 sip-dev media-relay[1733]: debug: Got traffic information for stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: 37.101.92.163:9078, RTCP: Unknown)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  method:  <ACK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  uri:     <sip:ipad@37.101.92.163>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1750294998>; state=16
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:sl:sl_filter_ACK: to late to be a local ACK!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=100
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <ACK>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:uri:has_totag: totag found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:is_preloaded: is_preloaded: No
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [37.101.92.163] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:check_self: host != me
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:after_loose: Topmost route URI: 'sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924' is me
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=200
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: content_length=0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:find_next_route: No next Route HF found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:after_loose: No next URI found!
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=d14.8a9bc924>
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_onroute: route param is 'd14.8a9bc924' (len=12)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:lookup_dlg: ref dlg 0xb2fea10c with 1 -> 4
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:lookup_dlg: dialog id=1117567400 found on entry 1053
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=58
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 3 to state 4, due event 6
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_onroute: sequential request successfully processed (dst_leg=1)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:compare_uris: straight-forward URI match
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: Remote contact succesfully validated
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:rr:get_route_set: Route [sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924] has been deleted
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:dlg_validate_dialog: Route Headers succesfully validated
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=78
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: start searching: hash=6301, isACK=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:parse_headers: flags=38
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_lookup_request: e2e proxy ACK found
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_newtran: building branch for end2end ACK - flags=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_relay_to: forwarding ACK
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_request: sending:#012ACK sip:ipad@37.101.92.163 SIP/2.0#015#012Via: SIP/2.0/UDP XXX.XXX.XXX.XXX:5060;branch=z9hG4bKd981.1aa84c9.2#015#012Via: SIP/2.0/UDP 192.168.1.123:5060;received=82.90.127.126;rport=1024;branch=z9hG4bK1750294998#015#012From: <sip:[hidden email]>;tag=1059686875#015#012To: <sip:[hidden email]>;tag=86587959#015#012Call-ID: 820030190#015#012CSeq: 21 ACK#015#012Contact: <sip:lg@82.90.127.126:1024>#015#012Proxy-Authorization: Digest username="lg", realm="XXX.XXX.XXX.XXX", nonce="514791d6000000580b1d3e612d9691781907d89e667ee42f", uri="sip:[hidden email]", response="579f62776dea202242c754f0304634f0", algorithm=MD5#015#012Max-Forwards: 69#015#012User-Agent: LinphoneAndroid/2.0.3 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012.
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:forward_request: orig. len=616, new_len=662, proto=1
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:20 sip-dev /usr/sbin/opensips[1930]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:22 sip-dev media-relay[1733]: debug: Got traffic information for stream: (audio) 192.168.1.123:7078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50072 <-> XXX.XXX.XXX.XXX:50074 <-> Unknown (RTP: 37.101.92.163:7076, RTCP: 37.101.92.163:7077)
Mar 18 23:14:22 sip-dev media-relay[1733]: debug: Got traffic information for stream: (video) 192.168.1.123:9078 (RTP: Unknown, RTCP: Unknown) <-> XXX.XXX.XXX.XXX:50076 <-> XXX.XXX.XXX.XXX:50078 <-> Unknown (RTP: 37.101.92.163:9078, RTCP: 37.101.92.163:9079)
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:2,tl=0xb30ba1e0 next=(nil), timeout=10982
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: removing 0xb30ba198 from table
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:delete_cell: delete transaction 0xb30ba198
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:next_state_dlg: unref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 4 to state 4, due event 1
Mar 18 23:14:24 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: done
Mar 18 23:14:30 sip-dev /usr/sbin/opensips[1931]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg: SIP Request:
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  method:  <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  uri:     <sip:lg@82.90.127.126:1024>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK789486656>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: preparing to run routing scripts...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=100
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:maxfwd:is_maxfwd_present: value = 70
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:uri:has_totag: totag found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:is_preloaded: is_preloaded: No
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [82.90.127.126] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 1024
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:check_self: host != me
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if host==us: 13==13 &&  [XXX.XXX.XXX.XXX] == [XXX.XXX.XXX.XXX]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:after_loose: Topmost route URI: 'sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924' is me
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: content_length=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:get_hdr_field: found end of header
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:find_next_route: No next Route HF found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:after_loose: No next URI found!
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=d14.8a9bc924>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onroute: route param is 'd14.8a9bc924' (len=12)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:lookup_dlg: ref dlg 0xb2fea10c with 1 -> 3
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:lookup_dlg: dialog id=1117567400 found on entry 1053
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=58
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to_param: tag=86587959
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:next_state_dlg: dialog 0xb2fea10c changed from state 4 to state 5, due event 7
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_onroute: BYE successfully processed - dst_leg = 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:remove_dialog_from_db: trying to remove a dialog, update_flag is 31
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 2 -> 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:compare_uris: straight-forward URI match
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: Remote contact succesfully validated
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:rr:get_route_set: Route [sip:XXX.XXX.XXX.XXX;lr;did=d14.8a9bc924] has been deleted
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:dlg_validate_dialog: Route Headers succesfully validated
Mar 18 23:14:45 sip-dev media-dispatcher[1184]: debug: Issuing "remove" command to relay at 127.0.0.1
Mar 18 23:14:45 sip-dev media-relay[1733]: debug: removing session 820030190: [hidden email] (1059686875) --> [hidden email]
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50072 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50073 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50074 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50075 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50076 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50077 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50078 Closed)
Mar 18 23:14:45 sip-dev media-relay[1733]: (Port 50079 Closed)
Mar 18 23:14:45 sip-dev media-dispatcher[1184]: debug: Got statistics: {'from_tag': '1059686875', 'dialog_id': None, 'start_time': None, 'timed_out': False, 'call_id': '820030190', 'to_tag': None, 'streams': [{'status': 'closed', 'caller_codec': 'Unknown', 'post_dial_delay': 4.6322281360626221, 'callee_codec': 'Dynamic(103)', 'start_time': None, 'caller_bytes': 0, 'callee_bytes': 0, 'caller_packets': 0, 'end_time': None, 'callee_remote': '37.101.92.163:9078', 'caller_remote': 'Unknown', 'media_type': 'video', 'callee_local': 'XXX.XXX.XXX.XXX:50078', 'timeout_wait': 0, 'caller_local': 'XXX.XXX.XXX.XXX:50076', 'callee_packets': 0}, {'status': 'closed', 'caller_codec': 'Unknown', 'post_dial_delay': 4.0785679817199707, 'callee_codec': 'Dynamic(110)', 'start_time': None, 'caller_bytes': 0, 'callee_bytes': 0, 'caller_packets': 0, 'end_time': None, 'callee_remote': '37.101.92.163:7076', 'caller_remote': 'Unknown', 'media_type': 'audio', 'callee_local': 'XXX.XXX.XXX.XXX:50074', 'timeout_wait': 0, 'caller_local': 'XXX.XXX.XXX.XXX:50072', 'callee_packets': 0}], 'duration': 0, 'to_uri': '[hidden email]', 'from_uri': '[hidden email]', 'callee_ua': 'Unknown', 'caller_ua': 'LinphoneAndroid/2.0.3 (eXosip2/3.6.0)'}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=ffffffffffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: start searching: hash=58449, isACK=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_lookup_request: no transaction found
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 2 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:ref_dlg: ref dlg 0xb2fea10c with 1 -> 2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:run_reqin_callbacks: trans=0xb30ba198, callback type 1, id 0 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:parse_headers: flags=78
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:mk_proxy: doing DNS lookup...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 500000
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [4]: 0xb30ba2e4 (11003400000)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:set_timer: relative timeout is 5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:insert_timer_unsafe: [0]: 0xb30ba300 (11007)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_relay_to: new transaction fwd'ed
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1928]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg: SIP Reply  (status):
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  version: <SIP/2.0>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  status:  <200>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_msg:  reason:  <OK>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK154e.c04fd1e5.0>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: this is the first via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: After parse_msg...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:forward_reply: found module tm, passing reply to it
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: start=0xffffffff
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=22
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 234, <received> = <37.101.92.163>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK789486656>; state=16
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_via: end of header reached, state=5
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: via found, flags=22
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: parse_headers: this is the second via
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to_param: tag=1059686875
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: end of header reached, state=29
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_to: display={}, ruri={sip:[hidden email]}
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: <To> [39]; uri=[sip:[hidden email]]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: to body [<sip:[hidden email]>]
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: hash 58449 label 1579021324 branch 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xb30ba198] after is 1
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_reply_matching: reply matched (T=0xb30ba198)!
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 2, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:parse_headers: flags=8
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_check: end=0xb30ba198
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_should_relay_response: T_code=0, new_code=200
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res:  old size: 371, new size: 304
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:build_res_buf_from_sip_res: copied size: orig:83, new: 16, rest: 288 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 37.101.92.163:5060;received=37.101.92.163;rport=5060;branch=z9hG4bK789486656#015#012From: <sip:[hidden email]>;tag=86587959#015#012To: <sip:[hidden email]>;tag=1059686875#015#012Call-ID: 820030190#015#012CSeq: 2 BYE#015#012User-Agent: LinphoneAndroid/2.0.3 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:_shm_resize: resize(0) called
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:insert_timer_unsafe: [2]: 0xb30ba1e0 (11008)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:relay_reply: sent buf=0xb71ff328: SIP/2.0 2..., shmem=0xb31410d8: SIP/2.0 2
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 128, id 1 entered
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:has_stmt_ctx: ctx found for acc
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb71f4f68 (tail=-1222686216) MC=0xb71f5248
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=3; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=8; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=10; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=9; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:tm:t_unref: UNREF_UNSAFE: [0xb30ba198] after is 0
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:destroy_avp_list: destroying list (nil)
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1929]: DBG:core:receive_msg: cleaning up
Mar 18 23:14:45 sip-dev /usr/sbin/opensips[1933]: DBG:tm:utimer_routine: timer routine:4,tl=0xb30ba2e4 next=(nil), timeout=11003400000
Mar 18 23:14:48 sip-dev /usr/sbin/opensips[1930]: DBG:core:udp_rcv_loop: probing packet received len = 4
Mar 18 23:14:49 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:0,tl=0xb30ba300 next=(nil), timeout=11007
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:timer_routine: timer routine:2,tl=0xb30ba1e0 next=(nil), timeout=11008
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: removing 0xb30ba198 from table
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:delete_cell: delete transaction 0xb30ba198
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:run_trans_callbacks: trans=0xb30ba198, callback type 4096, id 0 entered
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:unref_dlg: unref dlg 0xb2fea10c with 1 -> 0
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:unref_dlg: ref <=0 for dialog 0xb2fea10c
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:destroy_dlg: destroing dialog 0xb2fea10c
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:dialog:destroy_dlg: dlg expired or not in list - dlg 0xb2fea10c [1053:1117567400] with clid '820030190' and tags '1059686875' '86587959'
Mar 18 23:14:50 sip-dev /usr/sbin/opensips[1933]: DBG:tm:wait_handler: done

 


If you reply to this email, your message will be added to the discussion below:
http://opensips-open-sip-server.1449251.n2.nabble.com/NAT-tp7584918p7585353.html
To unsubscribe from NAT, click here.
NAML