Merge pull request jaliss#374 from jeantil/logger

Improve logging behaviour

Author: jaliss

docs/src/manual/source/guide/configuration.md

@@ -249,3 +249,12 @@ A sample usage would look like:
 ## Clustered environments
 
 SecureSocial uses the Play cache to store values while signing in users via OAuth.  If you have more than one server then make sure to use a distributed cache (eg: memcached).
+
+## Logging configuration
+
+All the securesocial loggers are defined using Play's logging API under the "securesocial" root logger. If you want to customize the logging level for a securesocial component all you have to do is add a line for it in you application.conf.
+For example adding the following line would set all the securesocial loggers at the debug level:
+
+    logger.securesocial=DEBUG
+
+For more information on how to customize logging in Play! you can check the corresponding [documentation](http://www.playframework.com/documentation/2.2.0/SettingsLogger)

module-code/app/securesocial/controllers/LoginPage.scala

@@ -22,14 +22,15 @@ import play.api.Play
 import Play.current
 import providers.UsernamePasswordProvider
 import providers.utils.RoutesHelper
-import play.Logger
 
 
 /**
  * The Login page controller
  */
 object LoginPage extends Controller
 {
+  private val logger = play.api.Logger("securesocial.controllers.LoginPage")
+
   /**
    * The property that specifies the page the user is redirected to after logging out.
    */
@@ -43,9 +44,7 @@ object LoginPage extends Controller
     val to = ProviderController.landingUrl
     if ( SecureSocial.currentUser.isDefined ) {
       // if the user is already logged in just redirect to the app
-      if ( Logger.isDebugEnabled() ) {
-        Logger.debug("User already logged in, skipping login page. Redirecting to %s".format(to))
-      }
+      logger.debug("User already logged in, skipping login page. Redirecting to %s".format(to))
       Redirect( to )
     } else {
       import com.typesafe.plugin._

module-code/app/securesocial/controllers/ProviderController.scala

@@ -19,7 +19,7 @@ package securesocial.controllers
 import play.api.mvc._
 import play.api.i18n.Messages
 import securesocial.core._
-import play.api.{Play, Logger}
+import play.api.Play
 import Play.current
 import providers.utils.RoutesHelper
 import securesocial.core.LoginEvent
@@ -33,6 +33,7 @@ import play.api.http.HeaderNames
  */
 object ProviderController extends Controller with SecureSocial
 {
+  private val logger = play.api.Logger("securesocial.controllers.ProviderController")
   /**
    * The property that specifies the page the user is redirected to if there is no original URL saved in
    * the session.
@@ -116,9 +117,7 @@ object ProviderController extends Controller with SecureSocial
               request.user match {
                 case Some(currentUser) =>
                   UserService.link(currentUser, user)
-                  if ( Logger.isDebugEnabled ) {
-                    Logger.debug(s"[securesocial] linked $currentUser to $user")
-                  }
+                  logger.debug(s"[securesocial] linked $currentUser to $user")
                   // improve this, I'm duplicating part of the code in completeAuthentication
                   Redirect(toUrl(modifiedSession)).withSession(modifiedSession-
                     SecureSocial.OriginalUrlKey -
@@ -135,7 +134,7 @@ object ProviderController extends Controller with SecureSocial
           }
 
           case other: Throwable => {
-            Logger.error("Unable to log user in. An exception was thrown", other)
+            logger.error("Unable to log user in. An exception was thrown", other)
             Redirect(RoutesHelper.login()).flashing("error" -> Messages("securesocial.login.errorLoggingIn"))
           }
         }
@@ -145,8 +144,8 @@ object ProviderController extends Controller with SecureSocial
   }
 
   def completeAuthentication(user: Identity, session: Session)(implicit request: RequestHeader): SimpleResult = {
-    if ( Logger.isDebugEnabled ) {
-      Logger.debug("[securesocial] user logged in : [" + user + "]")
+    if ( logger.isDebugEnabled ) {
+      logger.debug("[securesocial] user logged in : [" + user + "]")
     }
     val withSession = Events.fire(new LoginEvent(user)).getOrElse(session)
     Authenticator.create(user) match {

module-code/app/securesocial/controllers/Registration.scala

@@ -21,7 +21,7 @@ import play.api.mvc.{RequestHeader, Result, Action, Controller}
 import play.api.data._
 import play.api.data.Forms._
 import play.api.data.validation.Constraints._
-import play.api.{Play, Logger}
+import play.api.Play
 import securesocial.core.providers.UsernamePasswordProvider
 import securesocial.core._
 import com.typesafe.plugin._
@@ -40,6 +40,7 @@ import scala.language.reflectiveCalls
  *
  */
 object Registration extends Controller {
+  private val logger = play.api.Logger("securesocial.controllers.Registration")
 
   val providerId = UsernamePasswordProvider.UsernamePassword
   val UserNameAlreadyTaken = "securesocial.signup.userNameAlreadyTaken"
@@ -190,9 +191,7 @@ object Registration extends Controller {
    */
   def signUp(token: String) = Action { implicit request =>
     if (registrationEnabled) {
-      if ( Logger.isDebugEnabled ) {
-        Logger.debug("[securesocial] trying sign up with token %s".format(token))
-      }
+      logger.debug("[securesocial] trying sign up with token %s".format(token))
       executeForToken(token, true, { _ =>
         Ok(use[TemplatesPlugin].getSignUpPage(form, token))
       })
@@ -220,9 +219,7 @@ object Registration extends Controller {
       executeForToken(token, true, { t =>
         form.bindFromRequest.fold (
           errors => {
-            if ( Logger.isDebugEnabled ) {
-              Logger.debug("[securesocial] errors " + errors)
-            }
+            logger.debug("[securesocial] errors " + errors)
             BadRequest(use[TemplatesPlugin].getSignUpPage(errors, t.uuid))
           },
           info => {
@@ -302,7 +299,7 @@ object Registration extends Controller {
             ( Success -> Messages(PasswordUpdated), eventSession)
           }
           case _ => {
-            Logger.error("[securesocial] could not find user with email %s during password reset".format(t.email))
+            logger.error("[securesocial] could not find user with email %s during password reset".format(t.email))
             ( Error -> Messages(ErrorUpdatingPassword), None)
           }
         }

module-code/app/securesocial/core/Events.scala

@@ -17,7 +17,7 @@
 package securesocial.core
 
 import play.api.mvc.{Controller, Session, RequestHeader}
-import play.api.{Logger, Plugin}
+import play.api.Plugin
 
 /**
  * A trait to model SecureSocial events
@@ -58,14 +58,16 @@ case class PasswordResetEvent(user: Identity) extends Event
  * The event listener interface
  */
 abstract class EventListener extends Plugin with Registrable with Controller {
+  private val logger = play.api.Logger("securesocial.core.EventListener")
+
   override def onStart() {
-    Logger.info("[securesocial] loaded event listener %s".format(id))
+    logger.info("[securesocial] loaded event listener %s".format(id))
     Registry.eventListeners.register(this)
   }
 
 
   override def onStop() {
-    Logger.info("[securesocial] unloaded event listener %s".format(id))
+    logger.info("[securesocial] unloaded event listener %s".format(id))
     Registry.eventListeners.unRegister(id)
   }
   /**

module-code/app/securesocial/core/IdentityProvider.scala

@@ -18,7 +18,7 @@ package securesocial.core
 
 import providers.utils.RoutesHelper
 import play.api.mvc.{SimpleResult, AnyContent, Request}
-import play.api.{Play, Application, Logger, Plugin}
+import play.api.{Play, Application, Plugin}
 import concurrent.{Await, Future}
 import play.api.libs.ws.Response
 
@@ -29,6 +29,8 @@ import play.api.libs.ws.Response
  *
  */
 abstract class IdentityProvider(application: Application) extends Plugin with Registrable {
+  private val logger = IdentityProvider.logger
+
   val SecureSocialKey = "securesocial."
   val Dot = "."
 
@@ -37,15 +39,15 @@ abstract class IdentityProvider(application: Application) extends Plugin with Re
    * Registers the provider in the Provider Registry
    */
   override def onStart() {
-    Logger.info("[securesocial] loaded identity provider: %s".format(id))
+    logger.info("[securesocial] loaded identity provider: %s".format(id))
     Registry.providers.register(this)
   }
 
   /**
    * Unregisters the provider
    */
   override def onStop() {
-    Logger.info("[securesocial] unloaded identity provider: %s".format(id))
+    logger.info("[securesocial] unloaded identity provider: %s".format(id))
     Registry.providers.unRegister(id)
   }
 
@@ -100,7 +102,7 @@ abstract class IdentityProvider(application: Application) extends Plugin with Re
   def loadProperty(property: String): Option[String] = {
     val result = application.configuration.getString(propertyKey + property)
     if ( !result.isDefined ) {
-      Logger.error("[securesocial] Missing property " + property + " for provider " + id)
+      logger.error("[securesocial] Missing property " + property + " for provider " + id)
     }
     result
   }
@@ -126,7 +128,7 @@ abstract class IdentityProvider(application: Application) extends Plugin with Re
 
   protected def throwMissingPropertiesException() {
     val msg = "[securesocial] Missing properties for provider '%s'. Verify your configuration file is properly set.".format(id)
-    Logger.error(msg)
+    logger.error(msg)
     throw new RuntimeException(msg)
   }
 
@@ -136,13 +138,14 @@ abstract class IdentityProvider(application: Application) extends Plugin with Re
 }
 
 object IdentityProvider {
+  private val logger = play.api.Logger("securesocial.core.IdentityProvider")
   val SessionId = "sid"
 
   val sslEnabled: Boolean = {
     import Play.current
     val result = current.configuration.getBoolean("securesocial.ssl").getOrElse(false)
     if ( !result && Play.isProd ) {
-      Logger.warn(
+      logger.warn(
         "[securesocial] IMPORTANT: Play is running in production mode but you did not turn SSL on for SecureSocial." +
           "Not using SSL can make it really easy for an attacker to steal your users' credentials and/or the " +
           "authenticator cookie and gain access to the system."

module-code/app/securesocial/core/OAuth1Provider.scala

@@ -19,7 +19,7 @@ package securesocial.core
 import _root_.java.util.UUID
 import play.api.cache.Cache
 import play.api.libs.oauth.{RequestToken, ConsumerKey, OAuth, ServiceInfo}
-import play.api.{Application, Logger, Play}
+import play.api.{Application, Play}
 import providers.utils.RoutesHelper
 import play.api.mvc.{SimpleResult, AnyContent, Request}
 import play.api.mvc.Results.Redirect
@@ -30,6 +30,8 @@ import Play.current
  * Base class for all OAuth1 providers
  */
 abstract class OAuth1Provider(application: Application) extends IdentityProvider(application)  {
+  private val logger = play.api.Logger("securesocial.core.OAuth1Provider")
+
   val serviceInfo = createServiceInfo(propertyKey)
   val service = OAuth(serviceInfo, use10a = true)
 
@@ -77,7 +79,7 @@ abstract class OAuth1Provider(application: Application) extends IdentityProvider
               )
             )
           case Left(oauthException) =>
-            Logger.error("[securesocial] error retrieving access token", oauthException)
+            logger.error("[securesocial] error retrieving access token", oauthException)
             throw new AuthenticationException()
         }
       }
@@ -86,9 +88,7 @@ abstract class OAuth1Provider(application: Application) extends IdentityProvider
       // the oauth_verifier field is not in the request, this is the 1st step in the auth flow.
       // we need to get the request tokens
       val callbackUrl = RoutesHelper.authenticate(id).absoluteURL(IdentityProvider.sslEnabled)
-      if ( Logger.isDebugEnabled ) {
-        Logger.debug("[securesocial] callback url = " + callbackUrl)
-      }
+      logger.debug("[securesocial] callback url = " + callbackUrl)
       service.retrieveRequestToken(callbackUrl) match {
         case Right(accessToken) =>
           val cacheKey = UUID.randomUUID().toString
@@ -97,7 +97,7 @@ abstract class OAuth1Provider(application: Application) extends IdentityProvider
           Cache.set(cacheKey, accessToken, 300) // set it for 5 minutes, plenty of time to log in
           Left(redirect)
         case Left(e) =>
-          Logger.error("[securesocial] error retrieving request token", e)
+          logger.error("[securesocial] error retrieving request token", e)
           throw new AuthenticationException()
       }
     }

module-code/app/securesocial/core/OAuth2Provider.scala

@@ -18,7 +18,7 @@ package securesocial.core
 
 import _root_.java.net.URLEncoder
 import _root_.java.util.UUID
-import play.api.{Logger, Play, Application}
+import play.api.{Play, Application}
 import play.api.cache.Cache
 import Play.current
 import play.api.mvc._
@@ -32,6 +32,8 @@ import scala.Some
  * Base class for all OAuth2 providers
  */
 abstract class OAuth2Provider(application: Application, jsonResponse: Boolean = true) extends IdentityProvider(application) {
+  private val logger = play.api.Logger("securesocial.core.OAuth2Provider")
+
   val settings = createSettings()
 
   def authMethod = AuthenticationMethod.OAuth2
@@ -73,17 +75,15 @@ abstract class OAuth2Provider(application: Application, jsonResponse: Boolean =
       buildInfo(awaitResult(call))
     } catch {
       case e: Exception => {
-        Logger.error("[securesocial] error trying to get an access token for provider %s".format(id), e)
+        logger.error("[securesocial] error trying to get an access token for provider %s".format(id), e)
         throw new AuthenticationException()
       }
     }
   }
 
   protected def buildInfo(response: Response): OAuth2Info = {
       val json = response.json
-      if ( Logger.isDebugEnabled ) {
-        Logger.debug("[securesocial] got json back [" + json + "]")
-      }
+      logger.debug("[securesocial] got json back [" + json + "]")
       OAuth2Info(
         (json \ OAuth2Constants.AccessToken).as[String],
         (json \ OAuth2Constants.TokenType).asOpt[String],
@@ -97,7 +97,7 @@ abstract class OAuth2Provider(application: Application, jsonResponse: Boolean =
       error match {
         case OAuth2Constants.AccessDenied => throw new AccessDeniedException()
         case _ =>
-          Logger.error("[securesocial] error '%s' returned by the authorization server. Provider type is %s".format(error, id))
+          logger.error("[securesocial] error '%s' returned by the authorization server. Provider type is %s".format(error, id))
           throw new AuthenticationException()
       }
       throw new AuthenticationException()
@@ -119,9 +119,7 @@ abstract class OAuth2Provider(application: Application, jsonResponse: Boolean =
           )
           SocialUser(IdentityId("", id), "", "", "", None, None, authMethod, oAuth2Info = oauth2Info)
         }
-        if ( Logger.isDebugEnabled ) {
-          Logger.debug("[securesocial] user = " + user)
-        }
+        logger.debug("[securesocial] user = " + user)
         user match  {
           case Some(u) => Right(u)
           case _ => throw new AuthenticationException()
@@ -140,10 +138,9 @@ abstract class OAuth2Provider(application: Application, jsonResponse: Boolean =
         settings.authorizationUrlParams.foreach( e => { params = e :: params })
         val url = settings.authorizationUrl +
           params.map( p => URLEncoder.encode(p._1, "UTF-8") + "=" + URLEncoder.encode(p._2, "UTF-8")).mkString("?", "&", "")
-        if ( Logger.isDebugEnabled ) {
-          Logger.debug("[securesocial] authorizationUrl = %s".format(settings.authorizationUrl))
-          Logger.debug("[securesocial] redirecting to: [%s]".format(url))
-        }
+        logger.debug("[securesocial] authorizationUrl = %s".format(settings.authorizationUrl))
+        logger.debug("[securesocial] redirecting to: [%s]".format(url))
+
         Left(Results.Redirect( url ).withSession(request.session + (IdentityProvider.SessionId, sessionId)))
     }
   }

module-code/app/securesocial/core/Registry.scala

@@ -16,7 +16,6 @@
  */
 package securesocial.core
 
-import play.api.Logger
 import providers.UsernamePasswordProvider
 import providers.utils.PasswordHasher
 import scala.None
@@ -27,6 +26,8 @@ trait Registrable {
 }
 
 class PluginRegistry[T <: Registrable](label: String) {
+  private val logger = play.api.Logger("securesocial.core.PluginRegistry")
+
   private var registry = Map[String, T]()
 
   def register(plugin: T) {
@@ -43,7 +44,7 @@ class PluginRegistry[T <: Registrable](label: String) {
   }
 
   def get(id: String): Option[T] = registry.get(id) orElse {
-    Logger.error("[securesocial] can't find %s for id %s".format(label, id))
+    logger.error("[securesocial] can't find %s for id %s".format(label, id))
     None
   }