Merge pull request #3384 from gizmoguy/test-debug

Implement test debug mode

Author: gizmoguy

Dockerfile.tests

@@ -1,6 +1,6 @@
 ## Image name: faucet/tests
 
-FROM faucet/test-base:6.0.0
+FROM faucet/test-base:7.0.0
 
 COPY ./ /faucet-src/
 WORKDIR /faucet-src/

clib/clib_mininet_test_main.py

@@ -455,6 +455,13 @@ def addSuccess(self, test):
         super(FaucetCleanupResult, self).addSuccess(test)
 
 
+def debug_exception_handler(etype, value, trace):
+    import traceback
+    import pdb
+    traceback.print_exception(etype, value, trace)
+    print()
+    pdb.pm()
+
 def test_runner(root_tmpdir, resultclass, failfast=False):
     resultclass.root_tmpdir = root_tmpdir
     return unittest.TextTestRunner(verbosity=255, resultclass=resultclass, failfast=failfast)
@@ -472,13 +479,19 @@ def run_parallel_test_suites(root_tmpdir, resultclass, parallel_tests):
     return results
 
 
-def run_single_test_suites(root_tmpdir, resultclass, single_tests):
+def run_single_test_suites(debug, root_tmpdir, resultclass, single_tests):
     results = []
     # TODO: Tests that are serialized generally depend on hardcoded ports.
     # Make them use dynamic ports.
     if single_tests.countTestCases():
         single_runner = test_runner(root_tmpdir, resultclass)
-        results.append(single_runner.run(single_tests))
+        if debug:
+            oldexcepthook = sys.excepthook
+            sys.excepthook = debug_exception_handler
+            single_tests.debug()
+            sys.excepthook = oldexcepthook
+        else:
+            results.append(single_runner.run(single_tests))
     return results
 
 
@@ -496,7 +509,10 @@ def report_tests(test_status, test_list, result):
         test_duration_secs = result.test_duration_secs[test_class.id()]
         tests_json.update({
             test_class.id(): {
-                'status': test_status, 'output': test_text, 'test_duration_secs': test_duration_secs}})
+                'status': test_status,
+                'output': test_text,
+                'test_duration_secs': test_duration_secs
+                }})
     return tests_json
 
 
@@ -529,14 +545,14 @@ def report_results(results, hw_config, report_json_filename):
                 report_json_file.write(json.dumps(report_json))
 
 
-def run_test_suites(report_json_filename, hw_config, root_tmpdir,
+def run_test_suites(debug, report_json_filename, hw_config, root_tmpdir,
                     resultclass, single_tests, parallel_tests, sanity_result):
     print('running %u tests in parallel and %u tests serial' % (
         parallel_tests.countTestCases(), single_tests.countTestCases()))
     results = []
     results.append(sanity_result)
     results.extend(run_parallel_test_suites(root_tmpdir, resultclass, parallel_tests))
-    results.extend(run_single_test_suites(root_tmpdir, resultclass, single_tests))
+    results.extend(run_single_test_suites(debug, root_tmpdir, resultclass, single_tests))
     report_results(results, hw_config, report_json_filename)
     successful_results = [result for result in results if result.wasSuccessful()]
     return len(results) == len(successful_results)
@@ -612,7 +628,7 @@ def clean_test_dirs(root_tmpdir, all_successful, sanity, keep_logs, dumpfail):
                         dump_failed_test(test_name, test_dir)
 
 
-def run_tests(module, hw_config, requested_test_classes, dumpfail,
+def run_tests(module, hw_config, requested_test_classes, dumpfail, debug,
               keep_logs, serial, repeat, excluded_test_classes, report_json_filename,
               port_order):
     """Actually run the test suites, potentially in parallel."""
@@ -643,10 +659,11 @@ def run_tests(module, hw_config, requested_test_classes, dumpfail,
         sanity_result = run_sanity_test_suite(root_tmpdir, resultclass, sanity_tests)
         if sanity_result.wasSuccessful():
             while True:
-                all_successful = run_test_suites(
-                    report_json_filename, hw_config, root_tmpdir,
-                    resultclass, copy.deepcopy(single_tests),
-                    copy.deepcopy(parallel_tests), sanity_result)
+                all_successful = run_test_suites(debug, report_json_filename,
+                                                 hw_config, root_tmpdir, resultclass,
+                                                 copy.deepcopy(single_tests),
+                                                 copy.deepcopy(parallel_tests),
+                                                 sanity_result)
                 if not repeat:
                     break
                 if not all_successful:
@@ -679,6 +696,8 @@ def parse_args():
         '-c', '--clean', action='store_true', help='run mininet cleanup')
     parser.add_argument(
         '-d', '--dumpfail', action='store_true', help='dump logs for failed tests')
+    parser.add_argument(
+        '--debug', action='store_true', help='enter debug breakpoint on assertion failure')
     parser.add_argument(
         '-k', '--keep_logs', action='store_true', help='keep logs even for OK tests')
     loglevels = ('debug', 'error', 'warning', 'info', 'output')
@@ -728,7 +747,7 @@ def parse_args():
 
 
     return (
-        requested_test_classes, args.clean, args.dumpfail,
+        requested_test_classes, args.clean, args.dumpfail, args.debug,
         args.keep_logs, args.nocheck, args.serial, args.repeat,
         excluded_test_classes, report_json_filename, port_order,
         args.loglevel, args.profile)
@@ -739,7 +758,7 @@ def test_main(module):
 
     print('testing module %s' % module)
 
-    (requested_test_classes, clean, dumpfail, keep_logs, nocheck,
+    (requested_test_classes, clean, dumpfail, debug, keep_logs, nocheck,
      serial, repeat, excluded_test_classes, report_json_filename, port_order,
      loglevel, profile) = parse_args()
 
@@ -769,7 +788,7 @@ def test_main(module):
         pr.enable()
 
     run_tests(
-        module, hw_config, requested_test_classes, dumpfail,
+        module, hw_config, requested_test_classes, dumpfail, debug,
         keep_logs, serial, repeat, excluded_test_classes, report_json_filename, port_order)
 
     if profile:

docs/testing.rst

@@ -18,7 +18,8 @@ You can build and run the mininet tests with the following commands:
   sudo docker build --pull -t faucet/tests -f Dockerfile.tests .
   sudo apparmor_parser -R /etc/apparmor.d/usr.sbin.tcpdump
   sudo modprobe openvswitch
-  sudo docker run --sysctl net.ipv6.conf.all.disable_ipv6=0 --privileged --rm \
+  sudo docker run --name=faucet-tests \
+                  --sysctl net.ipv6.conf.all.disable_ipv6=0 --privileged --rm \
                   -v /var/local/lib/docker:/var/lib/docker \
                   -v /tmp/faucet-pip-cache:/var/tmp/pip-cache \
                   -ti faucet/tests
@@ -185,7 +186,8 @@ Then you can build and run the test suite:
 .. code:: console
 
   sudo docker build --pull -t faucet/tests -f Dockerfile.tests .
-  sudo docker run --privileged --rm --net=host --cap-add=NET_ADMIN \
+  sudo docker run --name=faucet-tests \
+                  --privileged --rm --net=host --cap-add=NET_ADMIN \
                   -v /var/local/lib/docker:/var/lib/docker \
                   -v /tmp/faucet-pip-cache:/var/tmp/pip-cache \
                   -v /etc/faucet:/etc/faucet \
@@ -272,7 +274,6 @@ the test suite will keep these files.
 
       -e FAUCET_TESTS="-k"
 
-
 Repeatedly running tests until failure
 --------------------------------------
 
@@ -282,3 +283,45 @@ Tests will continue to run forever until at least one fails or the test is inter
 .. code:: console
 
       -e FAUCET_TESTS="-r"
+
+Test debugging
+--------------
+
+Often while debugging a failed integration test it can be useful to pause the
+test suite at the point of the failure. The test can then be inspected live to
+narrow down the exact issue. To do this, run your test with the ``--debug``
+flag (replace `TEST_NAME` with actual name of test).
+
+.. code:: console
+
+      -e FAUCET_TESTS="--debug TEST_NAME"
+
+The test suite will now run in a mode where it ignores successful tests and
+drops into a pdb shell when a failure occurs inside a test.
+There are a number of different
+`pdb commands <https://docs.python.org/3/library/pdb.html#debugger-commands>`_
+that can be run to check the actual test code.
+
+It is also possible to login to the virtual container environment to run
+interactive debug commands to inspect the state of the system.
+
+.. code:: console
+
+      sudo sudo docker exec -it faucet-tests /bin/bash
+
+One useful thing can be to find the running mininet containers and execute
+commands inside of them, e.g ping:
+
+.. code:: console
+
+      root@35b98943f736:/faucet-src# ps w | grep mininet:
+
+        995 pts/1    Ss+    0:00 bash --norc --noediting -is mininet:faucet-637
+        997 pts/2    Ss+    0:00 bash --norc --noediting -is mininet:u021
+       1001 pts/3    Ss+    0:00 bash --norc --noediting -is mininet:u022
+       1005 pts/4    Ss+    0:00 bash --norc --noediting -is mininet:u023
+       1009 pts/5    Ss+    0:00 bash --norc --noediting -is mininet:u024
+       1013 pts/6    Ss+    0:00 bash --norc --noediting -is mininet:s02
+       1077 pts/7    Ss+    0:00 bash --norc --noediting -is mininet:gauge-637
+
+      root@35b98943f736:/faucet-src# m u021 ping 127.0.0.1