Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register #2559

Closed
gmaruzz opened this issue Jun 24, 2021 · 6 comments
Closed

[BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register #2559

gmaruzz opened this issue Jun 24, 2021 · 6 comments
Assignees
@liviuchircu
Labels
bug fixed
Milestone
3.1.17

Comments

@gmaruzz
Copy link

gmaruzz commented Jun 24, 2021 •
edited

OpenSIPS version you are running

latest 3.1.3-nightly

version: opensips 3.1.3 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll, sigio_rt, select.
git revision: c9450c8d4
main.c compiled on  with gcc 8

Describe the bug

active/passive cluster, passive tries to send expiration to main register

To Reproduce

loadmodule "usrloc.so"
modparam("usrloc", "location_cluster", 1)
modparam("usrloc", "pinging_mode", "ownership")
modparam("usrloc", "mi_dump_kv_store", 1)
modparam("usrloc", "contact_refresh_timer", true)
modparam("usrloc", "working_mode_preset", "full-sharing-cluster")

loadmodule "mid_registrar.so"
modparam("mid_registrar", "mode", 2) /* 0 = mirror / 1 = ct / 2 = AoR */
modparam("mid_registrar", "outgoing_expires", 7200)
modparam("mid_registrar", "max_expires", 604800)
modparam("mid_registrar", "min_expires", 60)
modparam("mid_registrar", "default_expires", 120)
modparam("mid_registrar", "received_avp", "$avp(rcv)")
modparam("mid_registrar", "received_param", "rcv")

modparam("mid_registrar", "pn_enable", true)
modparam("mid_registrar", "pn_providers", "apns, fcm, webpush")

        mid_registrar_save("location", "$var(mid_registrar_flags)",,$var(mid_registrar_outgoing_expires),"service");

on active machine:

(opensips-cli): mi ul_show_contact table_name=location aor=1033@dittabianchi.opentelecom.it
ERROR: command 'ul_show_contact' returned: 404: AOR not found
(opensips-cli):

(opensips-cli): mi ul_show_contact table_name=location aor=1033@dittabianchi.opentelecom.it
{
    "AOR": "1033@dittabianchi.opentelecom.it",
    "Contacts": [
        {
            "Contact": "sip:60jada2s@g2jcv3tqfeir.invalid;transport=wss",
            "ContactID": "2405766625946086565",
            "Expires": 99,
            "Q": "",
            "Callid": "5lif431hcp8von67d3rks7",
            "Cseq": 82,
            "User-agent": "SaraPhone 32 [R:1 T:0 O:0 L:15:08 N:06:58 G:15:08]",
            "Received": "sip:5.170.41.154:34971;transport=wss",
            "State": "CS_NEW",
            "Flags": 0,
            "Cflags": "SIPPING_RTO SIPPING_FLAG NATED_CALLEE",
            "Socket": "wss:128.189.72.218:5443",
            "Methods": 5439,
            "SIP_instance": "",
            "KV-Store": "{\"CID\":\"5lif431hcp8von67d3rks7\",\"Con\":\"sip:1033%40dittabianchi.opentelecom.it@192.168.20.180:5060\",\"F\":\"sip:1033@dittabianchi.opentelecom.it\",\"LRTs\":0,\"Seq\":82,\"T\":\"sip:1033@dittabianchi.opentelecom.it\",\"_st\":\"service\",\"exp\":120,\"expO\":7300,\"hop\":\"sip:192.168.20.185:5060\",\"ru\":\"sip:dittabianchi.opentelecom.it\"}"
        }
    ],
    "KV-Store": "{\"CID\":\"5lif431hcp8von67d3rks7\",\"Con\":\"sip:1033%40dittabianchi.opentelecom.it@192.168.20.180:5060\",\"F\":\"sip:1033@dittabianchi.opentelecom.it\",\"LRTs\":1624540110,\"Seq\":82,\"T\":\"sip:1033@dittabianchi.opentelecom.it\",\"expO\":7300,\"hop\":\"sip:192.168.20.185:5060\",\"ru\":\"sip:dittabianchi.opentelecom.it\"}"
}
(opensips-cli):

on passive machine:

(opensips-cli): mi ul_show_contact table_name=location aor=1033@dittabianchi.opentelecom.it
ERROR: command 'ul_show_contact' returned: 404: AOR not found
(opensips-cli):

(opensips-cli): mi ul_show_contact table_name=location aor=1033@dittabianchi.opentelecom.it
{
    "AOR": "1033@dittabianchi.opentelecom.it",
    "Contacts": [
        {
            "Contact": "sip:60jada2s@g2jcv3tqfeir.invalid;transport=wss",
            "ContactID": "2405766625946086565",
            "Expires": 107,
            "Q": "",
            "Callid": "5lif431hcp8von67d3rks7",
            "Cseq": 82,
            "User-agent": "SaraPhone 32 [R:1 T:0 O:0 L:15:08 N:06:58 G:15:08]",
            "Received": "sip:5.170.41.154:34971;transport=wss",
            "State": "CS_NEW",
            "Flags": 0,
            "Cflags": "SIPPING_RTO SIPPING_FLAG NATED_CALLEE",
            "Socket": "wss:128.189.72.218:5443",
            "Methods": 5439,
            "SIP_instance": "",
            "KV-Store": "{\"_st\":\"service\"}"
        }
    ]
}
(opensips-cli):

after first re-registration, nothing changes on active machine, but on passive machine it becomes:

(opensips-cli): mi ul_show_contact table_name=location aor=1033@dittabianchi.opentelecom.it
{
    "AOR": "1033@dittabianchi.opentelecom.it",
    "Contacts": [
        {
            "Contact": "sip:60jada2s@g2jcv3tqfeir.invalid;transport=wss",
            "ContactID": "2405766625946086565",
            "Expires": 43,
            "Q": "",
            "Callid": "5lif431hcp8von67d3rks7",
            "Cseq": 84,
            "User-agent": "SaraPhone 32 [R:1 T:0 O:0 L:15:08 N:06:58 G:15:08]",
            "Received": "sip:5.170.41.154:34971;transport=wss",
            "State": "CS_NEW",
            "Flags": 0,
            "Cflags": "SIPPING_RTO SIPPING_FLAG NATED_CALLEE",
            "Socket": "wss:128.189.72.218:5443",
            "Methods": 5439,
            "SIP_instance": "",
            "KV-Store": "{\"CID\":\"5lif431hcp8von67d3rks7\",\"Con\":\"sip:1033%40dittabianchi.opentelecom.it@192.168.20.180:5060\",\"F\":\"sip:1033@dittabianchi.opentelecom.it\",\"LRTs\":1624540200,\"Seq\":84,\"T\":\"sip:1033@dittabianchi.opentelecom.it\",\"_st\":\"service\",\"_urec_kvs\":\"{\\\"CID\\\":\\\"5lif431hcp8von67d3rks7\\\",\\\"Con\\\":\\\"sip:1033%40dittabianchi.opentelecom.it@192.168.20.180:5060\\\",\\\"F\\\":\\\"sip:1033@dittabianchi.opentelecom.it\\\",\\\"LRTs\\\":1624540110,\\\"Seq\\\":82,\\\"T\\\":\\\"sip:1033@dittabianchi.opentelecom.it\\\",\\\"expO\\\":7300,\\\"hop\\\":\\\"sip:192.168.20.185:5060\\\",\\\"ru\\\":\\\"sip:dittabianchi.opentelecom.it\\\"}\",\"exp\":120,\"expO\":7300,\"hop\":\"sip:192.168.20.185:5060\",\"ru\":\"sip:dittabianchi.opentelecom.it\"}"
        }
    ],
    "KV-Store": "{\"CID\":\"5lif431hcp8von67d3rks7\",\"Con\":\"sip:1033%40dittabianchi.opentelecom.it@192.168.20.180:5060\",\"F\":\"sip:1033@dittabianchi.opentelecom.it\",\"LRTs\":1624540110,\"Seq\":82,\"T\":\"sip:1033@dittabianchi.opentelecom.it\",\"expO\":7300,\"hop\":\"sip:192.168.20.185:5060\",\"ru\":\"sip:dittabianchi.opentelecom.it\"}"
}
(opensips-cli):

btw, it still is different from the one on active machine

Then, when active machine sends the expire REGISTER (because the phone failed to renew registration before expiration time) to main register, passive machine cries:

Jun 24 15:15:01 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:01 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:01 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:01 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:t_uac: attempt to send to 'sip:192.168.20.185:5060' failed
Jun 24 15:15:02 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:02 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:02 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:03 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:03 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:03 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:05 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:05 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:05 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:09 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:09 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:09 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:13 lxc181 /usr/sbin/opensips[4821]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:13 lxc181 /usr/sbin/opensips[4821]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:13 lxc181 /usr/sbin/opensips[4821]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:17 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:17 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:17 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:21 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:21 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:21 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:25 lxc181 /usr/sbin/opensips[4822]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:25 lxc181 /usr/sbin/opensips[4822]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:25 lxc181 /usr/sbin/opensips[4822]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed
Jun 24 15:15:29 lxc181 /usr/sbin/opensips[4820]: ERROR:core:proto_udp_send: sendto(sock,0x7f85a5c979c8,501,0,0x7f85a5c9b708,16): Invalid argument(22) [192.168.20.185:5060]
Jun 24 15:15:29 lxc181 /usr/sbin/opensips[4820]: CRITICAL:core:proto_udp_send: invalid sendtoparameters#012one possible reason is the server is bound to localhost and#012attempts to send to the net
Jun 24 15:15:29 lxc181 /usr/sbin/opensips[4820]: ERROR:tm:msg_send: send() to 192.168.20.185:5060 for proto udp/1 failed

Expected behavior

only active machine sends expires REGISTER to main registrar

Relevant System Logs

OS/environment information

  • Operating System:
  • OpenSIPS installation:
  • other relevant information:

debian 10 (buster) from nightly deb packages

Additional context
@gmaruzz
Copy link
Author

gmaruzz commented Jun 24, 2021

pn, push, etc, are not involved here.

just a normal sip phone, that happen to be on wss

@gmaruzz
Copy link
Author

gmaruzz commented Jun 24, 2021

this happen when the phone failed to renew registration before expiration time, so mid-register (the active one) must send a REGISTER with expires=0 to main registrar

@gmaruzz gmaruzz changed the title [BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register (fails because has no the floating ip) [BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register (fails because it does not have the floating ip) Jun 24, 2021
@gmaruzz gmaruzz changed the title [BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register (fails because it does not have the floating ip) [BUG] 3.1.3-nightly mid-register on passive machine tries to send expiration to main register Jun 24, 2021
@liviuchircu liviuchircu self-assigned this Jun 24, 2021
@gmaruzz
Copy link
Author

gmaruzz commented Jun 24, 2021

#2525

that one is possible related to this

@github-actions
Copy link

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

@github-actions github-actions bot added the stale label Jul 17, 2021
@gmaruzz
Copy link
Author

gmaruzz commented Jul 19, 2021

update for bot satisfaction

@stale stale bot removed the stale label Jul 19, 2021
@github-actions
Copy link

github-actions bot commented Aug 4, 2021

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

@github-actions github-actions bot added the stale label Aug 4, 2021
@liviuchircu liviuchircu added this to the 3.1.4 milestone Aug 13, 2021
liviuchircu added a commit that referenced this issue Aug 13, 2021
@liviuchircu
mid-registrar: Avoid generating De-REGISTER from Passive node
e8494eb 
    * enhance the usrloc API with a contact ownership checking function
    * mid-registrar now only generates De-REGISTER for owned contacts

Credits to Giovanni Maruzzelli for detailed reporting and instructions
on how to reproduce this issue!

Fixes #2559

(cherry picked from commit 4128f67)
liviuchircu added a commit that referenced this issue Aug 13, 2021
@liviuchircu
mid-registrar: Avoid generating De-REGISTER from Passive node
907023e 
    * enhance the usrloc API with a contact ownership checking function
    * mid-registrar now only generates De-REGISTER for owned contacts

Credits to Giovanni Maruzzelli for detailed reporting and instructions
on how to reproduce this issue!

Fixes #2559

(cherry picked from commit 4128f67)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@liviuchircu liviuchircu

Labels
bug fixed
Projects
None yet
Milestone
3.1.17
Development

No branches or pull requests
2 participants
@gmaruzz @liviuchircu