Troubleshooting

Um den aktuell in der Föderation publizierten xml-Metadatensatz Ihres IdP oder SP herunterzuladen, melden Sie sich an der Metadatenverwaltung an. In der Übersicht wählen Sie den entsprechenden Eintrag aus und klicken rechts unter Aktionen auf das Download-Symbol.

  • Beobachten Sie die fortlaufenden Logdateien idp-process.log (Standardpfad: /opt/shibboleth-idp/logs/) und das Tomcat-Log.
  • Setzen Sie das Loglevel auf DEBUG hoch. Warnungen und Fehler bekommen Sie auch so zu sehen, aber z.B. die Inhalte der übertragenen SAML-Assertions nicht. In vielen Fällen reicht es, dies für idp, messages und encryption zu tun:
    /opt/shibboleth-idp/conf/logback.xml
        <variable name="idp.loglevel.idp" value="DEBUG" />
        <variable name="idp.loglevel.ldap" value="INFO" />
        <variable name="idp.loglevel.messages" value="DEBUG" />
        <variable name="idp.loglevel.encryption" value="DEBUG" />
        <variable name="idp.loglevel.opensaml" value="INFO" />
        <variable name="idp.loglevel.props" value="INFO" />
        <variable name="idp.loglevel.httpclient" value="INFO" />
  • Stoßen Sie das Neuladen des Servlets manuell an (touch /opt/shibboleth-idp/war/idp.war) oder warten Sie bis zum automatischen Reload der Logging-Konfiguration. Die Reload-Intervalle sind in /opt/shibboleth-idp/conf/services.properties konfigurierbar. Für die conf/logback.xml sind standardmäßig 5 Minuten eingestellt.
  • Wenn Sie im idp-process.log Warnungen oder Fehler sehen, lesen Sie das Log von oben nach unten ab dem letzten IdP-Neustart. Dies ist wichtig, denn die ersten Fehlermeldungen benennen häufig Gründe (z.B. Syntaxfehler in Konfigurationsdateien mit Zeile o.ä.), während die letzten Fehler oft Folgefehler sind, die immer gleich aussehen. Ein Beispiel für einen solchen Folgefehler:
    'shibboleth.metrics.RegisterMetricSets$child#0' defined in file [C:\Program Files (x86)\shibboleth\idp\system\conf\..\..\conf\admin\metrics.xml]: Cannot resolve reference to bean 'shibboleth.metrics.AttributeResolverGaugeSet' while setting bean property 'arguments' with key [7]; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'shibboleth.metrics.AttributeResolverGaugeSet' defined in file [C:\Program Files (x86)\shibboleth\idp\system\conf\general-admin-system.xml]: Invocation of init method failed; nested exception is net.shibboleth.utilities.java.support.component.ComponentInitializationException: Injected service was null or not an AttributeResolver

    Scrollen Sie hoch und suchen Sie nach Fehlern beim Laden der Datei conf/attribute-resolver.xml.

  • Beim Eintragen von Werten in .properties-Dateien vermeiden Sie bitte Leerzeichen am Zeilenende! Ein Blank hinter einem Passwort macht dieses ungültig! Beim LDAP-Fehler Invalid Credentials stellen Sie bitte sicher, dass Sie bei den Zugangsdaten keine Leerzeichen an den Zeilenenden stehen haben. Das Passwort steht nicht in Hochkommata oder Anführungszeichen.
  • Achten Sie auf Präzision bei der Konfiguration, etwa bei der Schreibweise von Entity IDs. Entity IDs mit und ohne Schrägstrich am Ende des URL (trailing slash) sind zwei verschiedene Entity IDs!

Wenn Ihr IdP gar keine Logfiles nach /opt/shibboleth-idp/logs/ (oder in ein von Ihnen eingestelltes abweichendes Verzeichnis) schreibt, dann schauen Sie bitte die Logdateien des Tomcat an. Auf Debian-Systemen finden Sie in /var/log/tomcat9 verschiedene Dateien. Beobachten Sie alle, etwa mit

root@idp:~# tail -f /var/log/tomcat9/*.log

und starten Sie in einem anderen Terminalfenster den Tomcat neu.

Um die komplette SAML-Assertion einzusehen, setzen Sie - wie oben beschrieben - das Loglevel für idp, messages und encryption auf DEBUG. Im idp-process.log sehen Sie dann die Assertion. Suchen Sie nach „Assertion before encryption“. In dieser SAML Assertion sehen Sie, dass die persistentId mit dem Wert „NMTR6SVZOCUWF5MNGDDIYQQBY4QCB76N“ und die Attribute eduPersonScopedAffiliation (mit drei Werten) und eduPersonEntitlement (mit einem Wert) von dem IdP mit der EntityId https://idp.local/idp/shibboleth and den SP mit der EntityId https://sp1.local/shibboleth übertragen wurden:

/opt/shibboleth-idp/logs/idp-process.log
2020-10-27 14:54:07,079 - 127.0.0.2 - DEBUG [org.opensaml.saml.saml2.encryption.Encrypter:339] - Assertion before encryption:
<?xml version="1.0" encoding="UTF-8"?><saml2:Assertion xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" ID="_3a89275f3cd179685b22a3cf616c518a" IssueInstant="2020-10-27T13:54:06.179Z" Version="2.0">
   <saml2:Issuer>https://idp.local/idp/shibboleth</saml2:Issuer>
   <saml2:Subject>
      <saml2:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:persistent" NameQualifier="https://idp.local/idp/shibboleth" SPNameQualifier="https://sp1.local/shibboleth" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">NMTR6SVZOCUWF5MNGDDIYQQBY4QCB76N</saml2:NameID>
      <saml2:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer">
         <saml2:SubjectConfirmationData Address="127.0.0.2" InResponseTo="_72e4da8e1fa8dfcea0f85a340ded8b7c" NotOnOrAfter="2020-10-27T13:59:06.581Z" Recipient="https://sp1.local/Shibboleth.sso/SAML2/POST"/>
      </saml2:SubjectConfirmation>
   </saml2:Subject>
   <saml2:Conditions NotBefore="2020-10-27T13:54:06.179Z" NotOnOrAfter="2020-10-27T13:59:06.179Z">
      <saml2:AudienceRestriction>
         <saml2:Audience>https://sp1.local/shibboleth</saml2:Audience>
      </saml2:AudienceRestriction>
   </saml2:Conditions>
   <saml2:AuthnStatement AuthnInstant="2020-10-27T13:53:52.456Z" SessionIndex="_d8a534b987abc20fe007a9cc80af7bdb">
      <saml2:SubjectLocality Address="127.0.0.2"/>
      <saml2:AuthnContext>
         <saml2:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef>
      </saml2:AuthnContext>
   </saml2:AuthnStatement>
   <saml2:AttributeStatement>
      <saml2:Attribute FriendlyName="eduPersonScopedAffiliation" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.9" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue>staff@local</saml2:AttributeValue>
         <saml2:AttributeValue>member@local</saml2:AttributeValue>
         <saml2:AttributeValue>employee@local</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonEntitlement" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.7" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue>urn:mace:dir:entitlement:common-lib-terms</saml2:AttributeValue>
      </saml2:Attribute>
   </saml2:AttributeStatement>
</saml2:Assertion>

Bei Shibboleth IdPs 4.x, die von einer Version 3.x upgegraded wurden, wird die Attribute Registry nicht ohne Hinzutun benutzt. Die Datei attribute-Resolver.xml enthält dann noch wie früher die Transcoding-Regeln für jedes definierte Attribut. Wenn Sie eine neue Attributdefinition einfügen, muss auch diese eine Transcoding-Regel enthalten, sonst kann der IdP das Attribut nicht in eine für SPs lesbare Form kodieren. Am Beispiel der SAML Pairwise ID sieht das so aus:

/opt/shibboleth-idp/conf/attribute-resolver.xml
    <AttributeDefinition xsi:type="Scoped" id="samlPairwiseID" scope="%{idp.scope}">
        <InputDataConnector ref="myStoredId" attributeNames="persistentId"/>
        <AttributeEncoder xsi:type="SAML2ScopedString" name="urn:oasis:names:tc:SAML:attribute:pairwise-id" friendlyName="pairwise-id" encodeType="false" />
    </AttributeDefinition>

Sie können den IdP alternativ auf die Nutzung der Attribute Registry umbauen. Die Zeile mit dem AttributeEncoder darf hingegen bei einem neu installierten IdP 4.x nicht hier auftauchen, sie wird aus der Attribute Registry unterhalb von conf/attributes geholt.

„opensaml::SecurityPolicyException Message was signed, but signature could not be verified.“

Diese Fehlermeldung erscheint, wenn das Zertifikat, das Sie beim IdP in der Metadatenverwaltung publiziert haben, nicht mit dem Zertifikat und dem zugehörigen private Key übereinstimmt, das am IdP für die SAML-Kommunikation verwendet wird. Bei der IdP-Installation wird automatisch ein selbstsigniertes Zertifikat generiert und in conf/idp.properties vorkonfiguriert. Dort müssen Sie die Pfadangaben zu Ihrem Schlüsselmaterial (private Key, Zertifikat) einstellen.

Übrigens: Die Datei metadata/idp-metadata.xml wird ebenfalls automatisch angelegt und mit den initialen Metadaten des IdP befüllt. In der DFN-AAI wird diese Datei aber ignoriert. Was dort drinsteht, ist also irrelevant. Für den IdP „gelten“ die Metadaten, die Sie in der Verwaltung einpflegen und aktuell halten.

„opensaml::FatalProfileException at (https://testsp2.aai.dfn.de/Shibboleth.sso/SAML2/POST)“

Diese Fehlermeldung erscheint, wenn der Service Provider keine Metadaten für den Identity Provider findet.

  • Prüfen Sie in der Metadatenverwaltung, ob Sie den IdP dort angelegt haben und ihn korrekt in die entsprechende Föderation eingetragen haben (DFN-AAI-Test, DFN-AAI-Basic oder DFN-AAI).
  • Vergleichen Sie die EntityID in conf/idp.properties und in dem Metadateneintrag - beide müssen identisch sein.
  • Bedenken Sie, dass Sie nach Änderungen in der Metadatenverwaltung 60-90 Minuten warten müssen, bis die neuen Metadaten aggregiert und verteilt sind.

Umgekehrt erhalten Sie im idp-process.log folgende Fehlermeldung, wenn der IdP keine Metadaten für den Service Provider finden kann:

INFO [org.opensaml.saml.common.binding.impl.SAMLMetadataLookupHandler:171] (...) Message Handler:  No metadata returned for 
 (...) in role {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor
  • Prüfen Sie, woher der IdP die Metadaten kennen müsste:
    • aus den Föderationsmetadaten?
    • aus den lokalen Metadaten Ihrer Einrichtung? (Ist der SP als lokaler SP bei Ihnen in der Metadatenverwaltung eingetragen?)
    • aus einem manuell hinzugefügten xml-Metadatensatz, der in ./conf/metadata-providers.xml eingebunden ist? Prüfen Sie den Inhalt beider Dateien.
  • Bedenken Sie bei den ersten beiden, dass Sie nach Änderungen in der Metadatenverwaltung 60-90 Minuten warten müssen, bis die neuen Metadaten aggregiert und verteilt sind.

„Web Login Service - Unsupported Request The application you have accessed is not registered for use with this service“, zu deutsch: „Web Anmeldedienst - Nicht unterstützte Anfrage Die Applikation, auf die Sie zugreifen möchten, ist für die Benutzung dieses Dienstes nicht registriert.“

Diese Fehlermeldung erscheint, wenn der IdP keinen Metadatensatz geladen hat, in dem der SP drinsteht.

  • Prüfen Sie, ob alle benötigten Metadata Provider in conf/metadata-providers.xml konfiguriert (Doku) sind.
  • Prüfen Sie, ob auf der Platte auch aktuelle Föderationsmetadaten ankommen (im Ordner /opt/shibboleth-idp/metadata). Dies können Sie übrigens auch der IdP-Statusseite (standardmäßig https://IHR-HOST/idp/status) entnehmen. In diesem Beispiel sind die DFN_AAI Metadaten abgelaufen.
service: shibboleth.MetadataResolverService
last successful reload attempt: 2020-12-22T07:58:12Z
last reload attempt: 2020-12-22T07:58:12Z

	metadata source: DFN_AAI
	last refresh attempt: 2020-12-24T05:26:48Z
	last update: 2020-12-24T05:26:48Z

	metadata source: DFN_AAI_eduGAIN
	last refresh attempt: 2021-01-05T08:57:55Z
	last update: 2021-01-05T08:57:55Z

	metadata source: DFN_AAI_TEST
	last refresh attempt: 2021-01-05T09:36:13Z
	last update: 2021-01-05T09:36:13Z
  • Schauen Sie ins DEBUG-Log. Vergleichen Sie den saml:Issuer aus dem AuthnRequest mit der EntityID, die Sie kontaktieren möchten. Wird im Authentication Request ein anderer String als Aussteller gesendet, kann der IdP diesen Aussteller nicht in den Metadaten finden. Kontaktieren Sie in diesem Fall den SP-Betreiber.

Sie erhalten (z.B. nach einem Zertifikatstausch) die Fehlermeldung „A non-proceed event occurred while processing the request: DecryptNameIDFailed“ - möglicherweise auch erst beim Single Logout. Der SP verschlüsselt offenbar mit einem Zertifikat, zu dem der IdP keinen privaten Schlüssel (mehr) hat. Entfernen Sie das alte Zertifikat aus den Metadaten und warten Sie die üblichen 60-90 Minuten, bis sich in der Föderation herumgesprochen hat, dass nur noch das neue Zertifikat verwendet werden soll.

Die Konfigurationsdateien im Auslieferungszustand finden Sie im Verzeichnis dist/conf. Von hier können Sie sich Dateien holen, wenn Sie noch einmal von vorn beginnen möchten oder wenn Sie schauen möchten, wie die Originaldatei in einer neueren Shibboleth-Version aussieht.

Wenn Sie bei einem Shibboleth IdP 4.x feststellen, dass Attribute doppelt übertragen werden, haben Sie die Datei conf/attribute-resolver.xml unbesehen aus einem IdP 3.x übernommen. Damit hat der IdP seine Transcoding-Regeln doppelt hinterlegt, nämlich im Resolver und in der Attribute Registry. Entfernen Sie doppelte Informationen aus der Datei, so dass sie diesem Beispiel folgt.

Eine genauere Erklärung der Attribute Registry finden Sie in unserem Upgrade-Vortrag, ca. ab Minute 13:40.

Wenn Sie untenstehende Fehlermeldung bekommen, dann haben Sie wahrscheinlich ein Attribut, z.B. die eduPersonTargetedId doppelt in der Attribute Registry hinterlegt. Möglicherweise haben Sie sowohl die Datei dfnMisc.xml eingebunden (wie hier beschrieben), als auch das Einzelattribut eduPersonTargetedId in einer .properties-Datei unterhalb von conf/attributes/custom/ hinterlegt. Löschen Sie am besten einfach die .properties-Datei, dann wird nur noch das Attribut aus dfnMisc.xml gelesen.

java.lang.IllegalArgumentException: {urn:oasis:names:tc:SAML:2.0:assertion}NameID is
already the child of another XMLObject and may not be inserted into this list

Die vom DFN-Verein herausgegebenen Metadatensätze mit den eduGAIN-Entitäten haben noch nie die Entitäten aus der DFN-AAI enthalten. Wir filtern sie heraus, weil Ihre Systeme sie ja bereits aus den DFN-AAI-Metadaten kennen und wir keine Doubletten verteilen möchten. Sie prüfen, ob eine Entität in eduGAIN ist, suchen Sie sie bitte in der eduGAIN Entities Database.

Wenn Sie Ihren IdP in die Föderation haben eintragen lassen und er nicht in der Einrichtungsauswahl des gewünschten Service Providers auftaucht, kann das folgende Gründe haben:

  • Der SP hat die aktuellsten Metadaten noch nicht geholt. Warten Sie bei den DFN-AAI-Föderationen (auch DFN-AAI-Test) 60-90 Minuten, bei eduGAIN 24 Stunden, bevor Sie testen. Sie können vorab prüfen, ob Ihr IdP schon in den eduGAIN-Metadaten angekommen ist: https://technical.edugain.org/entities
  • Sie haben in der Metadatenverwaltung das Häkchen bei „hide from discovery“ gesetzt. Entfernen Sie das Häkchen und warten Sie 60-90 Minuten.

Ein Service Provider kann über seinen Metadatensatz bekannt geben, dass er die Authentication Requests an einen Identity Provider signiert und/oder dass er gerne signierte SAML Assertions zurückbekommen möchte. Unsere Metadatenverwaltung kann beides nur anzeigen, wenn es bereits beim Einlesen der xml-Datei vorhanden ist. Erweitern Sie die SP-Metadaten dazu bei md:SPSSODescriptor wie folgt:

<md:SPSSODescriptor AuthnRequestsSigned="true" WantAssertionsSigned="true" protocolSupportEnumeration="urn:oasis:names:tc:SAML:2.0:protocol">

Wenn die ScriptedAttributes aus Ihrer conf/attribute-resolver.xml-Datei nicht mehr ausgeführt werden und Sie die Fehlermeldung „No scripting engine associated with scripting language javascript“ bekommen, dann haben Sie wahrscheinlich auf Java 17 (bzw. JDK 15 oder höher) aktualisiert. Die Scripting Engine „Nashorn“, mit der Javascript ausgeführt werden kann, muss in dem Fall über ein IdP-Plugin ergänzt werden: Ab der IdP-Version 4.2 können Sie das direkt mit folgendem Befehl tun:

root@idp:~# /opt/shibboleth-idp/bin/plugin.sh -I net.shibboleth.idp.plugin.nashorn

Weder eine Konfiguration noch das Aktivieren eines Modules sind nötig.

Ohne zusätzliche Konfiguration (ORM Workaround), wie beschrieben von den Schweizer Kollegen https://www.switch.ch/aai/guides/idp/installation/#ormxmlworkaround speichert PostgreSQL die Werte als 'large Objects' in der Systemtabelle und schreibt in die Spalte 'value' nur die Link ID.

Um die korrekte Funktion sicher zu stellen, muss obiger Workaround dringend angewendet werden.

Leider sind hinterher die Daten der Datenbank nicht mehr kompatibel. D.h. vor dem Neustart des IdP müssen die Werte der Spalte value in der Tabelle storagerecords konvertiert werden.

Eine Möglichkeit geht wie folgt direkt auf der schon vorhandenen Datenbank:

DB als postgres Nutzer öffnen, da die Daten in der Systemtabelle pg_largeobject liegen:

psql -Upostgres shibboleth

Temporär werden die Werte decodiert mit den ID's in eine neue Tabelle geschrieben. Diese neue Tabelle gehört postgres, daher evtl. danach den Owner aktualisieren:

shibboleth=> create table new_table as (select context, id, value, encode(data, 'escape') as new_value from storagerecords left join pg_largeobject on oid(value) = loid);
shibboleth=> alter table new_table owner to shibboleth;

Jetzt anhand der values die ID's durch deren Inhalte aus der neuen Tabelle ersetzen:

shibboleth=> update storagerecords set value = new_table.new_value from new_table where storagerecords.value = new_table.value;

Die Temporäre Tabelle wieder löschen:

shibboleth=> drop table new_table;

Danach den IdP (tomcat) neu starten. Die Session und Attribute-Constent Daten sind weiterhin (wieder) verfügbar.

  • Zuletzt geändert: vor 10 Monaten