Fix log checking in PRH so that only entries generated during test execution are taken into account.

- fixing "Should not send PNF ready when DMaaP event is not JSON array" test that was passing due to checking log entry generated by a previous test
- improving logs generated by keyword waiting for log entry
- changing 'find log entry' to 'wait for log entry' with explicit timeout setting
- adjusting timeouts for waiting for log entries to appear (20s is enough when prh workflow execution is scheduled every 10s)

Change-Id: I20c67dfce6e8d1809d24ddb3108a088b00165996
Issue-ID: DCAEGEN2-1544
Signed-off-by: grabinsk <maciej.grabinski@nokia.com>

5 files changed, 62 insertions, 47 deletions

diff --git a/tests/dcaegen2/prh-testcases/assets/ves-event-not-a-json-object/invalid-ves-event.json b/tests/dcaegen2/prh-testcases/assets/ves-event-not-a-json-object/invalid-ves-event.json
new file mode 100644
index 00000000..cf378ebe
--- /dev/null
+++ b/tests/dcaegen2/prh-testcases/assets/ves-event-not-a-json-object/invalid-ves-event.json
@@ -0,0 +1 @@
+"notajsonobject"
diff --git a/tests/dcaegen2/prh-testcases/assets/ves-event-not-array/invalid-ves-event.json b/tests/dcaegen2/prh-testcases/assets/ves-event-not-array/invalid-ves-event.json
deleted file mode 100644
index cc6502fd..00000000
--- a/tests/dcaegen2/prh-testcases/assets/ves-event-not-array/invalid-ves-event.json
+++ /dev/null
@@ -1,15 +0,0 @@
-{
-  "event": {
-    "commonEventHeader": {
-      "sourceName":"NOK6061ZW1"
-    },
-    "pnfRegistrationFields": {
-      "oamV4IpAddress":"10.16.123.234",
-      "oamV6IpAddress":"2001:0db8:85a3:0000:0000:8a2e:0370:7334",
-      "serialNumber":"NOkkaaa123",
-      "vendorName":"equipVendor",
-      "modelNumber":"equipModel",
-      "unitType":"equipType"
-    }
-  }
-}
diff --git a/tests/dcaegen2/prh-testcases/prh_tests.robot b/tests/dcaegen2/prh-testcases/prh_tests.robot
index 69ce27dc..17db590f 100644
--- a/tests/dcaegen2/prh-testcases/prh_tests.robot
+++ b/tests/dcaegen2/prh-testcases/prh_tests.robot
@@ -29,16 +29,16 @@ Simple registration event
     ${TEST_CASES_DIR}/ves-event-with-empty-additional-fields
     ${TEST_CASES_DIR}/ves-event-with-empty-attachment-point
 
-Should not send PNF ready when DMaaP event is invalid
+Should not send PNF ready when DMaaP event has missing required field
     [Documentation]    PRH get from DMaaP event with missing required field
     [Tags]    PRH    Invalid event
     [Template]    Verify event with missing required field is logged
     ${TEST_CASES_DIR}/ves-event-missing-field
 
 Should not send PNF ready when DMaaP event is not JSON array
-    [Documentation]    Event from DMaaP is not JSON array
+    [Documentation]    Event from DMaaP is not an array of JSON objects
     [Tags]    PRH    Invalid event
-    Verify incorrect JSON event is logged    ${TEST_CASES_DIR}/ves-event-not-array
+    Verify incorrect JSON event is logged    ${TEST_CASES_DIR}/ves-event-not-a-json-object
 
 Should not send PNF ready when AAI record doesn't exist
     [Documentation]    PRH get from DMaaP valid event but given PNF doesn't exists in AAI
diff --git a/tests/dcaegen2/prh-testcases/resources/PrhLibrary.py b/tests/dcaegen2/prh-testcases/resources/PrhLibrary.py
index b3f5f8d9..d1992283 100644
--- a/tests/dcaegen2/prh-testcases/resources/PrhLibrary.py
+++ b/tests/dcaegen2/prh-testcases/resources/PrhLibrary.py
@@ -2,29 +2,45 @@ import json
 import re
 import docker
 import time
+import datetime
 
 
 class PrhLibrary(object):
+    ROBOT_LIBRARY_SCOPE = 'TEST SUITE'
+    ROBOT_LISTENER_API_VERSION = 2
 
     def __init__(self):
-        pass
+        self.ROBOT_LIBRARY_LISTENER = self
+
+    def _start_test(self, name, attrs):
+        # http://robotframework.org/robotframework/latest/RobotFrameworkUserGuide.html#test-libraries-as-listeners
+        self.test_start_time = self.get_current_utc_datetime()
 
     @staticmethod
-    def find_one_of_log_entryies(searched_entries):
-        print(type(searched_entries))
-        client = docker.from_env()
-        container = client.containers.get('prh')
-        print("Check for log searches for pattern: ", searched_entries)
-        for line in container.logs(stream=True):
-            print("Check for log analysis line: ", line )
+    def get_current_utc_datetime():
+        return datetime.datetime.utcnow()
+
+    def get_docker_logs_since_test_start(self, container_id):
+        return self.get_docker_logs(container_id, self.test_start_time)
+
+    @staticmethod
+    def get_docker_logs(container_id, since=None):
+        container = PrhLibrary.__get_docker_container(container_id)
+        return container.logs(stream=False, since=since)
+
+    def wait_for_one_of_docker_log_entries(self, container_id, searched_entries):
+        print("Looking for: %s" % searched_entries)
+        container = PrhLibrary.__get_docker_container(container_id)
+        print("Log lines:")
+        for line in container.logs(stream=True, since=self.test_start_time):
+            print(line)
             for searched_entry in searched_entries:
                 if searched_entry in line.strip():
                     return True
         else:
             return False
 
-    @staticmethod
-    def find_log_json(prefix, json_message):
+    def wait_for_log_entry_with_json_message(self, prefix, json_message):
         print("Looking for:")
         print("Prefix: " + str(prefix))
         print("Json: " + str(json_message))
@@ -34,10 +50,10 @@ class PrhLibrary(object):
             print("Could not decode given message")
             return False
         pattern = re.compile(prefix + "(.*)$")
-        client = docker.from_env()
-        container = client.containers.get('prh')
-        for line in container.logs(stream=True):
-            print("Check for log analysis line: ", line )
+        container = PrhLibrary.__get_docker_container('prh')
+        print("Log lines:")
+        for line in container.logs(stream=True, since=self.test_start_time):
+            print(line)
             if PrhLibrary.__same_json_in_log(decoded_message, line, pattern):
                 return True
         else:
@@ -168,3 +184,8 @@ class PrhLibrary(object):
         if len(split) > 3:
             return split[3]
         return None
+
+    @staticmethod
+    def __get_docker_container(container_id):
+        docker_client = docker.from_env()
+        return docker_client.containers.get(container_id)
diff --git a/tests/dcaegen2/prh-testcases/resources/prh_library.robot b/tests/dcaegen2/prh-testcases/resources/prh_library.robot
index 892ee523..80017349 100644
--- a/tests/dcaegen2/prh-testcases/resources/prh_library.robot
+++ b/tests/dcaegen2/prh-testcases/resources/prh_library.robot
@@ -36,32 +36,29 @@ Verify event with missing required field is logged
     Log    Invalid ves event: ${invalid_ves_event}
     ${notification}=    Create invalid notification    ${invalid_ves_event}
     ${error_msg}=    Set Variable    Incorrect json, consumerDmaapModel can not be created:
-    Wait Until Keyword Succeeds    10x    3000ms    Check PRH json log    ${error_msg}    ${notification}
+    Wait for PRH json log entry    20s    ${error_msg}    ${notification}
 
 Verify incorrect JSON event is logged
-    [Timeout]    60s
     [Arguments]    ${test_case_directory}
     ${invalid_ves_event}=    Get Data From File    ${test_case_directory}/invalid-ves-event.json
     Set VES event in DMaaP    ${invalid_ves_event}
-    Check PRH log    |WARN    |Incorrect json, consumerDmaapModel can not be created:
+    Wait for PRH log entry    20s    java.lang.IllegalStateException: Not a JSON Object
 
 Verify missing AAI record is logged
-    [Timeout]    100s
     [Arguments]    ${test_case_directory}
     ${incorrect_aai_entry}=    Get Data From File    ${test_case_directory}/incorrect-aai-entry.json
     ${ves_event}=    Get Data From File    ${test_case_directory}/ves-event.json
     Add PNF entry in AAI    ${incorrect_aai_entry}
     Set VES event in DMaaP    ${ves_event}
-    Check PRH log    Request failed for URL 'https://aai:3334/aai/v12/network/pnfs/pnf/NOK6061ZW8'. Response code: 404 Not Found
+    Wait for PRH log entry    20s    Request failed for URL 'https://aai:3334/aai/v12/network/pnfs/pnf/NOK6061ZW8'. Response code: 404 Not Found
 
 Verify AAI not responding is logged
-    [Timeout]    100s
     [Arguments]    ${test_case_directory}
     ${ves_event}=    Get Data From File    ${test_case_directory}/ves-event.json
     Ensure Container Is Exited    aai_simulator
     Set VES event in DMaaP    ${ves_event}
-    Check PRH log    connection timed out: aai    Host is unreachable: aai
-    Ensure Container Is Running   aai_simulator
+    Wait for one of PRH log entries    90s    connection timed out: aai    Host is unreachable: aai
+    [Teardown]    Ensure Container Is Running   aai_simulator
 
 Verify PNF re registration
     [Timeout]    500s
@@ -124,14 +121,20 @@ Check created Logical Link
     Should Be Equal As Strings    ${resp.status_code}    200
     Should Be Equal As JSON    ${resp.content}    ${expected_logical_link_in_aai}
 
-Check PRH log
-    [Arguments]    @{log_entries}
-    ${found}=    Find one of log entryies    ${log_entries}
+Wait for PRH log entry
+    [Arguments]    ${timeout}    ${log_entry}
+    Wait for one of PRH log entries    ${timeout}    ${log_entry}
+
+Wait for one of PRH log entries
+    [Arguments]    ${timeout}    @{log_entries}
+    [Timeout]     ${timeout}
+    ${found}=    Wait for one of docker log entries   prh   ${log_entries}
     Should Be True    ${found}
 
-Check PRH json log
-    [Arguments]    ${prefix}    ${json}
-    ${found}=    Find log json    ${prefix}    ${json}
+Wait for PRH json log entry
+    [Arguments]    ${timeout}    ${prefix}    ${json}
+    [Timeout]     ${timeout}
+    ${found}=    Wait for log entry with json message    ${prefix}    ${json}
     Should Be True    ${found}
 
 Create event parsing error
@@ -209,4 +212,9 @@ Verify logging level
 
 Verify logs with heartbeat
     Get Request    prh_session    /heartbeat
-    Check PRH log   Heartbeat request received
\ No newline at end of file
+    Verify PRH logs contains    Heartbeat request received
+
+Verify PRH logs contains
+   [Arguments]    ${expected_entry}
+   ${log}=    Get docker logs since test start    prh
+   Should Contain    ${log}    ${expected_entry}
\ No newline at end of file