👌 IMPROVE: Add RMQ message logging

[chrisjsewell]

Add debug logging for sending task/rpc/broadcast to RMQ.

Note aio-pika does have message logging: https://github.com/mosquito/aio-pika/blob/94066fa900d9c08624d936f9b94037640267ac37/aio_pika/exchange.py#L220-L225, but it does not show the message body which is not very useful for debugging aiida-core, e.g.:

02/21/2021 06:34:26 AM <1075612> kiwipy.rmq.tasks: [DEBUG] Sending task with routing key 'aiida-49e364abe4394599af772f4bd4dba24a.process.queue' to RMQ queue 'aiida-49e364abe4394599af772f4bd4dba24a.tasks-reply-44cf8e9d-f4ae-4846-a934-8cd0d11d3e4f' (reply=False): {'task': 'continue', 'args': {'pid': 1308, 'nowait': False, 'tag': None}}

02/21/2021 06:34:26 AM <1075612> aio_pika.exchange: [DEBUG] Publishing message with routing key 'aiida-49e364abe4394599af772f4bd4dba24a.process.queue' via exchange <Exchange(aiida-49e364abe4394599af772f4bd4dba24a.tasks): auto_delete=False, durable=None, arguments={})>: Message:{'app_id': None,
 'body_size': 93,
 'content_encoding': None,
 'content_type': None,
 'correlation_id': 'b059c96a-4225-40dc-92eb-34138bdd9a8a',
 'delivery_mode': 2,
 'expiration': None,
 'headers': {},
 'message_id': None,
 'priority': 0,
 'reply_to': 'aiida-49e364abe4394599af772f4bd4dba24a.tasks-reply-44cf8e9d-f4ae-4846-a934-8cd0d11d3e4f',
 'timestamp': None,
 'type': 'None',
 'user_id': None}

02/21/2021 06:32:12 AM <1074374> kiwipy.rmq.communicator: [DEBUG] Sending broadcast with routing key '[broadcast]' to RMQ via exchange 'aiida-49e364abe4394599af772f4bd4dba24a.messages': {'body': None, 'sender': 1300, 'subject': 'state_changed.running.finished', 'correlation_id': None}

02/21/2021 06:32:12 AM <1074374> aio_pika.exchange: [DEBUG] Publishing message with routing key '[broadcast]' via exchange <Exchange(aiida-49e364abe4394599af772f4bd4dba24a.messages): auto_delete=False, durable=None, arguments={})>: Message:{'app_id': None,
 'body_size': 85,
 'content_encoding': None,
 'content_type': None,
 'correlation_id': None,
 'delivery_mode': 1,
 'expiration': None,
 'headers': {},
 'message_id': None,
 'priority': 0,
 'reply_to': None,
 'timestamp': None,
 'type': 'None',
 'user_id': None}

02/21/2021 06:34:39 AM <1075716> kiwipy.rmq.communicator: [DEBUG] Sending RPC with routing key '[rpc].1308' to RMQ queue 'aiida-49e364abe4394599af772f4bd4dba24a.messages-reply-2c5e701a-2e74-47ee-93dd-37a7d2785cba': {'intent': 'kill', 'message': 'Killed through `verdi process kill`'}

02/21/2021 06:34:39 AM <1075716> aio_pika.exchange: [DEBUG] Publishing message with routing key '[rpc].1308' via exchange <Exchange(aiida-49e364abe4394599af772f4bd4dba24a.messages): auto_delete=False, durable=None, arguments={})>: Message:{'app_id': None,
 'body_size': 58,
 'content_encoding': None,
 'content_type': None,
 'correlation_id': '8cf6434c-2502-4193-9085-79f008e61c8a',
 'delivery_mode': 1,
 'expiration': None,
 'headers': {},
 'message_id': None,
 'priority': 0,
 'reply_to': 'aiida-49e364abe4394599af772f4bd4dba24a.messages-reply-2c5e701a-2e74-47ee-93dd-37a7d2785cba',
 'timestamp': None,
 'type': 'None',
 'user_id': None}

Also, just out of interest I traced the call chain for sending a kill message:

verdi process kill

plumpy.process_comms.RemoteProcessThreadController.kill_process msg={"intent": "kill", "message": "..."}
-> kiwipy.rmq.threadcomms.RmqThreadCommunicator.rpc_send (wrap syncio await with timeout)
-> async kiwipy.rmq.communicator.RMQCommunicator.rpc_send
-> async kiwipy.rmq.communicator.RmqPublisher.rpc_send (converts message to aio_pika.Message)
-> async kiwipy.rmq.messages.BasePublisherWithReplyQueue.publish_expect_response
-> async kiwipy.rmq.messages.BasePublisherWithReplyQueue.publish
-> async aio_pika.exchange.Exchange.publish
-> async aiormq.channel.Channel.basic_publish

lot of steps

[codecov[bot]]

Codecov Report

All modified and coverable lines are covered by tests :white_check_mark:

Project coverage is 90.24%. Comparing base (22ebb81) to head (7f8a453).

Additional details and impacted files

```diff @@ Coverage Diff @@ ## develop #100 +/- ## =========================================== + Coverage 90.21% 90.24% +0.04% =========================================== Files 16 16 Lines 1123 1127 +4 =========================================== + Hits 1013 1017 +4 Misses 110 110 ```

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.