Repository: scikit-learn/scikit-learn
Pull request: Yield stack trace information in resilient mode model_selection warnings
Fixes #15621

Now a stack trace will be included in the FitFailedWarning so that not having early termination will still allow proper analysis of errors.

Note: this change could break functionality where the warning message is parsed and assumes a 2 line message with the warning tag line and the specific Python exception detail.

The new format would be warning tag line + stack trace + specific Python exception detail.  If we want backward compatibility, then a flag would need to be added.  However aside from test code which is being fixed, I think generally this could be an upgrade requirement, rather than over-cluttering the class parameters for every class which uses this - may be more than just GridSearchCV.

Problem statement:
GridSearchCV does not allow errors in underlying fit function to be properly displayed (does not catch error in best estimator)
#### Description
If the underlying fit() function constantly throws an error, GridSeachCV will raise a FitFailedWarning which does not show a stack trace and thus has destroyed any hope of getting details of the error.  Using code patterns such as `with warnings.catch_warnings` does not help as the error is already caught and the warning does not provide the stacktrace.

It will only print the same information already printed but does allow for early termination - at least this is possible.

Yet we see in line 715 of _search.py: `self.best_estimator_.fit(X, y, **fit_params)` has no error handler around it.

So it calls fit on the best estimator without error handling and finally the exception after all the CV for k=whatever value fits have failed.  This is inconsistent behavior.  However, best_estimator_.fit() could be better off without exception handling presumably, though since its a termination case anyway perhaps its better not having it.

Yet the resilience without information is annoying here for anyone debugging algorithms.  After doing lengthy operations, one may very well want to turn that warning into an exception with a stacktrace and stop prematurely and go fix the bug, not continue on several times before the best_estimator_ fit finally yields the error.

The only workaround now is to put try/except into the actual fit function itself and print out a message in there.  Propose to add stacktrace to the FitFailedWarning.  At least early termination is possible, but its not enough.

Also instead of resilience, error_score='raise' would allow the original error to be preserved.  But we cannot use error_score as a numeric value, so it continues running and gives useful error info.

#### Steps/Code to Reproduce
```
from sklearn.model_selection import GridSearchCV
class MyClassifier:
    def __init__(self, fake=1): pass
    def fit(self, X, y): return 3 / 0
    def score(self, X, y): return 0
    def get_params(self, deep=True): return {'fake':1}
    def set_params(self, **params): return self
mdl = MyClassifier()
params = [{'fake': [1]}]
clf = GridSearchCV(mdl, params, cv=2, iid=True, error_score=np.nan, verbose=100)
bestmdl = clf.fit([[True, True], [False, False]], [True, False])
with warnings.catch_warnings():
    warnings.simplefilter('error') #'error'
    try:
        bestmdl = clf.fit([[True, True], [False, False]], [True, False])
    except Exception as e:
        print(e)
```
#### Expected Results
The stack trace of any underlying errors is printed.

#### Actual Results
No stack trace is printed until best_estimator_.fit(), only useless warning messages that indicate an error occurred and also the specific Python error message but no indication of exactly where the error occurred from a stacktrace.

```
Fitting 2 folds for each of 1 candidates, totalling 2 fits
[Parallel(n_jobs=1)]: Using backend SequentialBackend with 1 concurrent workers.
[CV] fake=1 ..........................................................
[CV] ................................ fake=1, score=nan, total=   0.0s
[Parallel(n_jobs=1)]: Done   1 out of   1 | elapsed:    0.0s remaining:    0.0s
[CV] fake=1 ..........................................................
[CV] ................................ fake=1, score=nan, total=   0.0s
[Parallel(n_jobs=1)]: Done   2 out of   2 | elapsed:    0.0s remaining:    0.0s
[Parallel(n_jobs=1)]: Done   2 out of   2 | elapsed:    0.0s finished
C:\ProgramData\Anaconda3\lib\site-packages\sklearn\model_selection\_validation.py:547: FitFailedWarning: Estimator fit failed. The score on this train-test partition for these parameters will be set to nan. Details: 
ZeroDivisionError: division by zero

  FitFailedWarning)
Traceback (most recent call last):

  File "<ipython-input-295-a07cf0123f96>", line 1, in <module>
    bestmdl = clf.fit([[True, True], [False, False]], [True, False])

  File "C:\ProgramData\Anaconda3\lib\site-packages\sklearn\model_selection\_search.py", line 715, in fit
    self.best_estimator_.fit(X, y, **fit_params)

  File "<ipython-input-290-0021295a1749>", line 3, in fit
    def fit(self, X, y): return 3 / 0

ZeroDivisionError: division by zero
```

With the `warnings.catch_warnings()`:
```
Fitting 2 folds for each of 1 candidates, totalling 2 fits
[Parallel(n_jobs=1)]: Using backend SequentialBackend with 1 concurrent workers.
[CV] fake=1 ..........................................................
Estimator fit failed. The score on this train-test partition for these parameters will be set to nan. Details: 
ZeroDivisionError: division by zero
```

#### Versions
```
System:
    python: 3.7.4 (default, Aug  9 2019, 18:34:13) [MSC v.1915 64 bit (AMD64)]
executable: C:\ProgramData\Anaconda3\pythonw.exe
   machine: Windows-10-10.0.18362-SP0

Python deps:
       pip: 19.2.3
setuptools: 41.4.0
   sklearn: 0.21.3
     numpy: 1.17.3
     scipy: 1.3.1
    Cython: 0.29.13
    pandas: 0.25.3
```

Hints from issue discussion:
Yes, it's a difficult balance... resilience vs early failure. We of course allow the user to choose which with error_score. I agree that a traceback should be provided.

Commit message: Update test_validation.py

Patch to review:
diff --git a/sklearn/exceptions.py b/sklearn/exceptions.py
index 95a876b88be4d..0a6e8c0e65d54 100644
--- a/sklearn/exceptions.py
+++ b/sklearn/exceptions.py
@@ -135,7 +135,12 @@ class FitFailedWarning(RuntimeWarning):
     ...         gs.fit(X, y)  # This will raise a ValueError since C is < 0
     ...     except ValueError:
     ...         pass
-    ...     print(repr(w[-1].message))
+    ...     msg = repr(w[-1].message)
+    ...     # if msg.find('Traceback (most recent call last):\\n') > -1:
+    ...     if msg.count('\\n') > 1:  # has stacktrace in middle of string
+    ...         split = msg.splitlines()  # note: handles more than '\\n'
+    ...         msg = split[0] + '\\n' + split[-1] + '\\n'
+    ...     print(msg)
     FitFailedWarning('Estimator fit failed. The score on this train-test
     partition for these parameters will be set to 0.000000.
     Details: \\nValueError: Penalty term must be positive; got (C=-2)\\n'...)
diff --git a/sklearn/model_selection/_validation.py b/sklearn/model_selection/_validation.py
index 88eb5d49c4d0f..0b2b2e96d6d60 100644
--- a/sklearn/model_selection/_validation.py
+++ b/sklearn/model_selection/_validation.py
@@ -13,7 +13,8 @@
 import warnings
 import numbers
 import time
-from traceback import format_exception_only
+from sys import exc_info
+from traceback import format_exception
 from contextlib import suppress
 
 import numpy as np
@@ -532,7 +533,8 @@ def _fit_and_score(estimator, X, y, scorer, train, test, verbose,
             warnings.warn("Estimator fit failed. The score on this train-test"
                           " partition for these parameters will be set to %f. "
                           "Details: \n%s" %
-                          (error_score, format_exception_only(type(e), e)[0]),
+                          (error_score, ''.join(format_exception(
+                            type(e), e, exc_info()[2]))),
                           FitFailedWarning)
         else:
             raise ValueError("error_score must be the string 'raise' or a"
diff --git a/sklearn/model_selection/tests/test_validation.py b/sklearn/model_selection/tests/test_validation.py
index aaf4f497f1585..027500a15c25b 100644
--- a/sklearn/model_selection/tests/test_validation.py
+++ b/sklearn/model_selection/tests/test_validation.py
@@ -1641,6 +1641,15 @@ def test_fit_and_score_failing():
     assert_warns_message(FitFailedWarning, warning_message, _fit_and_score,
                          *fit_and_score_args, **fit_and_score_kwargs)
 
+    # check traceback is included
+    def testwarntrace(msg):
+        assert(msg.find('Traceback (most recent call last):\n') > -1)
+        split = msg.splitlines()  # note: handles more than '\n'
+        mtb = split[0] + '\n' + split[-1]
+        return warning_message in mtb
+    assert_warns_message(FitFailedWarning, testwarntrace, _fit_and_score,
+                         *fit_and_score_args, **fit_and_score_kwargs)
+
     fit_and_score_kwargs = {'error_score': 'raise'}
     # check if exception was raised, with default error_score='raise'
     assert_raise_message(ValueError, "Failing classifier failed as required",
diff --git a/sklearn/utils/_testing.py b/sklearn/utils/_testing.py
index 4aaf7c1fd388c..7d5a556423846 100644
--- a/sklearn/utils/_testing.py
+++ b/sklearn/utils/_testing.py
@@ -188,14 +188,18 @@ def assert_warns_message(warning_class, message, func, *args, **kw):
         # Checks the message of all warnings belong to warning_class
         for index in [i for i, x in enumerate(found) if x]:
             # substring will match, the entire message with typo won't
-            msg = w[index].message  # For Python 3 compatibility
+            msg, mtb = w[index].message, ''  # For Python 3 compatibility
             msg = str(msg.args[0] if hasattr(msg, 'args') else msg)
+            # if msg.find('Traceback (most recent call last):\n') > -1:
+            if msg.count('\n') > 1:  # has stacktrace in middle of string
+                split = msg.splitlines()  # note: handles more than '\n'
+                mtb = split[0] + '\n' + split[-1]
             if callable(message):  # add support for certain tests
                 check_in_message = message
             else:
                 check_in_message = lambda msg: message in msg
 
-            if check_in_message(msg):
+            if check_in_message(msg) or check_in_message(mtb):
                 message_found = True
                 break
 


Code review comments:
diff_hunk: @@ -135,7 +135,12 @@ class FitFailedWarning(RuntimeWarning):
     ...         gs.fit(X, y)  # This will raise a ValueError since C is < 0
     ...     except ValueError:
     ...         pass
-    ...     print(repr(w[-1].message))
+    ...     msg = repr(w[-1].message)
+    ...     # if msg.find('Traceback (most recent call last):\\n') > -1:
+    ...     if msg.count('\\n') > 1:  # has stacktrace in middle of string
path: sklearn/exceptions.py
text: @user1:
Having to include this here seems strange...

Also not sure why we want escaped newlines in the message rather than actually line breaks

@author:
Totally agree format_exc is sufficient, did not realize about it and I thought you were just short abbreviating for format_exception, my mistake.  Take things literally :)

I agree it is strange.  As for the new lines, I kept getting complaints in ALL of the builds with `'\n'` so after checking the docs, it has to be escaped even in code blocks apparently.  But the errors must be some system specific stuff I had guessed `\r\n` or something like that but so far I have not figured out why 4 systems consistently error.

@author:
But since we cannot put the stack trace into the expected output given that its easily change breakable from future refactorings or code which shifts line numbers, its best to filter the first and last line and compare those.  

Perhaps we need to use an even uglier `chr(13)` instead of `\\n` to avoid the errors and make the change all environment friendly.  I will give it a try if it continues to fail.

@author:
It could also be a Unicode issue too, unfortunately this is a rather petty annoying detail but one that should be resolved.

diff_hunk: @@ -532,7 +533,8 @@ def _fit_and_score(estimator, X, y, scorer, train, test, verbose,
             warnings.warn("Estimator fit failed. The score on this train-test"
                           " partition for these parameters will be set to %f. "
                           "Details: \n%s" %
-                          (error_score, format_exception_only(type(e), e)[0]),
+                          (error_score, ''.join(format_exception(
path: sklearn/model_selection/_validation.py
text: @user1:
Is format_exc() not sufficient?