Pulire e migliorare il log

Dovremmo pulire un po' il log. Propongo di usare livelli distinti:
DEBUG: tutto quello che serve allo sviluppatore del testenv2 (cioè a @fmarco :-))
INFO: tutto quello che serve all'utente del testenv2 (messaggi decodificati ecc.)
Quello che segue, ad esempio, è ciò che compare alla ricezione e al successivo processamento di una LogoutRequest. Ci sono alcune cose che potrebbero confondere l'utente che legge questo log:
la stringa <Request ...> che sembra un tag XML
la stringa parsed authn_request quando invece non è una AuthnRequest (quel messaggio lì in generale mi sembra da DEBUG e non da INFO)
l'HTML del form post
!!! il fatto che la riga di log del web server con la chiamata GET appaia alla fine! nella sequenza logica dovrebbe apparire all'inizio
127.0.0.1 - - [06/Aug/2018 23:18:17] "GET /favicon.ico HTTP/1.1" 404 -
[2018-08-06 23:18:17,784] DEBUG in spid-testenv: req: '<Request 'http://localhost:8088/slo?SAMLRequest=nZJdSyMxFIbv%2FRVD7ttJ5jMJ7YBQhYK7i1ZW1htJkzM1OE3qnMxW%2F73ph8v6gRdCOBcv73vy5ORMUK27bCMv%2FMoP4QoeB8CQzGKxTgXr3ZTch7CRadp5rbp7j0FyynmKnSfJb%2Bhx78nGlCTz2ZTcFZXQQixzENTwmjLIqWZiWWSaGVowFW2IA8wdBuVCTFLGRzSe6jpjknHJ6luSPK07h%2FLANiVD76RXaFE6tQaUQcvF6Y8LGW%2BVm94Hr333JvN1RCFCv3sbaSZ7u9wj9cm579cqfB3eKdaM2r1Vggs2PJPkZ1QvB9XZ1kJ%2FGBnGmW2323EE%2FKvGNqSk%2BVSepP8zvBLtGs5n3yAKvXJoI9enUB%2F%2BkTRVVgJTS1OUojC15qZluhKt0aIuqhqgNIrlLVSlycqcsRoYX%2BaVULTgma5z%2Bsp%2FID7yb%2BQCcLcac2fgqYl41cPNnzNYDOLm7PLh1wrbY%2B6d85%2F6ZiGbkxc%3D&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&Signature=K8cxDUY0pNVvi9eAPyWUFyYT%2FZj7qt3ymHeYtnOzrThrUrKisp7HfkoM4k0yOWoZ2avnEX2MgH8SsemylSV2yk3sOjnglSseJ8impap4fSrzqPXUIPZb0hrJSpiP6H8lpjVjkX6k56IpNdEHN0OItg1lHoLLsPGAhEVsNvy199rqgbDF0W7wKZ7HfbBTmZo4hqHpQpQrFKyWRSfmJhmgky5ulEgoLdnFAIH5Oj3rKctc66NJ8HWG%2F6BeSFJqQtx9RSi7O2TjgIv89XQ1ds8lXScqh5qT7pmMihjs4LcJb09DtaPjXcNTA3OMsY3OBsyFh0NH4XueCJJnvxBpmyn4Wg%3D%3D' [GET]>'
[2018-08-06 23:18:17,790] DEBUG in spid-testenv: LogoutRequest:
<ns0:LogoutRequest xmlns:ns0="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:ns1="urn:oasis:names:tc:SAML:2.0:assertion" Destination="http://localhost:8088/slo" ID="_469c99b3e90d8701e30c19b42c1d041a" IssueInstant="2018-08-06T21:18:17Z" Version="2.0">
  <ns1:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity" NameQualifier="https://www.prova.it/">https://www.prova.it/</ns1:Issuer>
  <ns1:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" NameQualifier="http://localhost:8088">625e1abd4594d7c8df1c69fdc97467ee5da13fe65d253117e18b369a0482c730</ns1:NameID>
  <ns0:SessionIndex>id-6kWYEeSu9WEQkOgsf</ns0:SessionIndex>
</ns0:LogoutRequest>

[2018-08-06 23:18:17,791] DEBUG in spid-testenv: parsed authn_request: {'attrs': {'ID': {'value': '_469c99b3e90d8701e30c19b42c1d041a', 'errors': {}}, 'Version': {'value': '2.0', 'errors': {}}, 'IssueInstant': {'value': '2018-08-06T21:18:17Z', 'errors': {}}, 'Destination': {'value': 'http://localhost:8088/slo', 'errors': {}}}, 'children': {'issuer': {'attrs': {'Format': {'value': 'urn:oasis:names:tc:SAML:2.0:nameid-format:entity', 'errors': {}}, 'NameQualifier': {'value': 'https://www.prova.it/', 'errors': {}}}, 'children': {}, 'errors': {}}, 'name_id': {'attrs': {'NameQualifier': {'value': 'http://localhost:8088', 'errors': {}}, 'Format': {'value': 'urn:oasis:names:tc:SAML:2.0:nameid-format:transient', 'errors': {}}}, 'children': {}, 'errors': {}}, 'session_index': {'attrs': {}, 'children': {}, 'errors': {}}}, 'errors': {}}
[2018-08-06 23:18:17,791] DEBUG in spid-testenv: Messaggio SAML firmato.
[2018-08-06 23:18:17,791] DEBUG in spid-testenv: security backend: RSACrypto
[2018-08-06 23:18:17,793] DEBUG in spid-testenv: Response binding:
urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
[2018-08-06 23:18:17,793] DEBUG in spid-testenv: Signature inside response:
True
[2018-08-06 23:18:17,826] DEBUG in spid-testenv: Response:
<?xml version="1.0"?>
<ns0:LogoutResponse xmlns:ns0="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:ns1="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns2="http://www.w3.org/2000/09/xmldsig#" Destination="http://localhost:3000/spid-slo" ID="id-LFUMYR1XFPf5BSGny" InResponseTo="_469c99b3e90d8701e30c19b42c1d041a" IssueInstant="2018-08-06T21:18:17Z" Version="2.0"><ns1:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">http://localhost:8088</ns1:Issuer><ns2:Signature Id="Signature1"><ns2:SignedInfo><ns2:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><ns2:SignatureMethod Algorithm="http://www.w3.org/2001/04/xmldsig-more#rsa-sha512"/><ns2:Reference URI="#id-LFUMYR1XFPf5BSGny"><ns2:Transforms><ns2:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><ns2:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/></ns2:Transforms><ns2:DigestMethod Algorithm="http://www.w3.org/2001/04/xmlenc#sha512"/><ns2:DigestValue>HIAfjjqR9Np6HGNxenfH7hIb+UigYBt/ombst4kPtadqMJ2mQtcTMF0ZLmtNIbvM
x+5p2jbDVP0Qw1FAUwZ6kQ==</ns2:DigestValue></ns2:Reference></ns2:SignedInfo><ns2:SignatureValue>BT500Jx0jP5hPhFkK8xJW+neHkYYYxYnpBYPbfRrIIdRlvryOWZFbRQhLu9Mnf93
aff8tgjmPGl3P0Pjh0YF1nlcjlevKLc9/JDwyReJrMDiHkSlyZF7rabz+3zK2IGn
Ko55/qrrctqjtIVJXCh5Q7PrwtCXfTZmMGmEBdVjBLpuIwp72r47d5A2x8wUYZ5l
TJNqnuZusR4psUfatoeyzJoA+k3L+J+OUh8fvnYcKmR5fcXobO7Eox0VWvFF8q4z
gBRekwyHjYiBsANcjeBzKFznsuDffpnqKy+eQ5AdthsrsOueWKQvg9V9DWtAIW0c
cBw01TpsGcm1j/gAXo9RAA==</ns2:SignatureValue><ns2:KeyInfo><ns2:X509Data><ns2:X509Certificate>MIICtDCCAZwCCQDQQ+FCxgMN6jANBgkqhkiG9w0BAQsFADAcMQswCQYDVQQGEwJJVDENMAsGA1UEBwwEUm9tYTAeFw0xODA2MjYxMDM5MzBaFw0xOTA2MjYxMDM5MzBaMBwxCzAJBgNVBAYTAklUMQ0wCwYDVQQHDARSb21hMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAudciVxyXnPvTt2r8+3wE9DsibXu9fZwHjji0rOE7FJj8fm/2rE0/GfDNyymGv7LHx9vKO8p1Ot4cl0ou/bR70PtJW9tM2ssyWPmHQXmBX84FB/IuuOitABEtc3/HsWOyAA23XanCGpv6j6CW8TRjO+bi7nQnW3y/rLuCoTkBihH4QGA0bkg8he56BSa3sAPnyO3VLavlYv3yYCQDqR+r2UM1f8gNPTlE5UIQzOYPXv1w/YrrFhEx7xUYPh1J2e4J6xRRbZqzvB74QF0t0A0XueCITXLuVQ5eQ1rIWFAL1nwMqWvep+3HvDpq0K8nzGFjnut6ElfyyhPp8+/H0zBOkQIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQBw4mfH+WtR/etTVWK1Jy9DXWxAazFViQcVBualTuleRSHZjCv/nyv4YbyFlTNarDI+LF+iG2rCABxgY40L6FpN9Gnsa5wijuKs0E6ZAvJ/rYfrYkE8wd0y8Z23VeoXD/m8OhwcysMtyM10GxZUtEBnpXDAhAFFDyAACfxAQy+/5u1u5dI0189AFk2EcqcSuA9pQWbzhswlQaSQFBU1nabIU2SwDPfHMwLFVrJdH09RuMSKM4IBNzCiLj5KgqepdFO3+8e0ewiwo8imhTYaTDR3ZXQaTNQt99fhT/LOMUcCR4hH14Cn72X7xTPK7hTz4p1D3uXfKT/o1qiql2PAjfl8</ns2:X509Certificate></ns2:X509Data></ns2:KeyInfo></ns2:Signature><ns0:Status><ns0:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:Success"/></ns0:Status></ns0:LogoutResponse>

[2018-08-06 23:18:17,828] DEBUG in spid-testenv: Destination http://localhost:3000/spid-slo
[2018-08-06 23:18:17,828] DEBUG in spid-testenv: Form post <!DOCTYPE html>
<html>
    <head>
        <meta charset="utf-8" />
    </head>
    <body onload="document.forms[0].submit()">
        <noscript>
            <p>
                <strong>Note:</strong> Since your browser does not support JavaScript,
                you must press the Continue button once to proceed.
            </p>
        </noscript>

        <form action="http://localhost:3000/spid-slo" method="post">
            <div>
                <input type="hidden" name="RelayState" value=""/>

                <input type="hidden" name="SAMLResponse" value="PD94bWwgdmVyc2lvbj0iMS4wIj8+CjxuczA6TG9nb3V0UmVzcG9uc2UgeG1sbnM6bnMwPSJ1cm46b2FzaXM6bmFtZXM6dGM6U0FNTDoyLjA6cHJvdG9jb2wiIHhtbG5zOm5zMT0idXJuOm9hc2lzOm5hbWVzOnRjOlNBTUw6Mi4wOmFzc2VydGlvbiIgeG1sbnM6bnMyPSJodHRwOi8vd3d3LnczLm9yZy8yMDAwLzA5L3htbGRzaWcjIiBEZXN0aW5hdGlvbj0iaHR0cDovL2xvY2FsaG9zdDozMDAwL3NwaWQtc2xvIiBJRD0iaWQtTEZVTVlSMVhGUGY1QlNHbnkiIEluUmVzcG9uc2VUbz0iXzQ2OWM5OWIzZTkwZDg3MDFlMzBjMTliNDJjMWQwNDFhIiBJc3N1ZUluc3RhbnQ9IjIwMTgtMDgtMDZUMjE6MTg6MTdaIiBWZXJzaW9uPSIyLjAiPjxuczE6SXNzdWVyIEZvcm1hdD0idXJuOm9hc2lzOm5hbWVzOnRjOlNBTUw6Mi4wOm5hbWVpZC1mb3JtYXQ6ZW50aXR5Ij5odHRwOi8vbG9jYWxob3N0OjgwODg8L25zMTpJc3N1ZXI+PG5zMjpTaWduYXR1cmUgSWQ9IlNpZ25hdHVyZTEiPjxuczI6U2lnbmVkSW5mbz48bnMyOkNhbm9uaWNhbGl6YXRpb25NZXRob2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzEwL3htbC1leGMtYzE0biMiLz48bnMyOlNpZ25hdHVyZU1ldGhvZCBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIwMDEvMDQveG1sZHNpZy1tb3JlI3JzYS1zaGE1MTIiLz48bnMyOlJlZmVyZW5jZSBVUkk9IiNpZC1MRlVNWVIxWEZQZjVCU0dueSI+PG5zMjpUcmFuc2Zvcm1zPjxuczI6VHJhbnNmb3JtIEFsZ29yaXRobT0iaHR0cDovL3d3dy53My5vcmcvMjAwMC8wOS94bWxkc2lnI2VudmVsb3BlZC1zaWduYXR1cmUiLz48bnMyOlRyYW5zZm9ybSBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIwMDEvMTAveG1sLWV4Yy1jMTRuIyIvPjwvbnMyOlRyYW5zZm9ybXM+PG5zMjpEaWdlc3RNZXRob2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGVuYyNzaGE1MTIiLz48bnMyOkRpZ2VzdFZhbHVlPkhJQWZqanFSOU5wNkhHTnhlbmZIN2hJYitVaWdZQnQvb21ic3Q0a1B0YWRxTUoybVF0Y1RNRjBaTG10Tklidk0KeCs1cDJqYkRWUDBRdzFGQVV3WjZrUT09PC9uczI6RGlnZXN0VmFsdWU+PC9uczI6UmVmZXJlbmNlPjwvbnMyOlNpZ25lZEluZm8+PG5zMjpTaWduYXR1cmVWYWx1ZT5CVDUwMEp4MGpQNWhQaEZrSzh4SlcrbmVIa1lZWXhZbnBCWVBiZlJySUlkUmx2cnlPV1pGYlJRaEx1OU1uZjkzCmFmZjh0Z2ptUEdsM1AwUGpoMFlGMW5sY2psZXZLTGM5L0pEd3lSZUpyTURpSGtTbHlaRjdyYWJ6KzN6SzJJR24KS281NS9xcnJjdHFqdElWSlhDaDVRN1Byd3RDWGZUWm1NR21FQmRWakJMcHVJd3A3MnI0N2Q1QTJ4OHdVWVo1bApUSk5xbnVadXNSNHBzVWZhdG9leXpKb0ErazNMK0orT1VoOGZ2blljS21SNWZjWG9iTzdFb3gwVld2RkY4cTR6CmdCUmVrd3lIallpQnNBTmNqZUJ6S0Z6bnN1RGZmcG5xS3krZVE1QWR0aHNyc091ZVdLUXZnOVY5RFd0QUlXMGMKY0J3MDFUcHNHY20xai9nQVhvOVJBQT09PC9uczI6U2lnbmF0dXJlVmFsdWU+PG5zMjpLZXlJbmZvPjxuczI6WDUwOURhdGE+PG5zMjpYNTA5Q2VydGlmaWNhdGU+TUlJQ3REQ0NBWndDQ1FEUVErRkN4Z01ONmpBTkJna3Foa2lHOXcwQkFRc0ZBREFjTVFzd0NRWURWUVFHRXdKSlZERU5NQXNHQTFVRUJ3d0VVbTl0WVRBZUZ3MHhPREEyTWpZeE1ETTVNekJhRncweE9UQTJNall4TURNNU16QmFNQnd4Q3pBSkJnTlZCQVlUQWtsVU1RMHdDd1lEVlFRSERBUlNiMjFoTUlJQklqQU5CZ2txaGtpRzl3MEJBUUVGQUFPQ0FROEFNSUlCQ2dLQ0FRRUF1ZGNpVnh5WG5QdlR0MnI4KzN3RTlEc2liWHU5Zlp3SGpqaTByT0U3RkpqOGZtLzJyRTAvR2ZETnl5bUd2N0xIeDl2S084cDFPdDRjbDBvdS9iUjcwUHRKVzl0TTJzc3lXUG1IUVhtQlg4NEZCL0l1dU9pdEFCRXRjMy9Ic1dPeUFBMjNYYW5DR3B2Nmo2Q1c4VFJqTytiaTduUW5XM3kvckx1Q29Ua0JpaEg0UUdBMGJrZzhoZTU2QlNhM3NBUG55TzNWTGF2bFl2M3lZQ1FEcVIrcjJVTTFmOGdOUFRsRTVVSVF6T1lQWHYxdy9ZcnJGaEV4N3hVWVBoMUoyZTRKNnhSUmJacXp2Qjc0UUYwdDBBMFh1ZUNJVFhMdVZRNWVRMXJJV0ZBTDFud01xV3ZlcCszSHZEcHEwSzhuekdGam51dDZFbGZ5eWhQcDgrL0gwekJPa1FJREFRQUJNQTBHQ1NxR1NJYjNEUUVCQ3dVQUE0SUJBUUJ3NG1mSCtXdFIvZXRUVldLMUp5OURYV3hBYXpGVmlRY1ZCdWFsVHVsZVJTSFpqQ3Yvbnl2NFlieUZsVE5hckRJK0xGK2lHMnJDQUJ4Z1k0MEw2RnBOOUduc2E1d2lqdUtzMEU2WkF2Si9yWWZyWWtFOHdkMHk4WjIzVmVvWEQvbThPaHdjeXNNdHlNMTBHeFpVdEVCbnBYREFoQUZGRHlBQUNmeEFReSsvNXUxdTVkSTAxODlBRmsyRWNxY1N1QTlwUVdiemhzd2xRYVNRRkJVMW5hYklVMlN3RFBmSE13TEZWckpkSDA5UnVNU0tNNElCTnpDaUxqNUtncWVwZEZPMys4ZTBld2l3bzhpbWhUWWFURFIzWlhRYVROUXQ5OWZoVC9MT01VY0NSNGhIMTRDbjcyWDd4VFBLN2hUejRwMUQzdVhmS1QvbzFxaXFsMlBBamZsODwvbnMyOlg1MDlDZXJ0aWZpY2F0ZT48L25zMjpYNTA5RGF0YT48L25zMjpLZXlJbmZvPjwvbnMyOlNpZ25hdHVyZT48bnMwOlN0YXR1cz48bnMwOlN0YXR1c0NvZGUgVmFsdWU9InVybjpvYXNpczpuYW1lczp0YzpTQU1MOjIuMDpzdGF0dXM6U3VjY2VzcyIvPjwvbnMwOlN0YXR1cz48L25zMDpMb2dvdXRSZXNwb25zZT4K"/>
            </div>
            <noscript>
                <div>
                    <input type="submit" value="Continue"/>
                </div>
            </noscript>
        </form>
            </body>
</html>
127.0.0.1 - - [06/Aug/2018 23:18:17] "GET /slo?SAMLRequest=nZJdSyMxFIbv%2FRVD7ttJ5jMJ7YBQhYK7i1ZW1htJkzM1OE3qnMxW%2F73ph8v6gRdCOBcv73vy5ORMUK27bCMv%2FMoP4QoeB8CQzGKxTgXr3ZTch7CRadp5rbp7j0FyynmKnSfJb%2Bhx78nGlCTz2ZTcFZXQQixzENTwmjLIqWZiWWSaGVowFW2IA8wdBuVCTFLGRzSe6jpjknHJ6luSPK07h%2FLANiVD76RXaFE6tQaUQcvF6Y8LGW%2BVm94Hr333JvN1RCFCv3sbaSZ7u9wj9cm579cqfB3eKdaM2r1Vggs2PJPkZ1QvB9XZ1kJ%2FGBnGmW2323EE%2FKvGNqSk%2BVSepP8zvBLtGs5n3yAKvXJoI9enUB%2F%2BkTRVVgJTS1OUojC15qZluhKt0aIuqhqgNIrlLVSlycqcsRoYX%2BaVULTgma5z%2Bsp%2FID7yb%2BQCcLcac2fgqYl41cPNnzNYDOLm7PLh1wrbY%2B6d85%2F6ZiGbkxc%3D&SigAlg=http%3A%2F%2Fwww.w3.org%2F2001%2F04%2Fxmldsig-more%23rsa-sha256&Signature=K8cxDUY0pNVvi9eAPyWUFyYT%2FZj7qt3ymHeYtnOzrThrUrKisp7HfkoM4k0yOWoZ2avnEX2MgH8SsemylSV2yk3sOjnglSseJ8impap4fSrzqPXUIPZb0hrJSpiP6H8lpjVjkX6k56IpNdEHN0OItg1lHoLLsPGAhEVsNvy199rqgbDF0W7wKZ7HfbBTmZo4hqHpQpQrFKyWRSfmJhmgky5ulEgoLdnFAIH5Oj3rKctc66NJ8HWG%2F6BeSFJqQtx9RSi7O2TjgIv89XQ1ds8lXScqh5qT7pmMihjs4LcJb09DtaPjXcNTA3OMsY3OBsyFh0NH4XueCJJnvxBpmyn4Wg%3D%3D HTTP/1.1" 200 -
italia / spid-testenv2

Pulire e migliorare il log #110
