Internally mozilla's log module codes uses |PR_NewLogModule| [1] for its env var parsing logic [2]. If we move the logic into LogModuleManager we can avoid this dependency and also avoid TSan issues due to |PR_NewLogModule| having thread-safety issues (see bug, bug). We can also avoid parsing the env vars every time a log module is created by caching the mappings after parsing once. This should be a reasonably straight-forward task although we'll probably want to add a test to make sure the parsing logic has parity with NSPR. [1] https://dxr.mozilla.org/mozilla-central/rev/e2a910c048dc82fc3be53475f18e7f81f03e377b/xpcom/base/Logging.cpp#55 [2] https://dxr.mozilla.org/mozilla-central/rev/e2a910c048dc82fc3be53475f18e7f81f03e377b/nsprpub/pr/src/io/prlog.c#310-346

Adds basic handling of the NSPR log module env var format to LogModuleManager's initialization. This removes the need to create a PR_LogModule for each mozilla::LogModule.

Comment on attachment 8700860 [details] [diff] [review] Remove usage of PR_NewLogModule in mozilla LogModule code Review of attachment 8700860 [details] [diff] [review]: ----------------------------------------------------------------- To be clear, this is just about removing the parsing that NSPR would do for us in PR_NewLogModule? We're not actually using Mozilla logging facilities yet? ::: xpcom/base/Logging.cpp @@ +57,5 @@ > + > + // Format: LOG_MODULES=Foo:2 Bar Baz:5 > + while (parser.ReadWord(moduleName)) { > + // Next should be :<level>, default to Error if not provided. > + LogLevel logLevel = LogLevel::Error; The format of NSPR_LOG_MODULES is somewhat richer: https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/NSPR_LOG_MODULES (I'm not sure we can support "all", but other things we ought to be able to support.) Tests for the parsing would be *lovely*.

(In reply to Nathan Froyd [:froydnj] from comment #2) > Comment on attachment 8700860 [details] [diff] [review] > Remove usage of PR_NewLogModule in mozilla LogModule code > > Review of attachment 8700860 [details] [diff] [review]: > ----------------------------------------------------------------- > > To be clear, this is just about removing the parsing that NSPR would do for > us in PR_NewLogModule? We're not actually using Mozilla logging facilities > yet? > > ::: xpcom/base/Logging.cpp > @@ +57,5 @@ > > + > > + // Format: LOG_MODULES=Foo:2 Bar Baz:5 > > + while (parser.ReadWord(moduleName)) { > > + // Next should be :<level>, default to Error if not provided. > > + LogLevel logLevel = LogLevel::Error; > > The format of NSPR_LOG_MODULES is somewhat richer: > > https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/ > NSPR_LOG_MODULES > > (I'm not sure we can support "all", but other things we ought to be able to > support.) I'm not convinced we need/want to support all of the NSPR options (none are used w/in our codebase at least). Either way, there's bug 1174972 which would cover handling timestamp, sync, etc. As-is if you specify those options they'll still be handled by NSPR. > Tests for the parsing would be *lovely*. Good point, I'll add a second patch w/ tests.

(In reply to Eric Rahm [:erahm] from comment #3) > (In reply to Nathan Froyd [:froydnj] from comment #2) > > The format of NSPR_LOG_MODULES is somewhat richer: > > > > https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/ > > NSPR_LOG_MODULES > > > > (I'm not sure we can support "all", but other things we ought to be able to > > support.) > > I'm not convinced we need/want to support all of the NSPR options (none are > used w/in our codebase at least). Either way, there's bug 1174972 which > would cover handling timestamp, sync, etc. As-is if you specify those > options they'll still be handled by NSPR. Sure. I should have been clearer: I don't think we have to take action on all the options in this bug. But I think we do have to at least parse arbitrary NSPR_LOG_MODULE syntax and it's not immediately clear that this code handles something like: NSPR_LOG_MODULES=timestamp,mozStorage:5 (from the MDN page) Unless ReadWord is doing something super-clever with the comma there. > > Tests for the parsing would be *lovely*. > > Good point, I'll add a second patch w/ tests. Thank you!

Adds basic parser for handling of the NSPR log module env var format.

Comment on attachment 8701607 [details] [diff] [review] Part 1: Add NSPRLogModulesParser Review of attachment 8701607 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/base/NSPRLogModulesParser.cpp @@ +34,5 @@ > + logLevel = ToLogLevel(level); > + } > + } > + > + aCallback(moduleName.get(), logLevel); Doing this unconditionally doesn't seem right, as if a level wasn't specified in the aLogModules, that's a syntax error, not a request for a particular log module with an Error logging level. Seems like we should skip it in that case, maybe passing something special to the callback to let it know an error occurred, or letting the callback return a boolean to indicate whether we should keep going. I think NSPR stops entirely if a level isn't specified. ::: xpcom/base/moz.build @@ +84,5 @@ > 'JSObjectHolder.h', > 'LinuxUtils.h', > 'Logging.h', > 'nsMemoryInfoDumper.h', > + 'NSPRLogModulesParser.h', Are we exporting this just so gtests can use it? I think we should just use LOCAL_INCLUDES in the gtest moz.build...

Comment on attachment 8701608 [details] [diff] [review] Part 2: Add tests for NSPRLogModulesParser Review of attachment 8701608 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/tests/gtest/TestNSPRLogModulesParser.cpp @@ +20,5 @@ > + mozilla::NSPRLogModulesParser("Foo", > + [](const char* aName, mozilla::LogLevel aLevel) { > + EXPECT_STREQ("Foo", aName); > + EXPECT_EQ(mozilla::LogLevel::Error, aLevel); > + }); Probably should have a callbackInvoked thingie here. @@ +25,5 @@ > +} > + > +TEST(NSPRLogModulesParser, LevelSpecified) > +{ > + mozilla::NSPRLogModulesParser("Foo:3", ...and for these tests too. @@ +31,5 @@ > + EXPECT_STREQ("Foo", aName); > + EXPECT_EQ(mozilla::LogLevel::Info, aLevel); > + }); > + > + // Too high. And a too low test as well. And one for each level if you want to be paranoid. (I like paranoid test writers.) @@ +44,5 @@ > +{ > + std::pair<const char*, mozilla::LogLevel> expected[] = { > + { "Foo", mozilla::LogLevel::Info }, > + { "Bar", mozilla::LogLevel::Error }, > + { "Baz", mozilla::LogLevel::Warning }, This bit can't be right, because one can have (citing https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/NSPR_LOG_MODULES ): export NSPR_LOG_MODULES=timestamp,mozStorage:5 for the mozStorage log to have timestamps added to it. I guess your thinking is that we just don't care about any of the options now, so we shouldn't even try to parse them? @@ +52,5 @@ > + auto* currTest = expected; > + > + size_t count = 0; > + mozilla::NSPRLogModulesParser("Foo:3, Bar,Baz:2, Qux:5", > + [&](const char* aName, mozilla::LogLevel aLevel) mutable { Should assert that we haven't walked off the edge of |expected| prior to the checks below. ::: xpcom/tests/gtest/TestThreadPool.cpp @@ +11,5 @@ > #include "nsIThreadPool.h" > #include "nsComponentManagerUtils.h" > #include "nsCOMPtr.h" > #include "nsIRunnable.h" > +#include "nsThreadUtils.h" What are the changes in this file for?

Comment on attachment 8701609 [details] [diff] [review] Part 3: Remove usage of PR_NewLogModule in mozilla LogModule code Review of attachment 8701609 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/base/Logging.cpp @@ +51,5 @@ > + void Init() > + { > + const char* modules = PR_GetEnv("NSPR_LOG_MODULES"); > + NSPRLogModulesParser(modules, [] (const char* aName, LogLevel aLevel) { > + LogModule::Get(aName)->SetLevel(aLevel); We need to support the special "all" name here too...though it's not obvious to me that specifying "all" here actually works, because it appears that you need to get all your logging modules setup prior to parsing the environment variable in that case. Maybe we should explicitly comment that we don't care about the "all" module?

I should clarify comment 10 and comment 4: I think it's OK to ignore the log-specific options NSPR_LOG_MODULES permits. I don't think it's OK to treat those options as a separate log altogether.

(In reply to Nathan Froyd [:froydnj] from comment #9) > Comment on attachment 8701607 [details] [diff] [review] > Part 1: Add NSPRLogModulesParser > > Review of attachment 8701607 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: xpcom/base/NSPRLogModulesParser.cpp > @@ +34,5 @@ > > + logLevel = ToLogLevel(level); > > + } > > + } > > + > > + aCallback(moduleName.get(), logLevel); > > Doing this unconditionally doesn't seem right, as if a level wasn't > specified in the aLogModules, that's a syntax error, not a request for a > particular log module with an Error logging level. Yeah I thought about this, it's a weird distinction. No level (and colon) means Error, colon and level means whatever level, colon and no level is probably a typo, but clearly there's intent to enable the log. Setting it to the default log level (Error) seems reasonable in this case. > Seems like we should > skip it in that case, maybe passing something special to the callback to let > it know an error occurred, or letting the callback return a boolean to > indicate whether we should keep going. I guess we could do that, but as the only user of this I'm just going to return true from the function. > I think NSPR stops entirely if a level isn't specified. Yes, I would argue this is an improvement over NSPR. > ::: xpcom/base/moz.build > @@ +84,5 @@ > > 'JSObjectHolder.h', > > 'LinuxUtils.h', > > 'Logging.h', > > 'nsMemoryInfoDumper.h', > > + 'NSPRLogModulesParser.h', > > Are we exporting this just so gtests can use it? I think we should just use > LOCAL_INCLUDES in the gtest moz.build... Yes, just for gtests. I'll move it.

Thanks for the review, I'll update the tests per your recommendations. (In reply to Nathan Froyd [:froydnj] from comment #10) > Comment on attachment 8701608 [details] [diff] [review] > Part 2: Add tests for NSPRLogModulesParser > > Review of attachment 8701608 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: xpcom/tests/gtest/TestNSPRLogModulesParser.cpp > @@ +20,5 @@ > > + mozilla::NSPRLogModulesParser("Foo", > > + [](const char* aName, mozilla::LogLevel aLevel) { > > + EXPECT_STREQ("Foo", aName); > > + EXPECT_EQ(mozilla::LogLevel::Error, aLevel); > > + }); > > Probably should have a callbackInvoked thingie here. > > @@ +25,5 @@ > > +} > > + > > +TEST(NSPRLogModulesParser, LevelSpecified) > > +{ > > + mozilla::NSPRLogModulesParser("Foo:3", > > ...and for these tests too. > > @@ +31,5 @@ > > + EXPECT_STREQ("Foo", aName); > > + EXPECT_EQ(mozilla::LogLevel::Info, aLevel); > > + }); > > + > > + // Too high. > > And a too low test as well. And one for each level if you want to be > paranoid. (I like paranoid test writers.) Hmm this interesting. I think mozilla::Tokenizer isn't going to properly parse the negative value. I'll look into a workaround. > @@ +44,5 @@ > > +{ > > + std::pair<const char*, mozilla::LogLevel> expected[] = { > > + { "Foo", mozilla::LogLevel::Info }, > > + { "Bar", mozilla::LogLevel::Error }, > > + { "Baz", mozilla::LogLevel::Warning }, > > This bit can't be right, because one can have (citing > https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/ > NSPR_LOG_MODULES ): > > export NSPR_LOG_MODULES=timestamp,mozStorage:5 > > for the mozStorage log to have timestamps added to it. I guess your > thinking is that we just don't care about any of the options now, so we > shouldn't even try to parse them? Correct, but I agree that adding code to ignore them properly is reasonable. > @@ +52,5 @@ > > + auto* currTest = expected; > > + > > + size_t count = 0; > > + mozilla::NSPRLogModulesParser("Foo:3, Bar,Baz:2, Qux:5", > > + [&](const char* aName, mozilla::LogLevel aLevel) mutable { > > Should assert that we haven't walked off the edge of |expected| prior to the > checks below. > > ::: xpcom/tests/gtest/TestThreadPool.cpp > @@ +11,5 @@ > > #include "nsIThreadPool.h" > > #include "nsComponentManagerUtils.h" > > #include "nsCOMPtr.h" > > #include "nsIRunnable.h" > > +#include "nsThreadUtils.h" > > What are the changes in this file for? It no longer compiled after adding a new test file. I assume it was some unified compilation weirdness and added the stuff it was missing.

(In reply to Eric Rahm [:erahm] from comment #13) > (In reply to Nathan Froyd [:froydnj] from comment #9) > > Comment on attachment 8701607 [details] [diff] [review] > > Part 1: Add NSPRLogModulesParser > > > > Review of attachment 8701607 [details] [diff] [review]: > > ----------------------------------------------------------------- > > > > ::: xpcom/base/NSPRLogModulesParser.cpp > > @@ +34,5 @@ > > > + logLevel = ToLogLevel(level); > > > + } > > > + } > > > + > > > + aCallback(moduleName.get(), logLevel); > > > > Doing this unconditionally doesn't seem right, as if a level wasn't > > specified in the aLogModules, that's a syntax error, not a request for a > > particular log module with an Error logging level. > > Yeah I thought about this, it's a weird distinction. No level (and colon) > means Error, colon and level means whatever level, colon and no level is > probably a typo, but clearly there's intent to enable the log. Setting it to > the default log level (Error) seems reasonable in this case. > > > I think NSPR stops entirely if a level isn't specified. > > Yes, I would argue this is an improvement over NSPR. That's fair, though I'm not sure how many logs we really have at LogLevel::Error. Let's go with it, without the boolean return value from the callback; please document it as a deviation from NSPR, and we can see what feedback is like, if any.

Updates per code review. Adds handling of negative values, ignores NSPR log options.

Code review updates. Adds checks for |callbackInvoked|, adds test for reserved keywords, expands levelSpecified tests to cover full valid range and negative values, makes sure we don't pass the end of the expected values array.

Comment on attachment 8703930 [details] [diff] [review] Part 2: Add tests for NSPRLogModulesParser Review of attachment 8703930 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/tests/gtest/TestNSPRLogModulesParser.cpp @@ +47,5 @@ > + }; > + > + auto* currTest = expected; > + > + for (size_t i = 0; i < PR_ARRAY_SIZE(expected); i++) { MOZ_ARRAY_SIZE, please. @@ +94,5 @@ > + > + size_t count = 0; > + mozilla::NSPRLogModulesParser("timestamp,Foo:3, Bar,Baz:2, Qux:5", > + [&](const char* aName, mozilla::LogLevel aLevel) mutable { > + ASSERT_LT(count, size_t(4)); MOZ_ARRAY_LENGTH(expected) instead of the bare 4? @@ +101,5 @@ > + currTest++; > + count++; > + }); > + > + EXPECT_EQ(size_t(4), count); This too?

Comment on attachment 8703929 [details] [diff] [review] Part 1: Add NSPRLogModulesParser Review of attachment 8703929 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/base/NSPRLogModulesParser.cpp @@ +51,5 @@ > + } > + } > + > + // NSPR reserves a few modules names for logging options. We just skip > + // those entries here. This is IMHO an unusual way to handle it, but OK.

(In reply to Nathan Froyd [:froydnj] from comment #19) > Comment on attachment 8703929 [details] [diff] [review] > Part 1: Add NSPRLogModulesParser > > Review of attachment 8703929 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: xpcom/base/NSPRLogModulesParser.cpp > @@ +51,5 @@ > > + } > > + } > > + > > + // NSPR reserves a few modules names for logging options. We just skip > > + // those entries here. > > This is IMHO an unusual way to handle it, but OK. What would the 'usual' way be? Filtering in the callback?

https://hg.mozilla.org/integration/mozilla-inbound/rev/ef2ab7d80dd1bb5013d6ec38e7584c2011756d65 Bug 1223222 - Part 1: Add NSPRLogModulesParser. r=froydnj https://hg.mozilla.org/integration/mozilla-inbound/rev/498fec1562198ca7d7536528f6b8ecca96426c56 Bug 1223222 - Part 2: Add tests for NSPRLogModulesParser. r=froydnj https://hg.mozilla.org/integration/mozilla-inbound/rev/30709eb90d8765f5afbdcc47b6df5f21f0d93af0 Bug 1223222 - Part 3: Remove usage of PR_NewLogModule in mozilla LogModule code. r=froydnj

https://hg.mozilla.org/mozilla-central/rev/ef2ab7d80dd1 https://hg.mozilla.org/mozilla-central/rev/498fec156219 https://hg.mozilla.org/mozilla-central/rev/30709eb90d87