Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 2218856

Summary:	"error : Unknown IO error" being printed when evaluating a rule
Product:	Red Hat Enterprise Linux 8	Reporter:	Renaud Métrich <rmetrich>
Component:	libxml2	Assignee:	David King <dking>
Status:	CLOSED MIGRATED	QA Contact:	Vera Budikova <vbudikov>
Severity:	medium	Docs Contact:
Priority:	medium
Version:	8.8	CC:	desktop-qa-list, ekolesni, mhaicman, mmarhefk, ohudlick, sbarcomb
Target Milestone:	rc	Keywords:	MigratedToJIRA
Target Release:	---	Flags:	pm-rhel: mirror+
Hardware:	All
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2023-09-15 17:44:15 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Renaud Métrich 2023-06-30 09:43:02 UTC

Description of problem:

A customer constantly gets the following messages, sometimes multiple times, when executing the following command:

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
# oscap xccdf eval --rule xccdf_org.ssgproject.content_rule_xwindows_runlevel_target --profile xccdf_org.ssgproject.content_profile_stig /usr/share/xml/scap/ssg/content/ssg-rhel8-ds.xml
error : Unknown IO error
[...]
--- Starting Evaluation ---

Title   Disable X Windows Startup By Setting Default Target
Rule    xccdf_org.ssgproject.content_rule_xwindows_runlevel_target
Ident   CCE-83380-6
Result  pass
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

We are trying to understand where this comes from (apparently it's from libxml2 library, xmlIO.c line 406) and if this is benign or not.

Version-Release number of selected component (if applicable):

openscap-scanner-1.3.7-1.el8.x86_64

How reproducible:

Always on customer system, couldn't reproduce internally

Comment 1 Renaud Métrich 2023-06-30 09:45:03 UTC

The strace shows a high number of `brk()` calls and `mremap()` just before (hence memory allocation), but nothing else:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
9140  12:20:06.995983 brk(NULL)         = 0x562a83433000 <0.000027>
9140  12:20:06.996096 brk(0x562a83454000) = 0x562a83454000 <0.000022>
9140  12:20:07.070091 brk(NULL)         = 0x562a83454000 <0.000026>
9140  12:20:07.070190 brk(0x562a83479000) = 0x562a83479000 <0.000021>
9140  12:20:07.070437 mremap(0x7f65561d0000, 331776, 659456, MREMAP_MAYMOVE) = 0x7f65561d0000 <0.000018>
9140  12:20:07.082584 brk(NULL)         = 0x562a83479000 <0.000020>
9140  12:20:07.082659 brk(0x562a8349d000) = 0x562a8349d000 <0.000020>
9140  12:20:07.107506 brk(NULL)         = 0x562a8349d000 <0.000021>
9140  12:20:07.107594 brk(0x562a834be000) = 0x562a834be000 <0.000019>
9140  12:20:07.113993 brk(NULL)         = 0x562a834be000 <0.000020>
9140  12:20:07.114050 brk(0x562a834df000) = 0x562a834df000 <0.000020>
9140  12:20:07.123826 brk(NULL)         = 0x562a834df000 <0.000039>
9140  12:20:07.123917 brk(0x562a83506000) = 0x562a83506000 <0.000018>
9140  12:20:07.750464 brk(NULL)         = 0x562a83506000 <0.000054>
9140  12:20:07.750607 brk(0x562a83527000) = 0x562a83527000 <0.000021>
9140  12:20:07.783420 brk(NULL)         = 0x562a83527000 <0.000023>
9140  12:20:07.783525 brk(0x562a83548000) = 0x562a83548000 <0.000026>
9140  12:20:07.838506 brk(NULL)         = 0x562a83548000 <0.000048>
9140  12:20:07.838659 brk(0x562a8356d000) = 0x562a8356d000 <0.000023>
9140  12:20:07.891447 brk(NULL)         = 0x562a8356d000 <0.000033>
9140  12:20:07.891552 brk(0x562a83590000) = 0x562a83590000 <0.000026>
9140  12:20:07.941167 brk(NULL)         = 0x562a83590000 <0.000027>
9140  12:20:07.941280 brk(0x562a835b1000) = 0x562a835b1000 <0.000025>
9140  12:20:07.956697 brk(NULL)         = 0x562a835b1000 <0.000016>
9140  12:20:07.956770 brk(0x562a835d2000) = 0x562a835d2000 <0.000020>
9140  12:20:07.971919 brk(NULL)         = 0x562a835d2000 <0.000025>
9140  12:20:07.972001 brk(0x562a835f3000) = 0x562a835f3000 <0.000020>
9140  12:20:08.191901 munmap(0x7f655617f000, 331776) = 0 <0.000141>
9140  12:20:08.198655 munmap(0x7f65561d0000, 659456) = 0 <0.000111>
9140  12:20:08.228927 munmap(0x7f6556273000, 151552) = 0 <0.000067>
9140  12:20:08.229188 write(2</dev/pts/2<char 136:2>>, "error : ", 8) = 8 <0.000384>
9140  12:20:08.229745 write(2</dev/pts/2<char 136:2>>, "Unknown IO error\n", 17) = 17 <0.000050>
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Comment 2 Renaud Métrich 2023-07-10 13:21:58 UTC

The customer delivered me a coredump which was taken when the "Unknown IO error" message was getting printed.

The backtrace shows this:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) bt
#0  0x00007f71479a9a28 in __GI___libc_write (fd=2, buf=0x7fff94db34a0, nbytes=17) at ../sysdeps/unix/sysv/linux/write.c:26
#1  0x00007f714791b9ed in _IO_new_file_write (f=0x7f7147c4a600 <_IO_2_1_stderr_>, data=0x7fff94db34a0, n=17)
    at fileops.c:1180
#2  0x00007f714791ad5f in new_do_write (fp=fp@entry=0x7f7147c4a600 <_IO_2_1_stderr_>, 
    data=data@entry=0x7fff94db34a0 "Unknown IO error\n", to_do=to_do@entry=17) at libioP.h:838
#3  0x00007f714791c11e in _IO_new_file_xsputn (n=17, data=<optimized out>, f=0x7f7147c4a600 <_IO_2_1_stderr_>)
    at fileops.c:1259
#4  _IO_new_file_xsputn (f=0x7f7147c4a600 <_IO_2_1_stderr_>, data=<optimized out>, n=17) at fileops.c:1201
#5  0x00007f71478f30ca in buffered_vfprintf (s=s@entry=0x7f7147c4a600 <_IO_2_1_stderr_>, 
    format=format@entry=0x7f714b3a337d "%s\n", args=args@entry=0x7fff94db5a50) at ../libio/libioP.h:838
#6  0x00007f71478f20b7 in _IO_vfprintf_internal (s=s@entry=0x7f7147c4a600 <_IO_2_1_stderr_>, 
    format=format@entry=0x7f714b3a337d "%s\n", ap=0x7fff94db5a50) at vfprintf.c:1329
#7  0x00007f71479c656c in ___vfprintf_chk (fp=0x7f7147c4a600 <_IO_2_1_stderr_>, flag=flag@entry=1, 
    format=format@entry=0x7f714b3a337d "%s\n", ap=ap@entry=0x7fff94db5a50) at vfprintf_chk.c:33
#8  0x00007f714b2b3677 in vfprintf (__ap=0x7fff94db5a50, __fmt=0x7f714b3a337d "%s\n", __stream=<optimized out>)
    at /usr/include/bits/stdio2.h:132
#9  xmlGenericErrorDefaultFunc (ctx=<optimized out>, msg=0x7f714b3a337d "%s\n") at ../error.c:78
#10 0x00007f714b2b3892 in xmlReportError (err=err@entry=0x7f714b5e6140 <xmlLastError>, ctxt=ctxt@entry=0x0, 
    str=str@entry=0x55d1d4c7b970 "Unknown IO error", channel=channel@entry=0x7f714b2b35c0 <xmlGenericErrorDefaultFunc>, 
    data=data@entry=0x7f7147c4a600 <_IO_2_1_stderr_>) at ../error.c:398
#11 0x00007f714b2b5466 in __xmlRaiseError (schannel=0x0, channel=0x7f714b2b35c0 <xmlGenericErrorDefaultFunc>, 
    data=0x7f7147c4a600 <_IO_2_1_stderr_>, ctx=0x0, nod=<optimized out>, domain=9, code=2003, level=XML_ERR_ERROR, 
    file=<optimized out>, line=0, str1=<optimized out>, str2=<optimized out>, str3=<optimized out>, int1=0, col=0, 
    msg=<optimized out>) at ../error.c:636
#12 0x00007f714b2b54f7 in __xmlSimpleError (domain=<optimized out>, code=<optimized out>, node=node@entry=0x0, 
    msg=<optimized out>, extra=extra@entry=0x7f714b3a0b1e "Syntax Error\n") at ../error.c:657
#13 0x00007f714b2e1419 in __xmlIOErr (domain=domain@entry=9, code=code@entry=2003, 
    extra=extra@entry=0x7f714b3a0b1e "Syntax Error\n") at ../xmlIO.c:413
#14 0x00007f714b3204e6 in xmlNanoFTPScanProxy__internal_alias (URL=<optimized out>) at ../nanoftp.c:441
#15 xmlNanoFTPScanProxy__internal_alias (URL=<optimized out>) at ../nanoftp.c:419
#16 0x00007f714b32055d in xmlNanoFTPInit__internal_alias () at ../nanoftp.c:204
[...]
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

The message happens because there is a FTP_PROXY env variable starting with `http://`, and this string is not understood by embedded nanoftp.c handler.
For some reason the code wants the string to start with `ftp://`:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
 418 void
 419 xmlNanoFTPScanProxy(const char *URL) {
 :
 438     uri = xmlParseURIRaw(URL, 1);
 439     if ((uri == NULL) || (uri->scheme == NULL) ||
 440         (strcmp(uri->scheme, "ftp")) || (uri->server == NULL)) {        <----- HERE check against "ftp"
 441         __xmlIOErr(XML_FROM_FTP, XML_FTP_URL_SYNTAX, "Syntax Error\n");
 442         if (uri != NULL)
 443             xmlFreeURI(uri);
 444         return;
 445     }
 :
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

This ends up reporting an error, but there is some oddity: on frame 13, we have "code == 2003" (XML_FTP_URL_SYNTAX error):

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) up
#13 0x00007f714b2e1419 in __xmlIOErr (domain=domain@entry=9, code=code@entry=2003, 
    extra=extra@entry=0x7f714b3a0b1e "Syntax Error\n") at ../xmlIO.c:413
413	    __xmlSimpleError(domain, code, NULL, IOerr[idx], extra);
(gdb) p code
$27 = 2003
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

But then in inner frame 12m the "code" automagically changed into 2 (XML_ERR_NO_MEMORY error):

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) down
#12 0x00007f714b2b54f7 in __xmlSimpleError (domain=<optimized out>, code=<optimized out>, node=node@entry=0x0, 
    msg=<optimized out>, extra=extra@entry=0x7f714b3a0b1e "Syntax Error\n") at ../error.c:657
657		    __xmlRaiseError(NULL, NULL, NULL, NULL, node, domain,
(gdb) list
652	                 const char *msg, const char *extra)
653	{
654	
655	    if (code == XML_ERR_NO_MEMORY) {
656		if (extra)
657		    __xmlRaiseError(NULL, NULL, NULL, NULL, node, domain,
658				    XML_ERR_NO_MEMORY, XML_ERR_FATAL, NULL, 0, extra,
659				    NULL, NULL, 0, 0,
660				    "Memory allocation failed : %s\n", extra);
661		else
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Assembly code shows "code" is supposed to be in $esi (2nd argument) and is compared against 2 (no memory error):
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) disassemble /m
Dump of assembler code for function __xmlSimpleError:
653	{
   0x00007f714b2b54b0 <+0>:	endbr64 

654	
655	    if (code == XML_ERR_NO_MEMORY) {
   0x00007f714b2b54b4 <+4>:	sub    $0x8,%rsp
   0x00007f714b2b54b8 <+8>:	mov    %edi,%r9d
   0x00007f714b2b54bb <+11>:	cmp    $0x2,%esi
 :
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

In upper frame, we can see at some point in time "code" is indeed stored in $esi:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) up
#13 0x00007f714b2e1419 in __xmlIOErr (domain=domain@entry=9, code=code@entry=2003, 
    extra=extra@entry=0x7f714b3a0b1e "Syntax Error\n") at ../xmlIO.c:413
413	    __xmlSimpleError(domain, code, NULL, IOerr[idx], extra);
(gdb) disassemble /m
Dump of assembler code for function __xmlIOErr:
247	{
 :
410	    if (code >= XML_IO_UNKNOWN) idx = code - XML_IO_UNKNOWN;
   0x00007f714b2e1420 <+64>:	lea    0xb57e1(%rip),%rcx        # 0x7f714b396c08
   0x00007f714b2e1427 <+71>:	cmp    $0x5db,%esi                       <------------ HERE
   0x00007f714b2e142d <+77>:	jle    0x7f714b2e140a <__xmlIOErr+42>
   0x00007f714b2e142f <+79>:	lea    -0x5dc(%rsi),%eax
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

But then the compiler optimized the next instruction (the "if") and in this optimized code, $esi gets changed:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
411	    if (idx >= (sizeof(IOerr) / sizeof(IOerr[0]))) idx = 0;
   0x00007f714b2e1435 <+85>:	cmp    $0x38,%eax
   0x00007f714b2e1438 <+88>:	jg     0x7f714b2e140a <__xmlIOErr+42>
   0x00007f714b2e143a <+90>:	lea    0x2fa6df(%rip),%rdx        # 0x7f714b5dbb20 <IOerr>
   0x00007f714b2e1441 <+97>:	mov    (%rdx,%rax,8),%rcx
   0x00007f714b2e1445 <+101>:	jmp    0x7f714b2e140a <__xmlIOErr+42>
   0x00007f714b2e1447 <+103>:	nopw   0x0(%rax,%rax,1)
 : lots of changes of $esi through "mov" statements
   0x00007f714b2e196e <+1422>:	jmpq   0x7f714b2e140a <__xmlIOErr+42>
   0x00007f714b2e1973 <+1427>:	lea    0xb53df(%rip),%rcx        # 0x7f714b396d59
   0x00007f714b2e197a <+1434>:	mov    $0x5ef,%esi
   0x00007f714b2e197f <+1439>:	jmpq   0x7f714b2e140a <__xmlIOErr+42>
   0x00007f714b2e1984 <+0>:	data16 nopw %cs:0x0(%rax,%rax,1)
   0x00007f714b2e198f <+11>:	nop

412	
413	    __xmlSimpleError(domain, code, NULL, IOerr[idx], extra);
   0x00007f714b2e140a <+42>:	add    $0x10,%rsp
   0x00007f714b2e140e <+46>:	mov    %rbx,%r8
   0x00007f714b2e1411 <+49>:	xor    %edx,%edx
   0x00007f714b2e1413 <+51>:	pop    %rbx
   0x00007f714b2e1414 <+52>:	jmpq   0x7f714b2ad800 <__xmlSimpleError@plt>
=> 0x00007f714b2e1419 <+57>:	nopl   0x0(%rax)
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

So clearly something is weird with that code.

The good news is it's super easy to reproduce:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[root@vm-rhel8 ~]# export FTP_PROXY=http://8.8.8.8:3128
[root@vm-rhel8 ~]# oscap xccdf eval --rule xccdf_org.ssgproject.content_rule_xwindows_runlevel_target --profile xccdf_org.ssgproject.content_profile_stig /usr/share/xml/scap/ssg/content/ssg-rhel8-ds.xml
error : Unknown IO error
[...]

--- Starting Evaluation ---

Title   Disable X Windows Startup By Setting Default Target
Rule    xccdf_org.ssgproject.content_rule_xwindows_runlevel_target
Ident   CCE-83380-6
Result  pass
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Comment 3 RHEL Program Management 2023-09-15 17:42:24 UTC

Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.

Comment 4 RHEL Program Management 2023-09-15 17:44:15 UTC

This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.