six 1.5.2 breaks calendar server 5.1

[macosforgebot]

Axel.Rau@… originally submitted this as ticket:832

• Keywords: calendarserver, replaceTwistedLoggers, MovedModule, six.py
• Port: FreeBSD 9.2

---

While preparing a FreeBSD port of calendar server 5.1, I get (with all programs, including caldavs):

[caldav3:/usr/local/lib] root# calendarserver_manage_principals --list-principal-types
Traceback (most recent call last):
  File "/usr/local/bin/calendarserver_manage_principals", line 32, in <module>
    main()
  File "/usr/local/lib/python2.7/site-packages/calendarserver/tools/principals.py", line 333, in main
    utilityMain(configFileName, PrincipalService, verbose=verbose)
  File "/usr/local/lib/python2.7/site-packages/calendarserver/tools/cmdline.py", line 95, in utilityMain
    service = maker.makeService(options)
  File "/usr/local/lib/python2.7/site-packages/calendarserver/tap/caldav.py", line 746, in makeService
    replaceTwistedLoggers()
  File "/usr/local/lib/python2.7/site-packages/twext/python/log.py", line 937, in replaceTwistedLoggers
    newLogger = Logger(namespace=module.__name__)
  File "/usr/local/lib/python2.7/site-packages/six.py", line 115, in __getattr__
    raise AttributeError
AttributeError

six is imported by python-dateutil 2.1. The following hack was introduced in six 1.5.2 in class MovedModule(_LazyDescr):

    def __getattr__(self, attr):
        # Hack around the Django autoreloader. The reloader tries to get
        # __file__ or __name__ of every module in sys.modules. This doesn't work
        # well if this MovedModule is for an module that is unavailable on this
        # machine (like winreg on Unix systems). Thus, we pretend __file__ and
        # __name__ don't exist if the module hasn't been loaded yet. See issues
        # #⁠51 and #⁠53.
        if attr in ("__file__", "__name__") and self.mod not in sys.modules:
            raise AttributeError
        _module = self._resolve()
        value = getattr(_module, attr)
        setattr(self, attr, value)
        return value

which seems to be responsible for the crash.

[macosforgebot]

@wsanchez originally submitted this as comment:1:⁠ticket:832

• Description modified

[macosforgebot]

@wsanchez originally submitted this as comment:2:⁠ticket:832

---

That’s just weird, but OK.

Fixed in r12415.

[macosforgebot]

@wsanchez originally submitted this as comment:3:⁠ticket:832

• Status changed from new to closed
• Priority changed from 1: Blocker to 2: Expected
• Resolution set to Software changed

[macosforgebot]

Axel.Rau@… originally submitted this as comment:4:⁠ticket:832

---

Applying your patch to the 5.1 module, resulted in: ---

File "/usr/local/lib/python2.7/site-packages/twext/python/log.py", line 936, in replaceTwistedLoggers
    for name, obj in module.__dict__.iteritems():
RuntimeError: dictionary changed size during iteration

--- Catching all exceptions of the inner loop, does the job: ---

        try:
            for name, obj in module.__dict__.iteritems():
                newLogger = Logger(namespace=module.__name__)
                legacyLogger = LegacyLogger(logger=newLogger)

                if obj is twisted.python.log:
                    log.info("Replacing Twisted log module object {0} in {1}"
                             .format(name, module.__name__))
                    setattr(module, name, legacyLogger)
                elif obj is twisted.python.log.msg:
                    log.info("Replacing Twisted log.msg object {0} in {1}"
                             .format(name, module.__name__))
                    setattr(module, name, legacyLogger.msg)
                elif obj is twisted.python.log.err:
                    log.info("Replacing Twisted log.err object {0} in {1}"
                             .format(name, module.__name__))
                    setattr(module, name, legacyLogger.err)
        except Exception:
            # Can't look up __name__.  A hack in the "six" module causes
            # this.  Skip the module.
            # See https://trac.calendarserver.org/ticket/832
            continue

---

[macosforgebot]

@wsanchez originally submitted this as comment:5:⁠ticket:832

---

Can you print moduleName in that except block? I’m curious what module is editing it’s symbols while we are in that loop.

[macosforgebot]

@wsanchez originally submitted this as comment:6:⁠ticket:832

• Status changed from closed to reopened
• Resolution Software changed deleted

[macosforgebot]

Axel.Rau@… originally submitted this as comment:7:⁠ticket:832

---

Replying to wsanchez@…:

Can you print moduleName in that except block? I’m curious what module is editing it’s symbols while we are in that loop.

Yes:

Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_commondialog/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.http_cookies/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.queue/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.html_entities/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.email_mime_text/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.winreg/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.SimpleHTTPServer/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_tksimpledialog/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_constants/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_tkfiledialog/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_dialog/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_ttk/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.xmlrpc_client/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.email_mime_base/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_messagebox/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.socketserver/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_simpledialog/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.reprlib/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.builtins/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_font/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.http_cookiejar/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.CGIHTTPServer/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.configparser/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.cPickle/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.email_mime_multipart/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_scrolledtext/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_tix/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.html_parser/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_dnd/mod
Exception in replaceTwistedLoggers during module/attribute six.moves._thread/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.dbm_gnu/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.http_client/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_colorchooser/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.copyreg/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.BaseHTTPServer/mod
Exception in replaceTwistedLoggers during module/attribute six.moves.tkinter_filedialog/mod

[macosforgebot]

@wsanchez originally submitted this as comment:8:⁠ticket:832

---

I can reproduce this now!

[macosforgebot]

@wsanchez originally submitted this as comment:9:⁠ticket:832

• Status changed from reopened to closed
• Milestone changed from CalendarServer-5.x to CalendarServer-6.x
• Resolution set to Software changed

---

Fixed in r13235 with the dumbest log message ever.