学会查看 RabbitMQ日志

如果在使用RabbitMQ的过程中出现了异常情况，通过翻阅RabbitMQ的服务日志可以让你在处理异常的过程中事半功倍。RabbitMQ日志中会有明确的事件日期、事件内容以及事件等级等。RabbitMQ的日志默认存放在$RABBITMQ_HOME/var/log/rabbitmq目录下。本问主要从RabbitMQ服务开启、RabbitMQ服务关闭以及RabbitMQ集群搭建的角度来举例说明RabbitMQ的日志的一些查看思路。

各位读者实际使用的RabbitMQ版本各有差异，这里我们挑选一个偏旧版本（3.6.2）来统筹说明，以期不会有太大的偏差。所幸各个版本的日志大致相同，也会有略微变化。读者需要培养一种使用服务日志来解决问题的思路，本文只做抛砖引玉之用。

欢迎支持笔者新作：《深入理解Kafka:核心设计与实践原理》和《RabbitMQ实战指南》，同时欢迎关注笔者的微信公众号：朱小厮的博客。

欢迎跳转到本文的原文链接：https://honeypps.com/mq/how-to-review-rabbitmq-log/

启动RabbitMQ服务

启动RabbitMQ服务可以使用rabbitmq-server -detached命令，这个命令会顺带启动Erlang虚拟机和RabbitMQ应用服务，而rabbitmqctl start_app用来启动RabbitMQ应用服务。注意RabbitMQ应用服务启动的前提是Erlang虚拟机是运转正常的。首先这里来看下在执行完rabbitmq-server -detached命令其相应的服务日志是什么。

Starting RabbitMQ 3.6.2 on Erlang 19.1
Copyright (C) 2007-2016 Pivotal Software, Inc.
Licensed under the MPL.  See http://www.rabbitmq.com/=INFO REPORT==== 3-Jul-2017::10:52:08 ===
node           : rabbit@node1
home dir       : /root
config file(s) : /opt/rabbitmq/etc/rabbitmq/rabbitmq.config (not found)
cookie hash    : VCwbL3S9/ydrGgVsrLjVkA==
log            : /opt/rabbitmq/var/log/rabbitmq/rabbit@node1.log
sasl log       : /opt/rabbitmq/var/log/rabbitmq/rabbit@node1-sasl.log
database dir   : /opt/rabbitmq/var/lib/rabbitmq/mnesia/rabbit@node1=INFO REPORT==== 3-Jul-2017::10:52:09 ===
Memory limit set to 3148MB of 7872MB total.=INFO REPORT==== 3-Jul-2017::10:52:09 ===
Disk free limit set to 50MB=INFO REPORT==== 3-Jul-2017::10:52:09 ===
Limiting to approx 924 file handles (829 sockets)=INFO REPORT==== 3-Jul-2017::10:52:09 ===
FHC read buffering:  OFF
FHC write buffering: ON=INFO REPORT==== 3-Jul-2017::10:52:09 ===
Database directory at /opt/rabbitmq/var/lib/rabbitmq/mnesia/rabbit@node1 is empty. Initialising from scratch...=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Priority queues enabled, real BQ is rabbit_variable_queue=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Adding vhost '/'=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Creating user 'guest'=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Setting user tags for user 'guest' to [administrator]=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Setting permissions for 'guest' in '/' to '.*', '.*', '.*'=INFO REPORT==== 3-Jul-2017::10:52:10 ===
msg_store_transient: using rabbit_msg_store_ets_index to provide index=INFO REPORT==== 3-Jul-2017::10:52:10 ===
msg_store_persistent: using rabbit_msg_store_ets_index to provide index=WARNING REPORT==== 3-Jul-2017::10:52:10 ===
msg_store_persistent: rebuilding indices from scratch=INFO REPORT==== 3-Jul-2017::10:52:10 ===
started TCP Listener on [::]:5672=INFO REPORT==== 3-Jul-2017::10:52:10 ===
Server startup complete; 0 plugins started.

这段日志包含了RabbitMQ的版本号、Erlang的版本号、RabbitMQ服务节点名称、cookie的hash值、RabbitMQ配置文件地址、内存限制、磁盘限制、默认账户guest的创建以及权限配置等等。如果是安装了rabbitmq_management插件的话，在启动rabbitmq的时候会多打印一些日志：

=INFO REPORT==== 3-Jul-2017::10:57:05 ===
Server startup complete; 6 plugins started.* rabbitmq_management* rabbitmq_management_agent* rabbitmq_web_dispatch* webmachine* mochiweb* amqp_client

当然还包括一些统计值信息的初始化日志，类似如下日志。

=INFO REPORT==== 3-Jul-2017::10:57:05 ===
Statistics garbage collector started for table {aggr_queue_stats_fine_stats,5000}.

与aggr_queue_stats_fine_stats日志一起的还有aggr_queue_stats_deliver_get，aggr_queue_stats_queue_msg_counts，channel_stats，connection_stats等等几十种。对于这些统计值，不同的版本可能略有差异，一般情况下对此无需过多探究。

如果你是使用rabbitmqctl stop_app命令关闭的RabbitMQ应用服务，那么你在使用rabbitmqctl start_app命令开启RabbitMQ应用服务的时候的启动日志和rabbitmq-server的启动日志相同。

关闭RabbitMQ服务

如果使用rabbitmqctl stop命令，会将Erlang虚拟机一同关闭，而rabbitmqctl stop_app只关闭RabbitMQ应用服务，在关闭的时候要多加注意之间的区别。下面先看一下rabbitmqctl stop_app所对应的服务日志：

=INFO REPORT==== 3-Jul-2017::10:54:01 ===
Stopping RabbitMQ=INFO REPORT==== 3-Jul-2017::10:54:01 ===
stopped TCP Listener on [::]:5672=INFO REPORT==== 3-Jul-2017::10:54:01 ===
Stopped RabbitMQ application

如果采用rabbitmqctl stop来进行关闭操作，则会多出下面的日志信息，即关闭Erlang虚拟机。

=INFO REPORT==== 3-Jul-2017::10:54:01 ===
Halting Erlang VM

建立集群

建立集群也是一种常用的操作。这里举例将节点rabbit@node2与rabbit@node1组成一个集群，有关如何建立RabbitMQ集群的细节可以参考RabbitMQ的安装及集群搭建方法。
首先在节点rabbit@node2中执行rabbitmq-server -detached开启Erlang VM以及RabbitMQ应用服务，之后再执行rabbitmqctl stop_app来关闭RabbitMQ应用服务，具体的日志可以参考前面的内容。之后需要重置节点rabbit@node2中的数据rabbitmqctl reset，相应的在节点rabbit@node2上的日志如下：

=INFO REPORT==== 3-Jul-2017::11:25:01 ===
Resetting Rabbit

在rabbit@node2节点上执行rabbitmqctl join_clcuster rabbit@node1将其加入到rabbit@node1中以组成一个集群，相应的在rabbit@node2节点中会打印日志：

=INFO REPORT==== 3-Jul-2017::11:30:46 ===
Clustering with [rabbit@node1] as disc node

与此同时在rabbit@node1中会有日志：

=INFO REPORT==== 3-Jul-2017::11:30:56 ===
node rabbit@node2 up

最后重启rabbit@node2节点，至于rabbit@node2中此时的日志可以参考前面的rabbitmq-server -detached或者rabbitmqctl start_app的启动日志。而此时在rabbit@node1节点中会有日志如下：

=INFO REPORT==== 3-Jul-2017::11:45:14 ===
rabbit on node rabbit@node2 up

如果此时在rabbit@node2节点上执行rabbitmqctl stop_app的动作，那么在rabbit@node1节点中会有如下信息：

=INFO REPORT==== 3-Jul-2017::11:54:01 ===
rabbit on node rabbit@node2 down=INFO REPORT==== 3-Jul-2017::11:54:01 ===
Keep rabbit@node2 listeners: the node is already back

通过上面的日志你可以看出某个RabbitMQ节点在某个时段的关闭启动的动作。可以通过尝试各种的操作以收集相应的服务日志，之后组成一个知识集，这个知识集不单指一个日志列表，可以通过后期的强化训练掌握其规律，让这个知识集了然于心。在真正遇到异常故障的时候可以通过查看服务日志来迅速的定位问题的根本，之后再采取相应的措施以解决问题。

这里博主有个心得，仅供参考，在执行任何RabbitMQ操作之前，都会打开一个新的窗口运行tail -f $RABBITMQ_HOME/var/log/rabbitmq/rabbit@$HOSTNAME.log -n 200命令来实时查看相应操作所对应的服务日志是什么，久而久之即可在脑海中建立一个相对完备的“知识集”。

欢迎跳转到本文的原文链接：https://honeypps.com/mq/how-to-review-rabbitmq-log/

欢迎支持笔者新作：《深入理解Kafka:核心设计与实践原理》和《RabbitMQ实战指南》，同时欢迎关注笔者的微信公众号：朱小厮的博客。