From 79c4800ac99c24400ad9da91101b48d6a55234b9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ale=C5=A1=20Smodi=C5=A1?= Date: Sat, 17 Oct 2015 21:16:55 +0200 Subject: Added periodic timed out request cleaner to SAML daemon. --- saml/saml.js | 124 ++++++++++++++++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 115 insertions(+), 9 deletions(-) (limited to 'saml') diff --git a/saml/saml.js b/saml/saml.js index 6a48af1..3eff569 100644 --- a/saml/saml.js +++ b/saml/saml.js @@ -337,9 +337,9 @@ var handleLogoutResponse = function (xml, form, res) { waiter.done = Date.now(); waiter.responseReject(new Error(errors.join(', '))); } - if (errors.length > 1) m = 'Multiple errors:\n' + errors.join('\n '); - //logger.error(''); // TODO: continue here + if (errors.length > 1) m = 'Multiple errors:\n ' + errors.join('\n '); else m = 'Error: ' + errors[0]; + logger.error('Received a SAML logout response and encountered errors processing it; response:\n' + xml + '\nErrors:\n ' + errors.join('\n ')); } else { if (waiter) { @@ -347,6 +347,7 @@ var handleLogoutResponse = function (xml, form, res) { waiter.responseResolve(); } m = 'OK'; + logger.debug('Received a SAML logout response:\n' + xml); } responded = true; res.set('Content-Type', 'text/plain'); @@ -496,7 +497,7 @@ http_app.get('/Shibboleth.sso/Login', function (req, res) { } } }; - makeSamlRedirectUrl(SSOServiceURL, 'SAMLRequest', request, null, function (err, svcUrl, responseXml) { + makeSamlRedirectUrl(SSOServiceURL, 'SAMLRequest', request, null, function (err, svcUrl, requestXml) { if (err) { logException('Error while assembling the Login SAML request for sid=' + sid + ': ' + err, err); waiter.done = Date.now(); @@ -506,6 +507,7 @@ http_app.get('/Shibboleth.sso/Login', function (req, res) { res.send('Failed: ' + err); return; } + logger.debug('Redirecting to IdP with a login request:\n' + requestXml); responded = true; res.redirect(svcUrl); // redirect to the IdP parkedLoginRequests[requestId] = waiter; @@ -571,7 +573,7 @@ http_app.get('/Shibboleth.sso/Logout', function (req, res) { res.send('Failed: ' + err); return; } - logger.debug('Redirecting with a logout request:\n' + requestXml); + logger.debug('Redirecting to IdP with a logout request:\n' + requestXml); responded = true; res.redirect(svcUrl); // redirect to the IdP parkedLogoutRequests[requestId] = waiter; @@ -741,11 +743,26 @@ http_app.get('/Shibboleth.sso/SLO/Redirect', function (req, res) { } handler(buffer.toString('utf8'), form, res); }; - if (form.SAMLRequest) zlib.inflateRaw(new Buffer(form.SAMLRequest, 'base64'), function (err, buffer) {delegateToHandler(err, buffer, handleLogoutRequest);}); - else if (form.SAMLResponse) zlib.inflateRaw(new Buffer(form.SAMLResponse, 'base64'), function (err, buffer) {delegateToHandler(err, buffer, handleLogoutResponse);}); - else { - logger.error('Invalid SAML logout request/response, query string: ' + JSON.stringify(req.query)); - res.send('Invalid SAML logout request/response.'); + try { + if (form.SAMLRequest) zlib.inflateRaw(new Buffer(form.SAMLRequest, 'base64'), function (err, buffer) { + delegateToHandler(err, buffer, handleLogoutRequest); + }); + else if (form.SAMLResponse) zlib.inflateRaw(new Buffer(form.SAMLResponse, 'base64'), function (err, buffer) { + delegateToHandler(err, buffer, handleLogoutResponse); + }); + else { + logger.error('Invalid SAML logout request/response, query string: ' + JSON.stringify(req.query)); + res.set('Content-Type', 'text/plain'); + res.send('Invalid SAML logout request/response.'); + } + } + catch (e) { + logException('Error while processing a SAML logout request/response, querystring=' + JSON.stringify(req.query) + ': ' + e, e); + try { + res.set('Content-Type', 'text/plain'); + res.send('Error: ' + e); + } + catch (e2) {} // ignore } }); @@ -804,3 +821,92 @@ http_app.get('/Shibboleth.sso/WaitLogout', function (req, res) { res.json({'code': 1, 'message': '' + err}); }).done(); }); + +// ================================================================================ +// A periodic cleaner: rejects and purges timed out requests +// ================================================================================ + +var cleanerTimer = setInterval(function () { // run every 10 seconds + var youngestTime = Date.now() - 300000, // request timeout: 5 minutes + keys = Object.keys(parkedLoginRequests), + i, key, waiter; + // parked logins: the user was already redirected at IdP for login + for (i = keys.length - 1; i >= 0; i--) { + key = keys[i]; + waiter = parkedLoginRequests[key]; + if (waiter.parked < youngestTime) { + if (waiter.promise.isPending()) { + logger.warn('A login request timed out at IdP: sid=' + waiter.sid + ', requestId=' + waiter.requestId) + waiter.promise.reject(new Error('Request timed out waiting for IdP login reply')); + } + else { + logger.info('Encountered a parked login request which has already been resolved: sid=' + waiter.sid + ', requestId=' + waiter.requestId); + } + delete parkedLoginRequests[key]; + delete waitingLogins[waiter.sid]; + } + } + // waiting logins; the user's sid was registered, but the user itself may not have been redirected at IdP for login yet + keys = Object.keys(waitingLogins); + for (i = keys.length - 1; i >= 0; i--) { + key = keys[i]; + waiter = waitingLogins[key]; + if ((waiter.parked || waiter.created) < youngestTime) { + if (waiter.promise.isPending()) { + if (waiter.parked) logger.warn('A login request, marked as parked but not encountered among parked requests, timed out at requester: sid=' + sid + ', requestId=' + waiter.requestId); + else logger.warn('A login request timed out at requester, with no outstanding request at IdP: sid=' + waiter.sid); + waiter.promise.reject(new Error('Request timed out waiting for user to start the login process')); + } + else { + logger.info('Encountered a waiting login request which has already been resolved: sid=' + waiter.sid + ', requestId=' + waiter.requestId); + } + delete waitingLogins[key]; + if (waiter.requestId) delete parkedLoginRequests[waiter.requestId]; + } + } + // parked logouts: the user was already redirected at IdP for logout, if the registration data was already provided, otherwise it's still waiting for redirection + keys = Object.keys(parkedLogoutRequests); + for (i = keys.length - 1; i >= 0; i--) { + key = keys[i]; + waiter = parkedLogoutRequests[key]; + if (waiter.parked < youngestTime) { + if (waiter.promise.isPending()) { + logger.warn('A logout request timed out waiting for registration info: sid=' + waiter.sid); + waiter.response.reject(new Error('Timed out waiting for registration info')); + if (waiter.responsePromise.isPending()) waiter.responsePromise.reject(new Error('Timed out waiting for registration info')); + } + else if (waiter.responsePromise.isPending()) { + logger.warn('A logout request timed out at IdP: sid=' + waiter.sid + ', requestId=' + waiter.requestId) + waiter.responsePromise.reject(new Error('Request timed out waiting for IdP logout reply')); + } + else { + logger.info('Encountered a parked logout request which has already been resolved: sid=' + waiter.sid + ', requestId=' + waiter.requestId); + } + delete parkedLogoutRequests[key]; + delete waitingLogouts[waiter.sid]; + } + } + // waiting logouts; the user's sid and registration data was registered, but the user itself may not have been redirected at IdP for logout yet + keys = Object.keys(waitingLogouts); + for (i = keys.length - 1; i >= 0; i--) { + key = keys[i]; + waiter = waitingLogouts[key]; + if ((waiter.parked || waiter.created) < youngestTime) { + if (waiter.promise.isPending()) { + if (waiter.parked) logger.warn('A logout request, marked as parked but not encountered among parked requests, timed out waiting for registration info: sid=' + sid + ', requestId=' + waiter.requestId); // this should be impossible: how can you go for logout at IdP if you have no registration info? + else logger.warn('A logout request timed out waiting for registration info, with no outstanding request at IdP: sid=' + waiter.sid); + waiter.response.reject(new Error('Timed out waiting for registration info')); + if (waiter.responsePromise.isPending()) waiter.responsePromise.reject(new Error('Timed out waiting for registration info')); + } + else if (waiter.responsePromise.isPending()) { + logger.warn('A logout request timed out at IdP: sid=' + waiter.sid + ', requestId=' + waiter.requestId) + waiter.responsePromise.reject(new Error('Request timed out waiting for IdP logout reply')); + } + else { + logger.info('Encountered a waiting logout request which has already been resolved: sid=' + waiter.sid + ', requestId=' + waiter.requestId); + } + delete waitingLogouts[key]; + if (waiter.requestId) delete parkedLogoutRequests[waiter.requestId]; + } + } +}, 10000); -- cgit v1.2.1