[Zope] Nasty logging bug: product import problems

[Dieter Maurer]

Have you ever had problems with the import of products?
Did they simply not show up in ControlPanel.Products (or with
an out of date traceback)?
Did you not get any hint to the problem cause?


I now can tell you why:

  The Zope logging system is a bit complex and weird:

    * While Zope is being imported, logging is done by "zLog.stupid_log_write".
      This nice function does not log at all unless
      "STUPID_LOG_FILE" is defined.

      Thus, first rule: *DEFINE* "STUPID_LOG_FILE",
      otherwise, many problems during product import
      happen without any glue to the problem cause.

      When you defined "STUPID_LOG_FILE", you will
      see a log entry for the problematic product:
      Zope Couldn't import <product>.

      Unfortunately, you will not get more information.
      This information is there, though, but
      it sits in the unflushed buffer of your
      log file.

    * After Zope has been imported, logging is switched
      to "ZLogger.stupidFileLogger.stupid_log_write".

      This function reopens your log file and forgets
      about the old opened file in "zLog._stupid_dest"
      and its unflushed buffer.
      The valuable information about the problem cause is lost.


What can you do?

  Add at the end of "zLog.stupid_log_write" (near line 274):
    _stupid_dest.flush()


For DC:
  I suggest, that "zLog" uses "ZLogger.stupidFileLogger"
  rather than have the code for "stupid_log_write" duplicated.


Dieter