Repository: joblib/joblib
Pull request #501 (2017-02-21 10:00:15)

[MRG] Shorten signature when there is an exception while loading cached results 
Closes #489.

codecov[bot]: # [Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=h1) Report
> Merging [#501](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=desc) into [master](https://codecov.io/gh/joblib/joblib/commit/79b622b1ca32adff32fce032c2eccc5f861b3e53?src=pr&el=desc) will **decrease** coverage by `-0.01%`.
> The diff coverage is `100%`.


```diff
@@            Coverage Diff            @@
##           master    #501      +/-   ##
=========================================
- Coverage   93.41%   93.4%   -0.01%     
=========================================
  Files          37      36       -1     
  Lines        4722    4701      -21     
=========================================
- Hits         4411    4391      -20     
+ Misses        311     310       -1
```


| [Impacted Files](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [joblib/memory.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL21lbW9yeS5weQ==) | `93.38% <100%> (+0.99%)` | :white_check_mark: |
| [joblib/test/test_memory.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9tZW1vcnkucHk=) | `98.06% <100%> (+0.06%)` | :white_check_mark: |
| [joblib/test/test_func_inspect.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9mdW5jX2luc3BlY3QucHk=) | `90.29% <100%> (+0.49%)` | :white_check_mark: |
| [joblib/backports.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2JhY2twb3J0cy5weQ==) | `39.58% <ø> (-54.17%)` | :x: |
| [joblib/disk.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2Rpc2sucHk=) | `78.43% <ø> (-1.97%)` | :x: |
| [joblib/test/common.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvY29tbW9uLnB5) | `84.61% <ø> (-1.93%)` | :x: |
| [joblib/logger.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2xvZ2dlci5weQ==) | `85.52% <ø> (-1.32%)` | :x: |
| [joblib/test/test_parallel.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9wYXJhbGxlbC5weQ==) | `93.89% <ø> (-1.07%)` | :x: |
| [joblib/func_inspect.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2Z1bmNfaW5zcGVjdC5weQ==) | `89.53% <ø> (-0.59%)` | :x: |
| [joblib/pool.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Bvb2wucHk=) | `90.32% <ø> (-0.41%)` | :x: |
| ... and [1 more](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=tree-more) | |

------

[Continue to review full report at Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=continue).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=footer). Last update [79b622b...e2f2c44](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...e2f2c4493d37517e989404c341d2e4b4d1f008a0?el=footer&src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).
codecov[bot]: # [Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=h1) Report
> Merging [#501](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=desc) into [master](https://codecov.io/gh/joblib/joblib/commit/79b622b1ca32adff32fce032c2eccc5f861b3e53?src=pr&el=desc) will **decrease** coverage by `-0.01%`.
> The diff coverage is `100%`.


```diff
@@            Coverage Diff            @@
##           master    #501      +/-   ##
=========================================
- Coverage   93.41%   93.4%   -0.01%     
=========================================
  Files          37      36       -1     
  Lines        4722    4701      -21     
=========================================
- Hits         4411    4391      -20     
+ Misses        311     310       -1
```


| [Impacted Files](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [joblib/memory.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL21lbW9yeS5weQ==) | `93.38% <100%> (+0.99%)` | :white_check_mark: |
| [joblib/test/test_func_inspect.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9mdW5jX2luc3BlY3QucHk=) | `90.29% <100%> (+0.49%)` | :white_check_mark: |
| [joblib/test/test_memory.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9tZW1vcnkucHk=) | `98.06% <100%> (+0.06%)` | :white_check_mark: |
| [joblib/backports.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2JhY2twb3J0cy5weQ==) | `39.58% <ø> (-54.17%)` | :x: |
| [joblib/disk.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2Rpc2sucHk=) | `78.43% <ø> (-1.97%)` | :x: |
| [joblib/test/common.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvY29tbW9uLnB5) | `84.61% <ø> (-1.93%)` | :x: |
| [joblib/logger.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2xvZ2dlci5weQ==) | `85.52% <ø> (-1.32%)` | :x: |
| [joblib/test/test_parallel.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Rlc3QvdGVzdF9wYXJhbGxlbC5weQ==) | `93.89% <ø> (-1.07%)` | :x: |
| [joblib/func_inspect.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL2Z1bmNfaW5zcGVjdC5weQ==) | `89.53% <ø> (-0.59%)` | :x: |
| [joblib/pool.py](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...3427a6a2609e293d03a065ce726795f8a87a667a?src=pr&el=tree#diff-am9ibGliL3Bvb2wucHk=) | `90.32% <ø> (-0.41%)` | :x: |
| ... and [1 more](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=tree-more) | |

------

[Continue to review full report at Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=continue).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/joblib/joblib/pull/501?src=pr&el=footer). Last update [79b622b...e2f2c44](https://codecov.io/gh/joblib/joblib/compare/79b622b1ca32adff32fce032c2eccc5f861b3e53...e2f2c4493d37517e989404c341d2e4b4d1f008a0?el=footer&src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).
lesteve: Turns out I am not convinced `format_signature` is good enough to fix the original issue ...
lesteve: > Turns out I am not convinced format_signature is good enough to fix the original issue ...

Actually I double-checked and I think it will fix the original issue. The problem was that one of the parameter was a list of messages whose string representation was greater than 4M in length. With this it will reduce the size of the arguments to 700ish.

lesteve: @ogrisel @aabadie if you want to review this, I think this is the last issue before we can do a new joblib release.
raghavrv: @lesteve Thanks a lot for the PR. Sorry for the burden :/ Got a bit carried away by other stuff...
lesteve: > @lesteve Thanks a lot for the PR. Sorry for the burden :/ Got a bit carried away by other stuff...

No worries, if you have some time to review it quickly before I merge it, this will be greatly appreciated.
lesteve: I pushed an update tackling the case of long arguments inside `**kwargs`

Patch:
diff --git a/joblib/func_inspect.py b/joblib/func_inspect.py
index 0a974a1..30d1192 100644
--- a/joblib/func_inspect.py
+++ b/joblib/func_inspect.py
@@ -316,6 +316,13 @@ def filter_args(func, ignore_lst, args=(), kwargs=dict()):
     return arg_dict
 
 
+def _format_arg(arg):
+    formatted_arg = pformat(arg, indent=2)
+    if len(formatted_arg) > 1500:
+        formatted_arg = '%s...' % formatted_arg[:700]
+    return formatted_arg
+
+
 def format_signature(func, *args, **kwargs):
     # XXX: Should this use inspect.formatargvalues/formatargspec?
     module, name = get_func_name(func)
@@ -328,14 +335,12 @@ def format_signature(func, *args, **kwargs):
     arg_str = list()
     previous_length = 0
     for arg in args:
-        arg = pformat(arg, indent=2)
-        if len(arg) > 1500:
-            arg = '%s...' % arg[:700]
+        formatted_arg = _format_arg(arg)
         if previous_length > 80:
-            arg = '\n%s' % arg
-        previous_length = len(arg)
-        arg_str.append(arg)
-    arg_str.extend(['%s=%s' % (v, pformat(i)) for v, i in kwargs.items()])
+            formatted_arg = '\n%s' % formatted_arg
+        previous_length = len(formatted_arg)
+        arg_str.append(formatted_arg)
+    arg_str.extend(['%s=%s' % (v, _format_arg(i)) for v, i in kwargs.items()])
     arg_str = ', '.join(arg_str)
 
     signature = '%s(%s)' % (name, arg_str)
diff --git a/joblib/memory.py b/joblib/memory.py
index f9ec1df..14d7552 100644
--- a/joblib/memory.py
+++ b/joblib/memory.py
@@ -31,6 +31,7 @@ import threading
 from . import hashing
 from .func_inspect import get_func_code, get_func_name, filter_args
 from .func_inspect import format_call
+from .func_inspect import format_signature
 from ._memory_helpers import open_py_source
 from .logger import Logger, format_time, pformat
 from . import numpy_pickle
@@ -528,10 +529,10 @@ class MemorizedFunc(Logger):
                     print(max(0, (80 - len(msg))) * '_' + msg)
             except Exception:
                 # XXX: Should use an exception logger
+                _, signature = format_signature(self.func, *args, **kwargs)
                 self.warn('Exception while loading results for '
-                          '(args=%s, kwargs=%s)\n %s' %
-                          (args, kwargs, traceback.format_exc()))
-
+                          '{}\n {}'.format(
+                              signature, traceback.format_exc()))
                 out, metadata = self.call(*args, **kwargs)
                 argument_hash = None
         return (out, argument_hash, metadata)


Test patch:
diff --git a/joblib/test/test_func_inspect.py b/joblib/test/test_func_inspect.py
index b728d3b..fc8ee3e 100644
--- a/joblib/test/test_func_inspect.py
+++ b/joblib/test/test_func_inspect.py
@@ -222,6 +222,30 @@ def test_format_signature(func, args, kwargs, sgn_expected):
     assert sgn_result == sgn_expected
 
 
+def test_format_signature_long_arguments():
+    shortening_threshold = 1500
+    # shortening gets it down to 700 characters but there is the name
+    # of the function in the signature and a few additional things
+    # like dots for the ellipsis
+    shortening_target = 700 + 10
+
+    arg = 'a' * shortening_threshold
+    _, signature = format_signature(h, arg)
+    assert len(signature) < shortening_target
+
+    nb_args = 5
+    args = [arg for _ in range(nb_args)]
+    _, signature = format_signature(h, *args)
+    assert len(signature) < shortening_target * nb_args
+
+    kwargs = {str(i): arg for i, arg in enumerate(args)}
+    _, signature = format_signature(h, **kwargs)
+    assert len(signature) < shortening_target * nb_args
+
+    _, signature = format_signature(h, *args, **kwargs)
+    assert len(signature) < shortening_target * 2 * nb_args
+
+
 @with_numpy
 def test_format_signature_numpy():
     """ Test the format signature formatting with numpy.
diff --git a/joblib/test/test_memory.py b/joblib/test/test_memory.py
index e10e15b..6d08d65 100644
--- a/joblib/test/test_memory.py
+++ b/joblib/test/test_memory.py
@@ -819,3 +819,42 @@ def test_concurrency_safe_write(tmpdir, backend):
              if i % 3 != 2 else load_func for i in range(12)]
     Parallel(n_jobs=2, backend=backend)(
         delayed(func)(obj, filename) for func in funcs)
+
+
+def test_memory_recomputes_after_an_error_why_loading_results(tmpdir,
+                                                              monkeypatch):
+    memory = Memory(tmpdir.strpath)
+
+    def func(arg):
+        return arg, time.time()
+
+    cached_func = memory.cache(func)
+    input_arg = 'arg'
+    arg, timestamp = cached_func(input_arg)
+
+    # Make sure the function is correctly cached
+    assert arg == input_arg
+
+    # Corrupting output.pkl to make sure that an error happens when
+    # loading the cached result
+    single_cache_item, = _get_cache_items(memory.cachedir)
+    output_filename = os.path.join(single_cache_item.path, 'output.pkl')
+    with open(output_filename, 'w') as f:
+        f.write('garbage')
+
+    recorded_warnings = []
+
+    def append_to_record(item):
+        recorded_warnings.append(item)
+
+    # Make sure that corrupting the file causes recomputation and that
+    # a warning is issued. Need monkeypatch because pytest does not
+    # capture stdlib logging output (see
+    # https://github.com/pytest-dev/pytest/issues/2079)
+    monkeypatch.setattr(cached_func, 'warn', append_to_record)
+    recomputed_arg, recomputed_timestamp = cached_func(arg)
+    assert len(recorded_warnings) == 1
+    exception_msg = 'Exception while loading results'
+    assert exception_msg in recorded_warnings[0]
+    assert recomputed_arg == arg
+    assert recomputed_timestamp > timestamp