diff --git a/.gitignore b/.gitignore index 409ac506eb..2a394d2af0 100644 --- a/.gitignore +++ b/.gitignore @@ -86,6 +86,7 @@ samples-and-tests/test-scala/tmp samples-and-tests/test-scala/logs samples-and-tests/i-am-a-developer/i-am-working-here samples-and-tests/i-am-a-developer/i-am-creating-jobs-here +samples-and-tests/i-am-a-developer/i-am-testing-log-levels-here samples-and-tests/just-test-cases/attachments samples-and-tests/booking/logs samples-and-tests/booking/tmp diff --git a/framework/src/play/Logger.java b/framework/src/play/Logger.java index d5279e02c3..7073619e84 100644 --- a/framework/src/play/Logger.java +++ b/framework/src/play/Logger.java @@ -48,6 +48,11 @@ public class Logger { */ public static java.util.logging.Logger juli = java.util.logging.Logger.getLogger("play"); + /** + * true if logger is configured manually (log4j-config file supplied by application) + */ + public static boolean configuredManually = false; + /** * Try to init stuff. */ @@ -63,6 +68,10 @@ public static void init() { shutUp.setProperty("log4j.rootLogger", "OFF"); PropertyConfigurator.configure(shutUp); } else if (Logger.log4j == null) { + + //we're configuring the Logger manually. + configuredManually = true; + PropertyConfigurator.configure(log4jConf); Logger.log4j = org.apache.log4j.Logger.getLogger("play"); // In test mode, append logs to test-result/application.log diff --git a/framework/src/play/Play.java b/framework/src/play/Play.java index d15370481f..e9d24e1bdb 100644 --- a/framework/src/play/Play.java +++ b/framework/src/play/Play.java @@ -206,7 +206,11 @@ public static void init(File root, String id) { // Configure logs Logger.init(); String logLevel = configuration.getProperty("application.log", "INFO"); - Logger.setUp(logLevel); + + //only override log-level if Logger was not configured manually + if( !Logger.configuredManually) { + Logger.setUp(logLevel); + } Logger.info("Starting %s", root.getAbsolutePath()); @@ -415,7 +419,10 @@ public void run(){ // Configure logs String logLevel = configuration.getProperty("application.log", "INFO"); - Logger.setUp(logLevel); + //only override log-level if Logger was not configured manually + if( !Logger.configuredManually) { + Logger.setUp(logLevel); + } // Locales langs = new ArrayList(Arrays.asList(configuration.getProperty("application.langs", "").split(","))); diff --git a/samples-and-tests/i-am-a-developer/tests.py b/samples-and-tests/i-am-a-developer/tests.py index 4f6bbf6fb9..8613175e1c 100755 --- a/samples-and-tests/i-am-a-developer/tests.py +++ b/samples-and-tests/i-am-a-developer/tests.py @@ -14,6 +14,95 @@ # --- TESTS class IamADeveloper(unittest.TestCase): + + def testLogLevelsAndLog4jConfig(self): + + # Testing job developing + step('Hello, I am testing loglevels') + + self.working_directory = bootstrapWorkingDirectory('i-am-testing-log-levels-here') + + # play new job-app + step('Create a new project') + + self.play = callPlay(self, ['new', '%s/loglevelsapp' % self.working_directory, '--name=LOGLEVELSAPP']) + self.assert_(waitFor(self.play, 'The new application will be created')) + self.assert_(waitFor(self.play, 'OK, the application is created')) + self.assert_(waitFor(self.play, 'Have fun!')) + self.play.wait() + + app = '%s/loglevelsapp' % self.working_directory + + #inserting some log-statements in our controller + insert(app, "app/controllers/Application.java", 13, ' Logger.debug("I am a debug message");') + insert(app, "app/controllers/Application.java", 14, ' Logger.info("I am an info message");') + + # Run the newly created application + step('Run our logger-application') + + self.play = callPlay(self, ['run', app]) + #wait for play to be ready + self.assert_(waitFor(self.play, 'Listening for HTTP on port 9000')) + + step("Send request to trigger some logging") + + browser = mechanize.Browser() + response = browser.open('http://localhost:9000/') + + + step("check that only info log message is logged") + self.assert_(waitForWithFail(self.play, 'I am an info message', 'I am a debug message')) + + step("stop play") + killPlay() + self.play.wait() + + #now we're going to manually configure log4j to log debug messages + step('Writing log4j config file') + + create(app, 'conf/log4j.xml') + + insert(app, "conf/log4j.xml", 1, '') + insert(app, "conf/log4j.xml", 2, '') + insert(app, "conf/log4j.xml", 3, '') + insert(app, "conf/log4j.xml", 4, ' ') + insert(app, "conf/log4j.xml", 5, ' ') + insert(app, "conf/log4j.xml", 6, ' ') + insert(app, "conf/log4j.xml", 7, ' ') + insert(app, "conf/log4j.xml", 8, ' ') + insert(app, "conf/log4j.xml", 9, ' ') + insert(app, "conf/log4j.xml", 10, ' ') + insert(app, "conf/log4j.xml", 11, ' ') + insert(app, "conf/log4j.xml", 12, ' ') + insert(app, "conf/log4j.xml", 13, ' ') + insert(app, "conf/log4j.xml", 14, ' ') + insert(app, "conf/log4j.xml", 15, ' ') + insert(app, "conf/log4j.xml", 16, ' ') + insert(app, "conf/log4j.xml", 17, '') + + + # Run the newly created application + step('re-run our logger-application') + + self.play = callPlay(self, ['run', app]) + #wait for play to be ready + self.assert_(waitFor(self.play, 'Listening for HTTP on port 9000')) + + step("Send request to trigger some logging") + + browser = mechanize.Browser() + response = browser.open('http://localhost:9000/') + + + step("check that both debug and info message is logged") + self.assert_(waitFor(self.play, 'I am a debug message')) + self.assert_(waitFor(self.play, 'I am an info message')) + + step("stop play") + killPlay() + self.play.wait() + + step("done testing logging") def testCreateAndRunForJobProject(self): @@ -563,7 +652,13 @@ def callPlay(self, args): play_process = subprocess.Popen(process_args,stdout=subprocess.PIPE) return play_process +#returns true when pattern is seen def waitFor(process, pattern): + return waitForWithFail(process, pattern, "") + + +#returns true when pattern is seen, but false if failPattern is seen +def waitForWithFail(process, pattern, failPattern): timer = threading.Timer(5, timeout, [process]) timer.start() while True: @@ -571,6 +666,9 @@ def waitFor(process, pattern): if line == '@KILLED': return False print line + if failPattern != "" and line.count(failPattern): + timer.cancel() + return False if line.count(pattern): timer.cancel() return True