search

signalwire / freeswitch

FreeSWITCH is a Software Defined Telecom Stack enabling the digital transformation from proprietary telecom switches to a versatile software implementation that runs on any commodity hardware. From a Raspberry PI to a multi-core server, FreeSWITCH can unlock the telecommunications potential of any device.
https://freeswitch.com/#getting-started
Other
3.65k stars 1.44k forks source link

Freeswitch mod_amqp does not send heartbeats ignoring configuration settings #59

Open jpVm5jYYRE1VIKL opened 5 years ago

jpVm5jYYRE1VIKL commented 5 years ago

Freeswitch module amqp not send heartbeat messages to rabbitmqserver for logging and producers.

amqp.conf

<configuration name="amqp.conf" description="mod_amqp">
  <producers>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_events"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="1"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="OutboundCallFsEvents"/>
        <param name="exchange-type" value="topic"/>
        <param name="circuit_breaker_ms" value="10000"/>
        <param name="reconnect_interval_ms" value="1000"/>
        <param name="send_queue_size" value="5000"/>
        <param name="enable_fallback_format_fields" value="1"/>
        <param name="format_fields" value="#FS,#OUTBOUNDGW22,Event-Name"/>
      </params>
    </profile>
  </producers>
  <commands>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_commands"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="1"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="Commands"/>
        <param name="binding_key" value="commandBindingKey"/>
        <param name="reconnect_interval_ms" value="2000"/>
      </params>
    </profile>
  </commands>
  <logging>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_logs"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="1"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="Logging"/>
        <param name="reconnect_interval_ms" value="2000"/>
        <param name="send_queue_size" value="5000"/>
        <param name="log-levels" value="warning,err,crit,alert"/>
      </params>
    </profile>
  </logging>
</configuration>

And logs from rabbitmq

2019-10-15 12:57:08.457 [info] <0.19046.0> connection <0.19046.0> (2.2.2.2:51114 -> 2.2.2.2:5672): user 'freesw_events' authenticated and granted access to vhost '/'
2019-10-15 12:57:08.460 [info] <0.19049.0> connection <0.19049.0> (2.2.2.2:51116 -> 2.2.2.2:5672): user 'freesw_logs' authenticated and granted access to vhost '/'
2019-10-15 12:57:11.459 [error] <0.19046.0> closing AMQP connection <0.19046.0> (2.2.2.2:51114 -> 2.2.2.2:5672):
missed heartbeats from client, timeout: 1s
2019-10-15 12:57:13.462 [error] <0.19049.0> closing AMQP connection <0.19049.0> (2.2.2.2:51116 -> 2.2.2.2:5672):
missed heartbeats from client, timeout: 1s

~~Sub issue 1: Freeswitch does not reconnect to producers in case if <param name="heartbeat" value="0"/> and connection to message broker temporary lost untill manual reload mod_amqp~~ Cannot recreate anymore. Did it easy before . Need some more investigations. Most probably non direct parameters sensitive Sub issue 2: Freeswitch does not reconnect to message broker if <param name="heartbeat" value="0"/> and message broker was not available yet during freeswitch bootup. After message broker ready only commands connection alive.

Update:

Log example for sub issue 2:

2019-10-17 09:45:06.695426 [DEBUG] mod_amqp_connection.c:119 Profile[default] trying to connect to AMQP broker 2.2.2.2:5672
2019-10-17 09:45:06.695546 [WARNING] mod_amqp_connection.c:123 Could not open socket connection to AMQP broker 2.2.2.2:5672 status(-9) a socket error occurred
2019-10-17 09:45:06.695557 [CRIT] mod_amqp_connection.c:132 Profile[default] could not connect to any AMQP brokers
2019-10-17 09:45:06.695579 [ERR] mod_amqp_producer.c:330 Profile[default] was unable to connect to any connection
2019-10-17 09:45:06.695585 [NOTICE] mod_amqp_producer.c:130 Profile[default] shutting down...
2019-10-17 09:45:06.695588 [NOTICE] mod_amqp_producer.c:140 Profile[default] closing AMQP socket...
2019-10-17 09:45:06.695592 [ERR] mod_amqp_utils.c:136 Failed to load mod_amqp profile [default]. Check configs
2019-10-17 09:45:06.695743 [DEBUG] mod_amqp_utils.c:162 Loaded mod_amqp profile [default] successfully
2019-10-17 09:45:06.695810 [DEBUG] mod_amqp_connection.c:119 Profile[default] trying to connect to AMQP broker 2.2.2.2:5672
2019-10-17 09:45:06.695893 [WARNING] mod_amqp_connection.c:123 Could not open socket connection to AMQP broker 2.2.2.2:5672 status(-9) a socket error occurred
2019-10-17 09:45:06.695901 [CRIT] mod_amqp_connection.c:132 Profile[default] could not connect to any AMQP brokers
2019-10-17 09:45:06.695926 [ERR] mod_amqp_logging.c:243 Profile[default] was unable to connect to any connection
2019-10-17 09:45:06.695931 [NOTICE] mod_amqp_logging.c:124 Profile[default] shutting down...
2019-10-17 09:45:06.695934 [NOTICE] mod_amqp_logging.c:134 Profile[default] closing AMQP socket...
2019-10-17 09:45:06.695938 [ERR] mod_amqp_utils.c:184 Failed to load mod_amqp profile [default]. Check configs
2019-10-17 09:45:06.695966 [NOTICE] switch_loadable_module.c:412 Adding API Function 'amqp'
2019-10-17 09:45:06.696432 [WARNING] mod_amqp_command.c:272 Amqp no connection- reconnecting...
2019-10-17 09:45:06.696500 [DEBUG] mod_amqp_connection.c:119 Profile[default] trying to connect to AMQP broker 2.2.2.2:5672
2019-10-17 09:45:06.696593 [WARNING] mod_amqp_connection.c:123 Could not open socket connection to AMQP broker 2.2.2.2:5672 status(-9) a socket error occurred
2019-10-17 09:45:06.696601 [CRIT] mod_amqp_connection.c:132 Profile[default] could not connect to any AMQP brokers
2019-10-17 09:45:06.696606 [WARNING] mod_amqp_command.c:276 Profile[default] failed to connect with code(9), sleeping for 2000ms

Configuration for sub issue 2:

<configuration name="amqp.conf" description="mod_amqp">
  <producers>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_events"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="0"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="OutboundCallFsEvents"/>
        <param name="exchange-type" value="topic"/>
        <param name="circuit_breaker_ms" value="10000"/>
        <param name="reconnect_interval_ms" value="1000"/>
        <param name="send_queue_size" value="5000"/>
        <param name="enable_fallback_format_fields" value="1"/>

        <param name="format_fields" value="#FS,#OUTBOUNDGW22,Event-Name"/>
      </params>
    </profile>
  </producers>
  <commands>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_commands"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="0"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="Commands"/>
        <param name="binding_key" value="commandBindingKey"/>
        <param name="reconnect_interval_ms" value="2000"/>
      </params>
    </profile>
  </commands>
  <logging>
    <profile name="default">
      <connections>
        <connection name="primary">
          <param name="hostname" value="2.2.2.2"/>
          <param name="virtualhost" value="/"/>
          <param name="username" value="freesw_logs"/>
          <param name="password" value="password"/>
          <param name="port" value="5672"/>
          <param name="heartbeat" value="0"/>
        </connection>
      </connections>
      <params>
        <param name="exchange-name" value="Logging"/>
        <param name="reconnect_interval_ms" value="2000"/>
        <param name="binding_key" value="*"/>
        <param name="send_queue_size" value="5000"/>
        <param name="log-levels" value="warning,err,crit,alert"/>
      </params>
    </profile>
  </logging>
</configuration>
cdosoftei commented 5 years ago

The core of the issue should be addressed by #61

The reconnect aspect to be handled by a subsequent PR

jpVm5jYYRE1VIKL commented 5 years ago

Added some extra logs, For sub issue 2. And bit updated sub issue 1.

cdosoftei commented 5 years ago

Can you share your amqp.conf file? Feel free to redact out host identifiers and credentials.

jpVm5jYYRE1VIKL commented 5 years ago

Thanks for your help. I added extra config for sub issue 2.

PS: And it look like that i found one more issue with aqmp module but most probably i need to open extra issue in tracker in brief : it is about parameter "binding_key" look like it works only for commands and does not work for producers and logging . And basically usage of parameter "binding_key" require review because exist parameter with binding but not exist parameter for target queue to bind. In case of commands it is just binds to random generated queue.

cdosoftei commented 5 years ago

I was able to recreate the reconnect issue and fixed it via #64

For the binding_key issue, let's open a separate issue to keep the scope well defined.

crienzo commented 5 years ago

Is this issue all set now?

jpVm5jYYRE1VIKL commented 4 years ago

In version FreeSWITCH Version 1.10.1-release-12-f9990221e6~64bit (-release-12-f9990221e6 64bit) issue still not solved. Freeswitch still don`t send heartbeat even if it is configured. Sub issue 2 also still not solved.

cdosoftei commented 4 years ago

Please test with the latest master; the 1.10.1 release predates the amqp improvements:

https://github.com/signalwire/freeswitch/compare/f9990221e6...master

On Wed, 4 Dec 2019 at 03:52, jpVm5jYYRE1VIKL notifications@github.com wrote:

In version FreeSWITCH Version 1.10.1-release-12-f9990221e6~64bit (-release-12-f9990221e6 64bit) issue still not solved

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalwire/freeswitch/issues/59?email_source=notifications&email_token=AB2II64ENDF2HMVR3OA7WS3QW5VVZA5CNFSM4JA2ZZB2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEF4GWWQ#issuecomment-561539930, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB2II6ZO7XRTNW5MXU24B3DQW5VVZANCNFSM4JA2ZZBQ .

-- Best Regards, Ciprian Dosoftei

The information transmitted is intended only for the addressee and may contain privileged and/or confidential material. If you are not the intended recipient, kindly contact the sender and delete the message.

Any disclosure, distribution or copying of this message is strictly prohibited without the expressed permission of the sender.

jpVm5jYYRE1VIKL commented 4 years ago

I can confirm that sub issue 2 fixed. In same time heartbeats still works only for command node and does not work for producers and logging.

jpVm5jYYRE1VIKL commented 4 years ago

up. In FreeSWITCH Version 1.10.3-release-15-129de34d84~64bit (-release-15-129de34d84 64bit) issue still not fixed. FS still dont send heart beat messages to rabbitmq

cdosoftei commented 4 years ago

The heartbeat issue lies in the upstream, specifically the way heartbeats are implemented in the C RabbitMQ API:

[ in ] heartbeat - the number of seconds between heartbeat frame to request of the broker. A value of 0 disables heartbeats. Note rabbitmq-c only has partial support for hearts, as of v0.4.0 heartbeats are only serviced during amqp_basic_publish(), and amqp_simple_wait_frame()/amqp_simple_wait_frame_noblock()

The appearance of heartbeats functioning properly for commands but not for producers nor for logging is a direct consequence of the above, the design of the former employs amqp_simple_wait_frame_noblock in its thread loop (indirectly, via amqp_consume_message), whereas if the later have pending payloads to publish, no heartbeats are emitted either.

One could force out heartbeats by publishing timed dummy payloads (matching the desired heartbeat interval from the configuration) though it's not elegant solution. Advice from a core maintainer would be greatly appreciated.

jpVm5jYYRE1VIKL commented 4 years ago

Do you tell about creation of random generated queue same way as for command and bind to it and periodically publish messages to exchange and catch it in queue ?

cdosoftei commented 4 years ago

I was thinking of using the existing routing key configuration for both components; the dummy messages would have to be clearly tagged as hearbeat/keep-alive so consuming applications won't be thrown off by them.

genmzy commented 3 years ago

Any process here?