hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written) 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
B----while when using 4.2.2 or 4.4 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
Hello,
the pending write message is due to asynchronous tcp -- practically, even if the tcp connection is not ready, the SIP routing process is not blocked.
If the connection is found or the connection was setup quickly, then is not a risk of blocking and the message is sent immediately.
I guess all went ok with sip routing, right?
Also, tcp is separate layer from sip transactions, so no relation between them here, probably you will get the same by using the forward*() functions, which don't create sip transactions.
Cheers, Daniel
On 25/01/16 15:28, david escartin wrote:
hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
*A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these*
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 *5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written)* 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
*B----while when using 4.2.2 or 4.4* 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 *1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758* 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
hello Daniel
thanks for the explanation. then i understand the "quick connect" message is also normal? seen in version 4.2.2 or 4.4?
best regards david
El mar, 26-01-2016 a las 12:45 +0100, Daniel-Constantin Mierla escribió:
Hello,
the pending write message is due to asynchronous tcp -- practically, even if the tcp connection is not ready, the SIP routing process is not blocked.
If the connection is found or the connection was setup quickly, then is not a risk of blocking and the message is sent immediately.
I guess all went ok with sip routing, right?
Also, tcp is separate layer from sip transactions, so no relation between them here, probably you will get the same by using the forward*() functions, which don't create sip transactions.
Cheers, Daniel
On 25/01/16 15:28, david escartin wrote:
hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written) 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
B----while when using 4.2.2 or 4.4 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
Hello,
yes, quick connect message is ok. It is an INFO level, messages to worry about start at level WARNING, ERROR or lower.
Cheers, Daniel
On 27/01/16 12:41, david wrote:
hello Daniel
thanks for the explanation. then i understand the "quick connect" message is also normal? seen in version 4.2.2 or 4.4?
best regards david
El mar, 26-01-2016 a las 12:45 +0100, Daniel-Constantin Mierla escribió:
Hello,
the pending write message is due to asynchronous tcp -- practically, even if the tcp connection is not ready, the SIP routing process is not blocked.
If the connection is found or the connection was setup quickly, then is not a risk of blocking and the message is sent immediately.
I guess all went ok with sip routing, right?
Also, tcp is separate layer from sip transactions, so no relation between them here, probably you will get the same by using the forward*() functions, which don't create sip transactions.
Cheers, Daniel
On 25/01/16 15:28, david escartin wrote:
hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
*A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these*
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 *5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written)* 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
*B----while when using 4.2.2 or 4.4* 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 *1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758* 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org mailto:sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda http://twitter.com/#%21/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
ok thanks Daniel
i was quite confused by seeing different things on different versions (which had sligthly configuration differences) and i though i was doing something wrong somewhere
best regards david
El mié, 27-01-2016 a las 14:55 +0100, Daniel-Constantin Mierla escribió:
Hello,
yes, quick connect message is ok. It is an INFO level, messages to worry about start at level WARNING, ERROR or lower.
Cheers, Daniel
On 27/01/16 12:41, david wrote:
hello Daniel
thanks for the explanation. then i understand the "quick connect" message is also normal? seen in version 4.2.2 or 4.4?
best regards david
El mar, 26-01-2016 a las 12:45 +0100, Daniel-Constantin Mierla escribió:
Hello,
the pending write message is due to asynchronous tcp -- practically, even if the tcp connection is not ready, the SIP routing process is not blocked.
If the connection is found or the connection was setup quickly, then is not a risk of blocking and the message is sent immediately.
I guess all went ok with sip routing, right?
Also, tcp is separate layer from sip transactions, so no relation between them here, probably you will get the same by using the forward*() functions, which don't create sip transactions.
Cheers, Daniel
On 25/01/16 15:28, david escartin wrote:
hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written) 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
B----while when using 4.2.2 or 4.4 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
Welcome!
On the other hand, I don't recall any significant change on this part of code between 4.2 and current devel (4.4), but I didn't look at the commit history right now ...
Cheers, Daniel
On 27/01/16 15:00, david wrote:
ok thanks Daniel
i was quite confused by seeing different things on different versions (which had sligthly configuration differences) and i though i was doing something wrong somewhere
best regards david
El mié, 27-01-2016 a las 14:55 +0100, Daniel-Constantin Mierla escribió:
Hello,
yes, quick connect message is ok. It is an INFO level, messages to worry about start at level WARNING, ERROR or lower.
Cheers, Daniel
On 27/01/16 12:41, david wrote:
hello Daniel
thanks for the explanation. then i understand the "quick connect" message is also normal? seen in version 4.2.2 or 4.4?
best regards david
El mar, 26-01-2016 a las 12:45 +0100, Daniel-Constantin Mierla escribió:
Hello,
the pending write message is due to asynchronous tcp -- practically, even if the tcp connection is not ready, the SIP routing process is not blocked.
If the connection is found or the connection was setup quickly, then is not a risk of blocking and the message is sent immediately.
I guess all went ok with sip routing, right?
Also, tcp is separate layer from sip transactions, so no relation between them here, probably you will get the same by using the forward*() functions, which don't create sip transactions.
Cheers, Daniel
On 25/01/16 15:28, david escartin wrote:
hello all
i'm facing some weird log from kamailio (i think they are weird) when using sip tcp in the caller side and udp in the callee side.
seems like the tcp socket is active in the caller side and the call is connected, since the invite transaction completes. After that, if we receive an in-dialog request from the callee side, the kamailio doesnt find the tcp connection created and it has to create again the socket by SYN procedure for the other conn way. up to this point i think it's everything correct.
*A----the thing i dont understand, is that checking version 4.2.6, the logs i have when the request in-dialog comes from UAS, are like these*
5(2979) DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one 5(2979) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 5(2979) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 5(2979) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:2178:0, 4 *5(2979) DEBUG: <core> [tcp_main.c:2699]: tcpconn_1st_send(): pending write on new connection 0x7fac1168f028 (-1/968 bytes written)* 5(2979) DEBUG: tm [t_funcs.c:395]: t_relay_to(): SER: new transaction fwd'ed
*B----while when using 4.2.2 or 4.4* 1(791) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one 1(791) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 79.170.68.171 1(791) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 5063, type 2 1(791) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 1522:3421:0, 4 *1(791) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7f880540f758* 1(791) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
the difference between A and B is that in B i use dialog flags to do the t_relay_to_tcp for the indialog requests (and not in A), and in A i use the advertised IP in the listen addresses since kamailio is behind a NAT, while B machine scenario has public IPs. could those 2 things explain the ebhaviour difference?
is there anything abnormal in the case B?
thanks a lot and regards david escartin
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org mailto:sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda http://twitter.com/#%21/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda http://twitter.com/#%21/miconda - http://www.linkedin.com/in/miconda Book: SIP Routing With Kamailio - http://www.asipto.com http://miconda.eu
-
Daniel-Constantin Mierla -
david -
david escartin