Many tweaks in log system + implement many log messages in low-level functions

This commit is contained in:
Alexandre Aubin 2019-10-03 20:42:01 +02:00
parent 474b922089
commit 1eb322df17
4 changed files with 52 additions and 33 deletions

View file

@ -25,6 +25,9 @@ local hlp = require "helpers"
-- Import Perl regular expressions library -- Import Perl regular expressions library
local rex = require "rex_pcre" local rex = require "rex_pcre"
-- Load logging module
local logger = require("log")
-- Just a note for the client to know that he passed through the SSO -- Just a note for the client to know that he passed through the SSO
ngx.header["X-SSO-WAT"] = "You've just been SSOed" ngx.header["X-SSO-WAT"] = "You've just been SSOed"
@ -47,7 +50,7 @@ if ngx.var.host ~= conf["portal_domain"] and ngx.var.request_method == "GET" the
user = cache:get("CDA|"..cda_key) user = cache:get("CDA|"..cda_key)
if user then if user then
hlp.set_auth_cookie(user, ngx.var.host) hlp.set_auth_cookie(user, ngx.var.host)
ngx.log(ngx.NOTICE, "Cross-domain authentication: "..user.." connected on "..ngx.var.host) logger.info("Cross-domain authentication: "..user.." connected on "..ngx.var.host)
cache:delete("CDA|"..cda_key) cache:delete("CDA|"..cda_key)
end end
@ -74,6 +77,7 @@ then
-- Force portal scheme -- Force portal scheme
if ngx.var.scheme ~= conf["portal_scheme"] then if ngx.var.scheme ~= conf["portal_scheme"] then
logger.debug("Redirecting to "..conf.portal_url.."Cross-domain authentication: "..user.." connected on "..ngx.var.host)
return hlp.redirect(conf.portal_url) return hlp.redirect(conf.portal_url)
end end
@ -88,6 +92,7 @@ then
-- Logout is also called via a `GET` method -- Logout is also called via a `GET` method
-- TODO: change this ? -- TODO: change this ?
if uri_args.action and uri_args.action == 'logout' then if uri_args.action and uri_args.action == 'logout' then
logger.debug("Logging out")
return hlp.logout() return hlp.logout()
-- If the `r` URI argument is set, it means that we want to -- If the `r` URI argument is set, it means that we want to
@ -100,7 +105,7 @@ then
-- pass some additional headers -- pass some additional headers
if string.match(back_url, "(.*)\n") then if string.match(back_url, "(.*)\n") then
hlp.flash("fail", hlp.t("redirection_error_invalid_url")) hlp.flash("fail", hlp.t("redirection_error_invalid_url"))
ngx.log(ngx.ERR, "Redirection url is invalid") logger.error("Redirection url is invalid")
return hlp.redirect(conf.portal_url) return hlp.redirect(conf.portal_url)
end end
@ -110,7 +115,7 @@ then
for _, domain in ipairs(conf["domains"]) do for _, domain in ipairs(conf["domains"]) do
local escaped_domain = domain:gsub("-", "%%-") -- escape dash for pattern matching local escaped_domain = domain:gsub("-", "%%-") -- escape dash for pattern matching
if string.match(back_url, "^http[s]?://"..escaped_domain.."/") then if string.match(back_url, "^http[s]?://"..escaped_domain.."/") then
ngx.log(ngx.INFO, "Redirection to a managed domain found") logger.debug("Redirection to a managed domain found")
managed_domain = true managed_domain = true
break break
end end
@ -120,7 +125,7 @@ then
-- redirect to portal home page -- redirect to portal home page
if not managed_domain then if not managed_domain then
hlp.flash("fail", hlp.t("redirection_error_unmanaged_domain")) hlp.flash("fail", hlp.t("redirection_error_unmanaged_domain"))
ngx.log(ngx.ERR, "Redirection to an external domain aborted") logger.error("Redirection to an external domain aborted")
return hlp.redirect(conf.portal_url) return hlp.redirect(conf.portal_url)
end end
@ -162,6 +167,7 @@ then
-- If all the previous cases have failed, redirect to portal -- If all the previous cases have failed, redirect to portal
else else
hlp.flash("info", hlp.t("please_login")) hlp.flash("info", hlp.t("please_login"))
logger.debug("User should log in to be able to access "..ngx.var.uri)
-- Force the scheme to HTTPS. This is to avoid an issue with redirection loop -- Force the scheme to HTTPS. This is to avoid an issue with redirection loop
-- when trying to access http://main.domain.tld/ (SSOwat finds that user aint -- when trying to access http://main.domain.tld/ (SSOwat finds that user aint
-- logged in, therefore redirects to SSO, which redirects to the back_url, which -- logged in, therefore redirects to SSO, which redirects to the back_url, which
@ -180,13 +186,16 @@ then
if hlp.string.ends(ngx.var.uri, conf["portal_path"].."password.html") if hlp.string.ends(ngx.var.uri, conf["portal_path"].."password.html")
or hlp.string.ends(ngx.var.uri, conf["portal_path"].."edit.html") or hlp.string.ends(ngx.var.uri, conf["portal_path"].."edit.html")
then then
logger.debug("User attempts to edit its information")
return hlp.edit_user() return hlp.edit_user()
else else
logger.debug("User attempts to log in")
return hlp.login() return hlp.login()
end end
else else
-- Redirect to portal -- Redirect to portal
hlp.flash("fail", hlp.t("please_login_from_portal")) hlp.flash("fail", hlp.t("please_login_from_portal"))
logger.debug("Invalid POST request not coming from the portal url...")
return hlp.redirect(conf.portal_url) return hlp.redirect(conf.portal_url)
end end
end end
@ -228,6 +237,7 @@ if conf["redirected_urls"] then
if url == ngx.var.host..ngx.var.uri..hlp.uri_args_string() if url == ngx.var.host..ngx.var.uri..hlp.uri_args_string()
or url == ngx.var.scheme.."://"..ngx.var.host..ngx.var.uri..hlp.uri_args_string() or url == ngx.var.scheme.."://"..ngx.var.host..ngx.var.uri..hlp.uri_args_string()
or url == ngx.var.uri..hlp.uri_args_string() then or url == ngx.var.uri..hlp.uri_args_string() then
logger.debug("Requested URI is in redirected_urls")
detect_redirection(redirect_url) detect_redirection(redirect_url)
end end
end end
@ -238,6 +248,7 @@ if conf["redirected_regex"] then
if match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex) if match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex)
or match(ngx.var.scheme.."://"..ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex) or match(ngx.var.scheme.."://"..ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex)
or match(ngx.var.uri..hlp.uri_args_string(), regex) then or match(ngx.var.uri..hlp.uri_args_string(), regex) then
logger.debug("Requested URI is in redirected_regex")
detect_redirection(redirect_url) detect_redirection(redirect_url)
end end
end end
@ -264,16 +275,19 @@ function is_protected()
for _, url in ipairs(conf["protected_urls"]) do for _, url in ipairs(conf["protected_urls"]) do
if hlp.string.starts(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), url) if hlp.string.starts(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), url)
or hlp.string.starts(ngx.var.uri..hlp.uri_args_string(), url) then or hlp.string.starts(ngx.var.uri..hlp.uri_args_string(), url) then
logger.debug(ngx.var.uri.." is in protected_urls")
return true return true
end end
end end
for _, regex in ipairs(conf["protected_regex"]) do for _, regex in ipairs(conf["protected_regex"]) do
if match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex) if match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex)
or match(ngx.var.uri..hlp.uri_args_string(), regex) then or match(ngx.var.uri..hlp.uri_args_string(), regex) then
logger.debug(ngx.var.uri.." is in protected_regex")
return true return true
end end
end end
logger.debug(ngx.var.uri.." is not in protected_urls/regex")
return false return false
end end
@ -291,6 +305,7 @@ if conf["skipped_urls"] then
if (hlp.string.starts(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), url) if (hlp.string.starts(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), url)
or hlp.string.starts(ngx.var.uri..hlp.uri_args_string(), url)) or hlp.string.starts(ngx.var.uri..hlp.uri_args_string(), url))
and not is_protected() then and not is_protected() then
logger.debug("Skipping "..ngx.var.uri)
return hlp.pass() return hlp.pass()
end end
end end
@ -301,6 +316,7 @@ if conf["skipped_regex"] then
if (match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex) if (match(ngx.var.host..ngx.var.uri..hlp.uri_args_string(), regex)
or match(ngx.var.uri..hlp.uri_args_string(), regex)) or match(ngx.var.uri..hlp.uri_args_string(), regex))
and not is_protected() then and not is_protected() then
logger.debug("Skipping "..ngx.var.uri)
return hlp.pass() return hlp.pass()
end end
end end
@ -327,6 +343,7 @@ end
function serveAsset(shortcut, full) function serveAsset(shortcut, full)
if string.match(ngx.var.uri, "^"..shortcut.."$") then if string.match(ngx.var.uri, "^"..shortcut.."$") then
logger.debug("Serving static asset "..full)
hlp.serve("/yunohost/sso/assets/"..full, "static_asset") hlp.serve("/yunohost/sso/assets/"..full, "static_asset")
end end
end end
@ -378,6 +395,7 @@ if conf["unprotected_urls"] then
if hlp.is_logged_in() then if hlp.is_logged_in() then
hlp.set_headers() hlp.set_headers()
end end
logger.debug(ngx.var.uri.." is in unprotected_urls")
return hlp.pass() return hlp.pass()
end end
end end
@ -391,6 +409,7 @@ if conf["unprotected_regex"] then
if hlp.is_logged_in() then if hlp.is_logged_in() then
hlp.set_headers() hlp.set_headers()
end end
logger.debug(ngx.var.uri.." is in unprotected_regex")
return hlp.pass() return hlp.pass()
end end
end end
@ -416,6 +435,7 @@ if auth_header then
_, _, user, password = string.find(ngx.decode_base64(b64_cred), "^(.+):(.+)$") _, _, user, password = string.find(ngx.decode_base64(b64_cred), "^(.+):(.+)$")
user = hlp.authenticate(user, password) user = hlp.authenticate(user, password)
if user then if user then
logger.debug("User got authenticated through basic auth")
-- If user has no access to this URL, redirect him to the portal -- If user has no access to this URL, redirect him to the portal
if not hlp.has_access(user) then if not hlp.has_access(user) then
return hlp.redirect(conf.portal_url) return hlp.redirect(conf.portal_url)
@ -450,5 +470,6 @@ end
-- when trying to access http://main.domain.tld/ (SSOwat finds that user aint -- when trying to access http://main.domain.tld/ (SSOwat finds that user aint
-- logged in, therefore redirects to SSO, which redirects to the back_url, which -- logged in, therefore redirects to SSO, which redirects to the back_url, which
-- redirect to SSO, ..) -- redirect to SSO, ..)
logger.debug("No rule found for this url. By default, redirecting to portal")
local back_url = "https://" .. ngx.var.host .. ngx.var.uri .. hlp.uri_args_string() local back_url = "https://" .. ngx.var.host .. ngx.var.uri .. hlp.uri_args_string()
return hlp.redirect(conf.portal_url.."?r="..ngx.encode_base64(back_url)) return hlp.redirect(conf.portal_url.."?r="..ngx.encode_base64(back_url))

View file

@ -55,7 +55,8 @@ function get_config()
ldap_attributes = {"uid", "givenname", "sn", "cn", "homedirectory", "mail", "maildrop"}, ldap_attributes = {"uid", "givenname", "sn", "cn", "homedirectory", "mail", "maildrop"},
allow_mail_authentication = true, allow_mail_authentication = true,
default_language = "en", default_language = "en",
theme = "default" theme = "default",
logging = "fatal" -- Only log fatal messages by default (so apriori nothing)
} }

View file

@ -10,7 +10,6 @@ module('helpers', package.seeall)
local cache = ngx.shared.cache local cache = ngx.shared.cache
local conf = config.get_config() local conf = config.get_config()
local logger = require("log") local logger = require("log")
logger.outfile = "/var/log/nginx/ssowat.log"
-- Read a FS stored file -- Read a FS stored file
function read_file(file) function read_file(file)
@ -239,7 +238,7 @@ function log_access(user, app)
local key = "ACC|"..user.."|"..app local key = "ACC|"..user.."|"..app
local block = cache:get(key) local block = cache:get(key)
if block == nil then if block == nil then
logger.info("ACC "..app.." by "..user.."@"..ngx.var.remote_addr) logger.info("User "..user.."@"..ngx.var.remote_addr.." accesses "..app)
cache:set(key, "block", 60) cache:set(key, "block", 60)
end end
end end
@ -258,6 +257,7 @@ function has_access(user, url)
-- If there are no `users` directive, or if the user has no ACL set, he can -- If there are no `users` directive, or if the user has no ACL set, he can
-- access the URL by default -- access the URL by default
if not conf["users"] or not conf["users"][user] then if not conf["users"] or not conf["users"][user] then
logger.debug("No access rules defined for user "..user..", assuming it can access..")
return true return true
end end
@ -271,10 +271,12 @@ function has_access(user, url)
end end
if string.starts(url, string.sub(u, 1, -2)) then if string.starts(url, string.sub(u, 1, -2)) then
logger.debug("Logged-in user can access "..ngx.var.uri)
log_access(user, app) log_access(user, app)
return true return true
end end
end end
logger.debug("Logged-in user cannot access "..ngx.var.uri)
return false return false
end end
@ -297,10 +299,10 @@ function authenticate(user, password)
attrs = {conf["ldap_identifier"]} attrs = {conf["ldap_identifier"]}
} do } do
if attribs[conf["ldap_identifier"]] then if attribs[conf["ldap_identifier"]] then
ngx.log(ngx.NOTICE, "Use email: "..user) logger.debug("Use email: "..user)
user = attribs[conf["ldap_identifier"]] user = attribs[conf["ldap_identifier"]]
else else
ngx.log(ngx.ERR, "Unknown email: "..user) logger.error("Unknown email: "..user)
return false return false
end end
end end
@ -324,14 +326,12 @@ function authenticate(user, password)
ensure_user_password_uses_strong_hash(connected, user, password) ensure_user_password_uses_strong_hash(connected, user, password)
end end
cache:add(user.."-password", password, conf["session_timeout"]) cache:add(user.."-password", password, conf["session_timeout"])
ngx.log(ngx.NOTICE, "Connected as: "..user) logger.info("User "..user.." succesfully authenticated from "..ngx.var.remote_addr)
logger.info("AUTHSUCC "..user.."@"..ngx.var.remote_addr)
return user return user
-- Else, the username/email or the password is wrong -- Else, the username/email or the password is wrong
else else
ngx.log(ngx.ERR, "Connection failed for: "..user) logger.error("Authentication failure for user "..user.." from "..ngx.var.remote_addr)
logger.info("AUTHFAIL "..user.."@"..ngx.var.remote_addr)
return false return false
end end
end end
@ -381,13 +381,13 @@ function set_headers(user)
-- If the ldap connection fail (because the password was changed). -- If the ldap connection fail (because the password was changed).
-- Logout the user and invalid the password -- Logout the user and invalid the password
if not ldap then if not ldap then
ngx.log(ngx.NOTICE, "LDAP connection failed. Disconnect user : ".. user) logger.debug("LDAP connection failed. Disconnect user : ".. user)
cache:delete(authUser.."-password") cache:delete(authUser.."-password")
flash("info", t("please_login")) flash("info", t("please_login"))
local back_url = ngx.var.scheme .. "://" .. ngx.var.host .. ngx.var.uri .. uri_args_string() local back_url = ngx.var.scheme .. "://" .. ngx.var.host .. ngx.var.uri .. uri_args_string()
return redirect(conf.portal_url.."?r="..ngx.encode_base64(back_url)) return redirect(conf.portal_url.."?r="..ngx.encode_base64(back_url))
end end
ngx.log(ngx.NOTICE, "Reloading LDAP values for: "..user) logger.debug("Reloading LDAP values for: "..user)
for dn, attribs in ldap:search { for dn, attribs in ldap:search {
base = conf["ldap_identifier"].."=".. user ..","..conf["ldap_group"], base = conf["ldap_identifier"].."=".. user ..","..conf["ldap_group"],
scope = "base", scope = "base",
@ -458,6 +458,9 @@ end
-- Takes an URI, and returns file content with the proper HTTP headers. -- Takes an URI, and returns file content with the proper HTTP headers.
-- It is used to render the SSOwat portal *only*. -- It is used to render the SSOwat portal *only*.
function serve(uri, cache) function serve(uri, cache)
logger.debug("Serving portal uri "..uri.." (if the corresponding file exists)")
rel_path = string.gsub(uri, conf["portal_path"], "/") rel_path = string.gsub(uri, conf["portal_path"], "/")
-- Load login.html as index -- Load login.html as index
@ -952,7 +955,7 @@ function login()
-- pass some additional headers -- pass some additional headers
if string.match(uri_args.r, "(.*)\n") then if string.match(uri_args.r, "(.*)\n") then
flash("fail", t("redirection_error_invalid_url")) flash("fail", t("redirection_error_invalid_url"))
ngx.log(ngx.ERR, "Redirection url is invalid") logger.debug("Redirection url is invalid")
return redirect(conf.portal_url) return redirect(conf.portal_url)
end end
@ -991,7 +994,7 @@ end
-- Set cookie and redirect (needed to properly set cookie) -- Set cookie and redirect (needed to properly set cookie)
function redirect(url) function redirect(url)
ngx.log(ngx.NOTICE, "Redirect to: "..url) logger.debug("Redirecting to "..url)
return ngx.redirect(url) return ngx.redirect(url)
end end
@ -999,6 +1002,7 @@ end
-- Set cookie and go on with the response (needed to properly set cookie) -- Set cookie and go on with the response (needed to properly set cookie)
function pass() function pass()
delete_redirect_cookie() delete_redirect_cookie()
logger.debug("Allowing to pass through "..ngx.var.uri)
-- When we are in the SSOwat portal, we need a default `content-type` -- When we are in the SSOwat portal, we need a default `content-type`
if string.ends(ngx.var.uri, "/") if string.ends(ngx.var.uri, "/")

23
log.lua
View file

@ -8,11 +8,10 @@
-- --
local log = { _version = "0.1.0" } local log = { _version = "0.1.0" }
local conf = config.get_config()
log.usecolor = true log.usecolor = true
log.outfile = nil log.level = conf.logging
log.level = "trace"
local modes = { local modes = {
{ name = "trace", color = "\27[34m", }, { name = "trace", color = "\27[34m", },
@ -63,27 +62,21 @@ for i, x in ipairs(modes) do
local msg = tostring(...) local msg = tostring(...)
local info = debug.getinfo(2, "Sl") local info = debug.getinfo(2, "Sl")
-- local lineinfo = info.short_src .. ":" .. info.currentline
local lineinfo = ""
-- Output to console -- Output to console
print(string.format("%s[%-6s%s]%s %s: %s", print(string.format("%s[%-6s%s]%s %s",
log.usecolor and x.color or "", log.usecolor and x.color or "",
nameupper, nameupper,
os.date("%H:%M:%S"), os.date("%H:%M:%S"),
log.usecolor and "\27[0m" or "", log.usecolor and "\27[0m" or "",
lineinfo,
msg)) msg))
-- Output to log file -- Output to log file
if log.outfile then local fp = io.open(log_file, "a")
local fp = io.open(log.outfile, "a") local str = string.format("[%-6s%s] %s\n",
local str = string.format("[%-6s%s] %s: %s\n", nameupper, os.date(), msg)
nameupper, os.date(), lineinfo, msg) fp:write(str)
fp:write(str) fp:close()
fp:close()
end
end end
end end