SAML request lost after notification
Use case: connect from an SAML SP, authenticate, get a notification and validate it. We should then be redirected to SAML SP with the SAML response. Instead we are stuck on portal.
Some logs:
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Launching ::Issuer::SAML::storeEnv
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] SAML method: HTTP-REDIRECT
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] HTTP-REDIRECT: SAML Request SAMLRequest=fVNNj9owEL3zK1Du5IOFsliQikI%2FkChEkPbQS%2BVMJoulxHY9zi777%2BskbGGrXXyxNDPv%2Bb2Z8Yx4VWq2qO1R7vFPjWR7fXdOVSmJtcm5VxvJFCdBTPIKiVlgh8X3DRv6IdNGWQWq9P6D3UZxIjRWKNnB1qu5t9t%2B3uy%2Brre%2FCwBAxAhwlAEUMB0Xo%2BHdZFREU7ifZGP8UNyP8yjsoD%2FRkOOZe47W63VsRDWuJVkurYuH0XQQTgZRlEZ3bBiy8ehXB105s0Jy28KP1mpiQQBKSgTr60JbmeX46AsVNIYCEvKhxIN4kLuz7OTs%2FZOQuUvetpx1RcS%2BpWkySHaHtCNZvLRiqSTVFZoDmkcB%2BGO%2FuaiiOiMwIsPXuhR3cwuIlK%2BP%2BiMH8uKWc9YIZm0fTHyNmAXXmUutZlsneL1KVCnguY0354syFbfv%2B4r8qI2IfFC0payWpBFEITD3%2FtEsylI9LQ1yi3PPmhq9fvDq8fPmYd7uoWuExZPtL1WluRHUjAdPHOzZ3cXhdfmydEu1xyK%2BuXfAoKlz4cRdT8rkzRDdwDFPDXfilbHnJr1J3qkObsiOey%2Fp608V%2FwU%3D&RelayState=https%3A%2F%2Fcstb.pfptnbdev.io%2Foauth%2Fsso.php
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Processing code ref
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Processing extractFormInfo
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Prepare token
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Token 1562779374_-7004 created
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Returned error: 9
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Display type standardform
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Skin returned: login
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Calling sendHtml with template login
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Template /usr/share/lemonldap-ng/portal/templates/kroqi/login.tpl not found
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] -> Trying to load /usr/share/lemonldap-ng/portal/templates/bootstrap/login.tpl
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Starting HTML generation using /usr/share/lemonldap-ng/portal/templates/bootstrap/login.tpl
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Sending /usr/share/lemonldap-ng/portal/templates/bootstrap/login.tpl
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Apply following CORS policy : $VAR1 = ['Access-Control-Allow-Origin','*','Access-Control-Allow-Credentials','true','Access-Control-Allow-Headers','*','Access-Control-Allow-Methods','POST,GET','Access-Control-Expose-Headers','*','Access-Control-Max-Age',86400];
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Required urldc : https://connect.pfptnbdev.io//saml
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Set CSP form-action with urldc : https://connect.pfptnbdev.io
[Thu Jul 11 13:20:54 2019] [LLNG:29818] [debug] Apply following CSP : default-src 'self';img-src 'self' data:;style-src 'self' 'unsafe-inline';font-src 'self';connect-src 'self';script-src 'self';form-action * https://connect.pfptnbdev.io;frame-ancestors 'none';
...
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Launching ::Issuer::SAML::storeEnv
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] SAML method: HTTP-POST
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] HTTP-POST: SAML Request fVNNj9owEL3zK1Du5IOFsliQikI/kChEkPbQS+VMJoulxHY9zi777+skbGGrXXyxNDPv+b2Z8Yx4VWq2qO1R7vFPjWR7fXdOVSmJtcm5VxvJFCdBTPIKiVlgh8X3DRv6IdNGWQWq9P6D3UZxIjRWKNnB1qu5t9t+3uy+rre/CwBAxAhwlAEUMB0Xo+HdZFREU7ifZGP8UNyP8yjsoD/RkOOZe47W63VsRDWuJVkurYuH0XQQTgZRlEZ3bBiy8ehXB105s0Jy28KP1mpiQQBKSgTr60JbmeX46AsVNIYCEvKhxIN4kLuz7OTs/ZOQuUvetpx1RcS+pWkySHaHtCNZvLRiqSTVFZoDmkcB+GO/uaiiOiMwIsPXuhR3cwuIlK+P+iMH8uKWc9YIZm0fTHyNmAXXmUutZlsneL1KVCnguY0354syFbfv+4r8qI2IfFC0payWpBFEITD3/tEsylI9LQ1yi3PPmhq9fvDq8fPmYd7uoWuExZPtL1WluRHUjAdPHOzZ3cXhdfmydEu1xyK+uXfAoKlz4cRdT8rkzRDdwDFPDXfilbHnJr1J3qkObsiOey/p608V/wU=
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Lasso error code -407: Invalid message
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Processing code ref
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Processing extractFormInfo
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Trying to load token 1562779374_-7004
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Processing getUser
...
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Display: notification detected
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Skin returned: notification
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Calling sendHtml with template notification
...
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [info] Session bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== can't be retrieved
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [info] Session cannot be tied: Invalid session ID: bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== at /usr/share/perl5/Lemonldap/NG/Common/Apache/Session/Generate/SHA256.pm line 49.
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [info] Session bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== can't be retrieved
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [info] Session cannot be tied: Invalid session ID: bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== at /usr/share/perl5/Lemonldap/NG/Common/Apache/Session/Generate/SHA256.pm line 49.
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Build URL https://connect.pfptnbdev.io/index.fcgi/psgi.js
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Redirect 81.250.130.213 to portal (url was /index.fcgi/psgi.js)
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] User not authenticated, Try in use, cancel redirection
[Thu Jul 11 13:21:14 2019] [LLNG:29818] [debug] Start routing psgi.js
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [info] Session bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== can't be retrieved
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [info] Session cannot be tied: Invalid session ID: bHICZOQnKahvxWA/Pt/ZRFipC8ELn93qH7nnkIrhvxZvhJbHnMJhYGfOidOQxIjZtKPVJqSIJ3PaBDi0Esk/6+GZDUnJzuXt5jedM6Fgdzu71wgv6svrAxsZvwsdHJgp0Asz6f1zEi6ttx0ATvawZw== at /usr/share/perl5/Lemonldap/NG/Common/Apache/Session/Generate/SHA256.pm line 49.
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Build URL https://connect.pfptnbdev.io/notifback
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Redirect 81.250.130.213 to portal (url was /notifback)
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] User not authenticated, Try in use, cancel redirection
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Start routing notifback
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Get session 57ffa01c7cea70adea384eaf663ebc7d401f91f83231d167cb38b937deb58214 from Handler::Main::Run
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check session validity from Handler
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Session timeout -> 72000
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Session _utime -> 1562851274
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] now -> 1562851283
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Session timeoutActivityInterval -> 60
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Session TTL = 71991
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [notice] clement.oudot@worteks.com has accepted notification cgu-kroqi
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Found 'whatToTrace' -> clement.oudot@worteks.com
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Update clement.oudot@worteks.com persistent session
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Update sessionInfo notification_cgu-kroqi
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Dump: $VAR1 = '1562851283';
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Try to get SSO session 57ffa01c7cea70adea384eaf663ebc7d401f91f83231d167cb38b937deb58214
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Get session 57ffa01c7cea70adea384eaf663ebc7d401f91f83231d167cb38b937deb58214 from Portal::Main::Run
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Return SSO session 57ffa01c7cea70adea384eaf663ebc7d401f91f83231d167cb38b937deb58214
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Notification cgu-kroqi registered in persistent session
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] All pending notifications have been accepted
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Processing controlUrl
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Calling autoredirect
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check if Appslist has to be displayed
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check if ChangePassword has to be displayed
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check if LoginHistory has to be displayed
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check if OidcConsents has to be displayed
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Check if Logout has to be displayed
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Skin returned: menu
[Thu Jul 11 13:21:23 2019] [LLNG:29818] [debug] Calling sendHtml with template menu