syslog configuration, rabbitmq 3.7.10

108 views
Skip to first unread message

Kevin Freeman

unread,
Jan 24, 2019, 1:46:20 PM1/24/19
to rabbitmq-users
We are unable to successfully configure syslog to a remote host via udp or tcp, this is our first attempt at logging to syslog via rabbitmq.  We have not enabled HiPE for this broker.  This node is in a cluster and is the only node configured for syslog thus far.  Any obvious mistakes?  Error messages, software versions and configs below.

When configuring syslog over tcp, the rabbitmq service fails to start.  tcpdump did not capture any traffic on port 1514.
When we configure for udp, rabbitmq does start and does not log any errors, but tcpdump does not show any activity on port 514 even though the local log file does contain entries.

CentOS Linux release 7.6.1810 (Core), up-to-date
rabbitmq-server-3.7.10-1.el6.noarch
erlang-21.2.2-1.el7.centos.x86_64

No HiPE:
$ sudo rabbitmqctl eval 'rabbit_amqqueue:module_info(native).'
false

#
# TCP
#

Test successfully sent via tcp to remote syslog server, verified via local tcpdump ($ sudo tcpdump -vv -Xni eth0 port 1514)
$ logger -n [remote syslog server] -P 1514 "Test Message - tcp" --tcp

TCP syslog config:
$ cat /etc/rabbitmq/rabbitmq.conf
log.file.level = debug
log.syslog = true
log.syslog.level = debug
log.syslog.ip = [remote syslog server]
log.syslog.transport = tcp
log.syslog.port = 1514
log.syslog.protocol = rfc5424

$ sudo systemctl restart rabbitmq-server
Job for rabbitmq-server.service failed because the control process exited with error code. See "systemctl status rabbitmq-server.service" and "journalctl -xe" for details.

rabbit.log:
2019-01-24 17:56:59.392 [error] <0.154.0> Lager event handler syslog_lager_backend exited with reason {'EXIT',{killed,{gen_server,call,[syslog_logger,{log,<<"<30>1 2019-01-24T17:56:59.389064Z PRE-VM1 rabbit 49945 <0.7657.0> -     xmerl">>},10$
2019-01-24 17:56:59.392 [error] <0.146.0> ** gen_event handler syslog_lager_backend crashed.
** Was installed in lager_event
** Last event was: {log,{lager_msg,[],[{module,rabbit},{function,stop_and_halt},{line,501},{pid,"<0.7657.0>"},{node,'rabbit@PRE-VM1'}],info,{["2019",45,"01",45,"24"],["17",58,"56",58,"59",46,"389"]},{1548,352619,389064},[72,97,108,116,105,110$
** When handler state == {state,{mask,255},lager_default_formatter,[color,"[",severity,"] ",{pid,[]}," ",message,"\n"],undefined,[],false}
** Reason == {killed,{gen_server,call,[syslog_logger,{log,<<"<30>1 2019-01-24T17:56:59.389064Z PRE-VM1 rabbit 49945 <0.7657.0> -     xmerl">>},1000]}}
2019-01-24 17:57:09.446 [debug] <0.156.0> Lager installed handler syslog_lager_backend into lager_event
2019-01-24 17:57:09.446 [debug] <0.160.0> Lager installed handler error_logger_lager_h into error_logger
2019-01-24 17:57:09.449 [debug] <0.163.0> Lager installed handler lager_forwarder_backend into error_logger_lager_event
2019-01-24 17:57:09.450 [debug] <0.166.0> Lager installed handler lager_forwarder_backend into rabbit_log_lager_event
2019-01-24 17:57:09.451 [debug] <0.175.0> Lager installed handler lager_forwarder_backend into rabbit_log_mirroring_lager_event
2019-01-24 17:57:09.451 [debug] <0.178.0> Lager installed handler lager_forwarder_backend into rabbit_log_queue_lager_event
2019-01-24 17:57:09.451 [debug] <0.181.0> Lager installed handler lager_forwarder_backend into rabbit_log_federation_lager_event
2019-01-24 17:57:09.450 [debug] <0.169.0> Lager installed handler lager_forwarder_backend into rabbit_log_channel_lager_event
2019-01-24 17:57:09.450 [debug] <0.172.0> Lager installed handler lager_forwarder_backend into rabbit_log_connection_lager_event
2019-01-24 17:57:09.451 [debug] <0.184.0> Lager installed handler syslog_lager_backend into rabbit_log_upgrade_lager_event
2019-01-24 17:57:09.452 [debug] <0.186.0> Lager installed handler {lager_file_backend,
                            "/var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log"} into rabbit_log_upgrade_lager_event
2019-01-24 17:57:09.926 [debug] <0.151.0> Lager installed handler lager_backend_throttle into lager_event
2019-01-24 17:57:11.354 [info] <0.43.0> Application mnesia exited with reason: stopped
2019-01-24 17:57:12.382 [error] <0.321.0> CRASH REPORT Process <0.321.0> with 0 neighbours exited with reason: bad argument in gen_tcp:connect/4 line 167
2019-01-24 17:57:12.383 [error] <0.320.0> Supervisor {<0.320.0>,syslog} had child syslog_logger started with syslog_logger:start_link() at undefined exit with reason badarg in context start_error
2019-01-24 17:57:12.384 [error] <0.318.0> CRASH REPORT Process <0.318.0> with 0 neighbours exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}} in application_master:init/4 line 138
2019-01-24 17:57:12.385 [info] <0.43.0> Application syslog exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}}
2019-01-24 17:57:12.387 [info] <0.43.0> Application prometheus_cowboy exited with reason: stopped
2019-01-24 17:57:12.389 [info] <0.43.0> Application prometheus_httpd exited with reason: stopped
2019-01-24 17:57:12.391 [info] <0.43.0> Application inets exited with reason: stopped
2019-01-24 17:57:12.426 [info] <0.43.0> Application mnesia exited with reason: stopped
2019-01-24 17:57:12.427 [info] <0.43.0> Application cowlib exited with reason: stopped
2019-01-24 17:57:12.427 [info] <0.43.0> Application crypto exited with reason: stopped
2019-01-24 17:57:12.427 [info] <0.43.0> Application accept exited with reason: stopped
2019-01-24 17:57:12.427 [info] <0.43.0> Application xmerl exited with reason: stopped
2019-01-24 17:57:12.427 [info] <0.43.0> Application recon exited with reason: stopped
2019-01-24 17:57:12.429 [info] <0.43.0> Application prometheus exited with reason: stopped
2019-01-24 17:57:12.429 [info] <0.43.0> Application jsx exited with reason: stopped
2019-01-24 17:57:12.430 [error] <0.8.0>
Error description:
    init:do_boot/3
    init:start_em/1
    rabbit:start_it/1 line 461
    rabbit:broker_start/0 line 337
    rabbit:start_apps/2 line 556
    app_utils:manage_applications/6 line 126
    lists:foldl/3 line 1263
    rabbit:'-handle_app_error/1-fun-0-'/3 line 652
throw:{could_not_start,syslog,
          {syslog,
              {{shutdown,{failed_to_start_child,syslog_logger,badarg}},
               {syslog,start,[normal,[]]}}}}
Log file(s) (may contain more information):
   /var/log/rabbitmq/rab...@PRE-VM1.log
   /var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log

$ sudo systemctl status rabbitmq-server.service
● rabbitmq-server.service - LSB: Enable AMQP service provided by RabbitMQ broker
   Loaded: loaded (/etc/rc.d/init.d/rabbitmq-server; bad; vendor preset: disabled)
   Active: failed (Result: exit-code) since Thu 2019-01-24 17:57:13 UTC; 28s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 55718 ExecStop=/etc/rc.d/init.d/rabbitmq-server stop (code=exited, status=0/SUCCESS)
  Process: 66074 ExecReload=/etc/rc.d/init.d/rabbitmq-server reload (code=exited, status=1/FAILURE)
  Process: 56135 ExecStart=/etc/rc.d/init.d/rabbitmq-server start (code=exited, status=1/FAILURE)
   CGroup: /system.slice/rabbitmq-server.service
           └─2389 /usr/lib64/erlang/erts-10.2.1/bin/epmd -daemon

Jan 24 17:57:04 PRE-VM1 runuser[56380]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 24 17:57:04 PRE-VM1 runuser[56386]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 24 17:57:13 PRE-VM1 runuser[56380]: pam_unix(runuser:session): session closed for user rabbitmq
Jan 24 17:57:13 PRE-VM1 rabbitmq-server[56135]: Starting rabbitmq-server: FAILED - check /var/log/rabbitmq/startup_{log, _err}
Jan 24 17:57:13 PRE-VM1 systemd[1]: rabbitmq-server.service: control process exited, code=exited status=1
Jan 24 17:57:13 PRE-VM1 rabbitmq-server[56135]: rabbitmq-server.
Jan 24 17:57:13 PRE-VM1 systemd[1]: Failed to start LSB: Enable AMQP service provided by RabbitMQ broker.
Jan 24 17:57:13 PRE-VM1 systemd[1]: Unit rabbitmq-server.service entered failed state.
Jan 24 17:57:13 PRE-VM1 systemd[1]: rabbitmq-server.service failed.
Jan 24 17:57:13 PRE-VM1 runuser[56386]: pam_unix(runuser:session): session closed for user rabbitmq

$ sudo journalctl -xe
Jan 24 17:57:03 PRE-VM1 systemd[1]: Starting LSB: Enable AMQP service provided by RabbitMQ broker...
-- Subject: Unit rabbitmq-server.service has begun start-up
-- Defined-By: systemd
-- 
-- Unit rabbitmq-server.service has begun starting up.
Jan 24 17:57:03 PRE-VM1 audispd[11846]: node=PRE-VM1 type=CRED_ACQ msg=audit(1548352623.643:6326): pid=56219 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:setcred grantors=pam_rootok acct="rabbitmq
Jan 24 17:57:03 PRE-VM1 runuser[56219]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 24 17:57:03 PRE-VM1 audispd[11846]: node=PRE-VM1 type=USER_START msg=audit(1548352623.644:6327): pid=56219 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_li
Jan 24 17:57:04 PRE-VM1 runuser[56219]: pam_unix(runuser:session): session closed for user rabbitmq
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=USER_END msg=audit(1548352624.519:6328): pid=56219 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:session_close grantors=pam_keyinit,pam_lim
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=CRED_DISP msg=audit(1548352624.519:6329): pid=56219 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:setcred grantors=pam_rootok acct="rabbitm
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=CRED_ACQ msg=audit(1548352624.543:6330): pid=56380 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:setcred grantors=pam_rootok acct="rabbitmq
Jan 24 17:57:04 PRE-VM1 runuser[56380]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=USER_START msg=audit(1548352624.543:6331): pid=56380 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_li
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=CRED_ACQ msg=audit(1548352624.548:6332): pid=56386 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:setcred grantors=pam_rootok acct="rabbitmq
Jan 24 17:57:04 PRE-VM1 runuser[56386]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 24 17:57:04 PRE-VM1 audispd[11846]: node=PRE-VM1 type=USER_START msg=audit(1548352624.549:6333): pid=56386 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_li
Jan 24 17:57:09 PRE-VM1 audispd[11846]: node=PRE-VM1 type=AVC msg=audit(1548352629.714:6334): avc:  denied  { unlink } for  pid=56760 comm="5_dirty_io_sche" name="cluster_nodes.config" dev="sdc1" ino=112460245 scontext=system_u:system_
Jan 24 17:57:09 PRE-VM1 audispd[11846]: node=PRE-VM1 type=SYSCALL msg=audit(1548352629.714:6334): arch=c000003e syscall=82 success=yes exit=0 a0=7f926b6048c8 a1=7f926b606200 a2=7f926b606244 a3=7f9060c915a8 items=0 ppid=56405 pid=56760 
Jan 24 17:57:09 PRE-VM1 audispd[11846]: node=PRE-VM1 type=PROCTITLE msg=audit(1548352629.714:6334): proctitle=2F7573722F6C696236342F65726C616E672F657274732D31302E322E312F62696E2F6265616D2E736D70002D570077002D4100323536002D4D42617300616
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=AVC msg=audit(1548352631.376:6335): avc:  denied  { rmdir } for  pid=56760 comm="4_dirty_io_sche" name="priv" dev="sdc1" ino=112459910 scontext=system_u:system_r:rabbitmq_t:s0 t
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=SYSCALL msg=audit(1548352631.376:6335): arch=c000003e syscall=84 success=yes exit=0 a0=7f90604e4230 a1=0 a2=7f90604e428a a3=7f9060c915a8 items=0 ppid=56405 pid=56760 auid=429496
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=PROCTITLE msg=audit(1548352631.376:6335): proctitle=2F7573722F6C696236342F65726C616E672F657274732D31302E322E312F62696E2F6265616D2E736D70002D570077002D4100323536002D4D42617300616
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=AVC msg=audit(1548352631.601:6336): avc:  denied  { create } for  pid=56760 comm="4_dirty_io_sche" name="rabbit@PRE-VM1-plugins-expand" scontext=system_u:system_r:rabbit
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=SYSCALL msg=audit(1548352631.601:6336): arch=c000003e syscall=83 success=yes exit=0 a0=7f9060a77a00 a1=1ff a2=7f9060a77a3e a3=7f90610e5760 items=0 ppid=56405 pid=56760 auid=4294
Jan 24 17:57:11 PRE-VM1 audispd[11846]: node=PRE-VM1 type=PROCTITLE msg=audit(1548352631.601:6336): proctitle=2F7573722F6C696236342F65726C616E672F657274732D31302E322E312F62696E2F6265616D2E736D70002D570077002D4100323536002D4D42617300616
Jan 24 17:57:12 PRE-VM1 audispd[11846]: node=PRE-VM1 type=AVC msg=audit(1548352632.381:6337): avc:  denied  { name_connect } for  pid=56760 comm="1_scheduler" dest=1514 scontext=system_u:system_r:rabbitmq_t:s0 tcontext=system_u:object_
Jan 24 17:57:12 PRE-VM1 audispd[11846]: node=PRE-VM1 type=SYSCALL msg=audit(1548352632.381:6337): arch=c000003e syscall=42 success=no exit=-22 a0=53 a1=7f9060444d88 a2=10 a3=0 items=0 ppid=56405 pid=56760 auid=4294967295 uid=996 gid=99
Jan 24 17:57:12 PRE-VM1 audispd[11846]: node=PRE-VM1 type=PROCTITLE msg=audit(1548352632.381:6337): proctitle=2F7573722F6C696236342F65726C616E672F657274732D31302E322E312F62696E2F6265616D2E736D70002D570077002D4100323536002D4D42617300616
Jan 24 17:57:13 PRE-VM1 runuser[56380]: pam_unix(runuser:session): session closed for user rabbitmq
Jan 24 17:57:13 PRE-VM1 audispd[11846]: node=PRE-VM1 type=USER_END msg=audit(1548352633.449:6338): pid=56380 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:session_close grantors=pam_keyinit,pam_lim
Jan 24 17:57:13 PRE-VM1 audispd[11846]: node=PRE-VM1 type=CRED_DISP msg=audit(1548352633.449:6339): pid=56380 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:initrc_t:s0 msg='op=PAM:setcred grantors=pam_rootok acct="rabbitm
Jan 24 17:57:13 PRE-VM1 rabbitmq-server[56135]: Starting rabbitmq-server: FAILED - check /var/log/rabbitmq/startup_{log, _err}
Jan 24 17:57:13 PRE-VM1 systemd[1]: rabbitmq-server.service: control process exited, code=exited status=1
Jan 24 17:57:13 PRE-VM1 rabbitmq-server[56135]: rabbitmq-server.
Jan 24 17:57:13 PRE-VM1 audispd[11846]: node=PRE-VM1 type=SERVICE_START msg=audit(1548352633.455:6340): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=rabbitmq-server comm="systemd" exe="/usr/lib/
Jan 24 17:57:13 PRE-VM1 systemd[1]: Failed to start LSB: Enable AMQP service provided by RabbitMQ broker.
-- Subject: Unit rabbitmq-server.service has failed
-- Defined-By: systemd
-- 
-- Unit rabbitmq-server.service has failed.
-- 
-- The result is failed.
Jan 24 17:57:13 PRE-VM1 systemd[1]: Unit rabbitmq-server.service entered failed state.
Jan 24 17:57:13 PRE-VM1 systemd[1]: rabbitmq-server.service failed.
Jan 24 17:57:13 PRE-VM1 sudo[55710]: pam_unix(sudo:session): session closed for user root


#
# UDP
#

Test successfully sent via udp to remote syslog server, verified via local tcpdump ($ sudo tcpdump -vv -Xni eth0 port 514)
$ logger -n [remote syslog server] -P 514 "Test Message - udp" --udp

The udp config below generates no errors, but does not send any traffic over port 514. 

UDP syslog config:
$ cat /etc/rabbitmq/rabbitmq.conf
log.file.level = debug
log.syslog = true
log.syslog.level = debug
log.syslog.ip = [remote syslog server]
log.syslog.port = 514
log.syslog.protocol = rfc5424

$ cat /etc/rabbitmq/advanced.config 
[
 {rabbit, [
   {cluster_partition_handling, pause_minority},
   {vm_memory_high_watermark, 0.6},
   {disk_free_limit, 1000000000},
   {queue_master_locator, "min-masters"}
 ]},
 {lager, [
        {error_logger_hwm, 5000}
 ]},
 {rabbitmq_queue_master_balancer, [
     {operational_priority,      200},
      {preload_queues,            false},
      {sync_delay_timeout,        5000},
      {policy_transition_delay,   500}
 ]},
 {prometheus, [
   {rabbitmq_exporter, [
     {connections_total_enabled, true},
     {queue_messages_stat, []},
     {exchange_messages_stat, []}
   ]},
  {collectors, [
     %% Standard prometheus collectors
     prometheus_vm_statistics_collector,
     prometheus_vm_system_info_collector,
     prometheus_vm_memory_collector,
     prometheus_mnesia_collector,

     %% Process Info Collector
     %% Process_collector works on Linux only
     %% prometheus_process_collector,

     %% Rabbitmq collectors
     prometheus_rabbitmq_overview_collector,
     %% prometheus_rabbitmq_exchanges_collector,
     %% prometheus_rabbitmq_queues_collector,
     prometheus_rabbitmq_mnesia_tables_collector,
     prometheus_rabbitmq_nodes_collector
    ]}
 ]},
 {rabbitmq_management, [
   {listener, [
     {port, 15672},
     {ssl, false}
   ]}
 ]}
].


$ sudo rabbitmqctl status
Status of node rabbit@PRE-VM1 ...
[{pid,58037},
 {running_applications,
     [{prometheus_rabbitmq_exporter,
          "RabbitMQ Prometheus.io metrics exporter","3.7.2.4"},
      {rabbitmq_shovel_management,
          "Management extension for the Shovel plugin","3.7.10"},
      {rabbitmq_top,"RabbitMQ Top","3.7.10"},
      {rabbitmq_management,"RabbitMQ Management Console","3.7.10"},
      {rabbitmq_shovel,"Data Shovel for RabbitMQ","3.7.10"},
      {rabbitmq_management_agent,"RabbitMQ Management Agent","3.7.10"},
      {rabbitmq_web_dispatch,"RabbitMQ Web Dispatcher","3.7.10"},
      {rabbitmq_queue_master_balancer,
          "Queue Master balancing tool for RabbitMQ","0.0.4"},
      {rabbit,"RabbitMQ","3.7.10"},
      {amqp_client,"RabbitMQ AMQP Client","3.7.10"},
      {rabbit_common,
          "Modules shared by rabbitmq-server and rabbitmq-erlang-client",
          "3.7.10"},
      {cowboy,"Small, fast, modern HTTP server.","2.6.1"},
      {ranch,"Socket acceptor pool for TCP protocols.","1.7.1"},
      {amqp10_client,"AMQP 1.0 client from the RabbitMQ Project","3.7.10"},
      {ssl,"Erlang/OTP SSL application","9.1.1"},
      {public_key,"Public key infrastructure","1.6.4"},
      {asn1,"The Erlang ASN1 compiler version 5.0.8","5.0.8"},
      {amqp10_common,
          "Modules shared by rabbitmq-amqp1.0 and rabbitmq-amqp1.0-client",
          "3.7.10"},
      {os_mon,"CPO  CXC 138 46","2.4.7"},
      {syslog,"An RFC 3164 and RFC 5424 compliant logging framework.","3.4.5"},
      {prometheus_cowboy,[],"0.1.4"},
      {prometheus_httpd,"Prometheus.io inets httpd exporter","2.1.8"},
      {inets,"INETS  CXC 138 49","7.0.3"},
      {mnesia,"MNESIA  CXC 138 12","4.15.5"},
      {cowlib,"Support library for manipulating Web protocols.","2.7.0"},
      {crypto,"CRYPTO","4.4"},
      {accept,"Accept header(s) for Erlang/Elixir","0.3.3"},
      {xmerl,"XML parser","1.3.18"},
      {recon,"Diagnostic tools for production use","2.3.6"},
      {prometheus,"Prometheus.io client in Erlang","3.5.1"},
      {jsx,"a streaming, evented json parsing toolkit","2.9.0"},
      {lager,"Erlang logging framework","3.6.5"},
      {goldrush,"Erlang event stream processor","0.1.9"},
      {compiler,"ERTS  CXC 138 10","7.3"},
      {syntax_tools,"Syntax tools","2.1.6"},
      {sasl,"SASL  CXC 138 11","3.3"},
      {stdlib,"ERTS  CXC 138 10","3.7"},
      {kernel,"ERTS  CXC 138 10","6.2"}]},
 {os,{unix,linux}},
 {erlang_version,
     "Erlang/OTP 21 [erts-10.2.1] [source] [64-bit] [smp:16:16] [ds:16:16:10] [async-threads:256] [hipe]\n"},
 {memory,
     [{connection_readers,10760},
      {connection_writers,0},
      {connection_channels,0},
      {connection_other,17436},
      {queue_procs,28500},
      {queue_slave_procs,0},
      {plugins,52339464},
      {other_proc,0},
      {metrics,213260},
      {mgmt_db,44272632},
      {mnesia,1830120},
      {other_ets,3197024},
      {binary,2374416},
      {msg_index,29232},
      {code,24550963},
      {atom,1213657},
      {other_system,30612308},
      {allocated_unused,34866296},
      {reserved_unallocated,0},
      {strategy,rss},
      {total,[{erlang,145664904},{rss,169054208},{allocated,180531200}]}]},
 {alarms,[]},
 {listeners,[{clustering,25672,"::"},{amqp,5672,"::"},{http,15672,"::"}]},
 {vm_memory_calculation_strategy,rss},
 {vm_memory_high_watermark,0.6},
 {vm_memory_limit,40525838745},
 {disk_free_limit,1000000000},
 {disk_free,2054314254336},
 {file_descriptors,
     [{total_limit,999900},
      {total_used,3},
      {sockets_limit,899908},
      {sockets_used,0}]},
 {processes,[{limit,1048576},{used,438}]},
 {run_queue,1},
 {uptime,853},
 {kernel,{net_ticktime,60}}]


$ sudo rabbitmqctl environment
Application environment of node rabbit@PRE-VM1 ...
[{accept,[]},
 {amqp10_client,[]},
 {amqp10_common,[]},
 {amqp_client,[{prefer_ipv6,false},{ssl_options,[]}]},
 {asn1,[]},
 {compiler,[]},
 {cowboy,[]},
 {cowlib,[]},
 {crypto,[{fips_mode,false},{rand_cache_size,896}]},
 {goldrush,[]},
 {inets,[]},
 {jsx,[]},
 {kernel,
     [{inet_default_connect_options,[{nodelay,true}]},
      {inet_dist_listen_max,25672},
      {inet_dist_listen_min,25672},
      {logger,
          [{handler,default,logger_std_h,
               #{config => #{type => standard_io},
                 formatter =>
                     {logger_formatter,
                         #{legacy_header => true,single_line => false}}}}]},
      {logger_level,notice},
      {logger_sasl_compatible,false}]},
 {lager,
     [{async_threshold,20},
      {async_threshold_window,5},
      {colored,false},
      {colors,
          [{debug,"\e[0;38m"},
           {info,"\e[1;37m"},
           {notice,"\e[1;36m"},
           {warning,"\e[1;33m"},
           {error,"\e[1;31m"},
           {critical,"\e[1;35m"},
           {alert,"\e[1;44m"},
           {emergency,"\e[1;41m"}]},
      {crash_log,"log/crash.log"},
      {crash_log_count,5},
      {crash_log_date,"$D0"},
      {crash_log_msg_size,65536},
      {crash_log_rotator,lager_rotator_default},
      {crash_log_size,10485760},
      {error_logger_format_raw,true},
      {error_logger_hwm,5000},
      {error_logger_hwm_original,5000},
      {error_logger_redirect,true},
      {extra_sinks,
          [{error_logger_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_channel_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_connection_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_mirroring_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_queue_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_federation_lager_event,
               [{handlers,[{lager_forwarder_backend,[lager_event,inherit]}]},
                {rabbit_handlers,
                    [{lager_forwarder_backend,[lager_event,inherit]}]}]},
           {rabbit_log_upgrade_lager_event,
               [{handlers,
                    [{syslog_lager_backend,
                         [debug,{},
                          {lager_default_formatter,
                              [color,"[",severity,"] ",
                               {pid,[]},
                               " ",message,"\n"]}]},
                     {lager_file_backend,
                         [{date,[]},
                          {file,
                              "/var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log"},
                          {formatter_config,
                              [date," ",time," ",color,"[",severity,"] ",
                               {pid,[]},
                               " ",message,"\n"]},
                          {level,debug},
                          {size,0}]}]},
                {rabbit_handlers,
                    [{syslog_lager_backend,
                         [debug,{},
                          {lager_default_formatter,
                              [color,"[",severity,"] ",
                               {pid,[]},
                               " ",message,"\n"]}]},
                     {lager_file_backend,
                         [{date,[]},
                          {file,
                              "/var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log"},
                          {formatter_config,
                              [date," ",time," ",color,"[",severity,"] ",
                               {pid,[]},
                               " ",message,"\n"]},
                          {level,debug},
                          {size,0}]}]}]}]},
      {handlers,
          [{lager_file_backend,
               [{date,[]},
                {file,"/var/log/rabbitmq/rab...@PRE-VM1.log"},
                {formatter_config,
                    [date," ",time," ",color,"[",severity,"] ",
                     {pid,[]},
                     " ",message,"\n"]},
                {level,debug},
                {size,0}]},
           {syslog_lager_backend,
               [debug,{},
                {lager_default_formatter,
                    [color,"[",severity,"] ",{pid,[]}," ",message,"\n"]}]}]},
      {log_root,"/var/log/rabbitmq"},
      {rabbit_handlers,
          [{lager_file_backend,
               [{date,[]},
                {file,"/var/log/rabbitmq/rab...@PRE-VM1.log"},
                {formatter_config,
                    [date," ",time," ",color,"[",severity,"] ",
                     {pid,[]},
                     " ",message,"\n"]},
                {level,debug},
                {size,0}]},
           {syslog_lager_backend,
               [debug,{},
                {lager_default_formatter,
                    [color,"[",severity,"] ",{pid,[]}," ",message,"\n"]}]}]}]},
 {mnesia,[{dir,"/var/lib/rabbitmq/mnesia/rabbit@PRE-VM1"}]},
 {os_mon,
     [{start_cpu_sup,false},
      {start_disksup,false},
      {start_memsup,false},
      {start_os_sup,false}]},
 {prometheus,
     [{collectors,
          [prometheus_vm_statistics_collector,
           prometheus_vm_system_info_collector,prometheus_vm_memory_collector,
           prometheus_mnesia_collector,prometheus_rabbitmq_overview_collector,
           prometheus_rabbitmq_mnesia_tables_collector,
           prometheus_rabbitmq_nodes_collector]},
      {rabbitmq_exporter,
          [{connections_total_enabled,true},
           {queue_messages_stat,[]},
           {exchange_messages_stat,[]}]}]},
 {prometheus_cowboy,[]},
 {prometheus_httpd,[]},
 {prometheus_rabbitmq_exporter,[]},
 {public_key,[]},
 {rabbit,
     [{auth_backends,[rabbit_auth_backend_internal]},
      {auth_mechanisms,['PLAIN','AMQPLAIN']},
      {autocluster,
          [{peer_discovery_backend,rabbit_peer_discovery_classic_config}]},
      {background_gc_enabled,false},
      {background_gc_target_interval,60000},
      {backing_queue_module,rabbit_priority_queue},
      {channel_max,2047},
      {channel_operation_timeout,15000},
      {cluster_keepalive_interval,10000},
      {cluster_nodes,{[],disc}},
      {cluster_partition_handling,pause_minority},
      {collect_statistics,fine},
      {collect_statistics_interval,5000},
      {config_entry_decoder,
          [{cipher,aes_cbc256},
           {hash,sha512},
           {iterations,1000},
           {passphrase,undefined}]},
      {connection_max,infinity},
      {credit_flow_default_credit,{400,200}},
      {default_consumer_prefetch,{false,0}},
      {default_permissions,[<<".*">>,<<".*">>,<<".*">>]},
      {default_user,<<"guest">>},
      {default_user_tags,[administrator]},
      {default_vhost,<<"/">>},
      {delegate_count,16},
      {disk_free_limit,1000000000},
      {disk_monitor_failure_retries,10},
      {disk_monitor_failure_retry_interval,120000},
      {enabled_plugins_file,"/etc/rabbitmq/enabled_plugins"},
      {fhc_read_buffering,false},
      {fhc_write_buffering,true},
      {frame_max,131072},
      {halt_on_upgrade_failure,true},
      {handshake_timeout,10000},
      {heartbeat,60},
      {hipe_compile,false},
      {hipe_modules,
          [rabbit_reader,rabbit_channel,gen_server2,rabbit_exchange,
           rabbit_command_assembler,rabbit_framing_amqp_0_9_1,rabbit_basic,
           rabbit_event,lists,queue,priority_queue,rabbit_router,rabbit_trace,
           rabbit_misc,rabbit_binary_parser,rabbit_exchange_type_direct,
           rabbit_guid,rabbit_net,rabbit_amqqueue_process,
           rabbit_variable_queue,rabbit_binary_generator,rabbit_writer,
           delegate,gb_sets,lqueue,sets,orddict,rabbit_amqqueue,
           rabbit_limiter,gb_trees,rabbit_queue_index,
           rabbit_exchange_decorator,gen,dict,ordsets,file_handle_cache,
           rabbit_msg_store,array,rabbit_msg_store_ets_index,rabbit_msg_file,
           rabbit_exchange_type_fanout,rabbit_exchange_type_topic,mnesia,
           mnesia_lib,rpc,mnesia_tm,qlc,sofs,proplists,credit_flow,pmon,
           ssl_connection,tls_connection,ssl_record,tls_record,gen_fsm,ssl]},
      {lager_default_file,"/var/log/rabbitmq/rab...@PRE-VM1.log"},
      {lager_extra_sinks,
          [rabbit_log_lager_event,rabbit_log_channel_lager_event,
           rabbit_log_connection_lager_event,rabbit_log_mirroring_lager_event,
           rabbit_log_queue_lager_event,rabbit_log_federation_lager_event,
           rabbit_log_upgrade_lager_event]},
      {lager_log_root,"/var/log/rabbitmq"},
      {lager_upgrade_file,
          "/var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log"},
      {lazy_queue_explicit_gc_run_operation_threshold,1000},
      {log,
          [{file,
               [{level,debug},
                {file,"/var/log/rabbitmq/rab...@PRE-VM1.log"}]},
           {syslog,[{level,debug},{enabled,true}]},
           {categories,
               [{upgrade,
                    [{file,
                         "/var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log"}]}]}]},
      {loopback_users,[<<"guest">>]},
      {memory_monitor_interval,2500},
      {mirroring_flow_control,true},
      {mirroring_sync_batch_size,4096},
      {mnesia_table_loading_retry_limit,10},
      {mnesia_table_loading_retry_timeout,30000},
      {msg_store_credit_disc_bound,{4000,800}},
      {msg_store_file_size_limit,16777216},
      {msg_store_index_module,rabbit_msg_store_ets_index},
      {msg_store_io_batch_size,4096},
      {num_ssl_acceptors,10},
      {num_tcp_acceptors,10},
      {password_hashing_module,rabbit_password_hashing_sha256},
      {plugins_dir,
          "/usr/lib/rabbitmq/plugins:/usr/lib/rabbitmq/lib/rabbitmq_server-3.7.10/plugins"},
      {plugins_expand_dir,
          "/var/lib/rabbitmq/mnesia/rabbit@PRE-VM1-plugins-expand"},
      {proxy_protocol,false},
      {queue_explicit_gc_run_operation_threshold,1000},
      {queue_index_embed_msgs_below,4096},
      {queue_index_max_journal_entries,32768},
      {queue_master_locator,"min-masters"},
      {reverse_dns_lookups,false},
      {server_properties,[]},
      {ssl_allow_poodle_attack,false},
      {ssl_apps,[asn1,crypto,public_key,ssl]},
      {ssl_cert_login_from,distinguished_name},
      {ssl_handshake_timeout,5000},
      {ssl_listeners,[]},
      {ssl_options,[]},
      {tcp_listen_options,
          [{backlog,128},
           {nodelay,true},
           {linger,{true,0}},
           {exit_on_close,false}]},
      {tcp_listeners,[5672]},
      {trace_vhosts,[]},
      {vhost_restart_strategy,continue},
      {vm_memory_calculation_strategy,rss},
      {vm_memory_high_watermark,0.6},
      {vm_memory_high_watermark_paging_ratio,0.5}]},
 {rabbit_common,[]},
 {rabbitmq_management,
     [{content_security_policy,"default-src 'self'"},
      {cors_allow_origins,[]},
      {cors_max_age,1800},
      {http_log_dir,none},
      {listener,[{port,15672},{ssl,false}]},
      {load_definitions,none},
      {management_db_cache_multiplier,5},
      {process_stats_gc_timeout,300000},
      {stats_event_max_backlog,250}]},
 {rabbitmq_management_agent,
     [{rates_mode,basic},
      {sample_retention_policies,
          [{global,[{605,5},{3660,60},{29400,600},{86400,1800}]},
           {basic,[{605,5},{3600,60}]},
           {detailed,[{605,5}]}]}]},
 {rabbitmq_queue_master_balancer,
     [{operational_priority,200},
      {policy_transition_delay,500},
      {preload_queues,false},
      {sync_delay_timeout,5000}]},
 {rabbitmq_shovel,
     [{defaults,
          [{prefetch_count,1000},
           {ack_mode,on_confirm},
           {publish_fields,[]},
           {publish_properties,[]},
           {reconnect_delay,5}]}]},
 {rabbitmq_shovel_management,[]},
 {rabbitmq_top,[]},
 {rabbitmq_web_dispatch,[]},
 {ranch,[]},
 {recon,[]},
 {sasl,[{errlog_type,error},{sasl_error_logger,false}]},
 {ssl,[]},
 {stdlib,[]},
 {syntax_tools,[]},
 {syslog,
     [{dest_host,"[remote syslog server]"},
      {dest_port,514},
      {protocol,{rfc5424,udp,[{ip,{127,0,0,1}}]}},
      {syslog_error_logger,false}]},
 {xmerl,[]}]

Luke Bakken

unread,
Jan 24, 2019, 2:57:22 PM1/24/19
to rabbitmq-users
Hi Kevin,

The redacted [remote syslog server] configuration key - is that a host name or an IP address?

If it's a host name, you must use the log.syslog.host configuration key, not the ip one.

Thanks,
Luke

Kevin Freeman

unread,
Jan 24, 2019, 4:14:29 PM1/24/19
to rabbitmq-users
[remote syslog server] is an IP address.

Kevin

Luke Bakken

unread,
Jan 24, 2019, 7:03:44 PM1/24/19
to rabbitmq-users
Hi Kevin,

I'm assuming the complete line in your configuration is something like this, correct?

log.syslog.ip = 192.168.1.1

The reason I ask is that I can't reproduce this issue locally - using an IPv4 address works fine. The environment output you provide is suspect:

 {syslog,
     [{dest_host,"[remote syslog server]"},
      {dest_port,514},
      {protocol,{rfc5424,udp,[{ip,{127,0,0,1}}]}},
      {syslog_error_logger,false}]},

There should not be an ip value in the protocol section (this probably explains the badarg error), and your configuration file specifies tcp, so I don't think RabbitMQ is reading the correct configuration files. When you start RabbitMQ, it will log what file(s) it reads, like this:

 config file(s) : /Users/lbakken/issues/rabbitmq-users/syslog-error-nv-wQiY0R_I/rabbitmq.conf

Could you paste the output or double-check that the expected rabbitmq.conf and advanced.config files are read?

Thanks,
Luke

Kevin Freeman

unread,
Jan 24, 2019, 7:47:16 PM1/24/19
to rabbitmq-users
Yes, the syslog IP is an IPv4 address.  rabbitmq.conf does have some commented lines that I omitted from the initial post.  Here is a raw transcript of logs and configs:
[PR@PRE-VM1 ~]$ sudo systemctl restart rabbitmq-server

[PR@PRE-VM1 ~]$ tail -n 100 /var/log/rabbitmq/rab...@PRE-VM1.log 
 Copyright (C) 2007-2018 Pivotal Software, Inc.
 Licensed under the MPL.  See http://www.rabbitmq.com/
2019-01-25 00:30:24.587 [info] <0.373.0> 
 node           : rabbit@PRE-VM1
 home dir       : /var/lib/rabbitmq
 config file(s) : /etc/rabbitmq/advanced.config
                : /etc/rabbitmq/rabbitmq.conf
 cookie hash    : REDACTED==
 log(s)         : /var/log/rabbitmq/rab...@PRE-VM1.log
                : /var/log/rabbitmq/rabbit@PRE-VM1_upgrade.log
 database dir   : /var/lib/rabbitmq/mnesia/rabbit@PRE-VM1
2019-01-25 00:30:24.606 [debug] <0.380.0> Supervisor rabbit_alarm_sup started rabbit_alarm:start_link() at pid <0.381.0>
2019-01-25 00:30:24.618 [info] <0.383.0> Memory high watermark set to 38648 MiB (40525838745 bytes) of 64414 MiB (67543064576 bytes) total
2019-01-25 00:30:24.619 [debug] <0.382.0> Supervisor vm_memory_monitor_sup started vm_memory_monitor:start_link(0.6, #Fun<rabbit_alarm.0.123076882>, #Fun<rabbit_alarm.1.123076882>) at pid <0.383.0>
2019-01-25 00:30:24.629 [info] <0.385.0> Enabling free disk space monitoring
2019-01-25 00:30:24.629 [info] <0.385.0> Disk free limit set to 1000MB
2019-01-25 00:30:24.637 [debug] <0.384.0> Supervisor rabbit_disk_monitor_sup started rabbit_disk_monitor:start_link(1000000000) at pid <0.385.0>
2019-01-25 00:30:24.637 [info] <0.400.0> Limiting to approx 999900 file handles (899908 sockets)
2019-01-25 00:30:24.637 [info] <0.401.0> FHC read buffering:  OFF
2019-01-25 00:30:24.637 [debug] <0.399.0> Supervisor file_handle_cache_sup started file_handle_cache:start_link(fun rabbit_alarm:set_alarm/1, fun rabbit_alarm:clear_alarm/1) at pid <0.400.0>
2019-01-25 00:30:24.637 [info] <0.401.0> FHC write buffering: ON
2019-01-25 00:30:24.688 [info] <0.373.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-01-25 00:30:24.753 [info] <0.373.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-01-25 00:30:24.801 [info] <0.373.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
2019-01-25 00:30:24.802 [info] <0.373.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
2019-01-25 00:30:24.802 [debug] <0.493.0> Supervisor rabbit_event_sup started rabbit_event:start_link() at pid <0.494.0>
2019-01-25 00:30:24.803 [info] <0.373.0> Priority queues enabled, real BQ is rabbit_variable_queue
2019-01-25 00:30:24.804 [debug] <0.495.0> Supervisor rabbit_epmd_monitor_sup started rabbit_epmd_monitor:start_link() at pid <0.496.0>
2019-01-25 00:30:24.815 [debug] <0.497.0> Supervisor rabbit_guid_sup started rabbit_guid:start_link() at pid <0.498.0>
2019-01-25 00:30:24.817 [info] <0.500.0> Starting rabbit_node_monitor
2019-01-25 00:30:24.817 [debug] <0.499.0> Supervisor rabbit_node_monitor_sup started rabbit_node_monitor:start_link() at pid <0.500.0>
2019-01-25 00:30:24.818 [debug] <0.518.0> Supervisor rabbit_memory_monitor_sup started rabbit_memory_monitor:start_link() at pid <0.519.0>
2019-01-25 00:30:24.847 [info] <0.373.0> Management plugin: using rates mode 'basic'
2019-01-25 00:30:24.983 [debug] <0.583.0> Recovering data for VHost <<"/">>
2019-01-25 00:30:24.984 [info] <0.583.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@PRE-VM1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
2019-01-25 00:30:24.985 [debug] <0.582.0> Supervisor {<0.582.0>,rabbit_vhost_sup} started rabbit_recovery_terms:start_link(<<"/">>) at pid <0.584.0>
2019-01-25 00:30:24.997 [info] <0.583.0> Starting message stores for vhost '/'
2019-01-25 00:30:24.997 [info] <0.587.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
2019-01-25 00:30:24.999 [info] <0.583.0> Started message store of type transient for vhost '/'
2019-01-25 00:30:24.999 [debug] <0.582.0> Supervisor {<0.582.0>,rabbit_vhost_sup} started rabbit_msg_store:start_link(msg_store_transient, "/var/lib/rabbitmq/mnesia/rabbit@PRE-VM1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L", undefined, {#Fun<rabbit_variable_queue.2.119734152>,ok}) at pid <0.587.0>
2019-01-25 00:30:24.999 [info] <0.590.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
2019-01-25 00:30:25.001 [info] <0.583.0> Started message store of type persistent for vhost '/'
2019-01-25 00:30:25.002 [debug] <0.582.0> Supervisor {<0.582.0>,rabbit_vhost_sup} started rabbit_msg_store:start_link(msg_store_persistent, "/var/lib/rabbitmq/mnesia/rabbit@PRE-VM1/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L", [<<28,70,142,99,80,142,212,58,158,130,79,117,207,78,73,137>>], {#Fun<rabbit_queue_index.2.122888644>,{start,[{resource,<<"/">>,queue,<<"notificationsoutcome.azu...">>}]}}) at pid <0.590.0>
2019-01-25 00:30:25.002 [debug] <0.582.0> Supervisor {<0.582.0>,rabbit_vhost_sup} started rabbit_amqqueue_sup_sup:start_link() at pid <0.596.0>
2019-01-25 00:30:25.002 [debug] <0.598.0> Supervisor {<0.598.0>,rabbit_amqqueue_sup} started rabbit_prequeue:start_link({amqqueue,{resource,<<"/">>,queue,<<"notificationsoutcome.azure">>},true,false,none,[],<0.588.0>,...}, recovery, <0.597.0>) at pid <0.599.0>
2019-01-25 00:30:25.047 [debug] <0.657.0> Supervisor rabbit_core_metrics_gc_sup started rabbit_core_metrics_gc:start_link() at pid <0.658.0>
2019-01-25 00:30:25.047 [debug] <0.659.0> Supervisor background_gc_sup started background_gc:start_link() at pid <0.660.0>
2019-01-25 00:30:25.049 [warning] <0.661.0> Setting Ranch options together with socket options is deprecated. Please use the new map syntax that allows specifying socket options separately from other options.
2019-01-25 00:30:25.050 [info] <0.675.0> started TCP listener on [::]:5672
2019-01-25 00:30:25.052 [info] <0.373.0> Setting up a table for connection tracking on this node: 'tracked_connection_on_node_rabbit@PRE-VM1'
2019-01-25 00:30:25.053 [info] <0.373.0> Setting up a table for per-vhost connection counting on this node: 'tracked_connection_per_vhost_on_node_rabbit@PRE-VM1'
2019-01-25 00:30:25.053 [info] <0.500.0> rabbit on node 'rabbit@PRE-VM2' up
2019-01-25 00:30:25.053 [debug] <0.682.0> Supervisor rabbit_queue_master_balancer_sup started rabbit_queue_master_balancer:start_link() at pid <0.683.0>
2019-01-25 00:30:25.084 [info] <0.500.0> rabbit on node 'rabbit@PRE-VM5' up
2019-01-25 00:30:25.113 [info] <0.500.0> rabbit on node 'rabbit@PRE-VM4' up
2019-01-25 00:30:25.139 [info] <0.500.0> rabbit on node 'rabbit@PRE-VM3' up
2019-01-25 00:30:25.166 [debug] <0.693.0> Supervisor rabbit_mgmt_agent_sup_sup started rabbit_mgmt_agent_sup:start_link() at pid <0.694.0>
2019-01-25 00:30:25.167 [debug] <0.738.0> Supervisor rabbit_shovel_sup started rabbit_shovel_status:start_link() at pid <0.739.0>
2019-01-25 00:30:25.167 [debug] <0.740.0> Supervisor rabbit_shovel_dyn_worker_sup_sup started supervisor2:start_link(mirrored_supervisor_sups, {delegate,{one_for_one,3,10}}) at pid <0.741.0>
2019-01-25 00:30:25.167 [debug] <0.740.0> Supervisor rabbit_shovel_dyn_worker_sup_sup started mirrored_supervisor:start_internal(rabbit_shovel_dyn_worker_sup_sup, fun rabbit_misc:execute_mnesia_transaction/1, []) at pid <0.742.0>
2019-01-25 00:30:25.170 [debug] <0.738.0> Supervisor rabbit_shovel_sup started rabbit_shovel_dyn_worker_sup_sup:start_link() at pid <0.740.0>
2019-01-25 00:30:25.200 [debug] <0.688.0> Starting HTTP[S] listener with transport ranch_tcp, options [{port,15672}] and protocol options #{}, stream handlers [rabbit_cowboy_stream_h,cowboy_compress_h,cowboy_stream_h]
2019-01-25 00:30:25.202 [info] <0.745.0> Management plugin: HTTP (non-TLS) listener started on port 15672
2019-01-25 00:30:25.202 [info] <0.851.0> Statistics database started.
2019-01-25 00:30:25.203 [debug] <0.849.0> Supervisor rabbit_mgmt_sup_sup started rabbit_mgmt_sup:start_link() at pid <0.850.0>
2019-01-25 00:30:25.421 [info] <0.8.0> Server startup complete; 8 plugins started.
 * prometheus_rabbitmq_exporter
 * rabbitmq_shovel_management
 * rabbitmq_top
 * rabbitmq_management
 * rabbitmq_shovel
 * rabbitmq_management_agent
 * rabbitmq_web_dispatch
 * rabbitmq_queue_master_balancer
 
 [PR@PRE-VM1 ~]$ cat /etc/rabbitmq/advanced.config 
[PR@PRE-VM1 ~]$ cat /etc/rabbitmq/rabbitmq.conf 
log.file.level = debug
#log.file.rotation.date = $D0
#log.file.rotation.size = 5242880
#log.file.rotation.count = 100
log.syslog = true
log.syslog.level = debug
log.syslog.ip = 192.168.1.1
#log.syslog.facility = user
#log.syslog.identity = RabbitMQ
#log.syslog.transport = tcp
log.syslog.port = 514
log.syslog.protocol = rfc5424

[PR@PRE-VM1 ~]$ sudo rabbitmqctl environment | tail -n 6
 {syslog,
     [{dest_host,"192.168.1.1"},
      {dest_port,514},
      {protocol,{rfc5424,udp,[{ip,{127,0,0,1}}]}},
      {syslog_error_logger,false}]},
 {xmerl,[]}]

Kevin

Kevin Freeman

unread,
Jan 25, 2019, 6:43:29 PM1/25/19
to rabbitmq-users
I reset the node, re-added to the cluster (no config changes) and the IP section is still in the environment.  Will investigate whether using advanced.config will cause different results.  Note that the config used specifies udp, and I have verified that the correct config files are being read.

PR@PRE-VM1 ~]$ sudo rabbitmqctl stop_app
Stopping rabbit application on node rabbit@PRE-VM1 ...
[PR@PRE-VM1 ~]$ sudo rabbitmqctl reset
Resetting node rabbit@PRE-VM1 ...
[PR@PRE-VM1 ~]$ sudo rabbitmqctl join_cluster rabbit@PRE-VM2
Clustering node rabbit@PRE-VM1 with rabbit@PRE-VM2
[PR@PRE-VM1 ~]$ sudo rabbitmqctl start_app
Starting node rabbit@PRE-VM1 ...
 completed with 8 plugins.
[PR@PRE-VM1 ~]$ sudo rabbitmqctl environment |tail -n 6
 {syslog,
     [{dest_host,"192.168.1.1"},
      {dest_port,514},
      {protocol,{rfc5424,udp,[{ip,{127,0,0,1}}]}},
      {syslog_error_logger,false}]},
 {xmerl,[]}]


Kevin

Kevin Freeman

unread,
Jan 25, 2019, 7:37:37 PM1/25/19
to rabbitmq-users
I moved syslog config from rabbitmq.conf to advanced.config:

 {rabbit, [

   {cluster_partition_handling, pause_minority},

   {vm_memory_high_watermark, 0.6},

   {disk_free_limit, 1000000000},

   {queue_master_locator, "min-masters"},

   {log, [{syslog, [{enabled, true}]}]}

 ]},

 {syslog, [{dest_host, {192, 168, 1, 1}}

 ]},


The environment still contains the loopback address.  I note that the destination host address is not quoted, and is in quotes when configured via rabbitmq.conf.  tcpdump still does not find any udp traffic on port 514.  Will try tcp next.

 {syslog,

     [{dest_host,{192,168,1,1}},

      {protocol,{rfc3164,udp,[{ip,{127,0,0,1}}]}},

      {syslog_error_logger,false}]},



Kevin

Kevin Freeman

unread,
Jan 25, 2019, 7:49:53 PM1/25/19
to rabbitmq-users
rabbitmq still crashes on start when configured for syslog on tcp via advanced.config.

[

 {rabbit, [

   {cluster_partition_handling, pause_minority},

   {vm_memory_high_watermark, 0.6},

   {disk_free_limit, 1000000000},

   {queue_master_locator, "min-masters"},

   {log, [{syslog, [{enabled, true}]}]}

 ]},

 {syslog, [{dest_host, {192, 168, 1, 1}},

           {dest_port, 1514},

           {protocol, {tcp, rfc5424}}



[PR@PRE-VM1 ~]$ cat /var/log/rabbitmq/startup_err 
init terminating in do_boot ({{case_clause,{ok,{tcp,rfc5424}}},[{rabbit_lager,configure_syslog,0,[{_},{_}]},{rabbit_lager,generate_handler,2,[{_},{_}]},{lists,flatmap,2,[{_},{_}]},{rabbit_lager,config

Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done

[PR@PRE-VM1 ~]$ cat /var/log/rabbitmq/startup_log 
{"init terminating in do_boot",{{case_clause,{ok,{tcp,rfc5424}}},[{rabbit_lager,configure_syslog,0,[{file,"src/rabbit_lager.erl"},{line,314}]},{rabbit_lager,generate_handler,2,[{file,"src/rabbit_lager.erl"},{line,383}]},{lists,flatmap,2,[{file,"lists.erl"},{line,1250}]},{rabbit_lager,configure_lager,0,[{file,"src/rabbit_lager.erl"},{line,235}]},{rabbit_lager,log_locations,0,[{file,"src/rabbit_lager.erl"},{line,88}]},{rabbit,boot_error,2,[{file,"src/rabbit.erl"},{line,871}]},{rabbit,start_it,1,[{file,"src/rabbit.erl"},{line,465}]},{init,start_em,1,[]}]}}

[PR@PRE-VM1 ~]$ sudo systemctl status rabbitmq-server.service
● rabbitmq-server.service - LSB: Enable AMQP service provided by RabbitMQ broker
   Loaded: loaded (/etc/rc.d/init.d/rabbitmq-server; bad; vendor preset: disabled)
   Active: failed (Result: exit-code) since Sat 2019-01-26 00:30:56 UTC; 28s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 62762 ExecStop=/etc/rc.d/init.d/rabbitmq-server stop (code=exited, status=0/SUCCESS)
  Process: 64673 ExecStart=/etc/rc.d/init.d/rabbitmq-server start (code=exited, status=1/FAILURE)
   CGroup: /system.slice/rabbitmq-server.service
           └─2389 /usr/lib64/erlang/erts-10.2.1/bin/epmd -daemon

Jan 26 00:30:51 PRE-VM1 runuser[64923]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 26 00:30:51 PRE-VM1 runuser[64929]: pam_unix(runuser:session): session opened for user rabbitmq by (uid=0)
Jan 26 00:30:56 PRE-VM1 runuser[64923]: pam_unix(runuser:session): session closed for user rabbitmq
Jan 26 00:30:56 PRE-VM1 rabbitmq-server[64673]: Starting rabbitmq-server: FAILED - check /var/log/rabbitmq/startup_{log, _err}
Jan 26 00:30:56 PRE-VM1 rabbitmq-server[64673]: rabbitmq-server.
Jan 26 00:30:56 PRE-VM1 systemd[1]: rabbitmq-server.service: control process exited, code=exited status=1
Jan 26 00:30:56 PRE-VM1 systemd[1]: Failed to start LSB: Enable AMQP service provided by RabbitMQ broker.
Jan 26 00:30:56 PRE-VM1 systemd[1]: Unit rabbitmq-server.service entered failed state.
Jan 26 00:30:56 PRE-VM1 systemd[1]: rabbitmq-server.service failed.
Jan 26 00:30:57 PRE-VM1 runuser[64929]: pam_unix(runuser:session): session closed for user rabbitmq
[PR@PRE-VM1 ~]$ cat /var/log/rabbitmq/startup_err 
init terminating in do_boot ({{case_clause,{ok,{tcp,rfc5424}}},[{rabbit_lager,configure_syslog,0,[{_},{_}]},{rabbit_lager,generate_handler,2,[{_},{_}]},{lists,flatmap,2,[{_},{_}]},{rabbit_lager,config

Crash dump is being written to: /var/log/rabbitmq/erl_crash.dump...done

[PR@PRE-VM1 ~]$ cat /var/log/rabbitmq/log/crash.log
2019-01-26 00:04:10 =ERROR REPORT====
** gen_event handler syslog_lager_backend crashed.
** Was installed in lager_event
** Last event was: {log,{lager_msg,[],[{module,rabbit},{function,stop_and_halt},{line,501},{pid,"<0.1111.0>"},{node,'rabbit@PRE-VM1'}],info,{["2019",45,"01",45,"26"],["00",58,"04",58,"10",46,"573"]},{1548,461050,573602},[72,97,108,116,105,110,103,32,69,114,108,97,110,103,32,86,77,32,119,105,116,104,32,116,104,101,32,102,111,108,108,111,119,105,110,103,32,97,112,112,108,105,99,97,116,105,111,110,115,58,"\n",32,32,32,32,"ranch","\n",32,32,32,32,"ssl","\n",32,32,32,32,"public_key","\n",32,32,32,32,"asn1","\n",32,32,32,32,"crypto","\n",32,32,32,32,"syslog","\n",32,32,32,32,"inets","\n",32,32,32,32,"recon","\n",32,32,32,32,"xmerl","\n",32,32,32,32,"jsx","\n",32,32,32,32,"lager","\n",32,32,32,32,"goldrush","\n",32,32,32,32,"compiler","\n",32,32,32,32,"syntax_tools","\n",32,32,32,32,"sasl","\n",32,32,32,32,"stdlib","\n",32,32,32,32,"kernel"]}}
** When handler state == {state,{mask,127},lager_default_formatter,[color,"[",severity,"] ",{pid,[]}," ",message,"\n"],undefined,[],false}
** Reason == {killed,{gen_server,call,[syslog_logger,{log,<<"<30>Jan 26 00:04:10 PRE-VM1 rabbit[57131] <0.1111.0> -     crypto">>},1000]}}

Luke Bakken

unread,
Jan 26, 2019, 2:10:27 PM1/26/19
to rabbitmq-users
Hi Kevin,

First thing, the presence of 127.0.0.1 in the output of rabbitmqctl environment isn't an issue - I actually see it in my environment too. It's a side-effect of this pull request that I did a while back: https://github.com/rabbitmq/rabbitmq-server/pull/1728 - you can read the linked issue if you're interested in the back story.

I think we need to step back in your environment and use a minimal configuration file, which I have attached to this response (rabbitmq.config). This file works on my machine using RabbitMQ 3.7.10 and syslog-ng 3.19.1 (I have attached the syslog-ng configuration, too). Please back up or re-name the existing configuration files in /etc/rabbitmq (use a .bak extension) and save the attached rabbitmq.config file there. Customize the dest_host value to the IP address that you are using, and start RabbitMQ. You may have to customize dest_port and protocol, but if you configure protocol, please ensure that the value follows the format specified here: https://github.com/schlagert/syslog/#configuration - I'm happy to assist with this.

Finally, ensure in the RabbitMQ startup output that only the /etc/rabbitmq/rabbitmq.config file is used (Check the config file(s): value).

Thanks. Sorry this is taking so much back-and-forth, I really don't know what's up with your environment. Just out of curiosity, have you upgraded RabbitMQ on this system or is it a fresh install?

Luke
rabbitmq.config
syslog-ng.conf
run-syslog-ng.sh

Kevin Freeman

unread,
Jan 28, 2019, 1:20:11 PM1/28/19
to rabbitmq-users
Luke,

Are there any additional package dependencies to publish to remote syslog-ng?  Our rabbitmq servers do not have syslog-ng installed.

package versions:

I am working with a different node today, non-clustered.  The VM is freshly built, and only the rabbitmq config files have been altered.  Using the minimal config which you posted, we see the same behavior as reported last week:
udp: rabbitmq-server starts but does not send any traffic to syslog (based on tcpdump of port 514)
tcp: rabbitmq fails to start with badarg error, no traffic to syslog, crash dump is generated.  We see badarg error both using minimal config verbatim as well as when the dest_host and port are edited to match our environment.

I am encluding logs generated using verbatim the posted minimal config (not expecting syslog to work due to incorrect dest IP and port, but not expecting rabbitmq failure to start).

First, from a run with udp config (so that rabbitmq starts) just to capture config file used:
2019-01-28 17:10:45.883 [info] <0.332.0> 
 node           : rabbit@PRE-MQLLOG-VM1
 home dir       : /var/lib/rabbitmq
 config file(s) : /etc/rabbitmq/rabbitmq.config

$ cat rabbitmq.config 
[
    {rabbit, [
        {log, [
            {syslog, [
                {level, debug},
                {enabled, true}
            ]}
        ]}
    ]},
    {syslog, [
        {protocol, {rfc5424, tcp}},
        {dest_host, {192, 168, 1, 5}},
        {dest_port, 5140}
    ]}
].

Now, logs when using posted minimal config:
$ sudo cat /var/log/rabbitmq/rab...@PRE-MQLLOG-VM1.log (tail of log after service restart)
2019-01-28 17:54:11.474 [info] <0.3274.0> Stopping application 'amqp10_client'
2019-01-28 17:54:19.725 [info] <0.8.0> Log file opened with Lager
2019-01-28 17:54:22.590 [error] <0.328.0> CRASH REPORT Process <0.328.0> with 0 neighbours exited with reason: bad argument in gen_tcp:connect/4 line 167
2019-01-28 17:54:22.591 [error] <0.327.0> Supervisor {<0.327.0>,syslog} had child syslog_logger started with syslog_logger:start_link() at undefined exit with reason badarg in context start_error
2019-01-28 17:54:22.592 [error] <0.325.0> CRASH REPORT Process <0.325.0> with 0 neighbours exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}} in application_master:init/4 line 138
2019-01-28 17:54:22.592 [info] <0.43.0> Application syslog exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}}
2019-01-28 17:54:22.594 [info] <0.43.0> Application prometheus_cowboy exited with reason: stopped
2019-01-28 17:54:22.595 [info] <0.43.0> Application prometheus_httpd exited with reason: stopped
2019-01-28 17:54:22.596 [info] <0.43.0> Application amqp10_client exited with reason: stopped
2019-01-28 17:54:22.598 [info] <0.43.0> Application inets exited with reason: stopped
2019-01-28 17:54:22.599 [info] <0.43.0> Application amqp_client exited with reason: stopped
2019-01-28 17:54:22.599 [info] <0.43.0> Application rabbit_common exited with reason: stopped
2019-01-28 17:54:22.601 [info] <0.43.0> Application cowboy exited with reason: stopped
2019-01-28 17:54:22.602 [info] <0.43.0> Application ranch exited with reason: stopped
2019-01-28 17:54:22.605 [info] <0.43.0> Application ssl exited with reason: stopped
2019-01-28 17:54:22.605 [info] <0.43.0> Application public_key exited with reason: stopped
2019-01-28 17:54:22.605 [info] <0.43.0> Application asn1 exited with reason: stopped
2019-01-28 17:54:22.607 [info] <0.43.0> Application prometheus exited with reason: stopped
2019-01-28 17:54:22.607 [info] <0.43.0> Application recon exited with reason: stopped
2019-01-28 17:54:22.607 [info] <0.43.0> Application xmerl exited with reason: stopped
2019-01-28 17:54:22.607 [info] <0.43.0> Application jsx exited with reason: stopped
2019-01-28 17:54:22.607 [info] <0.43.0> Application cowlib exited with reason: stopped
2019-01-28 17:54:22.652 [info] <0.43.0> Application mnesia exited with reason: stopped
2019-01-28 17:54:22.652 [info] <0.43.0> Application amqp10_common exited with reason: stopped
2019-01-28 17:54:22.652 [info] <0.43.0> Application accept exited with reason: stopped
2019-01-28 17:54:22.652 [info] <0.43.0> Application crypto exited with reason: stopped
2019-01-28 17:54:22.653 [error] <0.8.0> 
Error description:
    init:do_boot/3
    init:start_em/1
    rabbit:start_it/1 line 461
    rabbit:broker_start/0 line 337
    rabbit:start_apps/2 line 556
    app_utils:manage_applications/6 line 126
    lists:foldl/3 line 1263
    rabbit:'-handle_app_error/1-fun-0-'/3 line 652
throw:{could_not_start,syslog,
          {syslog,
              {{shutdown,{failed_to_start_child,syslog_logger,badarg}},
               {syslog,start,[normal,[]]}}}}
Log file(s) (may contain more information):
   /var/log/rabbitmq/rab...@PRE-MQLLOG-VM1.log
   /var/log/rabbitmq/rabbit@PRE-MQLLOG-VM1_upgrade.log

$ sudo cat /var/log/rabbitmq/rabbit@PRE-MQLLOG-VM1_upgrade.log
2019-01-28 17:54:19.724 [info] <0.8.0> Log file opened with Lager

$ sudo cat /var/log/rabbitmq/startup_log 
=INFO REPORT==== 28-Jan-2019::17:54:22.591830 ===
    application: syslog
    exited: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},
             {syslog,start,[normal,[]]}}
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.594021 ===
    application: prometheus_cowboy
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.595501 ===
    application: prometheus_httpd
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.596645 ===
    application: amqp10_client
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.597920 ===
    application: inets
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.599272 ===
    application: amqp_client
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.599430 ===
    application: rabbit_common
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.601287 ===
    application: cowboy
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.602651 ===
    application: ranch
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.605227 ===
    application: ssl
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.605411 ===
    application: public_key
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.605607 ===
    application: asn1
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.607240 ===
    application: prometheus
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.607451 ===
    application: recon
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.607614 ===
    application: xmerl
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.607714 ===
    application: jsx
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.607850 ===
    application: cowlib
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.652149 ===
    application: mnesia
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.652298 ===
    application: amqp10_common
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.652391 ===
    application: accept
    exited: stopped
    type: temporary
=INFO REPORT==== 28-Jan-2019::17:54:22.652584 ===
    application: crypto
    exited: stopped
    type: temporary
{"init terminating in do_boot",{could_not_start,syslog,{syslog,{{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}}}}}

$ sudo cat /var/log/rabbitmq/startup_err 
[debug] <0.126.0> Lager installed handler lager_forwarder_backend into rabbit_log_channel_lager_event
[debug] <0.112.0> Lager installed handler {lager_file_backend,
                            "/var/log/rabbitmq/rab...@PRE-MQLLOG-VM1.log"} into lager_event
[debug] <0.129.0> Lager installed handler lager_forwarder_backend into rabbit_log_connection_lager_event
[debug] <0.117.0> Lager installed handler error_logger_lager_h into error_logger
[debug] <0.132.0> Lager installed handler lager_forwarder_backend into rabbit_log_mirroring_lager_event
[debug] <0.120.0> Lager installed handler lager_forwarder_backend into error_logger_lager_event
[debug] <0.135.0> Lager installed handler lager_forwarder_backend into rabbit_log_queue_lager_event
[debug] <0.123.0> Lager installed handler lager_forwarder_backend into rabbit_log_lager_event
[debug] <0.138.0> Lager installed handler lager_forwarder_backend into rabbit_log_federation_lager_event
[debug] <0.141.0> Lager installed handler syslog_lager_backend into rabbit_log_upgrade_lager_event
[debug] <0.143.0> Lager installed handler {lager_file_backend,
                            "/var/log/rabbitmq/rabbit@PRE-MQLLOG-VM1_upgrade.log"} into rabbit_log_upgrade_lager_event
[info] <0.8.0> Log file opened with Lager
[info] <0.8.0> Log file opened with Lager
[debug] <0.108.0> Lager installed handler lager_backend_throttle into lager_event
[error] <0.328.0> CRASH REPORT Process <0.328.0> with 0 neighbours exited with reason: bad argument in gen_tcp:connect/4 line 167
[error] <0.327.0> Supervisor {<0.327.0>,syslog} had child syslog_logger started with syslog_logger:start_link() at undefined exit with reason badarg in context start_error
[error] <0.325.0> CRASH REPORT Process <0.325.0> with 0 neighbours exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}} in application_master:init/4 line 138
[info] <0.43.0> Application syslog exited with reason: {{shutdown,{failed_to_start_child,syslog_logger,badarg}},{syslog,start,[normal,[]]}}
[info] <0.43.0> Application prometheus_cowboy exited with reason: stopped
[info] <0.43.0> Application prometheus_httpd exited with reason: stopped
[info] <0.43.0> Application amqp10_client exited with reason: stopped
[info] <0.43.0> Application inets exited with reason: stopped
[info] <0.43.0> Application amqp_client exited with reason: stopped
[info] <0.43.0> Application rabbit_common exited with reason: stopped
[info] <0.43.0> Application cowboy exited with reason: stopped
[info] <0.43.0> Application ranch exited with reason: stopped
[info] <0.43.0> Application ssl exited with reason: stopped
[info] <0.43.0> Application public_key exited with reason: stopped
[info] <0.43.0> Application asn1 exited with reason: stopped
[info] <0.43.0> Application prometheus exited with reason: stopped
[info] <0.43.0> Application recon exited with reason: stopped
[info] <0.43.0> Application xmerl exited with reason: stopped
[info] <0.43.0> Application jsx exited with reason: stopped
[info] <0.43.0> Application cowlib exited with reason: stopped
[info] <0.43.0> Application mnesia exited with reason: stopped

BOOT FAILED
===========

Error description:
    init:do_boot/3
    init:start_em/1
    rabbit:start_it/1 line 461
    rabbit:broker_start/0 line 337
    rabbit:start_apps/2 line 556
    app_utils:manage_applications/6 line 126
    lists:foldl/3 line 1263
    rabbit:'-handle_app_error/1-fun-0-'/3 line 652
throw:{could_not_start,syslog,
          {syslog,
              {{shutdown,{failed_to_start_child,syslog_logger,badarg}},
               {syslog,start,[normal,[]]}}}}
Log file(s) (may contain more information):
   /var/log/rabbitmq/rab...@PRE-MQLLOG-VM1.log
   /var/log/rabbitmq/rabbit@PRE-MQLLOG-VM1_upgrade.log

[info] <0.43.0> Application amqp10_common exited with reason: stopped
[info] <0.43.0> Application accept exited with reason: stopped
[info] <0.43.0> Application crypto exited with reason: stopped
[error] <0.8.0> 
Error description:
    init:do_boot/3
    init:start_em/1
    rabbit:start_it/1 line 461
    rabbit:broker_start/0 line 337
    rabbit:start_apps/2 line 556
    app_utils:manage_applications/6 line 126
    lists:foldl/3 line 1263
    rabbit:'-handle_app_error/1-fun-0-'/3 line 652
throw:{could_not_start,syslog,
          {syslog,
              {{shutdown,{failed_to_start_child,syslog_logger,badarg}},
               {syslog,start,[normal,[]]}}}}
Log file(s) (may contain more information):
   /var/log/rabbitmq/rab...@PRE-MQLLOG-VM1.log
   /var/log/rabbitmq/rabbit@PRE-MQLLOG-VM1_upgrade.log
init terminating in do_boot ({could_not_start,syslog,{syslog,{{shutdown,{_}},{syslog,start,[_]}}}})

Luke Bakken

unread,
Jan 28, 2019, 2:35:25 PM1/28/19
to rabbitmq-users
Hi Kevin,

You don't need any additional dependencies to publish to a remote syslog (or syslog-ng) server.

I was able to reproduce the same error you report using the attached Vagrantfile. I'm investigating now.

Thanks a lot for your patience and all of the information you're providing.

Luke

Luke Bakken

unread,
Jan 28, 2019, 2:56:56 PM1/28/19
to rabbitmq-users
Forgot to actually attach the Vagrantfile. I will follow up!
Vagrantfile

Luke Bakken

unread,
Jan 28, 2019, 4:44:17 PM1/28/19
to rabbitmq-users
Hi Kevin,

The issue is specific to the Erlang rpm package created by the RabbitMQ team - https://github.com/rabbitmq/erlang-rpm/issues/72 - this is why it took me so long to narrow it down, as I was using my own Erlang on my workstation which works fine. This is a very unexpected error.

I also tested the ESL Erlang packages and they have the same issue.


I will follow up once I determine what's going on.

Thanks,
Luke

Luke Bakken

unread,
Jan 28, 2019, 5:01:50 PM1/28/19
to rabbitmq-users
Hi Kevin,

Actually, this issue is not due to the Erlang packages, it's due to the changes in this PR:


Specifically, the change that sets the local listening address for the UDP connection to 127.0.0.1. I made this change, because without it, running netstat shows a UDP listener on all interfaces which freaks people out even though nothing is done with the data (https://serverfault.com/questions/933092/why-does-erlang-runtime-or-rabbitmq-listen-on-a-random-udp-port)

This listening address of 127.0.0.1 is passed to both the TCP and UDP listeners. Testing with this works fine on my workstation because syslog-ng is also listening on 127.0.0.1 so there is a route to that host. But, as soon as you use a different IP address, you will see the badarg error due to an unreachable network. It's too bad the error returned isn't more descriptive.

What I will do is revert that change. At this point your only option for a workaround would be to set up a syslog server on the same host as RabbitMQ and configure it to forward logs to your intended syslog host.

This fix will ship in RabbitMQ 3.7.11 which will be available soon.

Thanks -
Luke

On Monday, January 28, 2019 at 1:44:17 PM UTC-8, Luke Bakken wrote:
Hi Kevin,

Kevin Freeman

unread,
Jan 28, 2019, 5:29:07 PM1/28/19
to rabbitmq-users
Thank you, Luke, for the quick response.

Kevin
Reply all
Reply to author
Forward
0 new messages