Archived

This forum has been archived. Please start a new discussion on GitHub.

icegridnode failed to reconnect registry after...

i use ice 3.1.1 demo/simple to do a test on winxp sp2,
it goes like this:
1. start icegridregistry and icegridnode on different machines
2. pull off the network cable on the registry side
...wait for timeout, until an exception throwed out...
3. put the cable back

then icegridnode says :
"a node with the same name is already registered and active"
and it never ends

maybe it's a bug or something need to config?

Comments

  • benoit
    benoit Rennes, France
    Hi,

    I'm afraid I'm unable to reproduce this.

    Are you using the configuration unmodified of the IceGrid simple demo? Could you try to reproduce the problem with the property IceGrid.Registry.Trace.Node set to 3 in the registry configuration file and post the tracing output here?

    Thanks,
    Benoit.
  • this is my config.grid:(only changed IP and Collocate)
    IceGrid.InstanceName=DemoIceGrid

    #
    # The IceGrid locator proxy.
    #
    Ice.Default.Locator=DemoIceGrid/Locator:default -h 192.168.101.87 -p 12000

    #
    # IceGrid registry configuration.
    #
    IceGrid.Registry.Client.Endpoints=default -p 12000
    IceGrid.Registry.Server.Endpoints=default
    IceGrid.Registry.Internal.Endpoints=default
    IceGrid.Registry.Admin.Endpoints=default
    IceGrid.Registry.Data=db/registry
    IceGrid.Registry.PermissionsVerifier=DemoIceGrid/NullPermissionsVerifier
    IceGrid.Registry.AdminPermissionsVerifier=DemoIceGrid/NullPermissionsVerifier

    #
    # IceGrid node configuration.
    #
    IceGrid.Node.Name=localhost
    IceGrid.Node.Endpoints=default
    IceGrid.Node.Data=db/node
    #IceGrid.Node.CollocateRegistry=1
    #IceGrid.Node.Output=db
    #IceGrid.Node.RedirectErrToOut=1

    #
    # Trace properties.
    #
    IceGrid.Node.Trace.Activator=1
    IceGrid.Node.Trace.Patch=1
    #IceGrid.Node.Trace.Adapter=2
    #IceGrid.Node.Trace.Server=3

    IceGrid.Registry.Trace.Node=3

    trace of the node:(error trace never ends)
    E:\Ice-3.1.1\demo\IceGrid\simple>icegridnode --Ice.Config=config.grid
    [ icegridnode: Activator: activating server `SimpleServer' ]
    SimpleServer says Hello World!
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active

    trace of the registry:(this is strange, no trace is output after the exception)
    D:\test\simple_test_3.1.1>icegridregistry --Ice.Config=config.grid
    icegridregistry: warning: administrative endpoints `IceGrid.Registry.Admin.Endpo
    ints' enabled
    [ icegridregistry: Node: node `localhost' up ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.0825, 0.0165, 0.0
    055) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.109167, 0.0218333
    , 0.00727778) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.109167, 0.0218333
    , 0.00727778) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.125833, 0.0251667
    , 0.00838889) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.135833, 0.0271667
    , 0.00905556) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.135833, 0.0271667
    , 0.00905556) ]
    icegridregistry: warning: unexpected exception while reaping node session:
    .\Network.cpp:675: Ice::ConnectFailedException:
    connect failed: WSAEHOSTUNREACH


    thanks!
  • benoit
    benoit Rennes, France
    Hi,

    It looks like a bug :(. This warning indicates that an unexpected exception occured while destroying the node session in the registry.

    Could you please try again with a little more tracing on the registry :)? Seeing the traces of the registry with the following properties would be helpful:

    Ice.Trace.Network=2
    Ice.Trace.Retry=1

    Thanks!

    Cheers,
    Benoit.
  • this is the new trace:


    registry:
    D:\test\simple_test_3.1.1>icegridregistry --Ice.Config=config.grid
    icegridregistry: warning: administrative endpoints `IceGrid.Registry.Admin.Endpo
    ints' enabled
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:3916 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:3917 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:1200
    0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:12000 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:12000 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:12000 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:3922 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:3923 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:3926 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:3927 ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.87
    :3926 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:3926
    remote address = 192.168.101.87:3930 ]
    [ icegridregistry: Network: tcp connection established
    local address = 192.168.101.87:3930
    remote address = 192.168.101.87:3926 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6905 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:3926
    remote address = 192.168.101.131:6908 ]
    [ icegridregistry: Node: node `localhost' up ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.13
    1:12000 ]
    [ icegridregistry: Network: tcp connection established
    local address = 192.168.101.87:3933
    remote address = 192.168.101.131:12000 ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.0825, 0.0165, 0.0
    055) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.124167, 0.0248333
    , 0.00827778) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.151667, 0.0303333
    , 0.0101111) ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6913 ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.13
    1:12000 ]
    [ icegridregistry: Network: tcp connection established
    local address = 192.168.101.87:3934
    remote address = 192.168.101.131:12000 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6918 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:3916
    remote address = 192.168.101.131:6921 ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.164167, 0.0328333
    , 0.0109444) ]
    [ icegridregistry: Node: node `localhost' keep alive (load = 0.165, 0.033, 0.011
    ) ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3916
    remote address = 192.168.101.131:6921 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3933
    remote address = 192.168.101.131:12000 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6905 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3926
    remote address = 192.168.101.131:6908 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3916
    remote address = 192.168.101.131:6921 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3930
    remote address = 192.168.101.87:3926 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3933
    remote address = 192.168.101.131:12000 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6918 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6905 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3926
    remote address = 192.168.101.87:3930 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3926
    remote address = 192.168.101.131:6908 ]
    [ icegridregistry: Retry: retrying operation call because of exception
    .\TcpTransceiver.cpp:161: Ice::ConnectionLostException:
    connection lost: WSAECONNRESET ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3930
    remote address = 192.168.101.87:3926 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6913 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6918 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3926
    remote address = 192.168.101.87:3930 ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.87
    :3926 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:3934
    remote address = 192.168.101.131:12000 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6913 ]
    [ icegridregistry: Retry: cannot retry operation call because retry limit has be
    en exceeded
    .\Network.cpp:675: Ice::ConnectFailedException:
    connect failed: WSAEHOSTUNREACH ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:3934
    remote address = 192.168.101.131:12000 ]
    icegridregistry: warning: unexpected exception while reaping node session:
    .\Network.cpp:675: Ice::ConnectFailedException:
    connect failed: WSAEHOSTUNREACH
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6927 ]
    [ icegridregistry: Network: accepted tcp connection
    local address = 192.168.101.87:3926
    remote address = 192.168.101.131:6928 ]
    [ icegridregistry: Network: shutting down tcp connection for writing
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6927 ]
    [ icegridregistry: Network: closing tcp connection
    local address = 192.168.101.87:12000
    remote address = 192.168.101.131:6927 ]


    thanks! :)
  • node:
    E:\Ice-3.1.1\demo\IceGrid\simple>icegridnode --Ice.Config=config.grid
    [ icegridnode: Network: attempting to bind to tcp socket 192.168.101.131:12000 ]

    [ icegridnode: Network: accepting tcp connections at 192.168.101.131:12000 ]
    [ icegridnode: Network: attempting to bind to tcp socket 127.0.0.1:12000 ]
    [ icegridnode: Network: accepting tcp connections at 127.0.0.1:12000 ]
    [ icegridnode: Network: trying to establish tcp connection to 192.168.101.87:120
    00 ]
    [ icegridnode: Network: tcp connection established
    local address = 192.168.101.131:6905
    remote address = 192.168.101.87:12000 ]
    [ icegridnode: Network: trying to establish tcp connection to 192.168.101.87:392
    6 ]
    [ icegridnode: Network: tcp connection established
    local address = 192.168.101.131:6908
    remote address = 192.168.101.87:3926 ]
    [ icegridnode: Network: accepted tcp connection
    local address = 192.168.101.131:12000
    remote address = 192.168.101.87:3933 ]
    [ icegridnode: Network: accepted tcp connection
    local address = 192.168.101.131:12000
    remote address = 192.168.101.131:6909 ]
    [ icegridnode: Network: shutting down tcp connection for writing
    local address = 192.168.101.131:12000
    remote address = 192.168.101.131:6909 ]
    [ icegridnode: Network: closing tcp connection
    local address = 192.168.101.131:12000
    remote address = 192.168.101.131:6909 ]
    [ icegridnode: Network: accepted tcp connection
    local address = 192.168.101.131:12000
    remote address = 192.168.101.87:3934 ]
    [ icegridnode: Activator: activating server `SimpleServer' ]
    SimpleServer says Hello World!
    [ icegridnode: Network: shutting down tcp connection for writing
    local address = 192.168.101.131:6908
    remote address = 192.168.101.87:3926 ]
    [ icegridnode: Network: closing tcp connection
    local address = 192.168.101.131:6908
    remote address = 192.168.101.87:3926 ]
    [ icegridnode: Network: trying to establish tcp connection to 192.168.101.87:392
    6 ]
    [ icegridnode: Network: shutting down tcp connection for writing
    local address = 192.168.101.131:6905
    remote address = 192.168.101.87:12000 ]
    [ icegridnode: Network: closing tcp connection
    local address = 192.168.101.131:6905
    remote address = 192.168.101.87:12000 ]
    [ icegridnode: Retry: retrying operation call because of exception
    .\TcpTransceiver.cpp:285: Ice::ConnectionLostException:
    connection lost: WSAECONNRESET ]
    [ icegridnode: Network: trying to establish tcp connection to 192.168.101.87:120
    00 ]
    [ icegridnode: Network: tcp connection established
    local address = 192.168.101.131:6927
    remote address = 192.168.101.87:12000 ]
    [ icegridnode: Network: trying to establish tcp connection to 192.168.101.87:392
    6 ]
    [ icegridnode: Network: tcp connection established
    local address = 192.168.101.131:6928
    remote address = 192.168.101.87:3926 ]
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    [ icegridnode: Network: shutting down tcp connection for writing
    local address = 192.168.101.131:6927
    remote address = 192.168.101.87:12000 ]
    [ icegridnode: Network: closing tcp connection
    local address = 192.168.101.131:6927
    remote address = 192.168.101.87:12000 ]
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active
    icegridnode: error: a node with the same name is already registered and active

    thanks! :)
  • benoit
    benoit Rennes, France
    Ok, I think this occurs because pluging out the cable on the machine where the registry is running brings down the network interface and the registry can't establish connections to itself anymore through this interface. The registry should be using the loopback interface instead. I believe it should work if you configure the registry internal endpoints with the following property:

    IceGrid.Regsitry.Internal.PublishedEndpoints=default:default -h 127.0.0.1

    This will ensure that the proxies created with the internal object adapter also contains the loopback interface endpoint.

    I'll will think about a way to enforce this configuration. Thanks for bringing this to our attention and let me know if this workaround works or not!

    Cheers,
    Benoit.
  • i add this property into the config file like you said:
    IceGrid.Registry.Internal.PublishedEndpoints=default:default -h 127.0.0.1

    registry cannot be started:(
    E:\Ice-3.1.1\demo\IceGrid\simple>icegridregistry --Ice.Config=config.grid
    icegridregistry: warning: administrative endpoints `IceGrid.Registry.Admin.Endpo
    ints' enabled
    icegridregistry: error: service caught unhandled Ice exception:
    .\Network.cpp:681: Ice::SocketException:
    socket exception: WSAEADDRNOTAVAIL

    :confused:
    thanks for your deeper look ~~
  • more trace here:
    D:\test\simple_test_3.1.1>icegridregistry --Ice.Config=config.grid
    icegridregistry: warning: administrative endpoints `IceGrid.Registry.Admin.Endpo
    ints' enabled
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:4610 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:4611 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:1200
    0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:12000 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:12000 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:12000 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:4616 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:4617 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 192.168.101.87:0 ]
    [ icegridregistry: Network: accepting tcp connections at 192.168.101.87:4620 ]
    [ icegridregistry: Network: attempting to bind to tcp socket 127.0.0.1:0 ]
    [ icegridregistry: Network: accepting tcp connections at 127.0.0.1:4621 ]
    [ icegridregistry: Network: trying to establish tcp connection to 127.0.0.1:0 ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.87
    :0 ]
    [ icegridregistry: Retry: retrying operation call because of exception
    .\Network.cpp:681: Ice::SocketException:
    socket exception: WSAEADDRNOTAVAIL ]
    [ icegridregistry: Network: trying to establish tcp connection to 192.168.101.87
    :0 ]
    [ icegridregistry: Network: trying to establish tcp connection to 127.0.0.1:0 ]
    [ icegridregistry: Retry: cannot retry operation call because retry limit has be
    en exceeded
    .\Network.cpp:681: Ice::SocketException:
    socket exception: WSAEADDRNOTAVAIL ]
    icegridregistry: error: service caught unhandled Ice exception:
    .\Network.cpp:681: Ice::SocketException:
    socket exception: WSAEADDRNOTAVAIL
    [ icegridregistry: Network: stopping to accept tcp connections at 192.168.101.87
    :4616 ]
    [ icegridregistry: Network: stopping to accept tcp connections at 192.168.101.87
    :12000 ]
    [ icegridregistry: Network: stopping to accept tcp connections at 192.168.101.87
    :4620 ]
    [ icegridregistry: Network: stopping to accept tcp connections at 192.168.101.87
    :4610 ]
    [ icegridregistry: Network: stopping to accept tcp connections at 127.0.0.1:4617
    ]
    [ icegridregistry: Network: stopping to accept tcp connections at 127.0.0.1:1200
    0 ]
    [ icegridregistry: Network: stopping to accept tcp connections at 127.0.0.1:4621
    ]
    [ icegridregistry: Network: stopping to accept tcp connections at 127.0.0.1:4611
    ]
  • benoit
    benoit Rennes, France
    Sorry, my mistake, the PublishedEndpoints property can't work because you don't specify a port. Instead you should set the IceGrid.Registry.Internal.Endpoints with the endpoint of each interface on your machine ("default -h 192.168.101.87:default -h 127.0.0.1"). Is this what you did to obtain the tracing from you last post?

    This tracing shows that the registry also fails to connect to the loopback interface. IceGrid requires the loopback interface to always be up so you need to change your network configuration to ensure it's always available.

    On my Windows XP machine, the loopback interface is always available even if all the network adapters are disabled, I'm not sure why it's not the case on your machine. You could try to see if you can still "ping 127.0.0.1" after unplugging the cable.

    Cheers,
    Benoit.
  • i guess the loopback interface is available here for i can ping 127.0.0.1 after unplugging the cable.

    the old setting of IceGrid.Registry.Internal.Endpoints is "default", after change it to "default -h 192.168.101.87:default -h 127.0.0.1" , registry works well. this should be the point of this problem.

    thanks benoit:)

    except for IceGrid, should we set the config of other applications like this?
  • benoit
    benoit Rennes, France
    leya wrote: »
    except for IceGrid, should we set the config of other applications like this?

    No, this shouldn't be necessary if your application doesn't require the loopback interface.

    Cheers,
    Benoit.