Archived

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

Communication via topics does not work after transitioning from Ice 3.5 to 3.7

Hi everyone,

After upgrading to Ubuntu18.04 and Ice 3.7, creating a topic publisher fails with src/Ice/Reference.cpp:1643: ::Ice::NoEndpointException: no suitable endpoint available for proxy IceStorm/TopicManager -t -e 1.0 Aborted (core dumped)

Communication via proxy works fine though!

I am thinking that this might have to do with some configuration issue due to upgrading from 3.5 to 3.7.

My configuration is as follows:

config.registry

IceGrid.InstanceName=IceGrid
Ice.Default.Locator = IceGrid/Locator:tcp -p 4061
Ice.Trace.Network = 1
IceGrid.Registry.Client.Endpoints = tcp -p 4061
IceGrid.Registry.Server.Endpoints=tcp
IceGrid.Registry.Internal.Endpoints=tcp
IceGrid.Registry.LMDB.Path=db

IceGrid.Registry.PermissionsVerifier=IceGrid/NullPermissionsVerifier
IceGrid.Registry.AdminPermissionsVerifier=IceGrid/NullPermissionsVerifier

IceGrid.Registry.DynamicRegistration=1
IceGrid.Registry.SessionTimeout=300
Ice.MessageSizeMax=10000000

IceGrid.Node.CollocateRegistry=1

IceGridAdmin.Username=foo
IceGridAdmin.Password=bar

config.node

Ice.Default.Locator = IceGrid/Locator:tcp -p 4061

IceGrid.Node.Name=Node1

IceGrid.Node.Endpoints=tcp
IceGrid.Node.Data=data

Ice.Trace.Network=1

application.xml

<icegrid>

  <application name="Demo">

   <server-template id="IceStorm">
     <parameter name="instance-name" default="IceStorm"/>
     <parameter name="topic-manager-endpoints" default="tcp -h localhost"/>
     <parameter name="publish-endpoints" default="tcp"/>

     <icebox id="${instance-name}" exe="icebox" activation="always">

       <service name="${instance-name}" entry="IceStormService,35:createIceStorm">

         <dbenv name="${service}"/>

         <adapter name="${service}.TopicManager"
          id="${instance-name}.TopicManager"
          endpoints="${topic-manager-endpoints}">
          <object identity="${instance-name}/TopicManager" type="::IceStorm::TopicManager"/>
        </adapter>

        <adapter name="${service}.Publish"
          id="${instance-name}.Publish"
          endpoints="${publish-endpoints}"/>

          <properties>
           <property name="${service}.InstanceName" value="${instance-name}"/>
           <property name="${service}.Trace.TopicManager" value="2"/>
           <property name="${service}.Trace.Topic" value="2"/>
           <property name="${service}.Trace.Subscriber" value="2"/>
         </properties>

       </service>
     </icebox>
   </server-template>

   <node name="Node1">
    <server-instance template="IceStorm"/>
  </node>

</application>

</icegrid>

and the commands I am executing are:

icegridregistry --Ice.Config=config.registry &
icegridnode --Ice.Config=config.node &
icegridadmin --Ice.Config=config.registry,config.node -e "application add 'application.xml'" &

Any idea what might be going wrong?

Comments

  • xdm
    xdm La Coruña, Spain

    You should update the IceStorm entry point to 3.7 IceStormService,37:createIceStorm instead of IceStormService,35:createIceStorm in your server template.

    If you want to run icegridregistry and icegridnode in background is preferable to use --daemon command line argument instead of &.

    I don't see why you want to run icegridamin in background, this command shouldn't take too long to finish.

    Cheers,
    José

  • ptriantd
    edited August 2019

    Hi José,

    Thanks for that! Unfortunately, it doesn't seem to fix the issue :/

    Also, if this was the problem, wouldn't proxies not work too? The weird thing for me is that communication via proxy works fine.

    Best,
    Pavlos

  • xdm
    xdm La Coruña, Spain

    What is the process that crash? can you provide a stack trace of the crash?

  • Sure!

    This is what I am getting on the subscriber side:

    -- 07/31/19 17:16:38.969 Network: listening for tcp connections
       local address = :::42447
       local interfaces = 127.0.0.1, 172.17.0.2
    -- 07/31/19 17:16:38.969 Network: published endpoints for object adapter `TextMessengerAdapter':
       tcp -h 172.17.0.2 -p 42447 -t 60000
    -- 07/31/19 17:16:38.969 Network: accepting tcp connections at :::42447
    -- 07/31/19 17:16:38.969 Locator: searching for well-known object
       well-known proxy = IceStorm/TopicManager -t -e 1.0
    -- 07/31/19 17:16:38.970 Network: established tcp connection
       local address = 127.0.0.1:35250
       remote address = 127.0.0.1:4061
    -- 07/31/19 17:16:38.971 Locator: retrieved adapter for well-known object from locator, adding to locator cache
       well-known proxy = IceStorm/TopicManager -t -e 1.0
       adapter = IceStorm.TopicManager
    -- 07/31/19 17:16:38.971 Locator: searching for adapter by id
       adapter = IceStorm.TopicManager
    -- 07/31/19 17:16:39.515 Locator: no endpoints configured for adapter
       adapter = IceStorm.TopicManager
    -- 07/31/19 17:16:39.516 Locator: searching for well-known object
       well-known proxy = IceStorm/TopicManager -t -e 1.0
    -- 07/31/19 17:16:39.516 Locator: retrieved adapter for well-known object from locator, adding to locator cache
       well-known proxy = IceStorm/TopicManager -t -e 1.0
       adapter = IceStorm.TopicManager
    -- 07/31/19 17:16:39.516 Locator: searching for adapter by id
       adapter = IceStorm.TopicManager
    -- 07/31/19 17:16:39.978 Locator: no endpoints configured for adapter
       adapter = IceStorm.TopicManager
    terminate called after throwing an instance of 'ice_management::TopicManagerException'
      what():  Error during creation 
    src/Ice/Reference.cpp:1643: ::Ice::NoEndpointException:
    no suitable endpoint available for proxy `IceStorm/TopicManager -t -e 1.0'
    Aborted (core dumped)
    

    and the IceGrid session outputs:

    -- 08/01/19 17:25:46.771 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:39938
    -- 08/01/19 17:25:46.907 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:39938
       src/Ice/StreamSocket.cpp:249: ::Ice::ConnectionLostException:
       connection lost: recv() returned zero
    
  • xdm
    xdm La Coruña, Spain

    Can you enable IceGrid.Node.Trace.Activator=3 and IceGrid.Node.Trace.Adapter=3 in icegridnode, it is not clear where the -e 1.0 is coming from

  • Ok, now that I enabled these, I see the error

    -- 08/02/19 10:27:06.781 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:43494
    -- 08/02/19 10:27:06.781 icegridadmin: Network: established tcp connection
       local address = 127.0.0.1:43494
       remote address = 127.0.0.1:4061
    -- 08/02/19 10:27:06.789 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:43494
    -- 08/02/19 10:27:06.789 icegridadmin: Network: closed tcp connection
       local address = 127.0.0.1:43494
       remote address = 127.0.0.1:4061
    -- 08/02/19 10:27:07.288 icegridnode: Activator: activating server `IceStorm'
       path = icebox
       pwd = /home/travis/IceManagement/Scripts/IceSetup
       uid/gid = 999/999
       args = icebox --Ice.Config=/home/travis/IceManagement/Scripts/IceSetup/data/servers/IceStorm/config/config
    -- 08/02/19 10:27:07.801 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:43496
    -- 08/02/19 10:27:07.802 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:172.17.0.2:34103
       remote address = ::ffff:172.17.0.2:53520
    -- 08/02/19 10:27:07.802 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    -- 08/02/19 10:27:07.803 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 10:27:07.803 icegridregistry: Network: closed tcp connection
       local address = ::ffff:172.17.0.2:34103
       remote address = ::ffff:172.17.0.2:53520
    -- 08/02/19 10:27:07.803 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:43496
    !! 08/02/19 10:27:07.804 IceStorm: error: exception while starting IceStorm service IceStorm:
       src/IceUtil/FileUtil.cpp:441: ::IceUtil::FileLockException:
       could not lock file: `IceStorm/icedb.lock'
       syscall exception: No such file or directory
    -- 08/02/19 10:27:07.804 icegridnode: Activator: detected termination of server `IceStorm'
       exit code = 1
    -- 08/02/19 10:27:07.805 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 10:27:07.805 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    

    icedb.lock seems to not exist...

    Just some more info about that... When we switched to Ice 3.7, we changed IceGrid.Registry.Data=registry to IceGrid.Registry.LMDB.Path=registry. Should we have done something more?

  • xdm
    xdm La Coruña, Spain

    Your IceStorm service template is missing LMDB configuration

    <property name="${service}.LMDB.Path" value="${service.data}"/>

    See https://github.com/zeroc-ice/ice/blob/3.7/cpp/config/templates.xml#L42

  • Thanks for that!

    When I added this property, the aforementioned error disappeared, but unfortunately I get a socket_exception now:

    -- 08/02/19 11:48:17.119 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:45154
    -- 08/02/19 11:48:17.119 icegridadmin: Network: established tcp connection
       local address = 127.0.0.1:45154
       remote address = 127.0.0.1:4061
    -- 08/02/19 11:48:17.126 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:45154
    -- 08/02/19 11:48:17.126 icegridadmin: Network: closed tcp connection
       local address = 127.0.0.1:45154
       remote address = 127.0.0.1:4061
    -- 08/02/19 11:48:17.625 icegridnode: Activator: activating server `IceStorm'
       path = icebox
       pwd = /home/travis/IceManagement/Scripts/IceSetup
       uid/gid = 999/999
       args = icebox --Ice.Config=/home/travis/IceManagement/Scripts/IceSetup/data/servers/IceStorm/config/config
    -- 08/02/19 11:48:18.185 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:45158
    -- 08/02/19 11:48:18.186 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:172.17.0.2:37765
       remote address = ::ffff:172.17.0.2:59036
    -- 08/02/19 11:48:18.186 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' activated: dummy -t -e 1.1:tcp -h 127.0.0.1 -p 45245 -t 60000
    -- 08/02/19 11:48:18.187 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' activated: dummy -t -e 1.1:tcp -h 127.0.0.1 -p 39857 -t 60000
    -- 08/02/19 11:48:18.188 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    -- 08/02/19 11:48:18.189 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 11:48:18.189 icegridregistry: Network: closed tcp connection
       local address = ::ffff:172.17.0.2:37765
       remote address = ::ffff:172.17.0.2:59036
    -- 08/02/19 11:48:18.189 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:45158
    !! 08/02/19 11:48:18.190 IceStorm: error: ServiceManager: src/Ice/Network.cpp:2368: ::Ice::SocketException:
       socket exception: Cannot assign requested address
    -- 08/02/19 11:48:18.191 icegridnode: Activator: detected termination of server `IceStorm'
       exit code = 1
    -- 08/02/19 11:48:18.191 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 11:48:18.191 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    
  • xdm
    xdm La Coruña, Spain

    Seems an attempt to bind is failing, can you enable network tracing in the service properties

    <properties>
    <property name="Ice.Trace.Network" value="2"/>
    ....
    
    </properties>
    
  • Sure!

    Here is the output:

    -- 08/02/19 15:10:09.065 icegridadmin: Network: trying to establish tcp connection to 127.0.0.1:4061
    -- 08/02/19 15:10:09.065 icegridregistry: Network: trying to accept tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46650
    -- 08/02/19 15:10:09.066 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46650-- 08/02/19 15:10:09.066 icegridadmin: Network: established tcp connection
       local address = 127.0.0.1:46650
       remote address = 127.0.0.1:4061
    
    -- 08/02/19 15:10:09.074 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46650
    -- 08/02/19 15:10:09.074 icegridadmin: Network: closed tcp connection
       local address = 127.0.0.1:46650
       remote address = 127.0.0.1:4061
    -- 08/02/19 15:10:09.573 icegridnode: Activator: activating server `IceStorm'
       path = icebox
       pwd = /home/travis/IceManagement/Scripts/IceSetup
       uid/gid = 999/999
       args = icebox --Ice.Config=/home/travis/IceManagement/Scripts/IceSetup/data/servers/IceStorm/config/config
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: attempting to bind to tcp socket :::0
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: listening for tcp connections
       local address = :::34547
       local interfaces = 127.0.0.1, 172.17.0.2
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: published endpoints for object adapter `IceStorm.TopicManager':
       tcp -h 172.17.0.2 -p 34547 -t 60000
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: attempting to bind to tcp socket :::0
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: listening for tcp connections
       local address = :::43465
       local interfaces = 127.0.0.1, 172.17.0.2
    -- 08/02/19 15:10:10.055 IceStorm-IceStorm: Network: published endpoints for object adapter `IceStorm.Publish':
       tcp -h 172.17.0.2 -p 43465 -t 60000
    -- 08/02/19 15:10:10.059 IceStorm-IceStorm: Network: trying to establish tcp connection to 127.0.0.1:4061
    -- 08/02/19 15:10:10.059 icegridregistry: Network: trying to accept tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46652
    -- 08/02/19 15:10:10.059 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46652
    -- 08/02/19 15:10:10.059 IceStorm-IceStorm: Network: established tcp connection
       local address = 127.0.0.1:46652
       remote address = 127.0.0.1:4061
    -- 08/02/19 15:10:10.059 IceStorm-IceStorm: Network: trying to establish tcp connection to 172.17.0.2:34841
    -- 08/02/19 15:10:10.060 icegridregistry: Network: trying to accept tcp connection
       local address = ::ffff:172.17.0.2:34841
       remote address = ::ffff:172.17.0.2:53542
    -- 08/02/19 15:10:10.060 IceStorm-IceStorm: Network: established tcp connection
       local address = 172.17.0.2:53542
       remote address = 172.17.0.2:34841-- 08/02/19 15:10:10.060 icegridregistry: Network: accepted tcp connection
       local address = ::ffff:172.17.0.2:34841
       remote address = ::ffff:172.17.0.2:53542
    
    -- 08/02/19 15:10:10.060 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' activated: dummy -t -e 1.1:tcp -h 172.17.0.2 -p 34547 -t 60000
    -- 08/02/19 15:10:10.060 IceStorm-IceStorm: Network: accepting tcp connections at :::34547
    -- 08/02/19 15:10:10.061 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' activated: dummy -t -e 1.1:tcp -h 172.17.0.2 -p 43465 -t 60000
    -- 08/02/19 15:10:10.061 IceStorm-IceStorm: Network: accepting tcp connections at :::43465
    -- 08/02/19 15:10:10.062 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    -- 08/02/19 15:10:10.062 IceStorm-IceStorm: Network: stopping to accept tcp connections at :::34547
    -- 08/02/19 15:10:10.062 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 15:10:10.062 IceStorm-IceStorm: Network: stopping to accept tcp connections at :::43465
    -- 08/02/19 15:10:10.063 icegridregistry: Network: closed tcp connection
       local address = ::ffff:172.17.0.2:34841
       remote address = ::ffff:172.17.0.2:53542
    -- 08/02/19 15:10:10.063 icegridregistry: Network: closed tcp connection
       local address = ::ffff:127.0.0.1:4061
       remote address = ::ffff:127.0.0.1:46652
    -- 08/02/19 15:10:10.063 IceStorm-IceStorm: Network: closed tcp connection
       local address = 172.17.0.2:53542
       remote address = 172.17.0.2:34841
    -- 08/02/19 15:10:10.063 IceStorm-IceStorm: Network: closed tcp connection
       local address = 127.0.0.1:46652
       remote address = 127.0.0.1:4061
    !! 08/02/19 15:10:10.063 IceStorm: error: ServiceManager: src/Ice/Network.cpp:2368: ::Ice::SocketException:
       socket exception: Cannot assign requested address
    -- 08/02/19 15:10:10.064 icegridnode: Activator: detected termination of server `IceStorm'
       exit code = 1
    -- 08/02/19 15:10:10.064 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.Publish' deactivated
    -- 08/02/19 15:10:10.064 icegridnode: Adapter: server `IceStorm' adapter `IceStorm.TopicManager' deactivated
    
  • xdm
    xdm La Coruña, Spain

    Can you paste or upload the configuration files used in you last attempt so that we can try with the same configuration.

  • Of course!

    I am attaching the application xml, the config files and the bash script I am using (I have added a .txt extension because I couldn't upload them otherwise).

  • xdm
    xdm La Coruña, Spain
    edited August 2019

    I tested your configuration files and worked fine in my box, I think it might be failing to bind to one of your interfaces.

    probably the Ice.Admin adapter created by IceBox, can you try adding

     <icebox id="${instance-name}" exe="icebox" activation="always">
           <option>--Ice.Trace.Network=2</option>
           <property name="Ice.Admin.Endpoints" value="tcp -h 127.0.0.1"/>
    ....
    </icebox>
    
  • Thanks José!! It worked like a charm!

    Could you briefly explain what this fix means?

  • xdm
    xdm La Coruña, Spain

    The default endpoint for Ice.Admin adapter is tcp -h localhost, if your system is properly configured for ipv6 localhost usually expands to 127.0.0.1, ::1 meaning /etc/hosts have something like:

    127.0.0.1       localhost
    # The following lines are desirable for IPv6 capable hosts
    ::1     localhost ip6-localhost ip6-loopback
    

    In this case your lo interface should have both ipv4 and ipv6 addresses

    ip addr show
    1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
        link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
        inet 127.0.0.1/8 scope host lo
           valid_lft forever preferred_lft forever
        inet6 ::1/128 scope host 
           valid_lft forever preferred_lft forever
    

    I assume that your Ubuntu machine has a missconfigured ipv6 for localhost and as result the bind of tcp -h localhost was failing, it will be good to fix the ipv6 configuration and use the default endpoint.

    We have a issue open in github to improve the SocketException to help debugging this issues, see https://github.com/zeroc-ice/ice/issues/389

    Then regarding your configuration a few things that you can cleanup:

    IceGrid.Registry.DynamicRegistration=1 This doesn't seems useful in your case as your servers are not using dynamic registration, you are defining them in the xml descriptor.

    Ice.MessageSizeMax=10000000 You shouldn't need that for the registry configuration as it doesn't send large requests

    IceGrid.Node.CollocateRegistry This is mean to run the registry in the same process than the node, as you are running them as separate process doesn't make sense to set this.

    <dbenv name="${service}"/> This is not required for IceStorm, it doesn't use Freeze anymore.

    Cheers,
    José