(トランザクジョンのトラブルシューティング)

Introduction

Transactions usually are problematic only when many ZEO front-end clients are used. When the site gets more load, ConflictErrors start to occur. Zope tries to solve the situation by replaying HTTP requests for CoflictErrors and has a default threshold (3) how many times the request is replayed.

Badly designed code will increase the opportunity window for ConflictErrors.

How to debug which object causes ConflictErrors

OID is visible in the ConflictError traceback.

You can turn OID back to Python object, as mentioned by A. Jung:

app._p_jar[p64(oid)]

Every transaction is write transaction

Plone and the underlying Zope handles transactions transparently. Due to magic nature of the transactions you might write accidentally code which turns all transactions to write transactions.

Symptoms

• Your Undo tab in ZMI will be full of entries, one added per page request
• If you run the server in single Zope server mode, it is slow
• If you run the server in ZEO mode you get the exceptions like one below. It may happen even with one user. This is because each page load requres more than one HTTP request: HTML load, image load, CSS load and so on. Browser makes many requests per page and those transactions are conflicting, because they are all write transactions.

Traceback example:

    * Module ZPublisher.Publish, line 202, in publish_module_standard
    * Module Products.LinguaPlone.patches, line 67, in new_publish
    * Module ZPublisher.Publish, line 170, in publish
    * Module Products.LinguaPlone.patches, line 67, in new_publish
    * Module ZPublisher.Publish, line 170, in publish
    * Module Products.LinguaPlone.patches, line 67, in new_publish
    * Module ZPublisher.Publish, line 170, in publish
    * Module Products.LinguaPlone.patches, line 67, in new_publish
    * Module ZPublisher.Publish, line 157, in publish
    * Module plone.app.linkintegrity.monkey, line 15, in zpublisher_exception_hook_wrapper
    * Module ZPublisher.Publish, line 125, in publish
    * Module Zope2.App.startup, line 238, in commit
    * Module transaction._manager, line 96, in commit
    * Module transaction._transaction, line 395, in commit
    * Module transaction._transaction, line 495, in _commitResources
    * Module ZODB.Connection, line 510, in commit
    * Module ZODB.Connection, line 547, in _commit

ConflictError: database conflict error (oid 0x2b92, class Products.CMFPlone.PropertiesTool.SimpleItemWithProperties)

How to debug it

Zope 2 hasn’t many well-documented ZODB debugging tools. Below is one snippet to examine the contents of the last transactions of offline Data.fs file. It is evolved version of this orignal script.

• Do something on badly behaving site
• Stop Zope instance
• Run the script below (debug.py) on Data.fs to see what objects have been changed
• Deducting from the object class name, guess the badly behaving code

Example how to run the script for the last 30 transaction under Zope egg environment using zopepy buildout recipe:

bin/zopepy -n 30 debug.py Data.fs

Code for debug.py:

##############################################################################
#
# Copyright (c) 2001, 2002 Zope Corporation and Contributors.
# All Rights Reserved.
#
# This software is subject to the provisions of the Zope Public License,
# Version 2.1 (ZPL).  A copy of the ZPL should accompany this distribution.
# THIS SOFTWARE IS PROVIDED "AS IS" AND ANY AND ALL EXPRESS OR IMPLIED
# WARRANTIES ARE DISCLAIMED, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
# WARRANTIES OF TITLE, MERCHANTABILITY, AGAINST INFRINGEMENT, AND FITNESS
# FOR A PARTICULAR PURPOSE
#
##############################################################################
 """Tool to dump the last few transactions from a FileStorage."""

from ZODB.fstools import prev_txn
from ZODB.serialize import ObjectReader, get_refs
from persistent.TimeStamp import TimeStamp
from ZODB.FileStorage.FileStorage import FileIterator
import cStringIO, cPickle
import optparse, getopt
import sys

class Nonce(object): pass

class Reader(ObjectReader):

    def __init__(self):
        self.identity = None

    def _get_unpickler(self, pickle):
        file = cStringIO.StringIO(pickle)
        unpickler = cPickle.Unpickler(file)
        unpickler.persistent_load = self._persistent_load

        def find_global(modulename, name):
            self.identity ="%s.%s"%(modulename, name)
            return Nonce

        unpickler.find_global = find_global

        return unpickler

    def getIdentity(self, pickle ):
        self.identity = None
        unpickler = self._get_unpickler( pickle )
        unpickler.load()
        return self.identity

    def getObject(self, pickle):
        unpickler = self._get_unpickler( pickle )
        ob = unpickler.load()
        return ob

def pretty_size( size ):
    if size < 1024:
        return "%sB"%(size)
    kb = size / 1024.0
    if kb < 1024.0:
        return '%0.1fKb'%kb
    else:
        mb = kb/1024.0
        return '%0.1fMb'%mb

def run(path, ntxn):
    f = open(path, "rb")
    f.seek(0, 2)

    th = prev_txn(f)
    for i in range(ntxn):
        th = th.prev_txn()
    f.close()
    reader = Reader()
    iterator = FileIterator(path, pos=th._pos)
    for i in iterator:
        print "Transaction ", TimeStamp(i.tid), i.user, i.description
        object_types = {}
        for o in i:
            ot = reader.getIdentity(o.data)
            if ot in object_types:
                size, count = object_types[ot]
                object_types[ot] = (size+len(o.data), count+1)
            else:
                object_types[ot] = (len(o.data),1)


            ob = cPickle.loads(o.data)

            print "Object data for :" + str(o)

            # Not sure why some objects are stored as tuple (object, ())
            if type(ob) == tuple and len(ob) == 2:
                ob = ob[0]

            if hasattr(ob, "__dict__"):
                for i in ob.__dict__.items():
                    if not callable(i[1]):
                        print i
            else:
                print "can't extract:" + str(ob)

            print "-------------------------------------------------------"

        keys = object_types.keys()
        keys.sort()
        for k in keys:
            # count, class, size (aggregate)
            print " - ", object_types[k][1], k, pretty_size(object_types[k][0])


def main():
    ntxn = 20
    opts, args = getopt.getopt(sys.argv[1:], "n:")
    path, = args
    for k, v in opts:
        if k == '-n':
            ntxn = int(v)
    run(path, ntxn)


if __name__ == "__main__":
    main()

zodbbrowser

zodbbrowser is not compatible with Plone 3 and works with pure Zope 3 only (not Five).