cool-RR / PySnooper

Never use print for debugging again
MIT License
16.34k stars 951 forks source link

test_exception is flaky #158

Closed cool-RR closed 4 years ago

cool-RR commented 4 years ago

@alexmojaki Check this out. While developing something unrelated, I noticed that test_exception with assert_sample_output that you wrote, is flaky. It failed once on Python 2.7 on Windows, and then it succeeded again (without any code changes) and I couldn't make it fail again.

Here is the failure details, let me know if you have any insights:

$ py -2.7  -m pytest                                                                                                   
============================= test session starts =============================                                        
platform win32 -- Python 2.7.13, pytest-4.3.0, py-1.7.0, pluggy-0.8.0                                                  
rootdir: C:\Users\Administrator\Documents\Python Projects\PySnooper, inifile: tox.ini                                  
collected 41 items                                                                                                     

tests\test_chinese.py .                                                  [  2%]                                        
tests\test_not_implemented.py ss                                         [  7%]                                        
tests\test_pysnooper.py ..........................F.........             [ 95%]                                        
tests\test_multiple_files\test_multiple_files.py .                       [ 97%]                                        
tests\test_utils\test_ensure_tuple.py .                                  [100%]                                        

================================== FAILURES ===================================                                        
_______________________________ test_exception ________________________________                                        

    def test_exception():                                                                                              
        from .samples import exception                                                                                 
>       assert_sample_output(exception)                                                                                

tests\test_pysnooper.py:1074:                                                                                          
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _                                        

module = <module 'tests.samples.exception' from 'C:\Users\Administrator\Documents\Python Projects\PySn                 
ooper\tests\samples\exception.py'>                                                                                     

    def assert_sample_output(module):                                                                                  
        with mini_toolbox.OutputCapturer(stdout=False,                                                                 
                                         stderr=True) as output_capturer:                                              
            module.main()                                                                                              

        time = '21:10:42.298924'                                                                                       
        time_pattern = re.sub(r'\d', r'\\d', time)                                                                     

        def normalise(out):                                                                                            
            out = re.sub(time_pattern, time, out).strip()                                                              
            out = re.sub(                                                                                              
                r'^( *)Source path:\.\.\. .*$',                                                                        
                r'\1Source path:... Whatever',                                                                         
                out,                                                                                                   
                flags=re.MULTILINE                                                                                     
            )                                                                                                          
            return out                                                                                                 

        output = output_capturer.string_io.getvalue()                                                                  

        try:                                                                                                           
>           assert (                                                                                                   
                    normalise(output) ==                                                                               
                    normalise(module.expected_output)                                                                  
            )                                                                                                          
E           AssertionError: assert 'Source path:...value:.. None' == 'Source path:....value:.. None'                   
E             Skipping 523 identical leading characters in diff, use -v to show                                        
E               ption                                                                                                  
E             -     10:15:33 exception   10         foo()                                                              
E             ?        ^^^^^                                                                                           
E             +     21:10:42.298924 exception   10         foo()                                                       
E             ?     +++   ^^^^^^^^^                                                                                    
E                   TypeError: bad...                                                                                  
E                                                                                                                      
E             ...Full output truncated (32 lines hidden), use '-vv' to show                                            

tests\utils.py:319: AssertionError                                                                                     
---------------------------- Captured stdout call -----------------------------                                        

Actual Output:                                                                                                         

Source path:... C:\Users\Administrator\Documents\Python Projects\PySnooper\tests\samples\exception.py                  
10:15:32.999000 call        17 def main():                                                                             
10:15:32.999000 line        18     try:                                                                                
10:15:32.999000 line        19         bar()                                                                           
    10:15:32.999000 call         8 def bar():                                                                          
    10:15:32.999000 line         9     try:                                                                            
    10:15:32.999000 line        10         foo()                                                                       
        10:15:32.999000 call         4 def foo():                                                                      
        10:15:32.999000 line         5     raise TypeError('bad')                                                      
        10:15:32.999000 exception    5     raise TypeError('bad')                                                      
        TypeError: bad                                                                                                 
        Call ended by exception                                                                                        
    10:15:33 exception   10         foo()                                                                              
    TypeError: bad                                                                                                     
    10:15:33 line        11     except Exception:                                                                      
    10:15:33 line        12         str(1)                                                                             
    10:15:33 line        13         raise                                                                              
    Call ended by exception                                                                                            
10:15:33 exception   19         bar()                                                                                  
TypeError: bad                                                                                                         
10:15:33 line        20     except:                                                                                    
10:15:33 line        21         pass                                                                                   
10:15:33 return      21         pass                                                                                   
Return value:.. None                                                                                                   

=============== 1 failed, 38 passed, 2 skipped in 0.41 seconds ================                                        
cool-RR commented 4 years ago

Ah, I guess it's because the tests were run just when the second elapsed.