[asterisk-commits] channels/pjsip/subscriptions/rls - Improve logging (testsuite[master])

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Fri Jun 5 15:45:05 CDT 2015


Mark Michelson has submitted this change and it was merged.

Change subject: channels/pjsip/subscriptions/rls - Improve logging
......................................................................


channels/pjsip/subscriptions/rls - Improve logging

The primary purpose of this is to improve logging in the RLS tests so that
the exact phases of the test and expectations being evaluated are known
at any given time when reviewing logs. In addition, some improvements have
been made to the integrity checks so that failures are reported back to the
rls_test module.

ASTERISK-25144
Reported by: Jonathan Rose

Change-Id: Iea3f5bb8a424d7ff813a85d6c8224a14ebc3e0dd
---
M tests/channels/pjsip/subscriptions/rls/rls_integrity.py
M tests/channels/pjsip/subscriptions/rls/rls_test.py
2 files changed, 164 insertions(+), 35 deletions(-)

Approvals:
  Mark Michelson: Looks good to me, approved; Verified
  Joshua Colp: Looks good to me, but someone else must approve



diff --git a/tests/channels/pjsip/subscriptions/rls/rls_integrity.py b/tests/channels/pjsip/subscriptions/rls/rls_integrity.py
index c886cd6..7f0f0d6 100755
--- a/tests/channels/pjsip/subscriptions/rls/rls_integrity.py
+++ b/tests/channels/pjsip/subscriptions/rls/rls_integrity.py
@@ -1,4 +1,11 @@
 #/usr/bin/env python
+"""
+Copyright (C) 2015, Digium, Inc.
+Jonathan Rose <jrose at digium.com>
+
+This program is free software, distributed under the terms of
+the GNU General Public License Version 2.
+"""
 
 import logging
 import xml.etree.ElementTree as ET
@@ -15,9 +22,9 @@
     """General class that validates a multipart RLS NOTIFY body"""
     def __init__(self, test_object, packet, version, full_state, list_name,
                  resources):
-        """Initializer
+        """Constructor
 
-        Keyword Arguments:
+        Arguments:
         test_object The test object for the running test.
         packet The Multipart NOTIFY body in full.
         version The expected RLMI version attribute. Expressed as an integer.
@@ -38,16 +45,28 @@
         self.resource_cids = {}
 
     def validate_body_part(self, part, resources, rlmi, list_name):
-        """Validates a single body part against the appropriate packet type validator
+        """Validates a single body part against the its packet type validator
+
+        Note: Will mark the test as failed if the packet does not match
+        expectations
+
+        Returns:
+        True if the component matched expectations
+        False if the component did not match expectations
         """
         if part.body.packet_type == 'RLMI':
-            self.validate_rlmi(part.body.list_elem, resources, list_name)
+            return self.validate_rlmi(part.body.list_elem, resources,
+                                      list_name)
         elif part.body.packet_type == 'PIDF':
-            self.validate_pidf(part.body, resources)
+            return self.validate_pidf(part.body, resources)
         elif part.body.packet_type == 'MWI':
-            self.validate_mwi(part.body, resources, rlmi)
+            return self.validate_mwi(part.body, resources, rlmi)
         elif part.body.packet_type == 'Multipart':
-            self.validate_multipart(part, resources)
+            return self.validate_multipart(part, resources)
+
+        msg = "Unrecognized body part packet type of '{0}'"
+        self.fail_test(msg.format(part.body.packet_type))
+        return False
 
     def check_integrity(self):
         """Validates a multipart RLS body
@@ -55,6 +74,11 @@
         If the multipart body does not pass validation, then the test will
         fail. If this method returns at all, it means that the body passed
         validation.
+
+        Returns:
+        True if the multipart RLS body matches the expectations provided at
+             construction
+        False if the multipart RLS body does not match the expectations
         """
         rlmi = None
 
@@ -62,6 +86,7 @@
         if len(self.packet.body.parts) != len(self.resources) + 1:
             self.fail_test("Unexpected number of parts (%d) in multipart body"
                            % len(self.packet.body.parts))
+            return False
 
         rlmi_parts = count_parts(self.packet.body.parts, 'RLMI')
         resource_parts = len(self.packet.body.parts) - 1
@@ -69,10 +94,12 @@
         if rlmi_parts != 1:
             self.fail_test("Unexpected number of RLMI parts (%d) in multipart"
                            "body" % rlmi_parts)
+            return False
 
         if resource_parts != len(self.resources):
             self.fail_test("Unexpected number of parts (%d) in multipart"
                            "body" % resource_parts)
+            return False
 
         for part in self.packet.body.parts:
             if part.body.packet_type == 'RLMI':
@@ -80,21 +107,29 @@
                 break
 
         for part in self.packet.body.parts:
-            self.validate_body_part(part, self.resources, rlmi, self.list_name)
+            x = self.validate_body_part(part, self.resources, rlmi,
+                                        self.list_name)
+            if not x:
+                return False
 
         if len(self.rlmi_cids) != len(self.resource_cids):
             self.fail_test("Gathered mismatching number of Content IDs. RLMI"
                            "document has %d. Should have %d" %
                            (len(self.rlmi_cids), len(self.resource_cids)))
+            return False
 
         for uri, cid in self.rlmi_cids.iteritems():
             if uri not in self.resource_cids:
                 self.fail_test("URI not found in %s documents" %
                                (uri))
+                return False
             if self.resource_cids.get(uri) != cid:
                 self.fail_test("Mismatching Content ID for URI %s. RLMI"
                                "document has %s. Document has %s" %
                                (uri, cid, self.resource_cids.get(uri)))
+                return False
+
+        return True
 
     def validate_rlmi(self, list_elem, resources, list_name):
         """Validate an RLMI document
@@ -103,31 +138,39 @@
         into a helper method to check the integrity of each resource
         element in the list.
 
-        Keyword Arguments:
+        Arguments:
         list_elem The XML <list> element in the RLMI body, as parsed by pyxb
         resources The expected resources dictionary relevant to this RLMI body
         """
+
         if list_elem.version != self.version:
             self.fail_test("Unexpected RLMI version %d" % list_elem.version)
+            return False
 
         if list_elem.fullState != self.full_state:
             self.fail_test("Unexpected fullState value %s" %
                            str(list_elem.fullState))
+            return False
 
         if len(list_elem.name) != 1:
             self.fail_test("Unexpected number of names (%d) in RLMI list" %
                            len(list_elem.name))
+            return False
 
         if len(list_elem.resource) != len(resources):
             self.fail_test("Unexpected number of resources (%d) in RLMI list" %
                            len(list_elem.resource))
+            return False
 
         if list_elem.name[0].value() != list_name:
             self.fail_test("Unexpected list name: %s" %
                            list_elem.name[0].value())
+            return False
 
         for resource in list_elem.resource:
-            self.validate_rlmi_resource(resource, resources)
+            if not self.validate_rlmi_resource(resource, resources):
+                return False
+        return True
 
     def validate_rlmi_resource(self, rlmi_resource, resources):
         """Validate an RLMI resource
@@ -135,7 +178,7 @@
         This method checks the integrity of a resource XML element within an
         RLMI list.
 
-        Keyword Arguments:
+        Arguments:
         rlmi_resource The XML <resource> element in the RLMI <list>, as parsed
         by pyxb
         resources The expected resources dictionary relevant to this RLMI
@@ -143,31 +186,40 @@
         """
         if not rlmi_resource.uri:
             self.fail_test("Resource is missing a URI")
+            return False
 
         if len(rlmi_resource.name) != 1:
             self.fail_test("Unexpected number of names (%d) in resource" %
                            len(rlmi_resource.name))
+            return False
 
         if len(rlmi_resource.instance) != 1:
             self.fail_test("Unexpeced number of instances (%d) in resource" %
                            len(rlmi_resource.instance))
+            return False
 
         name = rlmi_resource.name[0].value()
         if name not in resources:
             self.fail_test("Unexpected resource name %s" % name)
+            return False
 
         instance = rlmi_resource.instance[0]
         if not instance.state:
             self.fail_test("Resource instance has no state")
+            return False
         if not instance.id:
             self.fail_test("Resource instance has no id")
+            return False
         if not instance.cid:
             self.fail_test("Resource instance has no cid")
+            return False
 
         if instance.state != resources[name]['state']:
             self.fail_test("Unexpected instance state %s" % instance.state)
+            return False
 
         self.rlmi_cids[rlmi_resource.uri] = rlmi_resource.instance[0].cid
+        return True
 
     def validate_pidf(self, pidf_part, resources):
         """Validates the integrity of a PIDF body
@@ -175,25 +227,33 @@
         This uses XML ElementTree to parse the PIDF body and ensures basic
         structural elements (as they relate to RLS) are present.
 
-        Keyword Arguments:
+        Arguments:
         pidf_part The PIDF part from a multipart body.
         resources The expected resources dictionary relevant to this PIDF body
+
+        Returns:
+        True if the pidf_part matched the expectations in resources
+        False if the pidf_part did not match the expectations in resources
         """
 
         if not pidf_part.content_id:
             self.fail_test("PIDF part does not have a Content-ID")
+            return False
 
         try:
             root = ET.fromstring(pidf_part.xml)
         except Exception as ex:
             self.fail_test("Exception when parsing PIDF XML: %s" % ex)
+            return False
 
         entity = root.get('entity')
         if not entity:
             self.fail_test("PIDF document root has no entity")
+            return False
 
         stripped_entity = entity.strip('<>')
         self.resource_cids[stripped_entity] = pidf_part.content_id
+        return True
 
     def validate_mwi(self, mwi_part, resources, rlmi):
         """Validates the integrity of an MWI body
@@ -202,16 +262,22 @@
         name and URI can be determined and linked to the appropriate
         resource.
 
-        Keyword Arguments:
+        Arguments:
         mwi_part The MWI part from a multipart body
         resources The expected resources dictionary relevant to this MWI body
         rlmi The rlmi that described the WMI body
+
+        Returns:
+        True if the mwi_part matched the expectations in resources
+        False if the mwi_part did not match the expectations in resources
         """
         if not mwi_part.content_id:
-            self.fail_test("WMI part does not have a Content-ID")
+            self.fail_test("MWI part does not have a Content-ID")
+            return False
 
         if not rlmi:
             self.fail_test("MWI part has now RLMI body")
+            return False
 
         my_name = None
         my_uri = None
@@ -221,33 +287,38 @@
             if resource.instance[0].cid == mwi_part.content_id:
                 my_name = resource.name[0].value()
                 my_uri = resource.uri
-                break;
+                break
 
         if not my_name:
             self.fail_test("Couldn't find MWI part with Content ID '%s' in "
                            "MWI body" % mwi_part.content_id)
-            return
+            return False
 
         if not my_uri:
             self.fail_test("URI not found for resource '%s'" % my_name)
-            return
+            return False
 
         relevant_resource = resources.get(my_name)
         if not relevant_resource:
-            self.fail_test("MWI '%s' not specified in expected resources" % my_name)
-            return
+            self.fail_test("MWI '%s' not specified in expected resources" %
+                           my_name)
+            return False
 
         if relevant_resource['type'] != 'MWI':
             self.fail_test("Resource expected type isn't an MWI type.")
-            return
+            return False
 
         if relevant_resource['voice_message'] != mwi_part.voice_message:
             self.fail_test("Voice-Message header doesn't match expectations")
+            return False
 
         if relevant_resource['messages_waiting'] != mwi_part.messages_waiting:
-            self.fail_test("Messages-Waiting header doesn't match expectations")
+            self.fail_test("Messages-Waiting header doesn't match " +
+                           "expectations")
+            return False
 
         self.resource_cids[my_uri] = mwi_part.content_id
+        return True
 
     def validate_multipart(self, multi_part, resources):
         """Validates the integrity of a Multipart body
@@ -256,16 +327,21 @@
         in order to recursively evaluate each element contained
         within.
 
-        Keyword Arguments:
+        Arguments:
         multi_part The Multipart part from a multipart body.
         resources The expected resources dictionary relevant for this
             multipart body. May be the full list specified by the test
             or a deeper node.
+
+        Returns:
+        True if the multi_part body matches the expectations in resources
+        False if the multi_part body does not match the expectations
         """
         rlmi = None
 
         if not multi_part.content_id:
             self.fail_test("Multipart does not have a Content-ID")
+            return False
 
         for part in multi_part.body.parts:
             if part.body.packet_type == 'RLMI':
@@ -278,20 +354,25 @@
         next_resources = resources.get(name)
         if not next_resources:
             self.fail_test("Missing '%s'" % name)
-            return
+            return False
 
         if next_resources['type'] != 'Multipart':
             self.fail_test("Packet Type is wrong -- processing multipart, "
                            "but expected type is %s" % next_resources['type'])
-            return
+            return False
 
         next_resources = next_resources['sublist']
 
         for part in multi_part.body.parts:
-            self.validate_body_part(part, next_resources, rlmi, name)
+            if not self.validate_body_part(part, next_resources, rlmi, name):
+                return False
+        return True
 
     def fail_test(self, message):
-        """Fail the test and stop the reactor"""
+        """Mark the test as failed and stop the reactor
+
+        Arguments:
+        message Reason for the test failure"""
         LOGGER.error(message)
         self.test_object.set_passed(False)
         self.test_object.stop_reactor()
diff --git a/tests/channels/pjsip/subscriptions/rls/rls_test.py b/tests/channels/pjsip/subscriptions/rls/rls_test.py
index f5762f3..b06c3da 100755
--- a/tests/channels/pjsip/subscriptions/rls/rls_test.py
+++ b/tests/channels/pjsip/subscriptions/rls/rls_test.py
@@ -1,4 +1,11 @@
 #/usr/bin/env python
+"""
+Copyright (C) 2015, Digium, Inc.
+Jonathan Rose <jrose at digium.com>
+
+This program is free software, distributed under the terms of
+the GNU General Public License Version 2.
+"""
 
 import sys
 import logging
@@ -12,14 +19,22 @@
 
 LOGGER = logging.getLogger(__name__)
 
+
 class IntegrityCheck(VOIPListener):
-    """A test module that observes incoming SIP notifies and compares them
+    """Verifies that SIP notifies contain expected updates
+
+       A test module that observes incoming SIP notifies and compares them
        to a set of expected results. Tests may optionally specify for an
        arbitrary number of AMI actions to be executed in order at 2 second
        intervals from the start of the test.
     """
     def __init__(self, module_config, test_object):
-        """Create listener and add AMI observer/callbacks."""
+        """Constructor
+
+        Arguments:
+        module_config Dictionary containing test configuration
+        test_object used to manipulate reactor and set/remove failure tokens
+        """
         self.set_pcap_defaults(module_config)
         VOIPListener.__init__(self, module_config, test_object)
 
@@ -42,8 +57,7 @@
         self.add_callback('SIP', self.multipart_handler)
 
     def set_pcap_defaults(self, module_config):
-        """Set default values for PcapListener module for values that aren't
-           explicitly overridden.
+        """Sets default values for the PcapListener
         """
         if not module_config.get('bpf-filter'):
             module_config['bpf-filter'] = 'udp port 5061'
@@ -55,16 +69,31 @@
             module_config['device'] = 'lo'
 
     def multipart_handler(self, packet):
-        """Checks multipart packets to see if NOTIFY messages have
-           anticipated data.
+        """Handles incoming SIP packets and verifies contents
+
+        Checks to see if a packet is a NOTIFY packet with a multipart body.
+        Provided that all the basic checks pass, creates and RLSValidator for
+        the packet that will verify that the contents of the NOTIFY match the
+        expectations set for NOTIFY in the test configuration.
+
+        Arguments:
+        packet Incoming SIP Packet
         """
+
+        LOGGER.debug('Received SIP packet')
+
         if 'NOTIFY' not in packet.request_line:
+            LOGGER.debug('Ignoring packet, is not a NOTIFY')
             return
 
         if packet.body.packet_type != 'Multipart':
+            LOGGER.debug('Ignoring packet, NOTIFY does not contain ' +
+                         'multipart body')
             return
 
         if self.version >= len(self.resources):
+            LOGGER.debug('Ignoring packet, version is higher than count of ' +
+                         'test expectations')
             return
 
         validator = RLSValidator(test_object=self.test_object,
@@ -73,10 +102,20 @@
                                  full_state=self.full_state[self.version],
                                  list_name=self.list_name,
                                  resources=self.resources[self.version])
-        validator.check_integrity()
+
+        debug_msg = "validating packet -- expecting {0}"
+        LOGGER.debug(debug_msg.format(self.resources[self.version]))
+        if not validator.check_integrity():
+            LOGGER.error('Integrity Check Failed.')
+            return
+
+        info_msg = "Packet validated successfully. Test Phase {0} Completed."
+        LOGGER.info(info_msg.format(self.version))
         self.version += 1
 
         if self.version == len(self.resources):
+            info_msg = "All test phases completed. RLS verification complete."
+            LOGGER.info(info_msg)
             self.test_object.remove_fail_token(self.token)
             if self.stop_after_notifys:
                 # We only deal with as many NOTIFIES as we have resources
@@ -90,10 +129,19 @@
     def scenario_started(self, scenario):
         """Callback when SIPp scenario has started.
 
-        If this test executes an AMI action, this
+        If this test executes AMI actions, this function will execute
+        those AMI actions at two second intervals.
+
+        Note: Overrides scenario_started from VOIPListener
+
+        Arguments:
+        scenario Not actually used, just part of the signature.
         """
         def _perform_ami_action():
-            self.ami.sendMessage(self.ami_action.pop(0))
+            action = self.ami_action.pop(0)
+            debug_msg = "Sending AMI action: {0}"
+            LOGGER.debug(debug_msg.format(action))
+            self.ami.sendMessage(action)
             if len(self.ami_action):
                 reactor.callLater(2, _perform_ami_action)
 

-- 
To view, visit https://gerrit.asterisk.org/587
To unsubscribe, visit https://gerrit.asterisk.org/settings

Gerrit-MessageType: merged
Gerrit-Change-Id: Iea3f5bb8a424d7ff813a85d6c8224a14ebc3e0dd
Gerrit-PatchSet: 1
Gerrit-Project: testsuite
Gerrit-Branch: master
Gerrit-Owner: Jonathan Rose <jrose at digium.com>
Gerrit-Reviewer: Joshua Colp <jcolp at digium.com>
Gerrit-Reviewer: Mark Michelson <mmichelson at digium.com>



More information about the asterisk-commits mailing list