Re: server shutdown -> not removed from routers, can't reconnect "too many regs"

Cropped to include relevant logs:

Server connects:
: [Logging] [Info] Incoming connection ssss.ss.ss.ss (sss.ss.ss.ss)
: 11:28:24 silc_server_accept_new_connection:2847: Starting key exchange protocol
: 11:28:25 silc_server_accept_completed:2671: Setting keys into use
: 11:28:25 silc_server_accept_completed:2693: Starting connection authentication
: 11:28:25 silc_server_accept_get_auth:2148: Remote connection type 2
: 11:28:25 silc_server_accept_auth_compl:2265: Checking whether connection is allowed
: 11:28:25 silc_server_connection_allowed:1175: Checking whether connection is allowed
: 11:28:25 silc_server_accept_auth_compl:2509: Remote host is server
: [Logging] [Info] Connection ssss.ss.ss.ss (sss.ss.ss.ss) is server
: 11:28:25 silc_idlist_add_server:83: Adding new server entry
: 11:28:25 silc_server_accept_auth_compl:2570: my_servers 2
There are now 2 servers....

: 11:28:25 silc_server_accept_auth_compl:2617: New connection 0x4b39fb00 authenticated
: 11:28:25 silc_server_config_destroy:1601: Unreferencing config [0x45901e00] refcnt 9->8
: 11:28:25 silc_server_config_destroy:1601: Unreferencing config [0x45901e00] refcnt 8->7
: 11:28:25 silc_server_packet_parse_type:307: Received NEW SERVER packet [flags 0]
: 11:28:25 silc_server_new_server:2335: Creating new server
: 11:28:25 silc_idlist_find_server_by_id:123: Server ID (sss.ss.ss.ss,49666,[00 ff])
: 11:28:25 silc_idlist_find_server_by_id:123: Server ID (sss.ss.ss.ss,49666,[00 ff])
: 11:28:25 silc_server_new_server:2486: New server id(sss.ss.ss.ss,49666,[00 ff])

This is weird notify from somewhere, probably from backup router
: 11:28:38 silc_server_packet_parse_type:307: Received NOTIFY packet [flags 0]
: 11:28:38 silc_server_notify_process:1190: SERVER SIGNOFF notify
: 11:28:38 silc_server_notify_process:1204: Ignoring my own ID for SERVER_SIGNOFF

Same server connects again
: 11:28:39 silc_server_accept_new_connection:2734: Accepting new connection
: 11:28:39 silc_server_accept_new_connection:2766: Created packet stream 0x4d85ef00
: 11:28:39 silc_server_accept_new_connection:2827: Created unknown connection 0x4d85e700
: 11:28:39 silc_server_config_ref:1580: Referencing config [0x45901e00] refcnt 7->8
: 11:28:39 silc_server_config_ref:1580: Referencing config [0x45901e00] refcnt 8->9
: [Logging] [Info] Incoming connection ssss.ss.ss.ss (sss.ss.ss.ss)
: 11:28:39 silc_server_accept_new_connection:2847: Starting key exchange protocol
: 11:28:40 silc_server_accept_completed:2671: Setting keys into use
: 11:28:40 silc_server_accept_completed:2693: Starting connection authentication
: 11:28:40 silc_server_accept_get_auth:2148: Remote connection type 2
: 11:28:40 silc_server_accept_auth_compl:2265: Checking whether connection is allowed
: 11:28:40 silc_server_connection_allowed:1175: Checking whether connection is allowed
: 11:28:40 silc_server_accept_auth_compl:2509: Remote host is server
: [Logging] [Info] Connection ssss.ss.ss.ss (sss.ss.ss.ss) is server
: 11:28:40 silc_idlist_add_server:83: Adding new server entry
: 11:28:40 silc_server_accept_auth_compl:2570: my_servers 3
There are now 3 servers

: 11:28:40 silc_server_accept_auth_compl:2617: New connection 0x4da6e880 authenticated
: 11:28:40 silc_server_config_destroy:1601: Unreferencing config [0x45901e00] refcnt 9->8
: 11:28:40 silc_server_config_destroy:1601: Unreferencing config [0x45901e00] refcnt 8->7
: 11:28:40 silc_server_packet_parse_type:307: Received NEW SERVER packet [flags 0]
: 11:28:40 silc_server_new_server:2335: Creating new server
: 11:28:40 silc_idlist_find_server_by_id:123: Server ID (sss.ss.ss.ss,49666,[00 ff])
: 11:28:40 silc_idlist_find_server_by_id:137: Found

Cannot connect twice...
: [Logging] [Error] Too many registrations from sss.ss.ss.ss (ssss.ss.ss.ss)
: 11:28:40 silc_server_disconnect_remote:3064: Disconnecting remote host, sock 0x4d85ef00
: [Logging] [Info] Closing connection ssss.ss.ss.ss:36162 [Server]
: 11:28:40 silc_server_connection_free:1300: Free connection 0x4da6e880
: 11:28:40 silc_server_free_sock_user_data:3171: Start, sock 0x4d85ef00
: 11:28:40 silc_server_free_sock_user_data:3209: Freeing server 0x4da70800 data
: 11:28:40 silc_server_remove_servers_by_server:782: Removing servers by server
: 11:28:40 silc_server_free_sock_user_data:3370: my_servers 2
Back to 2 servers

: 11:28:40 silc_idlist_del_server:258: Unknown server, did not delete
: 11:28:40 silc_idlist_del_server:258: Unknown server, did not delete

So it looks like the server connects twice.  This is probably bug in the 
reconnection logic.  I think I've seen this sometimes or heard that it can 
happen...  There seems to be also bug in deleting the second server entry 
from the cache, hence the "Unknown server, did not delete", which in 
effect will leak memory...

The server that keeps reconnecting even though it has already active 
connection is probably in a state that it thinks it doesn't have active 
connection and it probably doesn't work properly in that case...

Other possibility is that for some reason the router didn't notice the 
network connection closing and the first server entry remains there even 
though it was supposed to be disconnected...  Dunno how that could 
happen...

The problem should fix by restarting the server, when it will close the 
first connection but you indicate that it doesn't help.  Only restarting 
router helps, which would indicate it missed somehow the network 
disconnection...

	Pekka
________________________________________________________________________
 Pekka Riikonen                                 priikone at silcnet.org
 Secure Internet Live Conferencing (SILC)       http://silcnet.org/
_______________________________________________________________________
Info:    https://lists.silcnet.org/mailman/listinfo/silc-announce
Archive: https://lists.silcnet.org/pipermail/silc-announce
FAQ:     http://silcnet.org/support/faq/