1-test-suite.log

1-test-suite.log (text/plain), 11.04 KB, created by Agostino Sarubbo on 2021-10-21 04:38:27 UTC

============================================
   rsyslog 8.2110.0: tests/test-suite.log
============================================

# TOTAL: 609
# PASS:  599
# SKIP:  9
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: omfwd_fast_imuxsock
=========================

testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:08:46[0]  Test: ./omfwd_fast_imuxsock.sh
------------------------------------------------------------
background tcp dummy receiver process id is 4804
config rstb_308296_905cd3a6Yydm_.conf is:
     1	module(load="../plugins/imdiag/.libs/imdiag")
     2	global(inputs.timeout.shutdown="60000"
     3	       default.action.queue.timeoutshutdown="20000"
     4	       default.action.queue.timeoutEnqueue="20000")
     5	# use legacy-style for the following settings so that we can override if needed
     6	$MainmsgQueueTimeoutEnqueue 20000
     7	$MainmsgQueueTimeoutShutdown 10000
     8	$IMDiagListenPortFileName rstb_308296_905cd3a6Yydm.imdiag.port
     9	$IMDiagServerRun 0
    10	$IMDiagAbortTimeout 580
    11	
    12	:syslogtag, contains, "rsyslogd"  ./rstb_308296_905cd3a6Yydm.started
    13	###### end of testbench instrumentation part, test conf follows:
    14	
    15	global(	debug.whitelist="on"
    16		debug.files=["imdiag.c", "queue.c"]
    17	)
    18	
    19	template(name="testformat" type="list") {
    20	    constant(value="{ ")
    21	    property(name="timereported" dateFormat="unixtimestamp" format="jsonf")
    22	    constant(value=", ")
    23	    property(name="syslogseverity-text" format="jsonf")
    24	    constant(value=", ")
    25	    property(name="programname" format="jsonf")
    26	    constant(value=", ")
    27	    property(name="msg" format="jsonf")
    28	    constant(value=" }\n")
    29	}
    30	template(name="outfmt" 
    31		type="string" 
    32		string="%msg:F,58:2%\n")
    33	
    34	# IMUX Input socket
    35	module(load="../plugins/imuxsock/.libs/imuxsock" sysSock.use="off")
    36	input(type="imuxsock" Socket="rstb_308296_905cd3a6Yydm-testbench_socket")
    37	
    38	# Note: stats module
    39	module(load="../plugins/impstats/.libs/impstats" log.file="rstb_308296_905cd3a6Yydm.stats" interval="1" ruleset="stats")
    40	
    41	main_queue(
    42	    queue.timeoutshutdown="10000"
    43	#    queue.timeoutEnqueue="20"
    44	#    queue.discardSeverity="3"
    45	)
    46	
    47	ruleset(name="stats") {
    48		stop # nothing to do here
    49	}
    50	
    51	if $msg contains "test message nbr" then
    52		action(
    53		    type="omfwd"
    54		    Target="127.0.0.1"
    55		    Port="48727"
    56		    Protocol="tcp"
    57		    TCP_Framing="octet-counted"
    58		    ResendLastMSGOnReconnect="on"
    59	
    60		    Template="testformat"
    61	
    62		    queue.discardMark="100"
    63		    queue.discardSeverity="3"
    64	
    65	#	    queue.timeoutEnqueue="5"
    66		    queue.type="linkedlist"
    67		)
rsyslogd: NOTE: RSYSLOG_DEBUG_TIMEOUTS_TO_STDERR activated
main Q:Reg: worker start requested, num workers currently 0
main Q:Reg: wrkr start initiated with state 0, num workers now 1
rsyslog debug: main Q:Reg: worker 0x55e059dafa00 started
rsyslog debug: main Q:Reg: started with state 3, num workers now 1
00:08:46[0]  rstb_308296_905cd3a6Yydm:.pid found, pid 4809
00:08:46[0]  rsyslogd startup msg seen, pid  4809
waiting for file rstb_308296_905cd3a6Yydm.imdiag.port
imdiag port: 35523
action-1-builtin:omfwd queue:Reg: worker start requested, num workers currently 0
action-1-builtin:omfwd queue:Reg: wrkr start initiated with state 0, num workers now 1
rsyslog debug: action-1-builtin:omfwd queue:Reg: worker 0x55e059da37f0 started
rsyslog debug: action-1-builtin:omfwd queue:Reg: started with state 3, num workers now 1
Shutting down instance 1
imdiag: wait q_empty: qsize 0 nempty 1
imdiag[35523]: mainqueue empty
rsyslogd debug: info: trying to cooperatively stop input ../plugins/imdiag/.libs/imdiag, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input imuxsock, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input impstats, timeout 60000 ms
rsyslog debug: main Q:Reg/w0: enter WrkrExecCleanup
rsyslog debug: 0x55e059dafb80: worker exiting
rsyslog debug: main Q:Reg/w0: thread joined
rsyslog debug: action-1-builtin:omfwd queue:Reg/w0: enter WrkrExecCleanup
minitcpsrv terminates itself
rsyslog debug: 0x55e059da3930: worker exiting
rsyslog debug: action-1-builtin:omfwd queue:Reg/w0: thread joined
00:08:48[2]  wait on shutdown of 4809

============================================================
FILE "rstb_308296_905cd3a6Yydm.stats" content:
     1	Thu Oct 21 00:08:47 2021: imdiag-stats-reporting-controller: origin=imdiag potentialTotalArtificialDelayInMs=0 actualTotalArtificialDelayInMs=0 delayInvocationCount=0 
     2	Thu Oct 21 00:08:47 2021: global: origin=dynstats 
     3	Thu Oct 21 00:08:47 2021: global: origin=percentile 
     4	Thu Oct 21 00:08:47 2021: imdiag(0): origin=imdiag submitted=0 
     5	Thu Oct 21 00:08:47 2021: action-0-builtin:omfile: origin=core.action processed=2 failed=0 suspended=0 suspended.duration=0 resumed=0 
     6	Thu Oct 21 00:08:47 2021: imuxsock: origin=imuxsock submitted=84379 ratelimit.discarded=0 ratelimit.numratelimiters=0 
     7	Thu Oct 21 00:08:47 2021: TCP-127.0.0.1-48727: origin=omfwd bytes.sent=10957900 
     8	Thu Oct 21 00:08:47 2021: action-1-builtin:omfwd: origin=core.action processed=84381 failed=0 suspended=0 suspended.duration=0 resumed=0 
     9	Thu Oct 21 00:08:47 2021: resource-usage: origin=impstats utime=1044414 stime=1327276 maxrss=4420 minflt=918 majflt=0 inblock=0 oublock=24 nvcsw=67163 nivcsw=15 openfiles=12 
    10	Thu Oct 21 00:08:47 2021: action-1-builtin:omfwd queue: origin=core.queue size=2 enqueued=84383 full=0 discarded.full=0 discarded.nf=0 maxqsize=45 
    11	Thu Oct 21 00:08:47 2021: main Q: origin=core.queue size=3 enqueued=84397 full=0 discarded.full=0 discarded.nf=0 maxqsize=17 
    12	Thu Oct 21 00:08:48 2021: imdiag-stats-reporting-controller: origin=imdiag potentialTotalArtificialDelayInMs=0 actualTotalArtificialDelayInMs=0 delayInvocationCount=0 
    13	Thu Oct 21 00:08:48 2021: global: origin=dynstats 
    14	Thu Oct 21 00:08:48 2021: global: origin=percentile 
    15	Thu Oct 21 00:08:48 2021: imdiag(0): origin=imdiag submitted=0 
    16	Thu Oct 21 00:08:48 2021: action-0-builtin:omfile: origin=core.action processed=2 failed=0 suspended=0 suspended.duration=0 resumed=0 
    17	Thu Oct 21 00:08:48 2021: imuxsock: origin=imuxsock submitted=100000 ratelimit.discarded=0 ratelimit.numratelimiters=0 
    18	Thu Oct 21 00:08:48 2021: TCP-127.0.0.1-48727: origin=omfwd bytes.sent=12988890 
    19	Thu Oct 21 00:08:48 2021: action-1-builtin:omfwd: origin=core.action processed=100000 failed=0 suspended=0 suspended.duration=0 resumed=0 
    20	Thu Oct 21 00:08:48 2021: resource-usage: origin=impstats utime=1193256 stime=1537259 maxrss=4868 minflt=951 majflt=0 inblock=0 oublock=64 nvcsw=78719 nivcsw=19 openfiles=11 
    21	Thu Oct 21 00:08:48 2021: action-1-builtin:omfwd queue: origin=core.queue size=0 enqueued=100000 full=0 discarded.full=0 discarded.nf=0 maxqsize=45 
    22	Thu Oct 21 00:08:48 2021: main Q: origin=core.queue size=0 enqueued=100023 full=0 discarded.full=0 discarded.nf=0 maxqsize=17 
FAIL: content_check failed to find "action-1-builtin:omfwd queue: origin=core.queue size=.* enqueued=100000 full=0 discarded.full=0 discarded.nf=.* maxqsize=100"
not reporting failure as RSYSLOG_STATSURL is not set
00:08:48[2]  FAIL: Test ./omfwd_fast_imuxsock.sh (took 2 seconds)
FAIL omfwd_fast_imuxsock.sh (exit status: 1)

SKIP: allowed-sender-tcp-hostname-fail
======================================

testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:11:58[0]  Test: ./allowed-sender-tcp-hostname-fail.sh
------------------------------------------------------------
HTTP endpoint 'http://testbench.rsyslog.com/testbench/echo-get.php' is not reachable. Skipping test ...
SKIP allowed-sender-tcp-hostname-fail.sh (exit status: 77)

SKIP: daqueue-persist
=====================

===============================================================================
[daqueue-persist.sh]: test data persisting at shutdown
TEST is currently DISABLE because it is unstable
SKIP daqueue-persist.sh (exit status: 77)

SKIP: omprog-restart-terminated
===============================

testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:24:43[0]  Test: ./omprog-restart-terminated.sh
------------------------------------------------------------
Testbench requires unavailable command: lsof
SKIP omprog-restart-terminated.sh (exit status: 77)

SKIP: omprog-restart-terminated-outfile
=======================================

testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:24:43[0]  Test: ./omprog-restart-terminated-outfile.sh
------------------------------------------------------------
Testbench requires unavailable command: lsof
SKIP omprog-restart-terminated-outfile.sh (exit status: 77)

SKIP: imfile-logrotate
======================

[inotify mode]
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:42:03[0]  Test: ./imfile-logrotate.sh
------------------------------------------------------------
Testbench requires unavailable command: logrotate
SKIP imfile-logrotate.sh (exit status: 77)

SKIP: imfile-logrotate-multiple
===============================

[inotify mode]
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:42:03[0]  Test: ./imfile-logrotate-multiple.sh
------------------------------------------------------------
Testbench requires unavailable command: logrotate
SKIP imfile-logrotate-multiple.sh (exit status: 77)

SKIP: imfile-logrotate-copytruncate
===================================

[inotify mode]
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:42:03[0]  Test: ./imfile-logrotate-copytruncate.sh
------------------------------------------------------------
Testbench requires unavailable command: logrotate
SKIP imfile-logrotate-copytruncate.sh (exit status: 77)

SKIP: imfile-logrotate-nocopytruncate
=====================================

[inotify mode]
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:42:03[0]  Test: ./imfile-logrotate-nocopytruncate.sh
------------------------------------------------------------
Testbench requires unavailable command: logrotate
SKIP imfile-logrotate-nocopytruncate.sh (exit status: 77)

SKIP: glbl-oversizeMsg-truncate-imfile
======================================

testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
00:42:23[0]  Test: ./glbl-oversizeMsg-truncate-imfile.sh
------------------------------------------------------------
[inotify mode]
imrelp parameter oversizeMode not available. Test stopped
SKIP glbl-oversizeMsg-truncate-imfile.sh (exit status: 77)