Merge lp:~kbielefe/bzr/551391-log-memory-usage into lp:bzr

We should probably have a flag to enable/disable this. "-Ddump_memory" comes to mind. I don't know which should be the default, sort of like core-dumping. I think the default for most people is to have it off, so I would probably go with that. So we could change the error message to mention "use -Dmemory_dump to get a memory dump" (or whatever).

I like the idea, the code seems fine otherwise.

Thanks very much for that.

Beyond John's comments I'd say:

 * probably the dump should go into /tmp (ie use tempfile.mkstemp), so
that it doesn't clutter up or cause trouble in people's working
directory; then print the name

 * if you get an ImportError or other error, please log the exception
so we have a chance of debugging it

 * I would print the filename, not just logging it - or return it, and
let the higher-level code print it

--
Martin

Okay, I incorporated both of your suggestions. I'm not sure what the process is from this point.

That looks good to me. I might let John have a look again, but we can merge it from here.

One thought... dump_all_objects builds a big set to make sure it gets everything, but only once.

If we just ran out of memory, maybe meliae.dump_gc_objects() would be more appropriate? It approximates dumping everything by dumping everything in gc + 1 level of references, it tends to be about 15-50% larger on disk, because of duplicate dumps, and it does miss some stuff, but it avoids needing to keep track of every object.

If we really-really wanted to be evil, we could set the high bit on all refcount values, to indicate this has been dumped, and then walk it again to remove it. But I don't really like mutating important state like that.

sent to pqm by email

I failed to catch this, but PQM did.

try:
except:
finally:

Doesn't work in python 2.4, (I think it is python 2.5).

Also, if something early raises an exception, there is no 'dump_file' for finally use.

So it should be:

fd, name = ...
dump_file = ...
try:
  try:
  except:
    return
finally:
  dump_file.close()

16 +def _dump_memory_usage(err_file):
17 + try:
18 + fd, name = tempfile.mkstemp(prefix="bzr_memdump", suffix=".json")
19 + dump_file = os.fdopen(fd, 'w')
20 + from meliae import scanner
21 + scanner.dump_all_objects(dump_file)
22 + err_file.write("Memory dumped to %s\n" % name)
23 + except ImportError:
24 + err_file.write("Dumping memory requires meliae module.\n")
25 + log_exception_quietly()
26 + except:
27 + err_file.write("Exception while dumping memory.\n")
28 + log_exception_quietly()
29 + finally:
30 + dump_file.close()

> If we just ran out of memory, maybe meliae.dump_gc_objects() would be more
> appropriate?

You're probably right. The way I tested it, it failed allocating one last big chunk, so it still had enough memory to build the set. However, I think the allocation that caused it to fail wouldn't show up in the dump anyway because it never existed. The stack trace would be more useful in that case.

Where a memory dump on MemoryError is really useful is when you have a slower accumulation of too many smaller objects, and an approximation is probably good enough for those purposes. Maybe a fallback from dump_all_objects to dump_gc_objects would be useful?

When you want the precision is while doing memory profiling for development, and then developers can use whichever method works best for their scenario.

It just occurred to me that since I'm fixing the PQM bugs anyway, if it would be useful to add a hidden command like "bzr decode-memdump /tmp/dumpfile.json" for printing the summary information. That would make it a lot easier for an end user to file a bug report.

Fixed PQM errors and ready for resubmit.

That looks good, thanks very much. We should also mention this in news, and in 'help debug-flags', which comes from bzrlib/help_topics/en

Okay, updated help and news. Thanks for your patience in walking me through this.

No problem, thanks for your persistence.

sent to pqm by email

This actually causes one correct test failure:

======================================================================
FAIL: bzrlib.tests.test_trace.TestTrace.test_format_memory_error
----------------------------------------------------------------------
_StringException: Text attachment: log
------------
1966.897 Traceback (most recent call last):
 File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/test_trace.py", line 79, in test_format_memory_error
   raise MemoryError()
MemoryError

------------
Text attachment: traceback
------------
Traceback (most recent call last):
 File "/usr/lib/python2.4/site-packages/testtools/runtest.py", line 128, in _run_user
   return fn(*args)
 File "/usr/lib/python2.4/site-packages/testtools/testcase.py", line 368, in _run_test_method
   testMethod()
 File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/test_trace.py", line 84, in test_format_memory_error
   "bzr: out of memory\n")
AssertionError: not equal:
a = 'bzr: out of memory\nUse -Dmem_dump to dump memory to a file.\n'
b = 'bzr: out of memory\n'

------------

That's nice because we can check it is actually being printed.

Okay, I fixed that test and added another test for if -Dmem_dump is specified. On the latter, I'm getting the following output, which I'm not sure is a problem or not. Also I'm not sure if the test should assume the meliae module is present.

Output of bzr selftest --verbose test_format_mem_dump:

test_trace.TestTrace.test_format_mem_dump /usr/lib/pymodules/python2.6/dbus/_dbus.py:251: DeprecationWarning: The dbus_bindings module is not public API and will go away soon.

Most uses of dbus_bindings are applications catching the exception
dbus.dbus_bindings.DBusException. You should use dbus.DBusException
instead (this is compatible with all dbus-python versions since 0.40.2).

If you need additional public API, please contact the maintainers via
<email address hidden>.

  import dbus.dbus_bindings as m
/usr/lib/python2.6/dist-packages/meliae/scanner.py:94: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
  recurse_depth=recurse_depth)
   OK 3602ms
----------------------------------------------------------------------
Ran 1 test in 3.684s

OK

The dbus warnings are probably caused by bzr-gtk; running with
--no-plugins should let your tests pass.

You can use ModuleAvailableFeature to make the tests check that a file
is written if meliae is installed and that it does not crash if it's
not.

--
Martin

@Karl: I went ahead and created https://code.edge.launchpad.net/~vila/bzr/551391-log-memory-usage/+merge/38103 so we can land this patch (see there for details).

> @Karl: I went ahead and created
> https://code.edge.launchpad.net/~vila/bzr/551391-log-memory-usage/+merge/38103
> so we can land this patch (see there for details).

Thanks for that. My time for open source work comes in bursts. For future reference, should I make it a practice to give bzr-core or someone access to my branch, so you wouldn't need to create a new one?

>>>>> Karl Bielefeldt <email address hidden> writes:

    >> @Karl: I went ahead and created
    >> https://code.edge.launchpad.net/~vila/bzr/551391-log-memory-usage/+merge/38103
    >> so we can land this patch (see there for details).

    > Thanks for that. My time for open source work comes in bursts.
    > For future reference, should I make it a practice to give bzr-core
    > or someone access to my branch, so you wouldn't need to create a
    > new one?

Hmm, not really.

I was reviewing your submission in a local branch, all I had to do was:

bzr push lp:~vila/bzr/`bzr nick`
bzr lp-open
and add your branch as a pre-requisite when proposing mine for merge.

If I had made a controversial change and thought you may agree or not
with it, I would also have 'bzr push' my branch and told you: 'If these
changes suit you, you could:

 bzr pull lp:~vila/bzr/551391-log-memory-usage

From there, you would have continue working on your branch, then 'bzr
push' again and add a comment in the ongoing merge proposal explaining
the new status.

There are a lot of variations around this theme, but in practive we
rarely use shared branches (in the ~bzr namespace).

Meh, I was sure you signed the contributor agreement but you're not part of https://launchpad.net/~contributor-agreement-canonical

Did I miss something ?

> Meh, I was sure you signed the contributor agreement but you're not part of
> https://launchpad.net/~contributor-agreement-canonical
>
> Did I miss something ?

Taken care of. I thought I had signed it as well, but it turns out I was thinking of the Code of Conduct.