Bug 47993 - slapd: error : Unknown IO Error
slapd: error : Unknown IO Error
Status: REOPENED
Product: UCS
Classification: Unclassified
Component: SAML
UCS 5.0
Other Linux
: P5 normal (vote)
: ---
Assigned To: UCS maintainers
UCS maintainers
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2018-10-15 15:32 CEST by Philipp Hahn
Modified: 2023-02-08 16:56 CET (History)
5 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 2: Will only affect a few installed domains
How will those affected feel about the bug?: 2: A Pain – users won’t like this once they notice it
User Pain: 0.114
Enterprise Customer affected?: Yes
School Customer affected?: Yes
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2020031621000469, 2022121521000226, 2023012821000248
Bug group (optional):
Max CVSS v3 score:


Attachments
slaptest-strace-d-trace.log (50.13 KB, text/plain)
2022-08-04 23:10 CEST, Arvid Requate
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Philipp Hahn univentionstaff 2018-10-15 15:32:21 CEST
For some yet unknown reason all "slap*" tools report an error on startup:
> error : Unknown IO error

Initially this was considered the reason for "slapd" no longer starting up after the upgrade from UCS-4.2-x to UCS-4.3-0, but that was later resolved to Bug #47974.

The error message persists but does not block "slapd" from starting.
The customer has 2 more environments with the same error message and is now afraid of restarting them, as the previous failure let to a downtime of multiple days.

Using "gdb" is was able to trace the error message from being printed by lasso_init(), but there "gdb" failed to load the debug symbols and source file. The call chains is something like this:
  opendlap/slaptest
  cyrus-sasl2
  crudesaml/cy2-saml
  lasso

PS: In the customer environment the Master itself is not the IdP provider, but the "super" domain. The file "/etc/ldap/sasl2/slapd.conf" is empty as no file "/usr/share/univention-management-console/saml/idp/*.xml" exists.

+++ This bug was initially created as a clone of Bug #47974 +++
Comment 2 Valentin Heidelberger univentionstaff 2019-08-14 11:55:39 CEST
I'm lowering the pain of this because it doesn't actually cause a problem but is a cosmetic issue which can lead to major confusion when debugging slapd problems
Comment 3 Ingo Steuwer univentionstaff 2021-05-14 16:38:19 CEST
This issue has been filed against UCS 4.3.

UCS 4.3 is out of maintenance and many UCS components have changed in later releases. Thus, this issue is now being closed.

If this issue still occurs in newer UCS versions, please use "Clone this bug" or reopen it and update the UCS version. In this case please provide detailed information on how this issue is affecting you.
Comment 4 Arvid Requate univentionstaff 2022-08-04 21:58:20 CEST
I also had this message today with slapindex in a customer environment.
I did not see any issues though and simple debugging techniques like 
raised loglevel or strace did not give any hint. But it's interesting
to see that this also happens with a cli slap* tool that doesn't involve
the slapd daemon.
Comment 5 Arvid Requate univentionstaff 2022-08-04 23:06:17 CEST
Also happens with slaptest.

A combination of strace and "slaptest -d trace" showed
that the messages seem to come up while the function
"slap_sasl_init" runs. In the runup before the error messsages
(in this case the message came twice) strace shows the loading
of several libraries found in /usr/lib/x86_64-linux-gnu/sasl2/
and the last libraries that get loaded before the error messages
are all the libraries linked to /usr/lib/x86_64-linux-gnu/sasl2/libsaml.so
So my feeling is that the message either originates in the cyrus sasl library
or in the crudesaml library. Maybe some configuration (file path?) is not properly
initialized somewhere there.

Source code analysis:
slaptest in servers/slapd/slaptest.c calls slap_tool_init
slap_tool_init in servers/slapd/slapcommon.c calls slap_init
slap_init with SLAP_TOOL_MODE in servers/slapd/init.c prints "%s init: initiated %s.\n"
          and then it calls slap_sasl_init
Then the error message appears in the console output and after that
slap_sasl_init in servers/slapd/sasl.c prints "slap_sasl_init: initialized!"
Comment 6 Arvid Requate univentionstaff 2022-08-04 23:10:49 CEST
Created attachment 10972 [details]
slaptest-strace-d-trace.log
Comment 7 Philipp Hahn univentionstaff 2022-08-05 06:59:56 CEST
(In reply to Arvid Requate from comment #5)
> Also happens with slaptest.
> 
> A combination of strace and "slaptest -d trace" showed
> that the messages seem to come up while the function
> "slap_sasl_init" runs. In the runup before the error messsages
> (in this case the message came twice) strace shows the loading
> of several libraries found in /usr/lib/x86_64-linux-gnu/sasl2/
> and the last libraries that get loaded before the error messages
> are all the libraries linked to /usr/lib/x86_64-linux-gnu/sasl2/libsaml.so
> So my feeling is that the message either originates in the cyrus sasl library
> or in the crudesaml library. Maybe some configuration (file path?) is not
> properly
> initialized somewhere there.
> 
> Source code analysis:
> slaptest in servers/slapd/slaptest.c calls slap_tool_init
> slap_tool_init in servers/slapd/slapcommon.c calls slap_init
> slap_init with SLAP_TOOL_MODE in servers/slapd/init.c prints "%s init:
> initiated %s.\n"
>           and then it calls slap_sasl_init
> Then the error message appears in the console output and after that
> slap_sasl_init in servers/slapd/sasl.c prints "slap_sasl_init: initialized!"

See Bug #54495 comment 2
Comment 8 Arvid Requate univentionstaff 2022-08-05 13:13:58 CEST
Ok, cool, thanks!

While the http_proxy/HTTP_PROXY https_proxy/HTTPS_PROXY settings look ok
in that customer environment in UCR (and env):

proxy/http: http://proxyclient:secret@<IPADDRESS>:8080
proxy/https: http://proxyclient:secret@<IPADDRESS>:8080

this actually is connected with one of the two error messages,
as unsetting all those 4 proxy variables reduces the number
of error messages from two to one. Acutally it's enough to
unset the 2 variables http_proxy and HTTP_PROXY:

root@primary:~# slaptest
error : Unknown IO error
error : Unknown IO error
62ecf5de WARNING: No dynamic config support for overlay translog.
62ecf5de WARNING: No dynamic config support for overlay dellog.
config file testing succeeded
root@primary:~# unset HTTP_PROXY http_proxy
root@primary:~# slaptest
error : Unknown IO error
62ecf5ed WARNING: No dynamic config support for overlay translog.
62ecf5ed WARNING: No dynamic config support for overlay dellog.
config file testing succeeded

And the SAML IdP metadata xml file referenced in /etc/ldap/sasl2/slapd.conf
is also ok.

So no clue yet regarding the questions:
1. why libxml2 doesn't get along with the above proxy settings
2. what causes the second `error : Unknown IO error` message
3. what effect these failures have on the operation of the SAML sasl2 mechanism
Comment 9 Arvid Requate univentionstaff 2022-08-05 17:57:54 CEST
Ah, the second occurrence of the message goes away
if I also unset ftp_proxy:

unset http_proxy HTTP_PROXY ftp_proxy

No clue why it has problems with the address.
Comment 10 Philipp Hahn univentionstaff 2022-08-07 14:41:21 CEST
(In reply to Arvid Requate from comment #9)
> Ah, the second occurrence of the message goes away
> if I also unset ftp_proxy:
> 
> unset http_proxy HTTP_PROXY ftp_proxy
> 
> No clue why it has problems with the address.

No idea why FTP is relevant here, but microHttp - which is used by OpenLDAP -> libsaml -> liblasso -> libxml2 - does not support credentials specified as part of the proxy url, e.g. http_proxy=http://user:password@host:port
See https://github.com/GNOME/libxml2/blob/3c4e4bb7264afeab0704df287343d4c77ca8f8a1/nanohttp.c#L277

Probably nothing that deep down the dependency chain should ever open a network connection to some (untrusted) network service to download some (untrusted) XML Schema for validation, especially not again on each access. A trusted version should be stored locally and fetched from there if needed. Network access should be blocked.

slapd should get a sanitized environment from systemd already, but that does not help when other slap* commands are executed from an unclean environment.
Comment 11 Philipp Hahn univentionstaff 2022-08-22 15:13:39 CEST
(In reply to Philipp Hahn from comment #10)
> (In reply to Arvid Requate from comment #9)
> > Ah, the second occurrence of the message goes away if I also unset ftp_proxy:
>
> No idea why FTP is relevant here, but microHttp - which is used by OpenLDAP
> -> libsaml -> liblasso -> libxml2 - does not support credentials specified
> as part of the proxy url, e.g. http_proxy=http://user:password@host:port

"xmlsec" always initializes both a FTP and HTTP proxy:
https://github.com/lsh123/xmlsec/blob/master/src/io.c#L166

`xmlNanoFTPInit()` and `xmlNanoHTTPInit()` are both functions from `libxml2` which use `xmlParseURIRaw()` to parse the URLs:
https://gitlab.gnome.org/GNOME/libxml2/-/blob/master/uri.c#L986

Deep down xmlParse3986Userinfo() the UserInfo is parsed and extracted: https://gitlab.gnome.org/GNOME/libxml2/-/blob/master/uri.c#L365

But xmlNanoHTTPScanProxy() only extracts the server name and port, nothing else:
https://gitlab.gnome.org/GNOME/libxml2/-/blob/master/nanohttp.c#L372

Also notice that only scheme `http://` is supported, not `https://`.

Reproducer:
apt-get install gcc make libxmlsec1-dev
cd /usr/share/doc/libxmlsec1-dev/examples
make
http_proxy=https://host/ ./sign3 sign1-tmpl.xml rsakey.pem rsacert.pem >/dev/null
Comment 12 Christina Scheinig univentionstaff 2022-12-19 10:44:37 CET
Same customer environment, but an other occurence because the 

xmlsec1 --list-transforms + kaputter proxy? = error : Unknown IO error
from the  /usr/share/univention-management-console/saml/update_metadata
fails with the same error.

Unsetting the proxy ucr Variables did not help to reexecute the joinscript.

Only this did the trick

unset http_proxy HTTP_PROXY ftp_proxy && univention-run-join-scripts --force --run-scripts 92univention-management-console-web-server.inst
Comment 13 Christina Scheinig univentionstaff 2022-12-19 10:45:47 CET
Ropend because it is still an issue
Comment 14 Christina Scheinig univentionstaff 2022-12-20 14:41:19 CET
(In reply to Christina Scheinig from comment #13)
> Ropend because it is still an issue

univention-app info 
UCS: 5.0-2 errata515

So Bug 54495 seems not to fix this
Comment 15 Christina Scheinig univentionstaff 2023-02-08 16:56:21 CET
Happend in an other customer environment
We have to set
env -i bash
to run the join-script. the unsets from http_proxy HTTP_PROXY ftp_proxy did not work in this case.