[Bug 2083700] Re: rsyslog FTBFS due to gzip different behavior with hw acceleration on s390x
Andreas Hasenack
2083700 at bugs.launchpad.net
Tue Feb 25 12:33:38 UTC 2025
** Description changed:
+ [ Impact ]
+
+ * An explanation of the effects of the bug on users and justification
+ for backporting the fix to the stable release.
+
+ * In addition, it is helpful, but not required, to include an
+ explanation of how the upload fixes this bug.
+
+ [ Test Plan ]
+
+ * detailed instructions how to reproduce the bug
+
+ * these should allow someone who is not familiar with the affected
+ package to reproduce the bug and verify that the updated package
+ fixes the problem.
+
+ * if other testing is appropriate to perform before landing this
+ update, this should also be described here.
+
+ [ Where problems could occur ]
+
+ * Think about what the upload changes in the software. Imagine the
+ change is wrong or breaks something else: how would this show up?
+
+ * It is assumed that any SRU candidate patch is well-tested before
+ upload and has a low overall risk of regression, but it's important
+ to make the effort to think about what ''could'' happen in the event
+ of a regression.
+
+ * This must never be "None" or "Low", or entirely an argument as to why
+ your upload is low risk.
+
+ * This both shows the SRU team that the risks have been considered,
+ and provides guidance to testers in regression-testing the SRU.
+
+ [ Other Info ]
+
+ * Anything else you think is useful to include
+
+ * Make sure to explain any deviation from the norm, to save the SRU
+ reviewer from having to infer your reasoning, possibly incorrectly.
+ This should also help reduce review iterations, particularly when the
+ reason for the deviation is not obvious.
+
+ * Anticipate questions from users, SRU, +1 maintenance, security teams
+ and the Technical Board and address these questions in advance
+
+
+ [ Original Description ]
+
During an archive rebuild, rsyslog FTBFS on s390x only:
https://launchpadlibrarian.net/751879056/buildlog_ubuntu-
oracular-s390x.rsyslog_8.2406.0-1ubuntu2_BUILDING.txt.gz
The build fails due to two tests:
FAIL: gzipwr_flushInterval
==========================
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
08:47:04[0] Test: ./gzipwr_flushInterval.sh
------------------------------------------------------------
config rstb_216690_cea0d3b3Yo0x_.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_216690_cea0d3b3Yo0x.imdiag.port
9 $IMDiagServerRun 0
10 $IMDiagAbortTimeout 580
11
12 :syslogtag, contains, "rsyslogd" ./rstb_216690_cea0d3b3Yo0x.started
13 ###### end of testbench instrumentation part, test conf follows:
14
15 module(load="../plugins/imtcp/.libs/imtcp")
16 input(type="imtcp" port="0" listenPortFileName="rstb_216690_cea0d3b3Yo0x.tcpflood_port")
17
18 template(name="outfmt" type="string" string="%msg:F,58:2%\n")
19 :msg, contains, "msgnum:" action(type="omfile" template="outfmt"
20 zipLevel="6" ioBufferSize="256k"
21 flushOnTXEnd="off" flushInterval="1"
22 asyncWriting="on"
23 file="rstb_216690_cea0d3b3Yo0x.out.log.gz")
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 0x2aa0873c810 started
rsyslog debug: main Q:Reg: started with state 3, num workers now 1
08:47:04[0] rstb_216690_cea0d3b3Yo0x:.pid found, pid 158166
08:47:04[0] rsyslogd startup msg seen, pid 158166
waiting for file rstb_216690_cea0d3b3Yo0x.imdiag.port
imdiag port: 35391
waiting for file rstb_216690_cea0d3b3Yo0x.tcpflood_port
TCPFLOOD_PORT now: 32793
starting run 1
Sending 2500 messages.
00002500 messages sent
runtime: 0.005
End of tcpflood Run
gzip: rstb_216690_cea0d3b3Yo0x.out.log.gz: invalid compressed data--format violated
scanf error in index i=0
gzip: rstb_216690_cea0d3b3Yo0x.out.log.gz: invalid compressed data--format violated
sequence error detected in rstb_216690_cea0d3b3Yo0x.out.log.gz
number of lines in file: 0 rstb_216690_cea0d3b3Yo0x.out.log.gz
sorted data has been placed in error.log, first 10 lines are:
1 scanf error in index i=0
---last 10 lines are:
1 scanf error in index i=0
UNSORTED data, first 10 lines are:
1 scanf error in index i=0
---last 10 lines are:
1 scanf error in index i=0
not reporting failure as RSYSLOG_STATSURL is not set
rsyslog pid file still exists, trying to shutdown...
rsyslogd debug: info: trying to cooperatively stop input ../plugins/imdiag/.libs/imdiag, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input imtcp, timeout 60000 ms
rsyslog debug: main Q:Reg/w0: enter WrkrExecCleanup
rsyslog debug: 0x2aa0873c990: worker exiting
rsyslog debug: main Q:Reg/w0: thread joined
08:47:09[5] FAIL: Test ./gzipwr_flushInterval.sh (took 5 seconds)
FAIL gzipwr_flushInterval.sh (exit status: 1)
FAIL: gzipwr_flushOnTXEnd
=========================
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
08:47:04[0] Test: ./gzipwr_flushOnTXEnd.sh
------------------------------------------------------------
config rstb_586738_b0a588ae30Do_.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_586738_b0a588ae30Do.imdiag.port
9 $IMDiagServerRun 0
10 $IMDiagAbortTimeout 580
11
12 :syslogtag, contains, "rsyslogd" ./rstb_586738_b0a588ae30Do.started
13 ###### end of testbench instrumentation part, test conf follows:
14
15 module(load="../plugins/imtcp/.libs/imtcp")
16 input(type="imtcp" port="0" listenPortFileName="rstb_586738_b0a588ae30Do.tcpflood_port")
17
18 template(name="outfmt" type="string" string="%msg:F,58:2%\n")
19 :msg, contains, "msgnum:" { action(type="omfile" template="outfmt"
20 zipLevel="6" ioBufferSize="256k"
21 flushOnTXEnd="on"
22 asyncWriting="on"
23 file="rstb_586738_b0a588ae30Do.out.log")
24 action(type="omfile" file="rstb_586738_b0a588ae30Do.countlog")
25 }
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 0x2aa18a89a50 started
rsyslog debug: main Q:Reg: started with state 3, num workers now 1
08:47:04[0] rstb_586738_b0a588ae30Do:.pid found, pid 158888
08:47:04[0] rsyslogd startup msg seen, pid 158888
waiting for file rstb_586738_b0a588ae30Do.imdiag.port
imdiag port: 35511
waiting for file rstb_586738_b0a588ae30Do.tcpflood_port
TCPFLOOD_PORT now: 39421
starting run 1
Sending 2500 messages.
00002500 messages sent
runtime: 0.001
End of tcpflood Run
imdiag: wait q_empty: qsize 1210 nempty 0
imdiag: wait q_empty: qsize 0 nempty 1
imdiag[35511]: mainqueue empty
test 1
wait_file_lines success, have 2500 lines, took 0 seconds, file rstb_586738_b0a588ae30Do.countlog
-rw-r--r-- 1 buildd buildd 4841 Sep 29 08:47 rstb_586738_b0a588ae30Do.out.log
gzip: stdin: invalid compressed data--format violated
chkseq: start 0, end 2499
scanf error in index i=0
sequence error detected
not reporting failure as RSYSLOG_STATSURL is not set
rsyslog pid file still exists, trying to shutdown...
rsyslogd debug: info: trying to cooperatively stop input ../plugins/imdiag/.libs/imdiag, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input imtcp, timeout 60000 ms
rsyslog debug: main Q:Reg/w0: enter WrkrExecCleanup
rsyslog debug: 0x2aa18a89bd0: worker exiting
rsyslog debug: main Q:Reg/w0: thread joined
08:47:05[1] FAIL: Test ./gzipwr_flushOnTXEnd.sh (took 1 seconds)
FAIL gzipwr_flushOnTXEnd.sh (exit status: 1)
--
Since these are both gzip related, I looked at zlib and noticed that
there are s390x-specific optimization patches for that package:
https://launchpad.net/ubuntu/+source/zlib/1:1.3.dfsg+really1.3.1-1ubuntu1.
In a PPA build, I re-built zlib without these s390x patches, and re-
built rsyslog against that version. In that case, the build succeeded:
https://launchpad.net/~enr0n/+archive/ubuntu/proposed-
migration/+build/29141297
Therefore, I believe the cause of this FTBFS is related the
s390x-specific patches in zlib. This needs investigating by someone more
familiar with s390x and/or these patches.
--
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to rsyslog in Ubuntu.
https://bugs.launchpad.net/bugs/2083700
Title:
rsyslog FTBFS due to gzip different behavior with hw acceleration on
s390x
Status in Ubuntu on IBM z Systems:
Confirmed
Status in gzip package in Ubuntu:
Fix Released
Status in rsyslog package in Ubuntu:
Invalid
Status in zlib package in Ubuntu:
Incomplete
Status in gzip source package in Noble:
Confirmed
Status in rsyslog source package in Noble:
Invalid
Status in zlib source package in Noble:
Incomplete
Status in gzip source package in Oracular:
Confirmed
Status in rsyslog source package in Oracular:
Invalid
Status in zlib source package in Oracular:
Incomplete
Status in gzip source package in Plucky:
Fix Released
Status in rsyslog source package in Plucky:
Invalid
Status in zlib source package in Plucky:
Incomplete
Bug description:
[ Impact ]
* An explanation of the effects of the bug on users and justification
for backporting the fix to the stable release.
* In addition, it is helpful, but not required, to include an
explanation of how the upload fixes this bug.
[ Test Plan ]
* detailed instructions how to reproduce the bug
* these should allow someone who is not familiar with the affected
package to reproduce the bug and verify that the updated package
fixes the problem.
* if other testing is appropriate to perform before landing this
update, this should also be described here.
[ Where problems could occur ]
* Think about what the upload changes in the software. Imagine the
change is wrong or breaks something else: how would this show up?
* It is assumed that any SRU candidate patch is well-tested before
upload and has a low overall risk of regression, but it's important
to make the effort to think about what ''could'' happen in the event
of a regression.
* This must never be "None" or "Low", or entirely an argument as to why
your upload is low risk.
* This both shows the SRU team that the risks have been considered,
and provides guidance to testers in regression-testing the SRU.
[ Other Info ]
* Anything else you think is useful to include
* Make sure to explain any deviation from the norm, to save the SRU
reviewer from having to infer your reasoning, possibly incorrectly.
This should also help reduce review iterations, particularly when the
reason for the deviation is not obvious.
* Anticipate questions from users, SRU, +1 maintenance, security teams
and the Technical Board and address these questions in advance
[ Original Description ]
During an archive rebuild, rsyslog FTBFS on s390x only:
https://launchpadlibrarian.net/751879056/buildlog_ubuntu-
oracular-s390x.rsyslog_8.2406.0-1ubuntu2_BUILDING.txt.gz
The build fails due to two tests:
FAIL: gzipwr_flushInterval
==========================
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
08:47:04[0] Test: ./gzipwr_flushInterval.sh
------------------------------------------------------------
config rstb_216690_cea0d3b3Yo0x_.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_216690_cea0d3b3Yo0x.imdiag.port
9 $IMDiagServerRun 0
10 $IMDiagAbortTimeout 580
11
12 :syslogtag, contains, "rsyslogd" ./rstb_216690_cea0d3b3Yo0x.started
13 ###### end of testbench instrumentation part, test conf follows:
14
15 module(load="../plugins/imtcp/.libs/imtcp")
16 input(type="imtcp" port="0" listenPortFileName="rstb_216690_cea0d3b3Yo0x.tcpflood_port")
17
18 template(name="outfmt" type="string" string="%msg:F,58:2%\n")
19 :msg, contains, "msgnum:" action(type="omfile" template="outfmt"
20 zipLevel="6" ioBufferSize="256k"
21 flushOnTXEnd="off" flushInterval="1"
22 asyncWriting="on"
23 file="rstb_216690_cea0d3b3Yo0x.out.log.gz")
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 0x2aa0873c810 started
rsyslog debug: main Q:Reg: started with state 3, num workers now 1
08:47:04[0] rstb_216690_cea0d3b3Yo0x:.pid found, pid 158166
08:47:04[0] rsyslogd startup msg seen, pid 158166
waiting for file rstb_216690_cea0d3b3Yo0x.imdiag.port
imdiag port: 35391
waiting for file rstb_216690_cea0d3b3Yo0x.tcpflood_port
TCPFLOOD_PORT now: 32793
starting run 1
Sending 2500 messages.
00002500 messages sent
runtime: 0.005
End of tcpflood Run
gzip: rstb_216690_cea0d3b3Yo0x.out.log.gz: invalid compressed data--format violated
scanf error in index i=0
gzip: rstb_216690_cea0d3b3Yo0x.out.log.gz: invalid compressed data--format violated
sequence error detected in rstb_216690_cea0d3b3Yo0x.out.log.gz
number of lines in file: 0 rstb_216690_cea0d3b3Yo0x.out.log.gz
sorted data has been placed in error.log, first 10 lines are:
1 scanf error in index i=0
---last 10 lines are:
1 scanf error in index i=0
UNSORTED data, first 10 lines are:
1 scanf error in index i=0
---last 10 lines are:
1 scanf error in index i=0
not reporting failure as RSYSLOG_STATSURL is not set
rsyslog pid file still exists, trying to shutdown...
rsyslogd debug: info: trying to cooperatively stop input ../plugins/imdiag/.libs/imdiag, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input imtcp, timeout 60000 ms
rsyslog debug: main Q:Reg/w0: enter WrkrExecCleanup
rsyslog debug: 0x2aa0873c990: worker exiting
rsyslog debug: main Q:Reg/w0: thread joined
08:47:09[5] FAIL: Test ./gzipwr_flushInterval.sh (took 5 seconds)
FAIL gzipwr_flushInterval.sh (exit status: 1)
FAIL: gzipwr_flushOnTXEnd
=========================
testbench: TZ env var not set, setting it to UTC
------------------------------------------------------------
08:47:04[0] Test: ./gzipwr_flushOnTXEnd.sh
------------------------------------------------------------
config rstb_586738_b0a588ae30Do_.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_586738_b0a588ae30Do.imdiag.port
9 $IMDiagServerRun 0
10 $IMDiagAbortTimeout 580
11
12 :syslogtag, contains, "rsyslogd" ./rstb_586738_b0a588ae30Do.started
13 ###### end of testbench instrumentation part, test conf follows:
14
15 module(load="../plugins/imtcp/.libs/imtcp")
16 input(type="imtcp" port="0" listenPortFileName="rstb_586738_b0a588ae30Do.tcpflood_port")
17
18 template(name="outfmt" type="string" string="%msg:F,58:2%\n")
19 :msg, contains, "msgnum:" { action(type="omfile" template="outfmt"
20 zipLevel="6" ioBufferSize="256k"
21 flushOnTXEnd="on"
22 asyncWriting="on"
23 file="rstb_586738_b0a588ae30Do.out.log")
24 action(type="omfile" file="rstb_586738_b0a588ae30Do.countlog")
25 }
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 0x2aa18a89a50 started
rsyslog debug: main Q:Reg: started with state 3, num workers now 1
08:47:04[0] rstb_586738_b0a588ae30Do:.pid found, pid 158888
08:47:04[0] rsyslogd startup msg seen, pid 158888
waiting for file rstb_586738_b0a588ae30Do.imdiag.port
imdiag port: 35511
waiting for file rstb_586738_b0a588ae30Do.tcpflood_port
TCPFLOOD_PORT now: 39421
starting run 1
Sending 2500 messages.
00002500 messages sent
runtime: 0.001
End of tcpflood Run
imdiag: wait q_empty: qsize 1210 nempty 0
imdiag: wait q_empty: qsize 0 nempty 1
imdiag[35511]: mainqueue empty
test 1
wait_file_lines success, have 2500 lines, took 0 seconds, file rstb_586738_b0a588ae30Do.countlog
-rw-r--r-- 1 buildd buildd 4841 Sep 29 08:47 rstb_586738_b0a588ae30Do.out.log
gzip: stdin: invalid compressed data--format violated
chkseq: start 0, end 2499
scanf error in index i=0
sequence error detected
not reporting failure as RSYSLOG_STATSURL is not set
rsyslog pid file still exists, trying to shutdown...
rsyslogd debug: info: trying to cooperatively stop input ../plugins/imdiag/.libs/imdiag, timeout 60000 ms
rsyslogd debug: info: trying to cooperatively stop input imtcp, timeout 60000 ms
rsyslog debug: main Q:Reg/w0: enter WrkrExecCleanup
rsyslog debug: 0x2aa18a89bd0: worker exiting
rsyslog debug: main Q:Reg/w0: thread joined
08:47:05[1] FAIL: Test ./gzipwr_flushOnTXEnd.sh (took 1 seconds)
FAIL gzipwr_flushOnTXEnd.sh (exit status: 1)
--
Since these are both gzip related, I looked at zlib and noticed that
there are s390x-specific optimization patches for that package:
https://launchpad.net/ubuntu/+source/zlib/1:1.3.dfsg+really1.3.1-1ubuntu1.
In a PPA build, I re-built zlib without these s390x patches, and re-
built rsyslog against that version. In that case, the build succeeded:
https://launchpad.net/~enr0n/+archive/ubuntu/proposed-
migration/+build/29141297
Therefore, I believe the cause of this FTBFS is related the
s390x-specific patches in zlib. This needs investigating by someone
more familiar with s390x and/or these patches.
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-z-systems/+bug/2083700/+subscriptions
More information about the foundations-bugs
mailing list