Opened 9 years ago

Closed 9 years ago

Last modified 9 years ago

#1008 closed defect (complete)

missing initLogger() should be caught more explicitly

Reported by: jinmei Owned by: stephen
Priority: medium Milestone: Sprint-20110628
Component: logging Version:
Keywords: Cc:
CVSS Scoring: Parent Tickets:
Sensitive: no Defect Severity: N/A
Sub-Project: Core Feature Depending on Ticket:
Estimated Difficulty: 2.0 Add Hours to Ticket: 0
Total Hours: 0 Internal?: no

Description

Yesterday I encountered an infinite loop in the unittests for
lib/datasrc. After struggling with it for an hour or so, I found it
was due to missing initialization of the logging system (by calling
initLogger()), and fixed it in commit 1302962. (The loop occurred
within liblog4cplus).

But I think we should catch such a condition more explicitly with an
assert() or an exception, because it'll happen again quite easily,
and, when it happens it's quite difficult to identify. Note also that
an infinite loop in unittest is very bad for the autobuilder.

I suggest this for the next sprint item.

Subtickets

Change History (12)

comment:1 follow-up: Changed 9 years ago by vorner

I don't agree. The problem with this would be we would have to be very careful not to have any logging inside functions we use from whatever static initalizers. The thing needs to at last survive such thing, but better, log.

comment:2 in reply to: ↑ 1 Changed 9 years ago by jinmei

Replying to vorner:

I don't agree. The problem with this would be we would have to be very careful not to have any logging inside functions we use from whatever static initalizers. The thing needs to at last survive such thing, but better, log.

??? I'm afraid you're confused. This has nothing to do with the
static initialization thing I raised separately.

comment:3 Changed 9 years ago by vorner

No, I don't mean the static initialization fiasco. I mean this:

class X {
public:
  X() {
    logger.info(NEW_X);
  }
};

X x;

int main(int, const char*) {
  initLogger();
}

If we add the exception you request, this will crash. I'd like this code to run (not necessarily log before the initLogger()), because it might turn out that we can have some logging buried deep down in some functions and it would be hell to pass around „yes, you can log already“ or make sure nothing is really called before the initLogger().

comment:4 Changed 9 years ago by stephen

  • Milestone changed from Next-Sprint-Proposed to Sprint-20110628

comment:5 Changed 9 years ago by stephen

  • Owner set to stephen
  • Status changed from new to assigned

comment:6 Changed 9 years ago by stephen

  • Owner changed from stephen to UnAssigned
  • Status changed from assigned to reviewing

I did consider Michal's point. Although solutions are possible (e.g. have the logger store messages in memory if called before initialization, outputting them through the normal logging system once logging has been successfully initialized), as Jinmei has said on bind10-dev, we should not really have a lot of code in static initializers. It therefore didn't seem worth implementing an elaborate solution for something that might never happen.

For this reason, the code has been modified to throw an exception if a logging method is called before logging initialization is done. We can revisit this if it proves to be a problem.

Change is commit 80dd433545aecf82aa178365dbc6e0650e12907b. It is not planned to have a ChangeLog entry for this modification.

comment:7 Changed 9 years ago by vorner

  • Owner changed from UnAssigned to vorner

comment:8 Changed 9 years ago by vorner

  • Owner changed from vorner to stephen

Hello

Well, my original proposal was not to store the messages but simply to drop them. Anyway, about the current code.

/// regardless of whether is is statically or automatically declared -  will
/// cause an exception to be thrown.

It might be worth noting which exception.

// Flag to hold logging initialization state.  This is held inside a function
// to ensure that it is correctly initialized even when referenced during
// program initialization (thus avoiding the "static initialization fiasco").

This seems we are really panicking about the static initialization fiasco. The bool is basic data type without a constructor or any code to initialize it, therefore there can be no problem with ordering of the code. Simple variables are just present somewhere in read-write section of the binary with their default value set. And, to note, simple static variables inside functions are handled the same way as module-level ones. The difference is only with when the initialization code (which doesn't exist for them) is called.

// Logger Run-Time Initialization.  This function is present for historical
// reasons.

We have historical reasons already? The logging is quite new, isn't it. Isn't it easier to just change whatever uses it, than dragging a historical function from almost the first snapshot release the logging is in?

Thanks

comment:9 Changed 9 years ago by stephen

  • Owner changed from stephen to vorner

Well, my original proposal was not to store the messages but simply to drop them.

True, but it set me thinking about going beyond that. After all, if one of the logging functions has been called, it's not too complicated to store the information somewhere and output it when logging is up and running.

It might be worth noting which exception.

Done.

This seems we are really panicking about the static initialization fiasco.

Nicely put :-). You are right, and I have got rid of the access function.

We have historical reasons already?

Mainly because it was written before LoggerManager::init() (which actually does the initialization) and I didn't want to change all calls to initLogger(). On reflection though, leaving the logging initialization function as initLogger makes sense since there is then just one (overloaded) function to perform the initialization (as indicated in my post to bind10-dev), I've removed the "historical" comment.

comment:10 Changed 9 years ago by vorner

  • Owner changed from vorner to stephen

Ok, thanks. Please merge.

comment:11 Changed 9 years ago by stephen

  • Resolution set to complete
  • Status changed from reviewing to closed

Merged into master as commit 3f15151252dd734210582a2ae8923dada661231f

comment:12 Changed 9 years ago by stephen

  • Estimated Difficulty changed from 0.0 to 2
Note: See TracTickets for help on using tickets.