This issue also happens using SOGo 5.x. I attach in this message the
report using the same configuration with SOGo 5.0.1.
Thank you!
El 18/1/21 a les 13:52, Odhiambo Washington ([email protected]) ha escrit:
If you mentioned that the problem happens with SOGo v5.x, perhaps the
developers will listen. If you refer to a v4 bug, and v4 is already
discontinued, I do not see them even considering your issue. Just a
thought.
On Mon, 18 Jan 2021 at 14:39, Roger Garcia Ferre <[email protected]
<mailto:[email protected]>> wrote:
We found someone who also reported this as a bug:
https://sogo.nu/bugs/view.php?id=5153
<https://sogo.nu/bugs/view.php?id=5153>
Our situation is identical to him.
El 14/1/21 a les 18:21, Roger Garcia Ferre ([email protected]
<mailto:[email protected]>) ha escrit:
Hello everybody,
We are trying to configure SAML2 authentication with SOGo. We
have tried everything we had in mind but without success.
In this message we attach a text file with all the configurations
and logs we got and we also attach all steps done in order to
get the result.
We will appreciate very much any help.
--
*Roger Garcia*
934 76 69 10
618 24 67 33
<http://www.datalab.es/>
Aviso Legal <http://www.datalab.es/cont_cas/legal.html>
--
[email protected] <mailto:[email protected]>
https://inverse.ca/sogo/lists <https://inverse.ca/sogo/lists>
--
*Roger Garcia*
934 76 69 10
618 24 67 33
<http://www.datalab.es/>
Aviso Legal <http://www.datalab.es/cont_cas/legal.html>
--
[email protected] <mailto:[email protected]>
https://inverse.ca/sogo/lists <https://inverse.ca/sogo/lists>
--
Best regards,
Odhiambo WASHINGTON,
Nairobi,KE
+254 7 3200 0004/+254 7 2274 3223
"Oh, the cruft.", grep ^[^#] :-)
--
[email protected]
https://inverse.ca/sogo/lists
--
*Roger Garcia*
934 76 69 10
618 24 67 33
<http://www.datalab.es/>
Aviso Legal <http://www.datalab.es/cont_cas/legal.html>
--
[email protected]
https://inverse.ca/sogo/lists
# Report SOGo SAML2/ADFS issues
This report summarizes the issues found while we were trying to authenticate users using SAML2 protocol. Our testbed has the especifications below:
- ADFS Server running in Windows 2012 R2 (SAML2 IdP Server)
- Debian 10 (buster) running SOGo version 5.0.1 server with dovecot and postfix
We have tried using two types of saml2 attributes: username and mail.
The first one doesn't include mail domain, the second includes (at) hostname.
Examples:
- username: testuser
- email: [email protected]
We also provide user database using AD/LDAP (it points to the same user storage than SAML2 ADFS Server). Before trying SAML2 we have checked the results using plain LDAP authentication and it was working like a charm.
## Behavior using the first approach (username)
sogo.conf contents:
```
{
SOGoProfileURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_user_profile";
OCSFolderInfoURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_folder_info";
OCSSessionsFolderURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_sessions_folder";
SOGoLanguage = English;
SOGoTimeZone = Europe/Madrid;
SOGoMailDomain = example.com;
SOGoIMAPServer = 127.0.0.1;
SOGoDraftsFolderName = "Drafts";
SOGoSentFolderName = "Sent Items";
SOGoTrashFolderName = "Deleted Items";
SOGoJunkFolderName = "Junk E-Mail";
SOGoMailingMechanism = smtp;
SOGoSMTPServer = 127.0.0.1;
SOGoSuperUsernames = (support);
SOGoPageTitle = SOGo;
SOGoVacationEnabled = YES;
SOGoForwardEnabled = YES;
SOGoSieveScriptsEnabled = YES;
SOGoSieveServer = sieve://127.0.0.1:4190;
WOWorkersCount = 90;
WOWatchDogRequestTimeout = 60;
SOGoMaximumPingInterval = 3540;
SOGoMaximumSyncInterval = 3540;
SOGoInternalSyncInterval = 60;
SOGoMaximumSyncResponseSize = 2048;
SOGoMaximumSyncWindowSize = 32;
SxVMemLimit = 512;
SOGoAuthenticationType = saml2;
SOGoSAML2PrivateKeyLocation = "/etc/letsencrypt/live/sogo-test.example.com/privkey.pem";
SOGoSAML2CertificateLocation = "/etc/letsencrypt/live/sogo-test.example.com/cert.pem";
SOGoSAML2IdpMetadataLocation = "/etc/sogo/FederationMetadata.xml";
SOGoSAML2IdpPublicKeyLocation = "/etc/sogo/certs/adfs-xml.pem";
SOGoSAML2IdpCertificateLocation = "/etc/sogo/certs/";
SAML2ServerURLString = "https://sogo-test.example.com/";;
SOGoSAML2LoginAttribute = "username";
NGImap4AuthMechanism = PLAIN;
SOGoForceExternalLoginWithEmail = YES;
SOGoUserSources = (
{
type = ldap;
CNFieldName = displayName;
IDFieldName = cn;
UIDFieldName = sAMAccountName;
bindFields = (sAMAccountName);
baseDN = "ou=Central,dc=hq,dc=example,dc=com";
bindDN = "cn=ldapbrowser,cn=users,dc=hq,dc=example,dc=com";
MailFieldNames = (mail);
canAuthenticate = NO;
displayName = "Shared Addresses";
hostname = "192.168.201.10";
id = public;
isAddressBook = YES;
port = 389;
}
);
}
```
Steps:
1. Open Mozilla Firefox Browser and point to sogo-test.example.com
2. SOGo redirects our session to IdP (ADFS)
3. ADFS asks our credentials
4. ADFS returns to SOGo with one assertion
5. SOGo stores some log error entries (liblasso related) and finally returns a 501 Error Code
Decrypted SAML2 assertion:
```
<?xml version="1.0"?>
<samlp:Response xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="_ad0d0b67-fb9a-4488-9d9c-2a9907fa5a81" Version="2.0" IssueInstant="2021-01-14T15:02:55.314Z" Destination="https://sogo-test.example.com/SOGo/saml2-signon-post"; Consent="urn:oasis:names:tc:SAML:2.0:consent:unspecified" InResponseTo="_F0F3974B0C13F5EB99BECC7EEBBB07F6">
<Issuer xmlns="urn:oasis:names:tc:SAML:2.0:assertion">http://adfs.example.com/adfs/services/trust</Issuer>
<samlp:Status>
<samlp:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:Success"/>
</samlp:Status>
<Assertion xmlns="urn:oasis:names:tc:SAML:2.0:assertion" ID="_9ad6304d-0465-4cae-bb45-29553aba33b8" IssueInstant="2021-01-14T15:02:55.314Z" Version="2.0">
<Issuer>http://adfs.example.com/adfs/services/trust</Issuer>
<ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#";>
<ds:SignedInfo>
<ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
<ds:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/>
<ds:Reference URI="#_9ad6304d-0465-4cae-bb45-29553aba33b8">
<ds:Transforms>
<ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/>
<ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
</ds:Transforms>
<ds:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/>
<ds:DigestValue>r/w7LmIOliL5HL/zjXB2BZNl4Ao=</ds:DigestValue>
</ds:Reference>
</ds:SignedInfo>
<ds:SignatureValue>IgtyBHwUh2hTqfzrlNYm0MF/yfSiO3n4IVpOefoyNlbyUJm/O+4HytJZftdXhw4xZRkI/zF4MMjpjwhS0ibunbDJ+GUSe772Ft3HxN1zkIaIbCfHWj1miKoZCI2teSdCJiLJHc891yvJViVVQF71lLTJ8Q5sO8JzPpsf/k3m2MSc4gE6ti0MuWpD98/FzJt74V3p366Z+CcrzdihNE0QGg9azR1Oru70TNfESJPDCKqYLexFNfWp3z3sKUrl4wg5H5bpvjuM6wQa1ZVPak9zp5mYojWcxKr5WG7cZXCKG+dnf359dhPzjswSCpvQ9kPyOEUU3I2kDGye1lzILlZpWg==</ds:SignatureValue>
<ds:KeyInfo>
<ds:X509Data>
<ds:X509Certificate>MIIFsTCCBJmgAwIBAgITEwAAAU6m5IvCuPU8awADAAABTjANBgkqhkiG9w0BAQsFADBUMRMwEQYKCZImiZPyLGQBGRYDbmV0MRUwEwYKCZImiZPyLGQBGRYFZGx0ZWMxEjAQBgoJkiaJk/IsZAEZFgJocTESMBAGA1UEAxMJZGx0ZWNtYWlsMB4XDTIwMTExOTA4NTEwM1oXDTM1MDMxMTA3MTM0M1owRjELMAkGA1UEBhMCRVMxDjAMBgNVBAoTBURMVEVDMQ4wDAYDVQQLEwVETFRFQzEXMBUGA1UEAxMOYWRmcy5kbHRlYy5uZXQwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDhES+Br2xjKMYxt+5Cg3KGzLyDXOvysfv9MLPn9srqTGikkZxqZrybDAJ5k7j9vGDZGijoR0o1TvJSrfuUHygJkbvqmV3BnXzaRIUGkXgJH+rILZp40ul/BPKDwPwj0Rq9bVXK0jWOQUrOy594/1YW74pgRIXC2TGpNfdU+5pvTrEBow0yx8acqhrqUXzrcDqjYnmLj80mo0G6owPkdUMWxaKKrvUjASXsQoTOxkWY5aNzLP3/FlTvxNTLqBoaSXSj9v9ZsxGrQhJlWI4cYD1ZOP/Cyd4wZlKNRyc/mKKs9eVvcv5M5Gks4sr7bEHu5TGLbwcVoUKfji/Q+GmM/nWXAgMBAAGjggKIMIIChDA7BgkrBgEEAYI3FQcELjAsBiQrBgEEAYI3FQiDloZij4oRh5WPOoePww+mkXmBGbDWaoHuzBgCAWQCAQ8wEwYDVR0lBAwwCgYIKwYBBQUHAwEwCwYDVR0PBAQDAgWgMBsGCSsGAQQBgjcVCgQOMAwwCgYIKwYBBQUHAwEwHQYDVR0OBBYEFBRnkO8BtK0lWUx5gQHNmtd81YvzMDEGA1UdEQQqMCiCDmFkZnMuZGx0ZWMubmV0ghZkbHRlY2FkZnMuaHEuZGx0ZWMubmV0MB8GA1UdIwQYMBaAFOl7mfDDCURsgp8F2jhel1CUcVckMIHQBgNVHR8EgcgwgcUwgcKggb+ggbyGgblsZGFwOi8vL0NOPWRsdGVjbWFpbCgzKSxDTj1ETFRFQ01BSUwsQ049Q0RQLENOPVB1YmxpYyUyMEtleSUyMFNlcnZpY2VzLENOPVNlcnZpY2VzLENOPUNvbmZpZ3VyYXRpb24sREM9aHEsREM9ZGx0ZWMsREM9bmV0P2NlcnRpZmljYXRlUmV2b2NhdGlvbkxpc3Q/YmFzZT9vYmplY3RDbGFzcz1jUkxEaXN0cmlidXRpb25Qb2ludDCBvwYIKwYBBQUHAQEEgbIwga8wgawGCCsGAQUFBzAChoGfbGRhcDovLy9DTj1kbHRlY21haWwsQ049QUlBLENOPVB1YmxpYyUyMEtleSUyMFNlcnZpY2VzLENOPVNlcnZpY2VzLENOPUNvbmZpZ3VyYXRpb24sREM9aHEsREM9ZGx0ZWMsREM9bmV0P2NBQ2VydGlmaWNhdGU/YmFzZT9vYmplY3RDbGFzcz1jZXJ0aWZpY2F0aW9uQXV0aG9yaXR5MA0GCSqGSIb3DQEBCwUAA4IBAQCCUzJnTbieMWuvUFwlLjE/Zw6eIIjHQvYmlm3Lme/SnF6OTZrmPuGdrxxZbjMa6NdXDN1+LdftEyfyofiSh7Wx04dGDyiC0Tc9eCpgIeeKK1z3TCIAiuvEzLkb9Fh/FVe6jMVR4c9cE8VvydVXmuNydyUv8ZT78IsILgSWw38uIDCsVwMOhPi6GN9EgqLRaZLoCs9S5bW/HQIBAzzfqIq4l0nGvu9aN81hOD/4wexPqJJFMIJkXT/3iPXO/wYiiF7lsG3j2b7lKUsdZnBRamiBvG9nK0CyMgMmcc3o5CQU7NC4egDXIcVujNphbQ8rx+LxvFeO8oaN01Sd7qyXGA6p</ds:X509Certificate>
</ds:X509Data>
</ds:KeyInfo>
</ds:Signature>
<Subject>
<NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:persistent">testuser</NameID>
<SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer">
<SubjectConfirmationData InResponseTo="_F0F3974B0C13F5EB99BECC7EEBBB07F6" NotOnOrAfter="2021-01-14T15:07:55.314Z" Recipient="https://sogo-test.example.com/SOGo/saml2-signon-post"/>
</SubjectConfirmation>
</Subject>
<Conditions NotBefore="2021-01-14T15:02:55.298Z" NotOnOrAfter="2021-01-14T16:02:55.298Z">
<AudienceRestriction>
<Audience>https://sogo-test.example.com/SOGo/saml2-metadata</Audience>
</AudienceRestriction>
</Conditions>
<AttributeStatement>
<Attribute Name="username">
<AttributeValue>testuser</AttributeValue>
</Attribute>
<Attribute Name="email">
<AttributeValue>[email protected]</AttributeValue>
</Attribute>
</AttributeStatement>
<AuthnStatement AuthnInstant="2021-01-14T15:02:55.220Z" SessionIndex="_9ad6304d-0465-4cae-bb45-29553aba33b8">
<AuthnContext>
<AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</AuthnContextClassRef>
</AuthnContext>
</AuthnStatement>
</Assertion>
</samlp:Response>
```
SOGo log:
```
Feb 03 11:19:10 sogod [16447]: version 5.0.1 (build root@sleipnir 202101062313) -- starting
Feb 03 11:19:10 sogod [16447]: vmem size check enabled: shutting down app when vmem > 512 MB. Currently at 84 MB
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7dab090[SOGoProductLoader]> SOGo products loaded from '/usr/lib/GNUstep/SOGo':
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7dab090[SOGoProductLoader]> AdministrationUI.SOGo, Appointments.SOGo, CommonUI.SOGo, Contacts.SOGo, ContactsUI.SOGo, MailPartViewers.SOGo, Mailer.SOGo, MailerUI.SOGo, MainUI.SOGo, PreferencesUI.SOGo, SchedulerUI.SOGo
Feb 03 11:19:10 sogod [16447]: All products loaded - current memory usage at 94 MB
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> listening on 127.0.0.1:20000
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> watchdog process pid: 16447
Feb 03 11:19:10 sogod [16447]: <0x0x7f2c0182e000[WOWatchDogChild]> watchdog request timeout set to 60 minutes
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> preparing 3 children
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> child spawned with pid 16449
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> child spawned with pid 16450
Feb 03 11:19:10 sogod [16447]: <0x0x55e3c7ddc150[WOWatchDog]> child spawned with pid 16452
2021-02-03 11:19:10.460 sogod[16449:16449] PostgreSQL72 connection established: <0x0x55e3c7c3e010[PGConnection]: connection=0x0x55e3c7ab8ee0>
2021-02-03 11:19:10.460 sogod[16449:16449] PostgreSQL72 channel 0x0x55e3c7e8c970 opened (connection=<0x0x55e3c7c3e010[PGConnection]: connection=0x0x55e3c7ab8ee0>)
2021-02-03 11:19:10.460 sogod[16449:16449] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_user_profile
2021-02-03 11:19:10.462 sogod[16449:16449] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_folder_info
2021-02-03 11:19:10.462 sogod[16450:16450] PostgreSQL72 connection established: <0x0x55e3c7f42110[PGConnection]: connection=0x0x55e3c7ab8ee0>
2021-02-03 11:19:10.462 sogod[16450:16450] PostgreSQL72 channel 0x0x55e3c7e8c970 opened (connection=<0x0x55e3c7f42110[PGConnection]: connection=0x0x55e3c7ab8ee0>)
2021-02-03 11:19:10.462 sogod[16452:16452] PostgreSQL72 connection established: <0x0x55e3c7f42110[PGConnection]: connection=0x0x55e3c7ab8ee0>
2021-02-03 11:19:10.462 sogod[16452:16452] PostgreSQL72 channel 0x0x55e3c7e8c970 opened (connection=<0x0x55e3c7f42110[PGConnection]: connection=0x0x55e3c7ab8ee0>)
2021-02-03 11:19:10.462 sogod[16450:16450] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_user_profile
2021-02-03 11:19:10.462 sogod[16452:16452] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_user_profile
2021-02-03 11:19:10.463 sogod[16450:16450] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_folder_info
2021-02-03 11:19:10.464 sogod[16452:16452] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_folder_info
2021-02-03 11:19:10.466 sogod[16449:16449] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_sessions_folder
2021-02-03 11:19:10.466 sogod[16452:16452] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_sessions_folder
2021-02-03 11:19:10.466 sogod[16450:16450] PG0x0x55e3c7e8c970 SQL: SELECT count(*) FROM sogo_sessions_folder
Feb 03 11:19:10 sogod [16452]: <0x0x55e3c80f7db0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 03 11:19:10 sogod [16449]: <0x0x55e3c80f7e40[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 03 11:19:10 sogod [16450]: <0x0x55e3c80f7db0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 03 11:26:29 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo'
Feb 03 11:26:29 sogod [16450]: <0x0x55e3c7f9a920[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Feb 03 11:26:29 sogod [16450]: <0x0x55e3c7f9a920[SOGoCache]> Using host(s) 'localhost' as server(s)
Feb 03 11:26:29 sogod [16450]: |SOGo| traverse(acquire): SOGo
Feb 03 11:26:29 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:29 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:29.444 sogod[16450:16450] PostgreSQL72 connection established: <0x0x55e3c82162f0[PGConnection]: connection=0x0x55e3c7ab8ee0>
2021-02-03 11:26:29.444 sogod[16450:16450] PostgreSQL72 channel 0x0x55e3c8222ad0 opened (connection=<0x0x55e3c82162f0[PGConnection]: connection=0x0x55e3c7ab8ee0>)
2021-02-03 11:26:29.444 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: SELECT c_defaults FROM sogo_user_profile WHERE c_uid = 'anonymous'
PostgreSQL72 connection dropped 0x0x55e3c7f42110 (channel=0x0x55e3c7e8c970)
(process:16450): Lasso-WARNING **: 11:26:29.457: 2021-02-03 11:26:29 Could not read public key from file /etc/sogo/certs/adfs-xml.pem
Feb 03 11:26:29 sogod [16450]: |SOGo| request took 0.087586 seconds to execute
Feb 03 11:26:29 sogod [16450]: <0x0x55e3c7dbd1f0[WOResponse]> Zipping of response disabled
Feb 03 11:26:29 sogod [16450]: 192.168.200.83 "GET /SOGo HTTP/1.1" 302 0/0 0.095 - - 5M - 12
Feb 03 11:26:44 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:44 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:44.627 sogod[16450:16450] PostgreSQL72 connection established: <0x0x55e3c8277f50[PGConnection]: connection=0x0x55e3c7ab8a30>
2021-02-03 11:26:44.627 sogod[16450:16450] PostgreSQL72 channel 0x0x55e3c82645f0 opened (connection=<0x0x55e3c8277f50[PGConnection]: connection=0x0x55e3c7ab8a30>)
2021-02-03 11:26:44.628 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:44.628 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='dJcQkbjLH/UpRwz93kTfSQ=='
2021-02-03 11:26:44.631 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:44.631 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:44.632 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348004, 1612348004, 'sUXlI6U6VNqp5aTo2NaHzE4CKEtIspgiEtV5KLrrHmFE0LlR06GKpSylkIgKZrbVynfnoa2cJpwfBfQUNjibQ/ZD/BEFxrFNXZ2RUbWjrDU8X2Q2QCvyKqWvaxM6DXpHK5n0RzkRHTP4n/S+3B9vMyx4i41UKT2XTcJCAuKde2F7LcpWaziE11B8w9QxJWM66Amoy04oRC0KG8hVJ2ntow==', 'dJcQkbjLH/UpRwz93kTfSQ==')
2021-02-03 11:26:44.633 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:44.704: 2021-02-03 11:26:44 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c81ba360
(process:16450): Lasso-CRITICAL **: 11:26:44.705: 2021-02-03 11:26:44 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c7a7e610
Feb 03 11:26:44 sogod [16450]: |SOGo| request took 0.107039 seconds to execute
Feb 03 11:26:44 sogod [16450]: <0x0x55e3c7f4ca40[WOResponse]> Zipping of response disabled
Feb 03 11:26:44 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.109 - - 480K - 13
Feb 03 11:26:44 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:44.714: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:44.717: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:44 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:44 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c82f9680> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:44 sogod [16450]: |SOGo| request took 0.019943 seconds to execute
Feb 03 11:26:44 sogod [16450]: <0x0x55e3c812ee50[WOResponse]> Zipping of response disabled
Feb 03 11:26:44 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.022 - - 516K - 13
Feb 03 11:26:44 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:44 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:44.863 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:44.864 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='vCbvt6c7lG4K3OA1pfCL8A=='
2021-02-03 11:26:44.865 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:44.865 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:44.865 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348004, 1612348004, 'kS9TzrBTpAPb+723rQbfPvLKGDkea7xsNj4kfoejuOov+KbxsoJBwbTQ+bK2NSF7xJXmJM7bDoAx1Ka6RiipA+KuczbZuZrGb3k4joHhobOX1FqGI9hncvQR90dPi24JRW6XIww413KXRtK8wnp12E/d8BV44EdtpK2txeHimeBH2C1pDyrTtU6pF+ySt8P40fMevIMTL3N6/Ktq+OVtrA==', 'vCbvt6c7lG4K3OA1pfCL8A==')
2021-02-03 11:26:44.866 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:44.875: 2021-02-03 11:26:44 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c818db00
(process:16450): Lasso-CRITICAL **: 11:26:44.875: 2021-02-03 11:26:44 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c7a7e790
Feb 03 11:26:44 sogod [16450]: |SOGo| request took 0.021021 seconds to execute
Feb 03 11:26:44 sogod [16450]: <0x0x55e3c82f1d50[WOResponse]> Zipping of response disabled
Feb 03 11:26:44 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.023 - - 252K - 13
Feb 03 11:26:44 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:44.884: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:44 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:44.887: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:44 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:44 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:44 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c7f45dc0> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:44 sogod [16450]: |SOGo| request took 0.008857 seconds to execute
Feb 03 11:26:44 sogod [16450]: <0x0x55e3c82f1d50[WOResponse]> Zipping of response disabled
Feb 03 11:26:44 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.010 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:45.018 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.019 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='4zdaawHF0RzN/+s3o33X0Q=='
2021-02-03 11:26:45.019 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:45.020 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.020 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348005, 1612348005, 'S8en1vY31ttN/FWjq3Y5mDH9GC48jGXS188/qaUWJK9u7nt3k3IM2c48Qsn4FJoNWa6syiOTazopX/BztiIJxIGRvycpFoDab1TWZvfAkxffWCdiiQtHAk/kGD7IoqgT+GQtPGAij9mYPEsRZGAeEQwIhpYBPmNWPJsC459MK8q1ihv0GahaXHaMgg+EwH4W/T60wBDlZ3O3M8qRXkC4kA==', '4zdaawHF0RzN/+s3o33X0Q==')
2021-02-03 11:26:45.022 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:45.026: 2021-02-03 11:26:45 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c81b5e60
(process:16450): Lasso-CRITICAL **: 11:26:45.026: 2021-02-03 11:26:45 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c826cc90
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.017016 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c7f4ca40[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.021 - - 8K - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.034: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.037: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:45 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:45 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c8324870> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.009823 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c7f4ca40[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.011 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:45.148 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.149 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='xmJ6yeG1aNgnHzacT4T9rA=='
2021-02-03 11:26:45.149 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:45.150 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.150 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348005, 1612348005, 'M+7QOZHEKs/SgIol172aqOj06Sr3B9ZflxP/WsVjQXry/XhTc3G7pzAhU0dEM3snFmL6TL2duUCgGhbYxuj/c7i9lNY4qqi9Y80pB07cOxVZp4J5sTmRqW9IL/eo91bulRojO7pQ7cxz67UhRwe0gIcs/PJaZyCAP1a+jmXmirVMiN7TboZAzHpPO1Z3LUrhULlyX8XP6zHx7Sm/KF3siw==', 'xmJ6yeG1aNgnHzacT4T9rA==')
2021-02-03 11:26:45.151 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:45.166: 2021-02-03 11:26:45 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c8169090
(process:16450): Lasso-CRITICAL **: 11:26:45.166: 2021-02-03 11:26:45 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c826cc30
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.027873 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c818a280[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.030 - - -8K - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.177: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.179: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:45 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:45 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c8328350> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.009638 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c818a280[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.011 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:45.301 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.302 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='RFCowl78v1WttuZlWhxgkg=='
2021-02-03 11:26:45.302 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:45.303 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.303 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348005, 1612348005, 'HdkUfUT1WG2LMvsPOIK4a5Aa6042BeGDzMZ0YtqaiGZCi/w+JueGSS7mgY8Y/v7bBGecRZL54t1mIHeKzfQ7tbk7dmYbmgeN1KmnCGknDh4KLyYqaC0gXBSp4AZ2uabzF9ie/PBzXlL3N7wtlN3UVcU7Rkz2pGLosqvznmjyLr3zlifaq4Zop7p9ecP99QUaOr686jSgNzEdHw9gsT09Ag==', 'RFCowl78v1WttuZlWhxgkg==')
2021-02-03 11:26:45.303 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:45.316: 2021-02-03 11:26:45 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c8169000
(process:16450): Lasso-CRITICAL **: 11:26:45.316: 2021-02-03 11:26:45 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c826c790
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.026700 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c812f0c0[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.029 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.326: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.330: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:45 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:45 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c8326210> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.011668 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c812f0c0[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.013 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:45.436 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.437 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: SELECT t1.c_creationdate, t1.c_id, t1.c_lastseen, t1.c_value FROM sogo_sessions_folder t1 WHERE t1.c_id='j+mj4PFDXiu3B16DxsYoRg=='
2021-02-03 11:26:45.437 sogod[16450:16450] PG0x0x55e3c8222ad0 SQL: ROLLBACK TRANSACTION
2021-02-03 11:26:45.437 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: BEGIN TRANSACTION
2021-02-03 11:26:45.438 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: INSERT INTO sogo_sessions_folder (c_lastseen, c_creationdate, c_value, c_id) VALUES (1612348005, 1612348005, 'Fjro2bQcE06b7cAIwf2t0U+8kDEJFeJ1pd4W5OjqgJb0cVhf4WG3kOpZR1KBEV7vjZdyjzBpKLOL4UJxVFLYQq9nmUtW46BIYzdTd9lNXLRwehn7rcwiFokiUh+bQDZhRiVUJmkkdwroVI1NOQhYq5JB1Ubj3SBTJ5OwusBrwaDhwqIuEs+RacqINAW/xhHBtuGqNba+BxHkPQSGDHKO/A==', 'j+mj4PFDXiu3B16DxsYoRg==')
2021-02-03 11:26:45.438 sogod[16450:16450] PG0x0x55e3c82645f0 SQL: COMMIT TRANSACTION
(process:16450): Lasso-CRITICAL **: 11:26:45.440: 2021-02-03 11:26:45 (profile.c/:939) Trying to unref a non GObject pointer file=profile.c:939 pointerbybname=profile->identity pointer=0x55e3c8169030
(process:16450): Lasso-CRITICAL **: 11:26:45.441: 2021-02-03 11:26:45 (profile.c/:942) Trying to unref a non GObject pointer file=profile.c:942 pointerbybname=profile->session pointer=0x55e3c826c550
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.017221 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c8282f70[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 302 0/10449 0.020 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'GET' on uri '/SOGo/user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.450: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => user
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'user'
(process:16450): GLib-GObject-CRITICAL **: 11:26:45.453: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse miss: name=user, acquire: i=1,count=2
Feb 03 11:26:45 sogod [16450]: |SOGo| miss is last object.
Feb 03 11:26:45 sogod [16450]: |SOGo| handle miss error: <SoAuthRequiredException: 0x55e3c81650a0> NAME:SoAuthRequired REASON:authentication required
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.009444 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c8282f70[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "GET /SOGo/user HTTP/1.1" 302 0/0 0.012 - - 0 - 13
Feb 03 11:26:45 sogod [16450]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:26:45 sogod [16450]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:26:45 sogod [16450]: |SOGo| set clientObject: <SOGo[0x0x55e3c7eb3510]: name=SOGo>
2021-02-03 11:26:45.565 sogod[16450:16450] EXCEPTION: <NSException: 0x55e3c82f63a0> NAME:LassoProfileErrorStatusNotSuccess REASON:Status code is not success INFO:(null)
Feb 03 11:26:45 sogod [16450]: |SOGo| request took 0.002278 seconds to execute
Feb 03 11:26:45 sogod [16450]: <0x0x55e3c83022f0[WOResponse]> Zipping of response disabled
Feb 03 11:26:45 sogod [16450]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 501 0/4917 0.004 - - 0 - 13
```
## Behavior using the second approach (email)
sogo.conf:
```
{
SOGoProfileURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_user_profile";
OCSFolderInfoURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_folder_info";
OCSSessionsFolderURL = "postgresql://sogo:[email protected]:5432/sogo/sogo_sessions_folder";
SOGoLanguage = English;
SOGoTimeZone = Europe/Madrid;
SOGoMailDomain = example.com;
SOGoIMAPServer = 127.0.0.1;
SOGoDraftsFolderName = "Drafts";
SOGoSentFolderName = "Sent Items";
SOGoTrashFolderName = "Deleted Items";
SOGoJunkFolderName = "Junk E-Mail";
SOGoMailingMechanism = smtp;
SOGoSMTPServer = 127.0.0.1;
SOGoSuperUsernames = (support);
SOGoPageTitle = SOGo;
SOGoVacationEnabled = YES;
SOGoForwardEnabled = YES;
SOGoSieveScriptsEnabled = YES;
SOGoSieveServer = sieve://127.0.0.1:4190;
WOWorkersCount = 90;
WOWatchDogRequestTimeout = 60;
SOGoMaximumPingInterval = 3540;
SOGoMaximumSyncInterval = 3540;
SOGoInternalSyncInterval = 60;
SOGoMaximumSyncResponseSize = 2048;
SOGoMaximumSyncWindowSize = 32;
SxVMemLimit = 512;
SOGoAuthenticationType = saml2;
SOGoSAML2PrivateKeyLocation = "/etc/letsencrypt/live/sogo-test.example.com/privkey.pem";
SOGoSAML2CertificateLocation = "/etc/letsencrypt/live/sogo-test.example.com/cert.pem";
SOGoSAML2IdpMetadataLocation = "/etc/sogo/FederationMetadata.xml";
SOGoSAML2IdpPublicKeyLocation = "/etc/sogo/certs/adfs-xml.pem";
SOGoSAML2IdpCertificateLocation = "/etc/sogo/certs/";
SAML2ServerURLString = "https://sogo-test.example.com/";;
SOGoSAML2LoginAttribute = "email";
NGImap4AuthMechanism = PLAIN;
SOGoForceExternalLoginWithEmail = YES;
SOGoUserSources = (
{
type = ldap;
CNFieldName = displayName;
IDFieldName = cn;
UIDFieldName = sAMAccountName;
baseDN = "ou=Central,dc=hq,dc=example,dc=com";
bindDN = "cn=ldapbrowser,cn=users,dc=hq,dc=example,dc=com";
bindFields = (sAMAccountName);
bindPassword = "passw0rd";
MailFieldNames = (mail);
canAuthenticate = NO;
displayName = "Shared Addresses";
hostname = "192.168.201.10";
id = public;
isAddressBook = YES;
port = 389;
}
);
}
```
Steps:
1. Open Mozilla Firefox Browser and point to sogo-test.example.com
2. SOGo redirects our session to IdP (ADFS)
3. ADFS asks our credentials
4. ADFS returns to SOGo with one assertion (identical to the previous test)
5. SOGo stores log an index array error related with login attribute and immediately returns a 501 Error Code
sogo.log:
```
Feb 03 11:05:51 sogod [30894]: |SOGo| request took 0.102331 seconds to execute
Feb 03 11:05:51 sogod [30894]: <0x0x558e4c3a7a40[WOResponse]> Zipping of response disabled
Feb 03 11:05:51 sogod [30894]: 192.168.200.83 "GET /SOGo HTTP/1.1" 302 0/0 0.107 - - 4M - 12
Feb 03 11:06:33 sogod [30894]: |SOGo| starting method 'POST' on uri '/SOGo/saml2-signon-post'
Feb 03 11:06:33 sogod [30894]: |SOGo| traverse(acquire): SOGo => saml2-signon-post
Feb 03 11:06:33 sogod [30894]: |SOGo| do traverse name: 'SOGo'
Feb 03 11:06:33 sogod [30894]: |SOGo| do traverse name: 'saml2-signon-post'
Feb 03 11:06:33 sogod [30894]: |SOGo| set clientObject: <SOGo[0x0x558e4c30e510]: name=SOGo>
2021-02-03 11:06:33.243 sogod[30894:30894] EXCEPTION: <NSException: 0x558e4c6a8af0> NAME:NSInvalidArgumentException REASON:Tried to add nil value for key 'login' to dictionary INFO:{}
Feb 03 11:06:33 sogod [30894]: |SOGo| request took 0.013832 seconds to execute
Feb 03 11:06:33 sogod [30894]: <0x0x558e4c0c2e20[WOResponse]> Zipping of response disabled
Feb 03 11:06:33 sogod [30894]: 192.168.200.83 "POST /SOGo/saml2-signon-post HTTP/1.1" 501 0/10449 0.018 - - 0 - 12
```
