Log the topic / queue / destination being used

[gregcorbett]

Would be useful in debugging "Topic doesn't exist" errors like the one below, we could skip the step of asking to see the sender config.

Probably also useful to log in a receiver as well.

SSM 3.2.0 sender log.

2021-06-10 09:42:02,000 - ssmsend - INFO - ========================================
2021-06-10 09:42:02,001 - ssmsend - INFO - Starting sending SSM version 3.2.0.
2021-06-10 09:42:02,001 - ssmsend - INFO - Setting up SSM with protocol: AMS
2021-06-10 09:42:02,002 - ssmsend - INFO - No AMS token provided, using cert/key pair instead.
2021-06-10 09:42:02,003 - ssmsend - INFO - No server certificate supplied.  Will not encrypt messages.
2021-06-10 09:42:02,003 - ssmsend - INFO - No path type defined, assuming dirq.
2021-06-10 09:42:02,085 - ssmsend - INFO - Messages will be signed using ****************
2021-06-10 09:42:02,137 - urllib3.connectionpool - INFO - Starting new HTTPS connection (1): msg.argo.grnet.gr
2021-06-10 09:42:05,094 - urllib3.connectionpool - DEBUG - "GET /v1/service-types/ams/hosts/msg.argo.grnet.gr:authx509 HTTP/1.1" 200 80
2021-06-10 09:42:05,216 - ssm.ssm2 - DEBUG - handle_connect called for AMS, doing nothing.
2021-06-10 09:42:05,217 - ssm.ssm2 - INFO - Found 6 messages.
2021-06-10 09:42:05,218 - ssm.ssm2 - WARNING - Message was locked. ************* will not be sent.
2021-06-10 09:42:05,219 - ssm.ssm2 - WARNING - Message was locked. ************* will not be sent.
2021-06-10 09:42:05,222 - ssm.ssm2 - INFO - Sending message: *************
2021-06-10 09:42:05,254 - urllib3.connectionpool - INFO - Starting new HTTPS connection (1): msg.argo.grnet.gr
SSM failed to complete successfully.  See log file for details.
2021-06-10 09:42:06,775 - ssmsend - ERROR - Unexpected exception in SSM: {'status': u'NOT_FOUND', 'status_code': 404, 'error': "While trying the [topic_publish]: Topic doesn't exist"}
2021-06-10 09:42:06,776 - ssmsend - ERROR - Exception type: <class 'argo_ams_library.amsexceptions.AmsServiceException'>
2021-06-10 09:42:06,777 - ssm.ssm2 - DEBUG - close_connection called for AMS, doing nothing.
2021-06-10 09:42:06,777 - ssmsend - INFO - SSM has shut down.
2021-06-10 09:42:06,778 - ssmsend - INFO - ========================================

[tofu-rocketry]

Did stomp.py log more info related to the destination? I seem to remember that there used to be that sort of info.

[gregcorbett]

🤷

[tofu-rocketry]

Ah, yes. With STOMP you'd get the additional lines I've bolded below in the receiver:

2021-07-04 03:22:05,238 - ssmreceive - INFO - ========================================
2021-07-04 03:22:05,238 - ssmreceive - INFO - Starting receiving SSM version 3.1.0.
2021-07-04 03:22:05,238 - ssmreceive - INFO - Setting up SSM with protocol: STOMP
2021-07-04 03:22:05,350 - ssmreceive - INFO - The SSM will run as a daemon.
2021-07-04 03:22:05,375 - ssmreceive - INFO - Fetching valid DNs.
2021-07-04 03:22:05,383 - ssm.ssm2 - INFO - Using stomp.py version 3.1.6.
2021-07-04 03:22:05,383 - ssm.ssm2 - INFO - Established connection to mq.cro-ngi.hr, port 6162
2021-07-04 03:22:05,383 - ssm.ssm2 - INFO - Connecting using SSL...
2021-07-04 03:22:05,655 - ssm.ssm2 - INFO - Connected.
2021-07-04 03:22:05,716 - ssm.ssm2 - INFO - Subscribing to: /queue/global.accounting.cpu.central
2021-07-04 03:22:05,754 - ssm.ssm2 - INFO - Received message. ID = 20210704/02233848101997

And in the sender:

2021-01-18 15:00:22,946 - ssmsend - INFO - ========================================
2021-01-18 15:00:22,958 - ssmsend - INFO - Starting sending SSM version 3.1.0.
2021-01-18 15:00:22,958 - ssmsend - INFO - Setting up SSM with protocol: STOMP
2021-01-18 15:00:22,958 - ssmsend - INFO - Retrieving broker details from ldap://lcg-bdii.cern.ch:2170 ...
2021-01-18 15:00:23,048 - ssmsend - INFO - Found 2 brokers.
2021-01-18 15:00:23,048 - ssmsend - INFO - No server certificate supplied. Will not encrypt messages.
2021-01-18 15:00:23,048 - ssmsend - INFO - No path type defined, assuming dirq.
2021-01-18 15:00:23,074 - ssm.ssm2 - INFO - Using stomp.py version 3.1.6.
2021-01-18 15:00:23,074 - ssm.ssm2 - INFO - Established connection to mq.cro-ngi.hr, port 6162
2021-01-18 15:00:23,074 - ssm.ssm2 - INFO - Connecting using SSL...
2021-01-18 15:00:23,346 - ssm.ssm2 - INFO - Connected.
2021-01-18 15:00:23,407 - ssm.ssm2 - INFO - Will send messages to: /queue/global.accounting.cpu.portal
2021-01-18 15:00:23,408 - ssm.ssm2 - INFO - Found 1318 messages.
2021-01-18 15:00:23,408 - ssm.ssm2 - INFO - Sending message: 6005a1bc/6005a1f7722e4c

These are probably generated by the STOMP callback handlers and we don't have an equivalent for AMS.

[jounaidr]

@apel/code-reviewers please see updated PR #177 :)