[PATCH 0/2] Fixes for logging tests

[PATCH 0/2] Fixes for logging tests

[David Gibson]

Here's a fix for a spurious test failure in the logging tests, along
with a trivial cleanup.

David Gibson (2):
  test: Slight simplification to pasta log tests
  test: Make log truncation test more robust

 test/pasta_options/log_to_file | 11 ++++-------
 1 file changed, 4 insertions(+), 7 deletions(-)

-- 
2.44.0

[PATCH 1/2] test: Slight simplification to pasta log tests

[David Gibson]

test/pasta_options/log_to_file contains a couple of rudimentary tests
where we start pasta with an interactive shell, then immediately exit it.
We can achieve the same thing by using /bin/true as the command to pasta.
This also means that waiting for pasta to start, waiting for the executed
command to complete and for pasta to clean up are all handled by simply
waiting for pasta to complete in the foreground, so there's no need for an
additional sleep.

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
---
 test/pasta_options/log_to_file | 8 ++------
 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
index fcdd5538..f1002167 100644
--- a/test/pasta_options/log_to_file
+++ b/test/pasta_options/log_to_file
@@ -33,15 +33,11 @@ test	Log creation
 set	PORTS -t 10001,10002 -u 10001,10002
 set	LOG_FILE __STATEDIR__/pasta.log
 
-passt	./pasta -l __LOG_FILE__
-passtb	exit
-sleep	1
+passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ -s __LOG_FILE__ ]
 
 test	Log truncated on creation
-passt	./pasta -l __LOG_FILE__
-passtb	exit
-sleep	1
+passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
 
 test	Maximum log size
-- 
@@ -33,15 +33,11 @@ test	Log creation
 set	PORTS -t 10001,10002 -u 10001,10002
 set	LOG_FILE __STATEDIR__/pasta.log
 
-passt	./pasta -l __LOG_FILE__
-passtb	exit
-sleep	1
+passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ -s __LOG_FILE__ ]
 
 test	Log truncated on creation
-passt	./pasta -l __LOG_FILE__
-passtb	exit
-sleep	1
+passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
 
 test	Maximum log size
-- 
2.44.0

[PATCH 2/2] test: Make log truncation test more robust

[David Gibson]

test/pasta_options/log_to_file checks that pasta truncates its log file
when started.  It does that by starting pasta with a log file once, then
starting it again and checking that after the second round, the log file
has only one line: the startup banner from the second invocation.

However, this test will break if the second invocation logs any additional
messages at startup.  This can easily happen on a host with multiple
network interfaces due to the "Multiple default route" informational
messages added in 639fdf06e ("netlink: Fix selection of template
interface").  I believe it could also happen on a host without IPv6
connectivity due to the "Couldn't pick external interface" messages, though
I haven't confirmed this.

Make the log file test more robust, by not testing for a single line, but
instead explicitly testing for the PID of the second pasta invocation in
the banner line.

Link: https://bugs.passt.top/show_bug.cgi?id=88

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
---
 test/pasta_options/log_to_file | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
index f1002167..fe50e50b 100644
--- a/test/pasta_options/log_to_file
+++ b/test/pasta_options/log_to_file
@@ -37,8 +37,9 @@ passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ -s __LOG_FILE__ ]
 
 test	Log truncated on creation
-passt	./pasta -l __LOG_FILE__ -- /bin/true
-check	[ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
+passt	./pasta -l __LOG_FILE__ -- /bin/true & wait
+pout	PID2 echo $!
+check	head -1 __LOG_FILE__ | grep '^pasta .* [(]__PID2__[)]$'
 
 test	Maximum log size
 passtb	./pasta --config-net -d -f -l __LOG_FILE__ --log-size $((100 * 1024)) -- sh -c 'while true; do tcp_crr --nolog -P 10001 -C 10002 -6; done'
-- 
@@ -37,8 +37,9 @@ passt	./pasta -l __LOG_FILE__ -- /bin/true
 check	[ -s __LOG_FILE__ ]
 
 test	Log truncated on creation
-passt	./pasta -l __LOG_FILE__ -- /bin/true
-check	[ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
+passt	./pasta -l __LOG_FILE__ -- /bin/true & wait
+pout	PID2 echo $!
+check	head -1 __LOG_FILE__ | grep '^pasta .* [(]__PID2__[)]$'
 
 test	Maximum log size
 passtb	./pasta --config-net -d -f -l __LOG_FILE__ --log-size $((100 * 1024)) -- sh -c 'while true; do tcp_crr --nolog -P 10001 -C 10002 -6; done'
-- 
2.44.0

Re: [PATCH 2/2] test: Make log truncation test more robust

[Stefano Brivio]

On Wed, 24 Apr 2024 14:30:00 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:

> test/pasta_options/log_to_file checks that pasta truncates its log file
> when started.  It does that by starting pasta with a log file once, then
> starting it again and checking that after the second round, the log file
> has only one line: the startup banner from the second invocation.
> 
> However, this test will break if the second invocation logs any additional
> messages at startup.  This can easily happen on a host with multiple
> network interfaces due to the "Multiple default route" informational
> messages added in 639fdf06e ("netlink: Fix selection of template
> interface").  I believe it could also happen on a host without IPv6
> connectivity due to the "Couldn't pick external interface" messages, though
> I haven't confirmed this.
> 
> Make the log file test more robust, by not testing for a single line, but
> instead explicitly testing for the PID of the second pasta invocation in
> the banner line.
> 
> Link: https://bugs.passt.top/show_bug.cgi?id=88
> 
> Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
> ---
>  test/pasta_options/log_to_file | 5 +++--
>  1 file changed, 3 insertions(+), 2 deletions(-)
> 
> diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
> index f1002167..fe50e50b 100644
> --- a/test/pasta_options/log_to_file
> +++ b/test/pasta_options/log_to_file
> @@ -37,8 +37,9 @@ passt	./pasta -l __LOG_FILE__ -- /bin/true
>  check	[ -s __LOG_FILE__ ]
>  
>  test	Log truncated on creation
> -passt	./pasta -l __LOG_FILE__ -- /bin/true
> -check	[ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
> +passt	./pasta -l __LOG_FILE__ -- /bin/true & wait
> +pout	PID2 echo $!
> +check	head -1 __LOG_FILE__ | grep '^pasta .* [(]__PID2__[)]$'
                                                       ^^^^^^^^^^^^^^

I'm mildly amused that this actually works. :)

-- 
Stefano

Re: [PATCH 0/2] Fixes for logging tests

[Stefano Brivio]

On Wed, 24 Apr 2024 14:29:58 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:

> Here's a fix for a spurious test failure in the logging tests, along
> with a trivial cleanup.
> 
> David Gibson (2):
>   test: Slight simplification to pasta log tests
>   test: Make log truncation test more robust

Applied.

-- 
Stefano