Benchmark the time it takes for virtmem to handle pagefault with noop
loadblk for loadblk both implemented in C and in Python.

On my computer it is:

	name          µs/op
	PagefaultC    269 ± 0%
	pagefault_py  291 ± 0%

Quite a big time in other words, and it will be investigated.

Rework py.bench output to match output of Go benchmarking[1] so that go
tools like benchstat & friends could be used to analyze and compare the
timings.

Before patch:

============================= test session starts ==============================
platform linux2 -- Python 2.7.14, pytest-3.3.2.dev2+g88f2cc9b.d20171206, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 11 items

pymod: bigfile/tests/bench_0virtmem.py
bench_file_mmapread_hole	0.21  (0.39 0.22 0.21)
bench_file_read_hole    	0.24  (0.24 0.24 0.24)
bench_file_readbig_hole 	0.30  (0.30 0.31 0.31)
bench_bigf_read_hole    	0.44  (0.44 0.45 0.44)
bench_file_mmapwrite0   	0.13  (0.13 0.13 0.13)
bench_file_write55      	0.08  (0.08 0.08 0.08)
bench_bigf_writeff      	0.47  (0.47 0.48 0.47)
bench_file_mmapread     	0.22  (0.22 0.22 0.22)
bench_file_read         	0.25  (0.25 0.25 0.26)
bench_file_readbig      	0.31  (0.31 0.31 0.31)
bench_bigf_read         	0.44  (0.45 0.44 0.44)

========================== 11 passed in 12.92 seconds ==========================

After patch:

============================= test session starts ==============================
platform linux2 -- Python 2.7.14, pytest-3.3.2.dev2+g88f2cc9b.d20171206, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 11 items

pymod: bigfile/tests/bench_0virtmem.py
Benchmarkfile_mmapread_hole	1	385839.939 µs/op
Benchmarkfile_mmapread_hole	1	219214.916 µs/op
Benchmarkfile_mmapread_hole	1	210209.131 µs/op
Benchmarkfile_read_hole    	1	238974.094 µs/op
Benchmarkfile_read_hole    	1	237294.197 µs/op
Benchmarkfile_read_hole    	1	238043.070 µs/op
Benchmarkfile_readbig_hole 	1	301330.090 µs/op
Benchmarkfile_readbig_hole 	1	301767.111 µs/op
Benchmarkfile_readbig_hole 	1	301135.063 µs/op
Benchmarkbigf_read_hole    	1	434718.132 µs/op
Benchmarkbigf_read_hole    	1	435019.970 µs/op
Benchmarkbigf_read_hole    	1	434729.099 µs/op
Benchmarkfile_mmapwrite0   	1	126471.996 µs/op
Benchmarkfile_mmapwrite0   	1	125886.917 µs/op
Benchmarkfile_mmapwrite0   	1	125730.038 µs/op
Benchmarkfile_write55      	1	86760.044 µs/op
Benchmarkfile_write55      	1	87507.010 µs/op
Benchmarkfile_write55      	1	87735.891 µs/op
Benchmarkbigf_writeff      	1	448369.980 µs/op
Benchmarkbigf_writeff      	1	448238.850 µs/op
Benchmarkbigf_writeff      	1	447322.845 µs/op
Benchmarkfile_mmapread     	1	207049.131 µs/op
Benchmarkfile_mmapread     	1	207813.978 µs/op
Benchmarkfile_mmapread     	1	210857.868 µs/op
Benchmarkfile_read         	1	238364.935 µs/op
Benchmarkfile_read         	1	236908.913 µs/op
Benchmarkfile_read         	1	238602.161 µs/op
Benchmarkfile_readbig      	1	303429.842 µs/op
Benchmarkfile_readbig      	1	302191.973 µs/op
Benchmarkfile_readbig      	1	304115.057 µs/op
Benchmarkbigf_read         	1	435079.098 µs/op
Benchmarkbigf_read         	1	434193.850 µs/op
Benchmarkbigf_read         	1	434813.976 µs/op

========================== 11 passed in 12.54 seconds ==========================

benchstat of new output:

	name                µs/op
	file_mmapread_hole   272k ±42%
	file_read_hole       238k ± 0%
	file_readbig_hole    301k ± 0%
	bigf_read_hole       435k ± 0%
	file_mmapwrite0      126k ± 0%
	file_write55        87.3k ± 1%
	bigf_writeff         448k ± 0%
	file_mmapread        209k ± 1%
	file_read            238k ± 0%
	file_readbig         303k ± 0%
	bigf_read            435k ± 0%

--------

Not only the output format is reworked here, but also b fixture is added
to BenchPlugin so that functions which accept it as arg, can run the
benchmark b.N times, can stop/restart timer etc - similar to
https://golang.org/pkg/testing/#B . If a bench_* func does not accept b,
B is still created, but b.N is assumed to be always 1.

The first benchmark which actually uses b will come in the next patch.

[1] https://github.com/golang/proposal/blob/master/design/14313-benchmark-format.md

Such directories are left in worktree after py.test run.

For several benchmarks in a python module instead of always printing
whole benchmark function path (nodeid in pytest speak), first print

	pymod: modulename

header, and then only function names.

Before patch:

============================= test session starts ==============================
platform linux2 -- Python 2.7.14, pytest-3.3.0, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 14 items

bigfile/tests/bench_0virtmem.py::bench_file_mmapread_hole 	0.22  (0.39 0.22 0.22)
bigfile/tests/bench_0virtmem.py::bench_file_read_hole    	0.24  (0.24 0.24 0.24)
bigfile/tests/bench_0virtmem.py::bench_file_readbig_hole 	0.30  (0.30 0.30 0.30)
bigfile/tests/bench_0virtmem.py::bench_bigf_read_hole    	0.43  (0.43 0.43 0.43)
bigfile/tests/bench_0virtmem.py::bench_file_mmapwrite0   	0.12  (0.13 0.12 0.13)
bigfile/tests/bench_0virtmem.py::bench_file_write55      	0.08  (0.08 0.08 0.08)
bigfile/tests/bench_0virtmem.py::bench_bigf_writeff      	0.45  (0.45 0.45 0.45)
bigfile/tests/bench_0virtmem.py::bench_file_mmapread     	0.21  (0.21 0.21 0.22)
bigfile/tests/bench_0virtmem.py::bench_file_read         	0.23  (0.23 0.24 0.24)
bigfile/tests/bench_0virtmem.py::bench_file_readbig      	0.30  (0.30 0.30 0.30)
bigfile/tests/bench_0virtmem.py::bench_bigf_read         	0.43  (0.44 0.43 0.44)
bigfile/tests/bench_1filezodb.py::bench_bigz_readhole    	0.42  (0.42 0.43 0.43)
bigfile/tests/bench_1filezodb.py::bench_bigz_writeff     	0.84  (0.84 1.25 1.25)
bigfile/tests/bench_1filezodb.py::bench_bigz_read        	0.60  (0.64 0.60 0.60)
========================== 14 passed in 21.78 seconds ==========================

After patch:

============================= test session starts ==============================
platform linux2 -- Python 2.7.14, pytest-3.3.0, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 14 items

pymod: bigfile/tests/bench_0virtmem.py
bench_file_mmapread_hole	0.21  (0.39 0.22 0.21)
bench_file_read_hole    	0.24  (0.24 0.24 0.24)
bench_file_readbig_hole 	0.30  (0.30 0.30 0.30)
bench_bigf_read_hole    	0.43  (0.43 0.43 0.43)
bench_file_mmapwrite0   	0.12  (0.13 0.12 0.13)
bench_file_write55      	0.08  (0.08 0.08 0.08)
bench_bigf_writeff      	0.45  (0.52 0.51 0.45)
bench_file_mmapread     	0.21  (0.21 0.21 0.21)
bench_file_read         	0.24  (0.24 0.24 0.24)
bench_file_readbig      	0.30  (0.30 0.30 0.30)
bench_bigf_read         	0.43  (0.43 0.43 0.43)

pymod: bigfile/tests/bench_1filezodb.py
bench_bigz_readhole     	0.43  (0.43 0.43 0.43)
bench_bigz_writeff      	0.83  (0.83 1.20 1.21)
bench_bigz_read         	0.60  (0.65 0.60 0.60)

========================== 14 passed in 21.80 seconds ==========================

The `key: value` header is compatible with Go benchmark format[1] and
further we'll be trying to teach py.bench to output results in that
format so that Go benchmarking tools like benchstat and perf.golang.org
could be used for free.

[1] https://github.com/golang/proposal/blob/master/design/14313-benchmark-format.md

Upstream pytest changed TerminalReporter._locationline() signature from

	def _locationline(self, collect_fspath, fspath, lineno, domain):

to

	def _locationline(self, nodeid, fspath, lineno, domain):

https://github.com/pytest-dev/pytest/commit/d73e6899 .

This way without adjusting py.bench was reporting just filenames instead
of benchmark names, e.g. this way:

(z-dev) kirr@deco:~/src/wendelin/wendelin.core$ ./t/py.bench bigfile/tests/bench_0virtmem.py
=============================================================== test session starts ===============================================================
platform linux2 -- Python 2.7.14, pytest-3.3.0, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 11 items

bigfile/tests/bench_0virtmem.py                                 0.21  (0.38 0.22 0.21)
bigfile/tests/bench_0virtmem.py                                 0.23  (0.23 0.24 0.23)
bigfile/tests/bench_0virtmem.py                                 0.30  (0.30 0.30 0.30)
bigfile/tests/bench_0virtmem.py                                 0.43  (0.43 0.43 0.43)
bigfile/tests/bench_0virtmem.py                                 0.12  (0.12 0.12 0.12)
bigfile/tests/bench_0virtmem.py                                 0.08  (0.08 0.08 0.08)
bigfile/tests/bench_0virtmem.py                                 0.44  (0.44 0.44 0.44)
bigfile/tests/bench_0virtmem.py                                 0.20  (0.20 0.20 0.21)
bigfile/tests/bench_0virtmem.py                                 0.24  (0.24 0.24 0.24)
bigfile/tests/bench_0virtmem.py                                 0.30  (0.30 0.30 0.30)
bigfile/tests/bench_0virtmem.py                                 0.43  (0.43 0.43 0.43)

=========================================================== 11 passed in 12.39 seconds ============================================================

Fix it.

In pytest3 pytest_runtest_call hook is always run as multicall and there
is no way to control to disable it and force e.g. 'firstresult'
behaviour. This way call.result in pytest_runtest_makereport is always a
list of returned results, not the first result itself.

Adjust the code in pytest_runtest_makereport to emulate 'firstresult'
behaviour manually.

Without the patch with recent pytest py.bench was crashing like this:

---- 8< ----
(z-dev) kirr@link:~/src/wendelin/wendelin.core$ make bench
python setup.py ll_build_ext --inplace
running ll_build_ext
copying build/lib.linux-x86_64-2.7/wendelin/bigfile/_bigfile.so -> bigfile
python t/py.bench --ignore=3rdparty --ignore=build --ignore=t
============================================================= test session starts ==============================================================
platform linux2 -- Python 2.7.14, pytest-3.3.0, py-1.5.2, pluggy-0.6.0
rootdir: /home/kirr/src/wendelin/wendelin.core, inifile:
collected 14 items

bigfile/tests/bench_0virtmem.py                          	INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/main.py", line 103, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/main.py", line 141, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/main.py", line 164, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/runner.py", line 63, in pytest_runtest_protocol
INTERNALERROR>     runtestprotocol(item, nextitem=nextitem)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/runner.py", line 77, in runtestprotocol
INTERNALERROR>     reports.append(call_and_report(item, "call", log))
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/_pytest/runner.py", line 161, in call_and_report
INTERNALERROR>     hook.pytest_runtest_logreport(report=report)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "/home/kirr/src/wendelin/venv/z-dev/local/lib/python2.7/site-packages/pluggy/callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "t/py.bench", line 165, in pytest_runtest_logreport
INTERNALERROR>     self._tw.write('%.2f' % min(report.bench_times))
INTERNALERROR> TypeError: float argument required, not list

If py.test machinery access any of the keys we change before we tweak
them - their values will be put to config._inicache and our tweaking
won't essentially have the effect.

It used to be working without explicit cache invalidation with older
pytests, but as of e.g. py.test 3.2.1 it does not work without explicit
cache clearing because e.g. 'python_files' is somehow accessed before
and is set to std 'test_*.py' + friends in the cache and this way
py.bench then does not collect benchmarks from bench_*.py files.

Fix it by making sure inicache is invalidated after our inicfg tweak.

Relicense to GPLv3+ with wide exception for all Free Software / Open Source projects + Business options.

Nexedi stack is licensed under Free Software licenses with various exceptions
that cover three business cases:

- Free Software
- Proprietary Software
- Rebranding

As long as one intends to develop Free Software based on Nexedi stack, no
license cost is involved. Developing proprietary software based on Nexedi stack
may require a proprietary exception license. Rebranding Nexedi stack is
prohibited unless rebranding license is acquired.

Through this licensing approach, Nexedi expects to encourage Free Software
development without restrictions and at the same time create a framework for
proprietary software to contribute to the long term sustainability of the
Nexedi stack.

Please see https://www.nexedi.com/licensing for details, rationale and options.

Since the beginning (1ee72371 "Demo program that shows how to work with
ZBigArrays bigger than RAM in size") the work size was 2*RAM.

However sometimes for demonstration purposes it could be handy to set it
to be even more (e.g.  16*RAM) or vise versa - to something lower.

So add command line option to do so instead of manually patching sources
every time.

A buffer object (pybuf) is passed by C-level loadblk to python loadblk
implementation. Since pybuf points to memory that will go away after
loadblk call returns to virtmem, PyBigFile tries hard to make sure
nothing stays referencing pybuf so it can be released.

It tries to:

1. automatically GC cycles referencing pybuf (9aa6a5d7 "bigfile/py: Teach
   loadblk() to automatically break reference cycles to pybuf")
2. replace pybuf with stub object if a calling frame referencing it still
   stays alive (61b18a40 "bigfile/py/loadblk: Replace pybuf with a stub
   object in calling frame in case it stays alive")
3. and as a last resort unpins pybuf from original buffer memeory to
   point it to NULL (024c246c "bigfile/py/loadblk: Resort to pybuf
   unpinning, if nothing helps")

Step #1 invokes GC. Step #2 calls gc.get_referrers(pybuf) and looks for
frames in there.

The gc.get_referrers() call happens at python level with allocating some
objects, e.g. tuple to pass arguments, resulting list etc. And we all
know that any object allocation might cause automatic garbage
collection, and GC'ing can in turn ran arbitrary code due to __del__ in
release objects and weakrefs callbacks.

At a first glance the scenario that GC will be triggered at step #2
looks unrealistic because the GC was just run at step #1 and it is only
a few objects being allocated for the call at step #2. However if
arbitrary code runs from under GC it can create new garbage and thus
upon returning from gc.collect() the garbage list is not empty as the
following program demonstrates:

    ---- 8< ----
    import gc

    # just an object we can set attributes on
    class X:
        pass

    # call f on __del__
    class DelCall:
        def __init__(self, f):
            self.f = f

        def __del__(self):
            self.f()

    # _mkgarbage creates n objects of garbage kept referenced from an object cycle
    # so that only cyclic GC can free them.
    def _mkgarbage(n):
        # cycle
        a, b = X(), X()
        a.b, b.a = b, a

        # cycle references [n] garbage
        a.objv = [X() for _ in range(n)]
        return a

    # mkgarbage creates cycled garbage and arranges for twice more garbage to be
    # created when original garbage is collected
    def mkgarbage(n):
        a = _mkgarbage(n)
        a.ondel = DelCall(lambda : _mkgarbage(2*n))

    def main():
        for i in xrange(10):
            mkgarbage(1000)
            print '> %s' % (gc.get_count(),)
            n = gc.collect()
            print '< %s' % (gc.get_count(),)

    main()
    ---- 8< ----

    kirr@deco:~/tmp/trashme/t$ ./gcmoregarbage.py
    > (482, 11, 0)
    < (1581, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)
    > (531, 3, 0)
    < (2070, 0, 0)

here lines starting with "<" show amount of live garbage objects after
gc.collect() call has been finished.

This way on a busy server there could be arrangements when GC is
explicitly ran at step #1 and then automatically run at step #2 (because of
gc.get_referrers() python-level call) and from under GC #2 arbitrary code runs
thus potentially mutating exception state which shows in logs as

    bigfile/_bigfile.c:685: pybigfile_loadblk: Assertion `!(ts->exc_type || ts->exc_value || ts->exc_traceback)' failed.

----

So don't assume we end with clean exception state after collecting pybuf
referrers and just clear exception state once again as we do after explicit GC.
Don't make a similar assumption for buffer unpinning as an object is
decrefed there and in theory this can run some code.

A test is added to automatically exercise exception state clearing for
get_referrers code path via approach similar to demonstrated in above -
- we generate more garbage from under garbage and also arrange for
finalizers, which mutate exceptions state, to be run at GC #2.

The test without the fix applied fails like this:

    bigfile/_bigfile.c:710 pybigfile_loadblk WARN: python thread-state found with handled but not cleared exception state
    bigfile/_bigfile.c:711 pybigfile_loadblk WARN: I will dump it and then crash
    ts->exc_type:   None
    ts->exc_value:  <nil>
    ts->exc_traceback:      <nil>
    Segmentation fault (core dumped)

The None in ts->exc_type and nil value and traceback are probably coming from
here in cpython runtime:

    https://github.com/python/cpython/blob/883520a8/Python/ceval.c#L3717

Since this took some time to find, more diagnostics is also added before
BUG_ONs corresponding to finding unclean exception state.

Before py3k python stores exception information not only in thread-local state
but also globally in sys.exc_* variables (wrt sys.exc_info()) for
"backward compatibility". However using them is not thread-safe as the
following example demonstrates:

---- 8< ----
from threading import Thread
import sys

def T1():
    print 'T1'
    while 1:
        exc_type = sys.exc_type
        if exc_type is not None:
            print 'AAA: %r' % exc_type

def f(): g()
def g(): h()
def h(): 1/0

def T2():
    print 'T2'
    while 1:
        try:
            f()
        except:
            pass

t1, t2 = Thread(target=T1), Thread(target=T2)
t1.start(); t2.start()
---- 8< ----

---- 8< ----
kirr@deco:~/tmp/trashme/t$ ./excthreads.py
T1
T2

AAA: <type 'exceptions.ZeroDivisionError'>
AAA: <type 'exceptions.ZeroDivisionError'>
AAA: <type 'exceptions.ZeroDivisionError'>
AAA: <type 'exceptions.ZeroDivisionError'>
AAA: <type 'exceptions.ZeroDivisionError'>
AAA: <type 'exceptions.ZeroDivisionError'>
^\Выход
---- 8< ----

Because of the above nothing modern (I've explicitly checked at least CPython
itself and Zope) uses this variables - wherever needed per-thread exception
state is retrieved with sys.exc_info().

So on wendelin.core side it is thus thankless job to try to preserve sys.exc_*
vars state because on a busy server they are literally changing all the -
arbitrary from the point of view of particular thread - time while its python
code runs.

Commit fb4bfb32 (bigfile/virtmem: Do storeblk() with virtmem lock
released) added bug-protection to fileh_dirty_writeout() so that it could
not be called twice at the same time or in parallel with other functions
which modify pages.

However it missed the code path when storeblk() call returned with error
and whole writeout was thus erroring out, but with fileh->writeout_inprogress
still left set to 1 incorrectly.

This was leading to things like

    bigfile/virtmem.c:419: fileh_dirty_discard: Assertion `!(fileh->writeout_inprogress)' failed.

and crashes.

Fix it.

This reverts commit 9ae42085.

When working with big arrays and accessing / changing it not in tiny
bits ZBlk1 is much slower compared to ZBlk0. See details here

    https://www.nexedi.com/blog/NXD-Document.Blog.Wendelin.Core.Release.0.5.Performance.Tests

and in

    13c0c17c (bigfile/zodb: Format #1 which is optimized for small changes)

Until we can rely on database handling both cases automatically,
projects which care about changing arrays in small parts can manually
set WENDELIN_CORE_ZBLK_FMT=ZBlk1 or under ERP5/SlapOS use this setting:

    nexedi/slapos@2558aadd

And let's have it performant in "big data" case by default.

/cc @yusei, @klaus, @Tyagov
/reviewed-on nexedi/wendelin.core!5

Remove debug print leftover from added test in e44bd761.

From time to time people keep trying to use wendelin.core with
dtype=object arrays and get segfaults without anything in logs or
whatever else.

Wendelin.core does not support it, because in case of dtype=object elements are
really pointers and data for each object is stored in separate place in RAM
with different per-object size.

As we are memory-mapping arrays this won't work. It also does not
essentially work for numpy.memmap for the same reason:

    (z4+numpy) kirr@mini:~/src/wendelin$ dd if=/dev/zero of=zero.dat bs=128 count=1
    1+0 records in
    1+0 records out
    128 bytes copied, 0.000209873 s, 610 kB/s
    (z4+numpy) kirr@mini:~/src/wendelin$ dd if=/dev/urandom of=random.dat bs=128 count=1
    1+0 records in
    1+0 records out
    128 bytes copied, 0.000225726 s, 567 kB/s
    (z4+numpy) kirr@mini:~/src/wendelin$ ipython
    ...

    In [1]: import numpy as np

    In [2]: np.memmap('zero.dat', dtype=np.object)
    Out[2]:
    memmap([None, None, None, None, None, None, None, None, None, None, None,
           None, None, None, None, None], dtype=object)

    In [3]: np.memmap('random.dat', dtype=np.object)
    Out[3]: Segmentation fault

So let's clarify this to users via explicitly raising exception when
BigArray with non-appropriate dtype is trying to be created with
descriptive explanation also logged.

/reviewed-on !4

In 2.0 transaction made an incomatible change to require description to
always be unicode, not string. ZODB3 was not updated.

Reference: https://github.com/zopefoundation/transaction/pull/32

to avoid bugging on `pybuf->ob_refcnt != 1`when an exception was internally raised & caught somewhere in loadblk() implementation.

Details are in 9aa6a5d7, 61b18a40. The last patch also resorts to buffer unpinning when nothing helps (please see details about unpinning there).

Fixes: nexedi/wendelin.core#7

/cc @Tyagov @klaus @jm
/reviewed-on nexedi/wendelin.core!3

to avoid deadlocks.

Description is in the last patch.

Fixes: nexedi/wendelin.core#6

/cc @Tyagov, @klaus, @jm
/reviewed-on nexedi/wendelin.core!2

There are situations possible when both exc_traceback and frame objects are
garbage-collected, but frame's f_locals remains not collected because e.g. it
was explicitly added to somewhere. We cannot detect such cases (dicts are not
listed in referrers).

So if nothing helped, as a last resort, unpin pybuf from its original
memory and make it point to zero-sized NULL.

In general this is not strictly correct to do as other buffers &
memoryview objects created from pybuf, copy its pointer on
initialization and thus pybuf unpinning won't adjust them.

However we require BigFile implementations to make sure not to use
such-created objects, if any, after return from loadblk().

Finally fixes #7

This code was added in 6da5172e (bigfile/py: Teach storeblk() how to
correctly propagate traceback on error) to unpin a storeblk pybuf to not
care whether its refcount == 1 - this way to be able to propagate python
error upper not caring whether pybuf is still referenced or not.

9aa6a5d7 (bigfile/py: Teach loadblk() to automatically break reference
cycles to pybuf) adds a note that such unpinning is not strictly
correct: becuase of other buffer objects were created from pybuf - they
are copying pointers on initialization and unpinning pybuf won't adjust
them.

However for loadblk codepath it turned out (see next patch) it is not
completely possible to unreference pybuf in all cases. For this reason
loadblk will be falling back to unpinning too.

As a preparatory step move common code to shared functions.

It turns out some code wants to store tracebacks e.g. for further
logging/whatever. This way GC won't help to free up references to pybuf.
However if pybuf remain referenced only from calling frames, we can
change there reference to pybuf to a stub object "<pybuf>" and this way
remove the reference.

With added test but without loadblk changes the failure would be as:

    pybigfile_loadblk WARN: pybuf->ob_refcnt != 1 even after GC:
    pybuf (ob_refcnt=2):    <read-write buffer ptr 0x7fae4911f000, size 2097152 at 0x7fae4998cef0>
    pybuf referrers:        [<frame object at 0x556daff41aa0>]		<-- NOTE
    bigfile/_bigfile.c:613 pybigfile_loadblk        BUG!

As comments being removed states "on python3 exception state is cleared
upon exiting from `except`" - so let's move exc_* fetching under except
clause - this way we'll get correct exception objects on both py2 and py3.

We'll need it in next patch to get and analyze this list.

Instead of only printing "BUG" let's print information about objects
which still refer to pybuf - to help debugging.

For example with the following artificial pybuf leak

```
diff --git a/bigfile/tests/test_basic.py b/bigfile/tests/test_basic.py
index c737621..f5e057a 100644
--- a/bigfile/tests/test_basic.py
+++ b/bigfile/tests/test_basic.py
@@ -126,6 +126,7 @@ def test_basic():

 # test that python exception state is preserved across pagefaulting
 def test_pagefault_savestate():
+    zzz = []
     class BadFile(BigFile):
         def loadblk(self, blk, buf):
             # simulate some errors in-between to overwrite thread exception
@@ -154,6 +155,7 @@ def loadblk(self, blk, buf):
             # which result in holding additional ref to buf, but loadblk caller
             # will detect and handle this situation via garbage-collecting
             # above cycle.
+            zzz.append(buf)

             self.loadblk_run = 1
```

it dies this way:

    bigfile/_bigfile.c:567 pybigfile_loadblk WARN: pybuf->ob_refcnt != 1 even after GC:
    pybuf (ob_refcnt=2):    <read-write buffer ptr 0x7f08d3e88000, size 2097152 at 0x7f08d48b7070>
    pybuf referrers:        [[<read-write buffer ptr 0x7f08d3e88000, size 2097152 at 0x7f08d48b7070>]]
    bigfile/_bigfile.c:573 pybigfile_loadblk        BUG!

Because otherwise we bug on pybuf->ob_refcnt != 1.

Such cycles might happen if inside loadblk implementation an exception
is internally raised and then caught even in deeply internal function
which does not receive pybuf as argument or by some other way:

After

	_, _, exc_traceback = sys.exc_info()

there is a reference loop created:

	exc_traceback
	  |        ^
	  |        |
	  v     .f_localsplus
	 frame

and since exc_traceback object holds reference to deepest frame, which via f_back
will be holding reference to frames up to frame with pybuf argument, it
will result in additional reference to pybuf being held until the above
cycle is garbage collected.

So to solve the problem while leaving loadblk, if pybuf->ob_refcnt !=
let's first do garbage-collection, and only then recheck left
references. After GC reference-loops created by exceptions should go
away.

NOTE PyGC_Collect() (C way to call gc.collect()) always performs
    GC - it is not affected by gc.disable() which disables only
    _automatic_ garbage collection.

NOTE it turned out out storeblk logic to unpin pybuf (see
    6da5172e "bigfile/py: Teach storeblk() how to correctly propagate
    traceback on error") is flawed, because when e.g. creating memoryview
    from pybuf internal pointer is copied and then clearing original buf
    does not result in clearing the copy.

NOTE it is ok to do gc.collect() from under sighandler - at least we are
    already doing it for a long time via running non-trivial python code
    which for sure triggers automatic GC from time to time (see also
    786d418d "bigfile: Simple test that we can handle GC from-under
    sighandler" for the reference)

Fixes: nexedi/wendelin.core#7

In the next patch we will need to use this from several places.

Like with loadblk (see f49c11a3 "bigfile/virtmem: Do loadblk() with
virtmem lock released" for the reference) storeblk() calls are
potentially slow and external code that serves the call can take other
locks in addition to virtmem lock taken by virtmem subsystem.
If that "other locks" are also taken before external code calls e.g.
with fileh_invalidate_page() in different codepath - a deadlock can happen:

      T1                  T2

      commit              invalidation-from-server received
      V -> storeblk
                          Z   <- ClientStorage.invalidateTransaction()
      Z -> zeo.store
                          V   <- fileh_invalidate_page (of unrelated page)

The solution to avoid deadlock, like for loadblk case, is to call storeblk()
with virtmem lock released.

However unlike loadblk which can be invoked at any time, storeblk is
invoked at commit time only so for storeblk case we handle rules for making
sure virtmem stays consistent after virtmem lock is retaken differently:

1. We disallow several parallel writeouts for one fileh. This way dirty
   pages handling logic can not mess up. This restriction is also
   consistent with ZODB 2 phase commit protocol where for a transaction
   commit logic is invoked/handled from only 1 thread.

2. For the same reason we disallow discard while writeout is in
   progress. This is also consistent with ZODB 2 phase commit protocol
   where txn.tpc_abort() is not expected to be called at the same time
   with txn.commit().

3. While writeout is in progress, for that fileh we disallow pages
   modifications and pages invalidations - because both operations would
   change at least fileh dirty pages list which is iterated over by
   writeout code with releasing/retaking the virtmem lock. By
   disallowing them we make sure fileh dirty pages list stays constant
   during whole fileh writeout.

   This restrictions are also consistent with ZODB commit semantics:

   - while an object is being stored into ZODB it is not expected it
     will be further modified or explicitly invalidated by client via
     ._p_invalidate()

   - server initiated invalidations come into effect only at transaction
     boundaries - when new transaction is started, not during commit time.

Also since now storeblk is called with virtmem lock released, for buffer
to store we no longer can use present page mapping in some vma directly,
because while virtmem lock is released that mappings can go away.

Fixes: nexedi/wendelin.core#6

bigfile/tests/thread: Don't invalidate exactly same page to test general virtmem deadlock on loadblk

The main deadlock described in f49c11a3 (bigfile/virtmem: Do loadblk()
with virtmem lock released) (V,Z in T1; Z,V in T2) can happen if in T2 V
is taken for whatever reason - e.g. for invalidating completely
unrelated page to what is being loaded in T1.

For invalidation of the same page we have explicit separate
test_thread_load_vs_invalidate() which verifies how loadblk handles this
situation.

This patch prepares general test_thread_lock_vs_virtmem_lock() to also
test V vs Z deadlock for storeblk() case - when it will be called with
virtmem lock released: for storeblk it will be forbidden by virtmem
rules to invalidate pages of fileh for which writeout is in progress.

Updates: #6

This allows writeout code not to scan whole pagemap to find dirty pages
to write out, which should be faster.

But more importantly iterating whole pagemap on writeout would become
unsafe, when in upcoming patch storeblk() will be called with virt_lock
released: because there pagemap could be modified e.g. due to processing
other read accesses.

So maintain fileh->dirty_pages list and use it when we need to go
through dirtied pages.

Updates: #6

Currently fileh_dirty_writeout() writes page via storeblk() in order -
- those with lower ->f_pgoffset are stored first.

This happens because current fileh_dirty_writeout() iterates whole
pagemap to find dirty pages and pagemap iteration is ordered by
f_pgoffset.

In upcoming patch we'll rework writeout code not to iterate through
whole pagemap, but only through dirty pages. However the property that
pages are emitted in canonical order is useful, so let's make sure via
tests this will stay preserved:

In mkdirty2() we modify pages in 2, 0 order, but the latter code checks
(via storeblk_trace()) they were actually stored in 0, 2 order.

Just update to latest CCAN for it to be a fresh one.

13c0c17c (bigfile/zodb: Format #1 which is optimized for small changes)
used BTree to organize ZBlk1 block's chunks and for loadblkdata() added
"TODO we are missing to free internal BTree structures on data load".

#3 besides other
things showed that even when we deactivate ZData objects, we are still
keeping them as ghosts occupying memory and the same for IOBucket
objects.

This all happens because there is no proper way to deactivate whole
btree - including internal buckets objects. And since internal buckets
are not deactivated, they stay in picklecache and thus hold a reference
to ZData objects and ZData objects in turn, even if explicitly
deactivated, stay in memory.

We can fix this all via implementing whole-btree deactivation procedure.

To do so we need to iterate over all btree buckets recursively, but
unfortunately there is no BTree API to access/iterate btree's buckets.
We can however still get reference to first top-level buckets via
gc.get_referents(btree) and then scan buckets further without hacks.

gc.get_referents(btree) is a hack, but

- it works in O(1)  (we only get pointers from btree, not scanning all
  gcable objects and deducing them)
- it works reliable if we filter out non-interesting objects.

So in the end it works.

Before the patch loading more and more ZBlk1 data with objgraph
instrumentation was showing itself like

    #                                    Nobj        δ
    wendelin.bigfile.file_zodb.ZData     7168      +512
    BTrees.IOBTree.IOBucket               238       +17
    BTrees.IOBTree.IOBTree                 14        +1

and after this patch we now have

    BTrees.IOBTree.IOBTree                 14        +1

we cannot remove that "IOBTree + 1", since ZBlk1 is holding direct
reference on it (via .chunktab) and we have to keep ZBlk1 live with
._v_zfile and ._v_zblk set for invalidation to work. "+1 IOBtree" is
however small - 144 bytes per 2M (= 0.006%) so we can neglect that the
same way we neglect keeping ZBlk1 staying live for each block.

The following started to appear after recent gcc upgrade on my host:

bigfile/virtmem.c: In function `vma_on_pagefault':
bigfile/virtmem.c:696:9: warning: implicit declaration of function `usleep' [-Wimplicit-function-declaration]
         usleep(10000);  // XXX with 1000 uslepp still busywaits

This updates and fixes 487e5226 (setup: specify setuptools location
explicitly when calling make.) to use @kazuhiko original idea to
propagate only setuptools location. The reason is - when propagating
whole sys.path things break under tox tests:

---- 8< ----
========================================================================== test session starts ===========================================================================
platform linux2 -- Python 2.7.12, pytest-2.9.2, py-1.4.31, pluggy-0.3.1
rootdir: /home/kirr/src/wendelin/release/wendelin.core, inifile:
collected 33 items

bigarray/tests/test_arrayzodb.py .......
bigarray/tests/test_basic.py ........
bigfile/tests/test_basic.py ....
bigfile/tests/test_filefile.py .
bigfile/tests/test_filezodb.py ........
bigfile/tests/test_thread.py ....
lib/tests/test_calc.py .

======================================================================= 33 passed in 14.14 seconds =======================================================================
x86_64-linux-gnu-gcc -pthread -g -Wall -D_GNU_SOURCE -std=gnu99 -fplan9-extensions -Wno-declaration-after-statement -Wno-error=declaration-after-statement  -Iinclude -I3rdparty/ccan -I3rdparty/include   bigfile/tests/tfault.c lib/bug.c lib/utils.c 3rdparty/ccan/ccan/tap/tap.c  -o bigfile/tests/tfault.t
t/tfault-run bigfile/tests/tfault.t faultr on_pagefault
ok 1 - !pagefault_init()
Fatal Python error: Py_Initialize: Unable to get the locale encoding
  File ".../wendelin.core/.tox/py27-ZODB3-zblk0-fs-numpy110/lib/python2.7/encodings/__init__.py", line 123
    raise CodecRegistryError,\
                            ^
SyntaxError: invalid syntax

Current thread 0x00007f9b80024780 (most recent call first):
t/tfault-run: line 28: 21521 Аварийный останов         (core dumped) gdb -q -batch $tfault core > core.info
E: can't gdb(core)
Makefile:189: ошибка выполнения рецепта для цели «faultr.tfault»
make: *** [faultr.tfault] Ошибка 1
rm bigfile/tests/test_virtmem.t bigfile/tests/test_ram.t bigfile/tests/tfault.t bigfile/tests/test_pagemap.t
error: Failed to execute `make test`
ERROR: InvocationError: '.../wendelin.core/.tox/py27-ZODB3-zblk0-fs-numpy110/bin/python setup.py test'
________________________________________________________________________________ summary _________________________________________________________________________________
ERROR:   py27-ZODB3-zblk0-fs-numpy110: commands failed
---- 8< ----

What happens here is:

- gdb is used in automated tests
- gdb is linked with libpython3.5
- tox is currently running tests with python27
- setup.py sets PYTHONPATH to whole path from python27
- gdb, upon starting, initializes python runtime, which tries to load
  py27 modules under py35 -> oops.

So propagating only setuptools location practically solves the issue for
now, but still there is potential risk that in future, there will be
other modules put in the same location as setuptools (location is parent
dir of a module/package) which python tries to load on startup and which
might be incompatible between 2 & 3.

Thus not setting PYTHONPATH at all - e.g. creating environments
virtualenv way - would be better, but buildout fundamentally works the
other way. We can not also use -c 'buildout sys.path hack' in $PYTHON
itself, as $PYTHON is used in general way inside Makefile.

So let the hack with setuptools location in PYTHONPATH stay there until
it practically works.