Refactor test apps to use unit-test framework #4014

bennylp · 2024-07-11T02:13:00Z

This PR contains modifications to PJSIP test apps (pjlib-test, pjlib-util-test, pjnath-test, pjmedia-test, and pjsip-test) to use the new unit test framework (#4007) with the main objective to make them complete faster.

Note: I recommend not to immediately delete the branch after merging to track possible future problems due to the very large changes in the test files.

Timing Results

Let's get straight to it. Below are the test time improvements from the original with the new framework using several worker thread settings.

test	Orig	1	2	3	4	7	10
pjlib-test	9m22s	4m51s	4m09s	2m52s	2m31s	2m21s	2m05s
pjlib-util-test	5m52s	3m03s		3m03s			3m03s
pjnath-test	45m42s			11m51s	9m44s	6m10s	4m31s
pjmedia-test	4m18s	2m08s		2m05s			2m05s
pjsip-test	28m22s			16m20s	14m12s	7m37s	7m37s

GitHub CI timings:

CI	Orig	3
ci-linux.yml	46m34s	29m17s
ci-mac.yml	1h3m32s	34m07s
ci-windows.yml	49m17s	32m23s
GH PR CI total	~1h03m	~35m

Notes on timing

Settings with three worker threads (totalling four threads with the main thread) are significant because our GitHub runners mostly use 4 VCPU according to this article.

Some tests cannot be made faster than certain limit with more worker threads, because that is the longest test case duration in that test.

General look and feel

All test apps have common look and feel with uniform command line options, which look something like this:

Usage:
  pjmedia-test [OPTIONS] [test_to_run] [test to run] [..]

where OPTIONS:

 -h, --help       Show this help screen
  -c, --config     Show configuration macros
  -l 0,1,2,3       0: Don't show logging after tests
                   1: Show logs of only failed tests (default)
                   2: Show logs of only successful tests
                   3: Show logs of all tests
  --log-no-cache   Do not cache logging
  -w N             Set N worker threads (0: disable. Default: 1)
  -L, --list       List the tests and exit
  --stop-err       Stop testing on error
  --shuffle        Shuffle the test order
  --seed N         Set shuffle random seed (must be >= 0)
  --stdout-buf N   Set stdout buffering mode:
  --stderr-buf N   Set stderr buffering mode:
                   0: unbufferred (default for stderr)
                   1: line
                   2: fully bufferred (default for stdout)
  -v, --verbose    Show info when starting/stopping tests
  -i               Ask ENTER before quitting
  -n               Do not trap signals

The test outputs are also uniform, which look something like this:

$ ../bin/pjlib-util-test-x86_64-unknown-linux-gnu -w 3
08:19:13.278 Performing 7 pjlib-util tests with 3 worker threads
[ 1/7] xml_test                         [OK] [0.000s]
[ 2/7] stun_test                        [OK] [0.000s]
[ 3/7] json_test                        [OK] [0.000s]
[ 4/7] encryption_benchmark             [OK] [0.016s]
[ 5/7] encryption_test                  [OK] [0.028s]
[ 6/7] resolver_test                    [OK] [168.830s]
[ 7/7] http_client_test                 [OK] [183.617s]
08:22:16.897 Unit test statistics for pjlib-util tests:
08:22:16.897     Total number of tests: 7
08:22:16.897     Number of test run:    7
08:22:16.897     Number of failed test: 0
08:22:16.897     Total duration:        3m3.618s

Running the tests

With Makefile build system, it is easier to run the tests with the make command. The Makefile accepts two environment variables: CI_ARGS contains arguments for the test apps, and CI_MODE to indicate we're running under GitHub CI (#3374). Sample invocation:

$ make pjlib-test CI_ARGS="-w 4"

Otherwise (e.g. on Windows) run each of the app directly. Use -h to get help.

GitHub CI modifications

There are for new variables in pjproject repository variable settings: CI_LIN_ARGS, CI_WIN_ARGS, CI_MAC_ARGS, and CI_MODE. Use CI_XXX_ARGS to control run-time arguments for the test apps, especially the number of worker threads, which should be equal to the number of vCPU of the GitHub action runners minus one (because the main thread also runs the test cases).
Combo steps in yaml were split into different steps
Shorten job names

Tips on troubleshooting errors

When the logging does not convey sufficient info about the error, use --log-no-cache to display logs as they are written, most likely with -w 0 to disable worker thread to avoid cluttering the output.

But sometimes, problem only arises with specific worker thread number and test orders. In this case, troubleshooting will be challenging indeed. :) Use -v, --verbose to display when tests are started/ended. This way you can know what tests were started when the failed test was running. After that, you can try running only these tests rather than all tests to reproduce the problem.

Test shuffling (--shuffle arg) is used by default on GitHub CI via repository variables (see above). To reproduce the error, make note of the seed value used when running the (failed) test (it is printed in the output), and re-run the test (locally) using --shuffle --seed N args.

The --stop-err option is useful to avoid waiting for all tests to complete when debugging an error.

Open issues

Reproducibility

As mentioned above, we're supposed to be able to reproduce the test sequence by using --shuffle and specific --seed value. But as it turns out, this is not the case. Even with the same seed, the test sequence can be different on different machine. We already use our own psudo random number generator in unittest.c, but this doesn't seem to fix the problem.

Intermitten crashes

There is an intermitten crashes in pjsip's regc_test. This could be related to tdata being dec-ref-ed more than it should (even though the test result is success). The exact cause however is still not known.

Test app modifications

General

There is a new utility file in pjlib/src/pjlib-test/test_util.h that is shared by all test apps to parse command line arguments, show usage, register tests, and control the unit testing process.

The main front-end files (main.c) were modified to be more nice as command line apps.

The main modification in test body (test.c) is to use the unit-test framework.

Some test codes were changed, replacing manual checks with PJ_TEST_XXX() macros, mainly to test the usage of these macros and to make the test nicer. But since it made the PR very big, I didn't continue the effort, unless when it was necessary for debugging some problems.

In general, large tests needed to be split into smaller ones to make them run in parallel. But major problems arose, mainly because the tests share global states or manipulate common objects.

More specific changes are discussed below.

`pjlib-test` notes

pjlib-test has "special" arrangements in test.c, because it needs to test the unit-test (UT) framework first, before running the rest of the test using the UT framework. But before testing the UT framework, it needs to test the components needed by the UT framework such as list, fifobuf, and OS. And so on. That's why the test output is different than the rest of the test apps.

Other than that, the modifications to the test functions are not too major, at least compared to pjnath-test and pjsip-test, and I think the test time is quite satisfactory.

`pjlib-util-test` notes

We couldn't speed up more because tests such as resolver_test() and http_client_test() takes about three minutes to complete and they couldn't be split up without major effort due to the use of global states. Since the test time is already quite satisfactory, I didn't pursue further optimizations.

`pjnath-test` notes

pjnath-test requires large modifications to make the tests run in parallel as follows:

remove global mem pool factory since many tests validate the memory leak in the pool factory, therefore having a single pool factory will not work
remove constant server port numbers in server.c so that server can be instantiated multiple times simultaneously (this was the motivation behind API to get DNS server's bound address to allow specifying zero as port number #3999).
split tests with multiple configurations (such as ice_test, turn_sock_test, concur_test) into individual test for each configuration, making them parallelable.

As the result, there are 70 smaller test items in pjnath-test, and with 7 worker threads, we can save 40 minutes of test time!

`pjmedia-test` notes

pjmedia-test has the least modifications because it has very few tests. The original duration was 4m18.691s, and has come down a little to 2m8.363s with 1 worker thread.

Having said that, some minor modifications were done:

replace pjmedia_endpt_create() with pjmedia_endpt_create2() (similarly ..destroy() with ..destroy2()) in mips_test() and codec_test_vectors(), to avoid inadvertently initializing pjmedia_aud_subsys which on Ubuntu emits lots of debugging messages during initialization (although the messages should have been suppressed in the code).
replace printf with log in jbuf test to make the output tidy, and renamed jbuf_main function name to jbuf_test to be consistent.

`pjsip-test` notes

pjsip-test has also gone through the biggest and most difficult modifications to make the tests parallelable, which involves:

changing tests to mark and uniquely identify its own message and skip messages belonging to other tests
remove global loop transport and replace with individual loop transport for each test, because each test usually modifies the loop transport's settings (such as to drop packets).
for the above, also use pjsip_tpselector to bind transaction (and tdata in case of stateless request) with specific loop transport, otherwise the transaction/tdata may find other instance of loop transport
fix tests that assume there is only one global loop transport (for example, with one global loop transport, there is no failover when sending messages fails).
bug fixing to the test code as some test flows have changed (for example, tsx_uac_test failed because UA layer has now been registered before the test)
changed tsx_basic_test, tsx_uac_test, tsx_uas_test to take the index to parameters rather than the parameter itself to make the test output more informative.

Detailed test timings/outputs

Below are detailed test timings/outputs for considerations and future reference. Maybe by looking at the test time you can have some idea to further speed up the tests.

Uncaught logging messages were removed for brevity.

`pjlib-test`

$ time make pjlib-test CI_ARGS='-w 7'
cd pjlib/build && ../bin/pjlib-test-x86_64-unknown-linux-gnu -w 7 
08:34:52.730 Testing the unit-test framework (basic)
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
08:34:55.734 Performing 9 essential tests
[ 1/9] errno_test                       [OK] [0.000s]
[ 2/9] exception_test                   [OK] [0.000s]
[ 3/9] os_test                          [OK] [0.000s]
[ 4/9] list_test                        [OK] [0.000s]
[ 5/9] pool_test                        [OK] [0.000s]
[ 6/9] string_test                      [OK] [0.000s]
[ 7/9] fifobuf_test                     [OK] [0.082s]
[ 8/9] mutex_test                       [OK] [0.000s]
[ 9/9] thread_test                      [OK] [12.001s]
08:35:07.819 Unit test statistics for essential tests:
08:35:07.819     Total number of tests: 9
08:35:07.819     Number of test run:    9
08:35:07.819     Number of failed test: 0
08:35:07.819     Total duration:        0m12.084s
08:35:07.819 Testing the unit-test test scheduling
[ 1/11] exclusive test a (arg: 140731305610480...) [OK] [0.300s]
[ 2/11] exclusive test b (arg: 140731305610496...) [OK] [0.200s]
[ 3/11] parallel test d (arg: 140731305610528...) [OK] [0.200s]
[ 4/11] parallel test e (arg: 140731305610544...) [OK] [0.500s]
[ 5/11] parallel test c (arg: 140731305610512...) [OK] [0.800s]
[ 6/11] exclusive test f (arg: 140731305610560...) [OK] [0.300s]
[ 7/11] exclusive test g (arg: 140731305610576...) [OK] [0.100s]
[ 8/11] exclusive test h (arg: 140731305610592...) [OK] [0.600s]
[ 9/11] parallel test k (arg: 140731305610640...) [OK] [0.100s]
[10/11] parallel test j (arg: 140731305610624...) [OK] [0.300s]
[11/11] parallel test i (arg: 140731305610608...) [OK] [0.500s]
08:35:10.621 Testing the unit-test framework (multithread)
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
[ 1/2] successful test (arg: 96)        [OK] [0.100s]
[ 2/2] failure test (arg: 353)          [Err: -123] [0.200s]
08:35:13.127 Performing 20 features tests with 7 worker threads
[ 1/20] atomic_test                      [OK] [0.000s]
[ 2/20] hash_test                        [OK] [0.000s]
[ 3/20] file_test                        [OK] [0.000s]
[ 4/20] pool_perf_test                   [OK] [0.002s]
[ 5/20] rand_test                        [OK] [0.002s]
[ 6/20] sock_test                        [Err: -121] [0.002s]
[ 7/20] select_test                      [OK] [0.010s]
[ 8/20] rbtree_test                      [OK] [0.015s]
[ 9/20] sock_perf_test                   [OK] [0.618s]
[10/20] ioqueue_perf_test0               [OK] [10.003s]
[11/20] timestamp_test                   [OK] [14.839s]
[12/20] udp_ioqueue_test                 [OK] [17.520s]
[13/20] sleep_test                       [OK] [17.602s]
[14/20] tcp_ioqueue_test                 [OK] [19.547s]
[15/20] ssl_sock_test                    [OK] [14.160s]
[16/20] timer_test                       [OK] [33.044s]
[17/20] udp_ioqueue_unreg_test           [OK] [95.355s]
[18/20] ioqueue_stress_test              [OK] [115.749s]
[19/20] activesock_test                  [OK] [101.703s]
[20/20] ioqueue_perf_test1               [OK] [110.049s]
08:37:13.800 ------------ Displaying failed test logs: ------------
08:37:13.800 ------------ Logs for sock_test [rc:-121]: ------------
08:35:13.128 ...format_test()
08:35:13.128 ....hostname is z840
08:35:13.128 ...IP address parsing
08:35:13.129 ...purity_test()
08:35:13.129 ...gethostbyname_test()
08:35:13.130 ...simple_sock_test()
08:35:13.130 ...udp_test()
08:35:13.130 ...bind error: [pj_status_t=120098] Address already in use
08:37:13.800 --------------------------------------------------------
08:37:13.800 Unit test statistics for features tests:
08:37:13.800     Total number of tests: 20
08:37:13.800     Number of test run:    20
08:37:13.800     Number of failed test: 1
08:37:13.800     Total duration:        2m0.672s
08:37:13.800  
08:37:13.800 Stack max usage: 0, deepest: :0
08:37:13.800 **Test completed with error(s)**
make: *** [Makefile:107: pjlib-test] Error 1

real	2m21.087s
user	3m7.641s
sys	8m46.307s

`pjlib-util-test`

$ time make pjlib-util-test CI_ARGS='-w 3'
cd pjlib-util/build && ../bin/pjlib-util-test-x86_64-unknown-linux-gnu -w 3
08:19:13.278 Performing 7 pjlib-util tests with 3 worker threads
[ 1/7] xml_test                         [OK] [0.000s]
[ 2/7] stun_test                        [OK] [0.000s]
[ 3/7] json_test                        [OK] [0.000s]
[ 4/7] encryption_benchmark             [OK] [0.016s]
[ 5/7] encryption_test                  [OK] [0.028s]
[ 6/7] resolver_test                    [OK] [168.830s]
[ 7/7] http_client_test                 [OK] [183.617s]
08:22:16.897 Unit test statistics for pjlib-util tests:
08:22:16.897     Total number of tests: 7
08:22:16.897     Number of test run:    7
08:22:16.897     Number of failed test: 0
08:22:16.897     Total duration:        3m3.618s

real	3m3.630s
user	0m0.178s
sys	0m0.121s

`pjnath-test`

$ time make pjnath-test CI_ARGS='-w 7'
cd pjnath/build && ../bin/pjnath-test-x86_64-unknown-linux-gnu -w 7
08:42:40.419                 test.c Performing 70 pjnath tests with 7 worker threads
[ 1/70] stun_test                        [OK] [0.000s]
[ 2/70] ice_test (arg: 4)                [OK] [1.628s]
[ 3/70] ice_test (arg: 2)                [OK] [1.668s]
[ 4/70] ice_test (arg: 0)                [OK] [1.676s]
[ 5/70] ice_test (arg: 1)                [OK] [1.678s]
[ 6/70] sess_auth_test                   [OK] [16.403s]
[ 7/70] ice_test (arg: 3)                [OK] [17.423s]
[ 8/70] ice_test (arg: 5)                [OK] [17.426s]
[ 9/70] trickle_ice_test                 [OK] [12.640s]
[10/70] turn_sock_test (arg: 0)          [OK] [26.754s]
[11/70] ice_test (arg: 6)                [OK] [59.185s]
[12/70] ice_test (arg: 8)                [OK] [59.173s]
[13/70] ice_test (arg: 7)                [OK] [59.255s]
[14/70] ice_test (arg: 9)                [OK] [59.283s]
[15/70] ice_test (arg: 10)               [OK] [59.303s]
[16/70] ice_test (arg: 11)               [OK] [59.265s]
[17/70] turn_sock_test (arg: 1)          [OK] [26.751s]
[18/70] turn_sock_test (arg: 2)          [OK] [27.137s]
[19/70] concur_test                      [OK] [42.074s]
[20/70] concur_test                      [OK] [42.086s]
[21/70] ice_conc_test                    [OK] [49.237s]
[22/70] concur_test                      [OK] [42.089s]
[23/70] concur_test                      [OK] [42.063s]
[24/70] concur_test                      [OK] [42.085s]
[25/70] stun_sock_test                   [OK] [129.213s]
[26/70] concur_test                      [OK] [42.060s]
[27/70] concur_test                      [OK] [42.105s]
[28/70] concur_test                      [OK] [42.079s]
[29/70] concur_test                      [OK] [42.113s]
[30/70] concur_test                      [OK] [42.096s]
[31/70] concur_test                      [OK] [42.086s]
[32/70] concur_test                      [OK] [42.086s]
[33/70] concur_test                      [OK] [42.063s]
[34/70] concur_test                      [OK] [42.057s]
[35/70] concur_test                      [OK] [42.110s]
[36/70] concur_test                      [OK] [42.090s]
[37/70] concur_test                      [OK] [42.121s]
[38/70] concur_test                      [OK] [42.103s]
[39/70] concur_test                      [OK] [42.088s]
[40/70] concur_test                      [OK] [42.078s]
[41/70] concur_test                      [OK] [42.104s]
[42/70] concur_test                      [OK] [42.053s]
[43/70] concur_test                      [OK] [42.092s]
[44/70] concur_test                      [OK] [42.102s]
[45/70] concur_test                      [OK] [42.084s]
[46/70] concur_test                      [OK] [42.114s]
[47/70] concur_test                      [OK] [42.097s]
[48/70] concur_test                      [OK] [42.091s]
[49/70] concur_test                      [OK] [42.056s]
[50/70] concur_test                      [OK] [42.071s]
[51/70] concur_test                      [OK] [42.089s]
[52/70] concur_test                      [OK] [42.092s]
[53/70] concur_test                      [OK] [42.092s]
[54/70] concur_test                      [OK] [42.097s]
[55/70] concur_test                      [OK] [42.118s]
[56/70] concur_test                      [OK] [42.071s]
[57/70] concur_test                      [OK] [42.068s]
[58/70] concur_test                      [OK] [42.059s]
[59/70] concur_test                      [OK] [42.085s]
[60/70] concur_test                      [OK] [42.081s]
[61/70] concur_test                      [OK] [42.096s]
[62/70] concur_test                      [OK] [42.083s]
[63/70] concur_test                      [OK] [42.107s]
[64/70] concur_test                      [OK] [42.072s]
[65/70] concur_test                      [OK] [42.057s]
[66/70] concur_test                      [OK] [42.068s]
[67/70] concur_test                      [OK] [42.099s]
[68/70] concur_test                      [OK] [42.106s]
[69/70] concur_test                      [OK] [42.094s]
[70/70] concur_test                      [OK] [42.101s]
08:48:50.813                 test.c Unit test statistics for pjnath tests:
08:48:50.813                 test.c     Total number of tests: 70
08:48:50.813                 test.c     Number of test run:    70
08:48:50.813                 test.c     Number of failed test: 0
08:48:50.813                 test.c     Total duration:        6m10.393s

real	6m10.410s
user	0m58.376s
sys	1m45.019s

`pjmedia-test`

$ time make pjmedia-test CI_ARGS='-w 3'
cd pjmedia/build && ../bin/pjmedia-test-x86_64-unknown-linux-gnu -w 3
08:25:07.868         os_core_unix.c !pjlib 2.14-dev for POSIX initialized
08:25:07.869 Performing 7 pjmedia tests with 3 worker threads
[ 1/7] mips_test                        [OK] [13.824s]
[ 2/7] vid_codec_test                   [OK] [61.585s]
[ 3/7] vid_dev_test                     [OK] [0.000s]
[ 4/7] sdp_neg_test                     [OK] [0.001s]
[ 5/7] jbuf_test                        [OK] [0.001s]
[ 6/7] codec_test_vectors               [OK] [0.067s]
[ 7/7] vid_port_test                    [OK] [50.556s]
08:27:13.836 Unit test statistics for pjmedia tests:
08:27:13.836     Total number of tests: 7
08:27:13.836     Number of test run:    7
08:27:13.836     Number of failed test: 0
08:27:13.836     Total duration:        2m5.966s
08:27:13.836 Looks like everything is okay!

real	2m6.044s
user	0m22.794s
sys	0m0.904s

`pjsip-test`

$ time make pjsip-test CI_ARGS='-w 7'
cd pjsip/build && ../bin/pjsip-test-x86_64-unknown-linux-gnu -w 7
********************************************************************
**                        W A R N I N G                           **
********************************************************************
** Due to centralized event processing in PJSIP, events may be    **
** read by different thread than the test's thread. This may      **
** cause logs to be saved by the wrong test when multithreaded    **
** testing is used. The test results are correct, but the log     **
** may not be accurate.                                           **
** For debugging with correct logging, use "-w 0 --log-no-cache"  **
********************************************************************
08:51:38.325                 test.c Performing 23 pjsip tests with 7 worker threads
[ 1/23] msg_err_test                     [OK] [0.000s]
[ 2/23] multipart_test                   [OK] [0.000s]
[ 3/23] transport_loop_multi_test        [OK] [0.101s]
[ 4/23] uri_test                         [OK] [0.781s]
[ 5/23] msg_test                         [OK] [0.843s]
[ 6/23] txdata_test                      [OK] [0.906s]
[ 7/23] tsx_basic_test (arg: 0)          [OK] [1.000s]
[ 8/23] tsx_basic_test (arg: 1)          [OK] [1.000s]
[ 9/23] inv_offer_answer_test            [OK] [8.176s]
[10/23] tsx_basic_test (arg: 2)          [OK] [1.000s]
[11/23] resolve_test                     [OK] [14.012s]
[12/23] tsx_bench                        [OK] [17.127s]
[13/23] transport_udp_test               [OK] [12.589s]
[14/23] transport_loop_test              [OK] [24.043s]
[15/23] tsx_uas_test (arg: 2)            [OK] [79.779s]
[16/23] transport_tcp_test               [OK] [54.472s]
[17/23] tsx_uas_test (arg: 1)            [OK] [194.910s]
[18/23] regc_test                        [OK] [200.878s]
[19/23] tsx_uac_test (arg: 1)            [OK] [208.502s]
[20/23] tsx_uac_test (arg: 2)            [OK] [202.502s]
[21/23] tsx_uac_test (arg: 0)            [OK] [262.503s]
[22/23] tsx_uas_test (arg: 0)            [OK] [295.951s]
[23/23] tsx_destroy_test                 [OK] [161.027s]
08:59:16.149                 test.c Unit test statistics for pjsip tests:
08:59:16.149                 test.c     Total number of tests: 23
08:59:16.149                 test.c     Number of test run:    23
08:59:16.149                 test.c     Number of failed test: 0
08:59:16.149                 test.c     Total duration:        7m37.823s
08:59:16.659                 test.c  
08:59:16.659                 test.c Stack max usage: 0, deepest: :0
08:59:16.659                 test.c Looks like everything is okay!..

real	7m38.347s
user	1m57.790s
sys	1m12.358s

…e new framework (reason: because parallel flag is not set, doh!)

…, skip essential tests, list tests

…ce returning value

…use of errors when running on Windows virtual machine

…t wait the previous test to complete)

…ing, and running unit test. This can be used by all test apps. pjlib-util-test has been ported to use this utilities

…sential test because it does not exist in features test (in pjlib-test)

…up from 45m originally to 15m using 10 worker threads

…4:30 minutes with 10 worker threads, from 45:42m originally)

…provements due to exclusive tests

… automatic error reporting) hopefully make it easier to use

…e with unit-test logging (see unittest.md)

…args are set in GitHub action variables

…Windows

…) except in pj_test_suite_shuffle(), 2) unit test PRNG explicitly uses pj_uint32_t instead of int. Also disable windows python tests since it is unreliable

…urrency issue

… counter value is 2*1e9 and is overflow during diff calculation

…sts in pj/config_site_test.h

…ely exit on error so that we can see correlated error log

…nally fail on Linux

…random port numbers, 2) increase delay waiting for various DNS timers, 3) reset global vars to zero because test may be repeated for IPv6

…since binding fails occasionally

…test

… into unittest-framework

sauwming · 2024-12-24T07:48:35Z

For failed pjsip-test on Mac, it is because of rwmutex.

After fixing this, it's never stuck again in ~15 runs here, but occasionally (~20%) will fail with:

14:38:51.301             unittest.c ------------ Displaying failed test logs: ------------
14:38:51.301             unittest.c ------------ Logs for inv_offer_answer_test [rc:-5]: ------------
14:27:28.914 inv_offer_answer_test. "pjsip_udp_transport_start(endpt, &addr, NULL, 1, &tp)" fails in inv_offer_answer_test.c:778, status=120048 (Address already in use)
14:38:51.301             unittest.c ------------ Logs for transport_udp_test [rc:-110]: ------------
14:27:58.633   transport_udp_test.c "pjsip_udp_transport_start( endpt, &addr, NULL, 1, &udp_tp)" fails in transport_udp_test.c:50, status=120048 (Address already in use)

bennylp · 2024-12-25T02:20:17Z

After fixing this, it's never stuck again in ~15 runs here, but occasionally (~20%) will fail with:

14:38:51.301             unittest.c ------------ Displaying failed test logs: ------------
14:38:51.301             unittest.c ------------ Logs for inv_offer_answer_test [rc:-5]: ------------
14:27:28.914 inv_offer_answer_test. "pjsip_udp_transport_start(endpt, &addr, NULL, 1, &tp)" fails in inv_offer_answer_test.c:778, status=120048 (Address already in use)
14:38:51.301             unittest.c ------------ Logs for transport_udp_test [rc:-110]: ------------
14:27:58.633   transport_udp_test.c "pjsip_udp_transport_start( endpt, &addr, NULL, 1, &udp_tp)" fails in transport_udp_test.c:50, status=120048 (Address already in use)

That failures happen here as well, and I tried to fix it in 58602a4

bennylp and others added 30 commits June 8, 2024 17:32

Initial work on unittest framework, tested

cdd4380

Finished reorganizing pjlib-test to use unit-test framework

eaef323

Fix big problem where performance improvement is not observed with th…

93f2848

…e new framework (reason: because parallel flag is not set, doh!)

Tidying up global vars in pjlib-test. Add test options: stop on error…

51d6d93

…, skip essential tests, list tests

Change the PJ_TEST_XX() signature to be more generic and does not for…

9383baa

…ce returning value

Modifications to some existing tests to use unit-test test macros

1d842db

Updated VS projects with argparse.h and unittest.h

d8bd130

Fix warnings on Windows

c8f93dd

Disable parallel unit-testing for ioqueue stress test on Windows beca…

56d221a

…use of errors when running on Windows virtual machine

Non-parallel test case will now run exclusively (previously it did no…

cbefbdf

…t wait the previous test to complete)

Add pjlib-test/test_util.h for common utilities for parsing, configur…

19f9f17

…ing, and running unit test. This can be used by all test apps. pjlib-util-test has been ported to use this utilities

Dirty hack to fix error message being displayed when user selected es…

b2e3108

…sential test because it does not exist in features test (in pjlib-test)

Replace PJ_TEST_PARALLEL with PJ_TEST_EXCLUSIVE

13db0c6

Ported pjnath-test to use unit-testing framework, with limited speed-…

6bfb5d2

…up from 45m originally to 15m using 10 worker threads

Large modifications in pjnath-test to speed-up test. It is fast now (…

2b735d0

…4:30 minutes with 10 worker threads, from 45:42m originally)

Ported pjmedia-test to use unit-test

b8594fe

Porting of pjsip test to unit testing framework. Not much of speed im…

af408ea

…provements due to exclusive tests

Merged changes from master

4f5d62c

Modifications in pj_argparse API (changed get() to get_bool() and add…

2e5fa0e

… automatic error reporting) hopefully make it easier to use

Refactor tsx_uas_test() to allow parallel testing

d4b267e

Parallelize tsx_uac_test()

f7f7392

Further effort to parallize tests in pjsip-test. Discoverd major issu…

64d5a61

…e with unit-test logging (see unittest.md)

Showing PJLIB config is optional with cmd line option

2b90407

Bug fixing failed pjsip tests when running in parallel mode

9caadb2

Finished paralleizing all pjsip tests except one

e886488

Continuing correcting errors

47d94bb

Add test shuffle feature

ed3ac46

Merge #4006 and fix transport_loop_test error

97b99c1

Modify CI workflows to use standard arguments: -w 3 --shuffle. These …

46ef3e6

…args are set in GitHub action variables

Updated due to change in argparse API signature (swap arg order)

b012957

bennylp added 2 commits July 19, 2024 13:36

Fix swig make error on Linux and runall.py error reading log file on …

b08343b

…Windows

Attempt to fix test repeatability by 1) delete all calls to pj_srand(…

7b86a22

…) except in pj_test_suite_shuffle(), 2) unit test PRNG explicitly uses pj_uint32_t instead of int. Also disable windows python tests since it is unreliable

nanangizz modified the milestones: release-2.15, release-2.16 Dec 3, 2024

bennylp added 14 commits December 17, 2024 11:50

Merge branch 'master' into unittest-framework

7dc7ee9

Fixed inexistant function

d0a68f2

Relaxing the strictness of the test since sometimes it raises error

988f65d

Set regc_test() exclusive because it crashes sometimes, probably conc…

6e9e4b2

…urrency issue

Modified thread counter to unsigned long (from pj_uint32_t) since the…

6dbb1ba

… counter value is 2*1e9 and is overflow during diff calculation

Fixed port double destruction in mips_test() and include benchmark te…

0f3941c

…sts in pj/config_site_test.h

Use any port since sometimes test fails with address in use error

b2a5134

Merge branch 'master' into unittest-framework

420595f

Merge branch 'mips_test' into unittest-framework

aea2049

Merge branch 'master' into unittest-framework

b69ac09

Fix conflicted return value in udp_ioqueue_test() and let it immediat…

d8f0280

…ely exit on error so that we can see correlated error log

Restore sleep(0) in thread test since without it the test may occasio…

cb5f7f8

…nally fail on Linux

Various attempt to fix fluke error in resolve_test.c: 1) servers use …

6d185a6

…random port numbers, 2) increase delay waiting for various DNS timers, 3) reset global vars to zero because test may be repeated for IPv6

Merge branch 'master' into unittest-framework

01712f1

bennylp mentioned this pull request Dec 19, 2024

Unit test framework #4007

Merged

bennylp added 9 commits December 19, 2024 20:53

More relaxed packet count tests in resolver_test

97b0949

Use any port instead of hardcoded one in udp ioqueue unregister_test …

d283d3b

…since binding fails occasionally

Merge branch 'master' into unittest-framework

cb2074d

Rollback previous changes in resolver_test that relaxed packet count …

734312f

…test

Protect access to pool from worker thread with mutex in resolver_test

3203ce8

Faster resolver_test time by reducing timeout

aea63e2

Merge branch 'unittest-framework' of https://github.com/pjsip/pjproject…

1506d37

… into unittest-framework

Use high number port to make it less prone to bind error

58602a4

Remove hardcoded port number, replace with bind to any

dadf081

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Refactor test apps to use unit-test framework #4014

Refactor test apps to use unit-test framework #4014

bennylp commented Jul 11, 2024 •

edited

Loading

sauwming commented Dec 24, 2024

bennylp commented Dec 25, 2024

Refactor test apps to use unit-test framework #4014

Are you sure you want to change the base?

Refactor test apps to use unit-test framework #4014

Conversation

bennylp commented Jul 11, 2024 • edited Loading

Timing Results

Notes on timing

General look and feel

Running the tests

GitHub CI modifications

Tips on troubleshooting errors

Open issues

Reproducibility

Intermitten crashes

Test app modifications

General

pjlib-test notes

pjlib-util-test notes

pjnath-test notes

pjmedia-test notes

pjsip-test notes

Detailed test timings/outputs

pjlib-test

pjlib-util-test

pjnath-test

pjmedia-test

pjsip-test

sauwming commented Dec 24, 2024

bennylp commented Dec 25, 2024

bennylp commented Jul 11, 2024 •

edited

Loading

`pjlib-test` notes

`pjlib-util-test` notes

`pjnath-test` notes

`pjmedia-test` notes

`pjsip-test` notes

`pjlib-test`

`pjlib-util-test`

`pjnath-test`

`pjmedia-test`

`pjsip-test`