Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

164 log the topic #177

Merged
merged 14 commits into from
Aug 9, 2022
Merged

164 log the topic #177

merged 14 commits into from
Aug 9, 2022

Conversation

jounaidr
Copy link
Contributor

@jounaidr jounaidr commented Aug 17, 2021

Resolves #164

Log output for sender.py:


2021-08-17 14:46:40,595 - ssmsend - INFO - ========================================
2021-08-17 14:46:40,595 - ssmsend - INFO - Starting sending SSM version 3.2.1.
2021-08-17 14:46:40,595 - ssmsend - INFO - Setting up SSM with protocol: AMS
2021-08-17 14:46:40,596 - ssmsend - INFO - No AMS token provided, using cert/key pair instead.
2021-08-17 14:46:40,596 - ssmsend - INFO - No server certificate supplied.  Will not encrypt messages.
2021-08-17 14:46:40,596 - ssmsend - INFO - Configured destination queue: gLite-APEL
2021-08-17 14:46:40,612 - ssmsend - INFO - Messages will be signed using /C=UK/L=Harwell/O=UKRI/OU=SCD/CN=host-172-16-113-220.nubes.stfc.ac.uk
SSM failed to complete successfully.  See log file for details.
2021-08-17 14:46:40,911 - ssmsend - ERROR - Unexpected exception in SSM: While trying the [auth_x509]: SSLError(MaxRetryError("HTTPSConnectionPool(host='msg-devel.argo.grnet.gr', port=8443): Max retries exceeded with url: /v1/service-types/ams/hosts/msg-devel.argo.grnet.gr:authx509 (Caused by SSLError(SSLError(1, u'[SSL: SSLV3_ALERT_BAD_CERTIFICATE] sslv3 alert bad certificate (_ssl.c:618)'),))",),)
2021-08-17 14:46:40,911 - ssmsend - ERROR - Exception type: 
2021-08-17 14:46:40,912 - ssmsend - INFO - SSM has shut down.
2021-08-17 14:46:40,912 - ssmsend - INFO - ========================================

Log output for receiver.py:


2021-08-17 14:48:04,611 - ssmreceive - INFO - ========================================
2021-08-17 14:48:04,611 - ssmreceive - INFO - Starting receiving SSM version 3.2.1.
2021-08-17 14:48:04,611 - ssmreceive - INFO - Setting up SSM with protocol: AMS
2021-08-17 14:48:04,612 - ssmreceive - INFO - No AMS token provided, using cert/key pair instead.
2021-08-17 14:48:04,612 - ssmreceive - INFO - The SSM will run as a daemon.
2021-08-17 14:48:04,612 - ssmreceive - INFO - Configured destination queue: /queue/ssm2test
2021-08-17 14:48:04,869 - ssmreceive - CRITICAL - Failed to initialise SSM: While trying the [auth_x509]: SSLError(MaxRetryError("HTTPSConnectionPool(host='msg-devel.argo.grnet.gr', port=8443): Max retries exceeded with url: /v1/service-types/ams/hosts/msg-devel.argo.grnet.gr:authx509 (Caused by SSLError(SSLError(1, u'[SSL: SSLV3_ALERT_BAD_CERTIFICATE] sslv3 alert bad certificate (_ssl.c:618)'),))",),)
2021-08-17 14:48:04,870 - ssmreceive - INFO - ========================================

Note that for testing purposes a new certificate was used, which is what's causing the error seen in the above logs.

@jounaidr
Copy link
Contributor Author

jounaidr commented Aug 21, 2021

Attempts to unit test the logging proved to be quite difficult, and all though it would be nice to have, since this is a small change I don't think its necessary to add.

@jounaidr jounaidr marked this pull request as ready for review August 21, 2021 15:02
@jounaidr jounaidr requested a review from a team as a code owner August 21, 2021 15:02
@tofu-rocketry tofu-rocketry self-assigned this Aug 24, 2021
@tofu-rocketry tofu-rocketry added this to the 3.3.0 milestone Aug 24, 2021
@jounaidr
Copy link
Contributor Author

jounaidr commented Sep 4, 2021

New logs based on updated comments from issue #164, the logging messages are the same as is seen with STOMP, however, no port is logged as it is not required for AMS see:

ssm/ssm/agents.py

Lines 148 to 152 in db3dace

# We only need a hostname, not a port
host = cp.get('broker', 'host')
# Use brokers variable so subsequent code is not dependant on
# the exact destination type.
brokers = [host]

Sender log:


2021-09-04 00:13:17,951 - ssmsend - INFO - ========================================
2021-09-04 00:13:17,951 - ssmsend - INFO - Starting sending SSM version 3.2.1.
2021-09-04 00:13:17,951 - ssmsend - INFO - Setting up SSM with protocol: AMS
2021-09-04 00:13:17,952 - ssmsend - INFO - No server certificate supplied.  Will not encrypt messages.
2021-09-04 00:13:17,969 - ssmsend - INFO - Messages will be signed using /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:13:18,011 - ssm.ssm2 - INFO - Using AMS version 0.5.5
2021-09-04 00:13:18,011 - ssm.ssm2 - INFO - Establishing connection to msg-devel.argo.grnet.gr
2021-09-04 00:13:18,011 - ssm.ssm2 - INFO - Will send messages to: test
2021-09-04 00:13:18,011 - ssm.ssm2 - INFO - Found 1 messages.
2021-09-04 00:13:18,012 - ssm.ssm2 - INFO - Sending message: testmessage
2021-09-04 00:13:18,302 - ssm.ssm2 - INFO - Sent testmessage, Argo ID: 55
2021-09-04 00:13:18,303 - ssm.ssm2 - INFO - Tidying message directory.
2021-09-04 00:13:18,303 - ssmsend - INFO - SSM run has finished.
2021-09-04 00:13:18,304 - ssmsend - INFO - SSM has shut down.
2021-09-04 00:13:18,304 - ssmsend - INFO - ========================================

Receiver log:


2021-09-04 00:32:23,225 - ssmreceive - INFO - ========================================
2021-09-04 00:35:00,948 - ssmreceive - INFO - ========================================
2021-09-04 00:35:00,949 - ssmreceive - INFO - Starting receiving SSM version 3.2.1.
2021-09-04 00:35:00,949 - ssmreceive - INFO - Setting up SSM with protocol: AMS
2021-09-04 00:35:00,949 - ssmreceive - INFO - The SSM will run as a daemon.
2021-09-04 00:35:00,989 - ssmreceive - INFO - Fetching valid DNs.
2021-09-04 00:35:01,007 - ssm.ssm2 - INFO - Using AMS version 0.5.5
2021-09-04 00:35:01,008 - ssm.ssm2 - INFO - Establishing connection to msg-devel.argo.grnet.gr
2021-09-04 00:35:01,008 - ssm.ssm2 - INFO - Subscribing to: testsub
2021-09-04 00:35:01,693 - ssm.ssm2 - INFO - Received message. ID = test.txt, Argo ID = 51
2021-09-04 00:35:01,757 - ssm.ssm2 - INFO - Valid signer: /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:35:01,758 - ssm.ssm2 - INFO - Message saved to incoming queue as 00000000/6132bf35b938bb
2021-09-04 00:35:02,016 - ssmreceive - INFO - Refreshing valid DNs and then sending ping.
2021-09-04 00:35:02,637 - ssm.ssm2 - INFO - Received message. ID = testmessage, Argo ID = 52
2021-09-04 00:35:02,703 - ssm.ssm2 - INFO - Valid signer: /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:35:02,703 - ssm.ssm2 - INFO - Message saved to incoming queue as 00000000/6132bf36abd4ab
2021-09-04 00:35:03,617 - ssm.ssm2 - INFO - Received message. ID = testmessage, Argo ID = 53
2021-09-04 00:35:03,679 - ssm.ssm2 - INFO - Valid signer: /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:35:03,679 - ssm.ssm2 - INFO - Message saved to incoming queue as 00000000/6132bf37a5fc4b
2021-09-04 00:35:04,550 - ssm.ssm2 - INFO - Received message. ID = testmessage, Argo ID = 54
2021-09-04 00:35:04,615 - ssm.ssm2 - INFO - Valid signer: /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:35:04,616 - ssm.ssm2 - INFO - Message saved to incoming queue as 00000000/6132bf3896717b
2021-09-04 00:35:05,493 - ssm.ssm2 - INFO - Received message. ID = testmessage, Argo ID = 55
2021-09-04 00:35:05,558 - ssm.ssm2 - INFO - Valid signer: /C=UK/O=eScience/OU=CLRC/L=RAL/CN=host-172-16-113-220.nubes.stfc.ac.uk
2021-09-04 00:35:05,559 - ssm.ssm2 - INFO - Message saved to incoming queue as 00000000/6132bf3988a15b

Also note that the ams package does not have a '.__version__' attribute associated with it, therefore pkg_resources.get_distribution() package has been imported and utilised.

Copy link
Member

@tofu-rocketry tofu-rocketry left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like the overall solution, but just need to be a bit more conservative in places.

@tofu-rocketry tofu-rocketry force-pushed the 164-log-the-topic branch 2 times, most recently from 7240e1b to b76fc05 Compare August 2, 2022 09:10
jounaidr and others added 10 commits August 2, 2022 12:28
This seperates out a helper method, and adds said method to run_reveiver
and run_sender methods in agents.py

Signed-off-by: jounaidr <[email protected]>
Add extra logging for AMS including version, host and port, and
destination queue (as is with STOMP).

Signed-off-by: jounaidr <[email protected]>
- Version only requires 1 string argument as it's taken using
  pkg_resources.get_distribution
- Port is omitted as it's not required for AMS

Signed-off-by: jounaidr <[email protected]>
With method contents only in run_sender(), as since the logging is done
elsewhere, this change is out of scope for this issue (although it would
probably be better still to have).

Signed-off-by: jounaidr <[email protected]>
As it's only to enhance the logging, we'll just log the version of
argo_ams_library if the module is available. pkg_resources is
distributed with setuptools, which is commonly installed, but we don't
want to add any dependencies for this "nice to have" functionality.
This reverts commit 46756d1.
We don't need to make the use of pkg_resources optional as setuptools
(which includes it) is already a dependency of python-ldap.
We use pkg_resources with is distributed with setuptools. Even though
setuptools is a dependency of python-ldap, so it would get installed
during dependency resolution, it's best to be explicit.
argo-ams-library is no longer experimental
@tofu-rocketry
Copy link
Member

tofu-rocketry commented Aug 3, 2022

More testing (ignore pidfile warning):

sender.py


2022-08-03 09:09:40,043 - ssmsend - INFO - ========================================
2022-08-03 09:09:40,044 - ssmsend - INFO - Starting sending SSM version 3.2.1.
2022-08-03 09:09:40,044 - ssmsend - INFO - Setting up SSM with protocol: AMS
2022-08-03 09:09:40,044 - ssmsend - INFO - No server certificate supplied.  Will not encrypt messages.
2022-08-03 09:09:40,062 - ssmsend - INFO - Messages will be signed using /C=XX/L=Default City/O=Default Company Ltd
2022-08-03 09:09:40,097 - ssm.ssm2 - INFO - Using AMS version 0.5.9
2022-08-03 09:09:40,097 - ssm.ssm2 - INFO - Will connect to msg-devel.argo.grnet.gr
2022-08-03 09:09:40,097 - ssm.ssm2 - INFO - Will send messages to: test
2022-08-03 09:09:40,097 - ssm.ssm2 - INFO - Found 1 messages.
...

receiver.py


2022-08-03 09:09:54,810 - ssmreceive - INFO - ========================================
2022-08-03 09:09:54,810 - ssmreceive - INFO - Starting receiving SSM version 3.2.1.
2022-08-03 09:09:54,810 - ssmreceive - INFO - Setting up SSM with protocol: AMS
2022-08-03 09:09:54,810 - ssmreceive - INFO - The SSM will run as a daemon.
2022-08-03 09:09:54,843 - ssmreceive - INFO - Fetching valid DNs.
2022-08-03 09:09:54,854 - ssm.ssm2 - WARNING - Failed to create pidfile /var/run/apel/ssmreceive.pid: [Errno 2] No such file or directory: '/var/run/apel/ssmreceive.pid'
2022-08-03 09:09:54,856 - ssm.ssm2 - INFO - Using AMS version 0.5.9
2022-08-03 09:09:54,856 - ssm.ssm2 - INFO - Will connect to msg-devel.argo.grnet.gr
2022-08-03 09:09:54,856 - ssm.ssm2 - INFO - Will subscribe to: testsub
2022-08-03 09:09:55,482 - ssm.ssm2 - INFO - Received message. ID = msg6, Argo ID = 106
...

@tofu-rocketry tofu-rocketry merged commit 0fb7c64 into apel:dev Aug 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

Log the topic / queue / destination being used
3 participants