Bug #1488

Socket transport between cpp and cl mostly fails on mac

Added by J. Wienke over 8 years ago. Updated about 8 years ago.

Status:ResolvedStart date:05/07/2013
Priority:NormalDue date:
Assignee:J. Moringen% Done:

100%

Category:Socket Transport
Target version:rsb-0.10

Description

I am not sure whether this is a bug of the cl rsb implementation of of the logger, but I observer the following difference in behavior:

I have the following setup using the socket transport:
  1. One logger just to provide the bus server for the socket transport
  2. A bag-play process for replay
  3. The cpp timesync application to synchronize some of the replayed scopes

Most of the time the timesync component does not receive any events, even though it correctly identified the existing bus server.

languitar@miles:~/work/src/rsb-tools-cpp/build-master/src/timesync$ ./timesync --strategy timeframe --primscope /monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/ --supscope /my --outscope /sync/vfoa
1367919298693 rsb.factory [INFO]: Registering default implementations
1367919298693 rsb.converter.repository [INFO]: Registering converter *rsb::converter::BoolConverter[wireType = std::string, wireSchema = bool, dataType = bool] at 0x7f9051d018d0
1367919298693 rsb.converter.repository [INFO]: Registering converter *rsb::converter::ByteArrayConverter[wireType = std::string, wireSchema = .*, dataType = bytearray] at 0x7f9051d01770
1367919298693 rsb.converter.repository [INFO]: Registering converter *EventIdConverter[wireType = std::string, wireSchema = .rsb.protocol.EventId, dataType = rsb::EventId] at 0x7f9051d01d80
1367919298693 rsb.converter.repository [INFO]: Registering converter *rsb::converter::StringConverter[wireType = std::string, wireSchema = utf-8-string, dataType = std::string] at 0x7f9051d01f40
1367919298693 rsb.converter.repository [INFO]: Registering converter *rsb::converter::Uint64Converter[wireType = std::string, wireSchema = uint64, dataType = unsigned long long] at 0x7f9051d02360
1367919298694 rsb.converter.repository [INFO]: Registering converter *rsb::converter::VoidConverter[wireType = std::string, wireSchema = void, dataType = void] at 0x7f9051d023b0
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpushconnector> [INFO]: Registering connector inprocess for schemas {inprocess}
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpushconnector> [INFO]: Registering connector spread for schemas {spread}
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpushconnector> [INFO]: Registering connector socket for schemas {socket}
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpullconnector> [INFO]: Registering connector inprocess for schemas {inprocess}
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpullconnector> [INFO]: Registering connector spread for schemas {spread}
1367919298694 rsb.transport.connectorfactory<rsb::transport::inpullconnector> [INFO]: Registering connector socket for schemas {socket}
1367919298694 rsb.transport.connectorfactory<rsb::transport::outconnector> [INFO]: Registering connector inprocess for schemas {inprocess}
1367919298694 rsb.transport.connectorfactory<rsb::transport::outconnector> [INFO]: Registering connector spread for schemas {spread}
1367919298694 rsb.transport.connectorfactory<rsb::transport::outconnector> [INFO]: Registering connector socket for schemas {socket}
1367919298694 rsb.factory [INFO]: Processing plugin configuration
1367919298694 rsc.config.configfilesource [TRACE]: Option #(transport, spread, enabled) -> 0
1367919298694 rsc.config.configfilesource [TRACE]: Option #(transport, inprocess, enabled) -> 0
1367919298694 rsc.config.configfilesource [TRACE]: Option #(transport, socket, enabled) -> 1
1367919298694 rsc.config.configfilesource [TRACE]: Option #(rsc, logging, LEVEL) -> ALL
1367919298694 rsc.plugins.configurator [DEBUG]: Processing option #(rsc, logging, LEVEL) = `ALL'
1367919298694 rsc.plugins.configurator [DEBUG]: Processing option #(transport, inprocess, enabled) = `0'
1367919298694 rsc.plugins.configurator [DEBUG]: Processing option #(transport, socket, enabled) = `1'
1367919298694 rsc.plugins.configurator [DEBUG]: Processing option #(transport, spread, enabled) = `0'
1367919298694 rsc.plugins.configurator [INFO]: No searchpath configured; using default: #("/Users/languitar/.rsb0.9/plugins", "/usr/local/lib/rsb0.9/plugins")
1367919298694 rsc.plugins.manager [INFO]: Adding path "/Users/languitar/.rsb0.9/plugins" 
1367919298694 rsc.plugins.manager [INFO]: Ignoring non-existent path `"/Users/languitar/.rsb0.9/plugins"'
1367919298694 rsc.plugins.manager [INFO]: Adding path "/usr/local/lib/rsb0.9/plugins" 
1367919298694 rsc.plugins.manager [INFO]: Ignoring non-existent path `"/usr/local/lib/rsb0.9/plugins"'
1367919298694 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298694 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298694 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298694 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsc.config.configfilesource [TRACE]: Option #(transport, spread, enabled) -> 0
1367919298695 rsc.config.configfilesource [TRACE]: Option #(transport, inprocess, enabled) -> 0
1367919298695 rsc.config.configfilesource [TRACE]: Option #(transport, socket, enabled) -> 1
1367919298695 rsc.config.configfilesource [TRACE]: Option #(rsc, logging, LEVEL) -> ALL
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.factory [DEBUG]: Default config rsb::ParticipantConfig[qosSpec = QualityOfServiceSpec[ordering = 10, reliability = 20], errorStrategy = 0, transports = {Transport[name = socket, converters = {}, options = p{ enabled: "1" }], Transport[name = spread, converters = {}, options = p{ enabled: "0" }], Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]}, eventReceivingStrategy = rsb::ParticipantConfig::EventProcessingStrategy[name = parallel, options = p{  }], eventSendingStrategy = rsb::ParticipantConfig::EventProcessingStrategy[name = direct, options = p{  }], options = p{  }]]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298695 rsb.factory [DEBUG]: Trying to add connector Transport[name = socket, converters = {}, options = p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }]
1367919298695 rsb.factory [DEBUG]: Supplied connector options p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298695 rsb.transport.socket.outconnector [DEBUG]: Creating OutConnector with properties p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298695 rsb.eventprocessing.outrouteconfigurator [DEBUG]: Adding connector *rsb::transport::socket::OutConnector[] at 0x7f9051d06790
1367919298695 rsb.eventprocessing.outrouteconfigurator [DEBUG]: Activating
1367919298695 rsb.transport.socket.connectorbase [DEBUG]: Activating
1367919298695 rsb.transport.socket.connectorbase [INFO]: Server mode: auto
1367919298695 rsb.transport.socket.factory [INFO]: Started service thread
1367919298695 rsb.transport.socket.factory [DEBUG]: Was asked for a bus server for localhost:55555
1367919298695 rsb.transport.socket.factory [DEBUG]: Did not find bus server; creating a new one
1367919298695 rsb.transport.socket.busserver [INFO]: Listening on 0.0.0.0:55555
1367919298696 rsb.transport.socket.bus [DEBUG]: Adding connector 0x7f9051d06700
1367919298696 rsb.transport.socket.factory [DEBUG]: Created new bus client *rsb::transport::socket::BusServer[connections = [], sinks = {}] at 0x7f9051d07920
1367919298696 rsb.transport.socket.connectorbase [DEBUG]: Using bus *rsb::transport::socket::BusServer[connections = [], sinks = {}] at 0x7f9051d07920
1367919298696 rsb.eventprocessing.outrouteconfigurator [DEBUG]: Adding connector *rsb::transport::socket::OutConnector[] at 0x7f9051d06790 to strategy *rsb::eventprocessing::DirectEventSendingStrategy[connectors = []] at 0x7f9051d08460
1367919298696 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298696 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298696 rsb.factory [DEBUG]: Trying to add connector Transport[name = socket, converters = {}, options = p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }]
1367919298696 rsb.factory [DEBUG]: Supplied connector options p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298696 rsb.transport.socket.inpushconnector [DEBUG]: Creating InPushConnector with properties p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298696 rsb.eventprocessing.inrouteconfigurator [DEBUG]: Adding connector *rsb::transport::socket::InPushConnector[scope = Scope[/]] at 0x7f9051d08b18
1367919298696 rsb.eventprocessing.inrouteconfigurator [DEBUG]: Activating
1367919298696 rsb.transport.socket.connectorbase [DEBUG]: Activating
1367919298696 rsb.transport.socket.connectorbase [INFO]: Server mode: auto
1367919298696 rsb.transport.socket.factory [DEBUG]: Was asked for a bus server for localhost:55555
1367919298696 rsb.transport.socket.factory [DEBUG]: Found existing bus server *rsb::transport::socket::BusServer[connections = [], sinks = {}] at 0x7f9051d07920
1367919298696 rsb.transport.socket.bus [DEBUG]: Adding connector 0x7f9051d08b30
1367919298696 rsb.transport.socket.connectorbase [DEBUG]: Using bus *rsb::transport::socket::BusServer[connections = [], sinks = {}] at 0x7f9051d07920
1367919298696 rsb.transport.socket.inconnector [DEBUG]: Activating
1367919298696 rsb.transport.socket.bus [DEBUG]: Adding sink *rsb::transport::socket::InPushConnector[scope = Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]] at 0x7f9051d08b18 to scope Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]
1367919298696 rsb.eventprocessing.pushinrouteconfigurator [DEBUG]: Instantiating event receiving strategy with config rsb::ParticipantConfig::EventProcessingStrategy[name = parallel, options = p{  }]
1367919298696 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = inprocess, converters = {}, options = p{ enabled: "0" }]
1367919298696 rsb.participantconfig [DEBUG]: Skipping disabled transport Transport[name = spread, converters = {}, options = p{ enabled: "0" }]
1367919298696 rsb.factory [DEBUG]: Trying to add connector Transport[name = socket, converters = {}, options = p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }]
1367919298696 rsb.factory [DEBUG]: Supplied connector options p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298696 rsb.transport.socket.inpushconnector [DEBUG]: Creating InPushConnector with properties p{ converters: <boost::shared_ptr<rsb::converter::ConverterSelectionStrategy<std::string> >>, enabled: "1" }
1367919298697 rsb.eventprocessing.inrouteconfigurator [DEBUG]: Adding connector *rsb::transport::socket::InPushConnector[scope = Scope[/]] at 0x7f9051d0bc08
1367919298697 rsb.eventprocessing.inrouteconfigurator [DEBUG]: Activating
1367919298697 rsb.transport.socket.connectorbase [DEBUG]: Activating
1367919298697 rsb.transport.socket.connectorbase [INFO]: Server mode: auto
1367919298697 rsb.transport.socket.factory [DEBUG]: Was asked for a bus server for localhost:55555
1367919298697 rsb.transport.socket.factory [DEBUG]: Found existing bus server *rsb::transport::socket::BusServer[connections = [], sinks = {Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]: [*rsb::transport::socket::InPushConnector[scope = Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]] at 0x7f9051d08b18]}] at 0x7f9051d07920
1367919298697 rsb.transport.socket.bus [DEBUG]: Adding connector 0x7f9051d0bc20
1367919298697 rsb.transport.socket.connectorbase [DEBUG]: Using bus *rsb::transport::socket::BusServer[connections = [], sinks = {Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]: [*rsb::transport::socket::InPushConnector[scope = Scope[/monitoring/augit/volhumavipsreleasesy3demobinrsbvfoacomponent/]] at 0x7f9051d08b18]}] at 0x7f9051d07920
1367919298697 rsb.transport.socket.inconnector [DEBUG]: Activating
1367919298697 rsb.transport.socket.bus [DEBUG]: Adding sink *rsb::transport::socket::InPushConnector[scope = Scope[/my/]] at 0x7f9051d0bc08 to scope Scope[/my/]
1367919298697 rsb.eventprocessing.pushinrouteconfigurator [DEBUG]: Instantiating event receiving strategy with config rsb::ParticipantConfig::EventProcessingStrategy[name = parallel, options = p{  }]

I have no idea why, but sometime without any pattern I could find, relaunching all processes over and over again resulted in a working connection. But this happens rarely.

My python client program works without any problems with the socket transport.


Related issues

Related to Robotics Service Bus - Enhancement #1054: "auto" server mode is inefficient New 07/02/2012
Related to Robotics Service Bus - Enhancement #1550: "Auto" mode of the socket transport should be smarter New 06/25/2013

Associated revisions

Revision 39ef934b
Added by J. Moringen about 8 years ago

Listen on all interfaces in src/transport/socket/bus-server.lisp

fixes #1488

The other implementations already do this and it sometimes avoids
problems with local bus clients.

  • src/transport/socket/bus-server.lisp (header): updated copyright
    (ensure-bus-server): listen on the "all interfaces" address
    independently of the specified host

Revision abeb2c8a
Added by J. Moringen about 8 years ago

Backport: Listen on all interfaces in src/transport/socket/bus-server.lisp

refs #1488

The other implementations already do this and it sometimes avoids
problems with local bus clients.

  • src/transport/socket/bus-server.lisp (header): updated copyright
    (ensure-bus-server): listen on the "all interfaces" address
    independently of the specified host

History

#1 Updated by J. Wienke over 8 years ago

I have started the logger process with log-level on trace. There is no output when the timesync should connect. If I connect any other cl or python client I see output. So I suspect that this is an issue with the C++ implementation of the transport.

#2 Updated by J. Wienke over 8 years ago

The problem is that the cl logger listens on 127.0.0.1:55555 but cpp first tries to create a server on 0.0.0.0:55555, which succeeds, so no client is created anymore.

#3 Updated by J. Moringen about 8 years ago

  • Target version changed from rsb-0.9 to rsb-0.10

#4 Updated by J. Moringen about 8 years ago

  • Status changed from New to Resolved
  • % Done changed from 0 to 100

Applied in changeset rsb-cl|commit:39ef934b6e4678cf39c0f1be9ccb18e8b042d45a.

Also available in: Atom PDF