Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Exception handling causes test timeouts issues #6046

Open
richtja opened this issue Oct 16, 2024 · 1 comment · May be fixed by #6060
Open

Exception handling causes test timeouts issues #6046

richtja opened this issue Oct 16, 2024 · 1 comment · May be fixed by #6060
Assignees
Labels

Comments

@richtja
Copy link
Contributor

richtja commented Oct 16, 2024

Describe the bug
Avocado uses TestInterrupt exceptions for interrupting tests on timeouts. Unfortunately, users might change this behaviour if they will add exception handling for Exception class. This will cause that tests won't end properly on timeout.

Steps to reproduce
Small change in timeouttests.py from avocado examples can work as reproducer.

import time

from avocado import Test


class TimeoutTest(Test):
    """
    Functional test for avocado. Throw a TestTimeoutError.

    :param sleep_time: How long should the test sleep
    """

    timeout = 3

    def test(self):
        """
        This should throw a TestTimeoutError.
        """
        try:
            sleep_time = float(self.params.get("sleep_time", default=5.0))
            self.log.info("Sleeping for %.2f seconds (2 more than the timeout)", sleep_time)
            time.sleep(sleep_time)
        except Exception:
            pass

Expected behavior

$ avocado run examples/tests/timeouttest.py -p sleep_time=10
JOB ID     : 041c947173551d6d4126c2310b2e1db36921be1e
JOB LOG    : /home/janrichter/avocado/job-results/job-2024-10-16T12.12-041c947/job.log
 (1/1) examples/tests/timeouttest.py:TimeoutTest.test: STARTED
 (1/1) examples/tests/timeouttest.py:TimeoutTest.test: INTERRUPTED: Test interrupted: Timeout reached (3.03 s)
RESULTS    : PASS 0 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 1 | CANCEL 0
JOB HTML   : /home/janrichter/avocado/job-results/job-2024-10-16T12.12-041c947/results.html
JOB TIME   : 4.10 s

Current behavior

$ avocado run examples/tests/timeouttest.py -p sleep_time=10
JOB ID     : 668063d3543528d371125073cd1e683a064c0667
JOB LOG    : /home/janrichter/avocado/job-results/job-2024-10-16T12.04-668063d/job.log
 (1/1) examples/tests/timeouttest.py:TimeoutTest.test: STARTED
 (1/1) examples/tests/timeouttest.py:TimeoutTest.test: PASS (3.01 s)
RESULTS    : PASS 1 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0 | CANCEL 0
JOB HTML   : /home/janrichter/avocado/job-results/job-2024-10-16T12.04-668063d/results.html
JOB TIME   : 3.96 s

You can see that the test was interrupted based on timeout, but the overall result is PASS.

@richtja richtja added the bug label Oct 16, 2024
@mr-avocado mr-avocado bot moved this to Triage in Default project Oct 16, 2024
@richtja
Copy link
Contributor Author

richtja commented Oct 17, 2024

The except Exception is widely used by avocado utils see:

grep -Rnw 'avocado' -e 'except Exception'
avocado/core/job.py:630:        except Exception as details:  # pylint: disable=W0703
avocado/core/output.py:603:        except Exception:  # pylint: disable=W0703
avocado/core/resolver.py:128:            except Exception as exc:  # pylint: disable=W0703
avocado/core/resolver.py:162:            except Exception as exc:  # pylint: disable=W0703
avocado/core/sysinfo.py:195:        except Exception as exc:  # pylint: disable=W0703
avocado/core/test.py:675:        except Exception as detail:  # pylint: disable=W0703
avocado/plugins/runners/avocado_instrumented.py:129:        except Exception as e:
avocado/plugins/runners/avocado_instrumented.py:183:        except Exception as e:
avocado/plugins/runners/exec_test.py:185:        except Exception as e:
avocado/plugins/runners/python_unittest.py:187:        except Exception as e:
avocado/plugins/runners/sysinfo.py:72:        except Exception as exc:  # pylint: disable=W0703
avocado/plugins/runners/sysinfo.py:196:        except Exception:  # pylint: disable=W0703
avocado/plugins/teststmpdir.py:45:            except Exception:  # pylint: disable=W0703
avocado/plugins/beaker_result.py:52:        except Exception as err:
avocado/utils/network/hosts.py:60:        except Exception as ex:
avocado/utils/network/hosts.py:90:        except Exception as ex:
avocado/utils/network/hosts.py:133:        except Exception as ex:
avocado/utils/network/interfaces.py:100:        except Exception:
avocado/utils/network/interfaces.py:129:        except Exception:
avocado/utils/network/interfaces.py:160:        except Exception as ex:
avocado/utils/network/interfaces.py:179:        except Exception as ex:
avocado/utils/network/interfaces.py:220:        except Exception as ex:
avocado/utils/network/interfaces.py:242:        except Exception as ex:
avocado/utils/network/interfaces.py:255:        except Exception as ex:
avocado/utils/network/interfaces.py:270:        except Exception as ex:
avocado/utils/network/interfaces.py:283:        except Exception as ex:
avocado/utils/network/interfaces.py:352:        except Exception as ex:
avocado/utils/network/interfaces.py:382:        except Exception as ex:
avocado/utils/network/interfaces.py:537:        except Exception as ex:
avocado/utils/network/interfaces.py:553:        except Exception as ex:
avocado/utils/network/interfaces.py:569:        except Exception as ex:
avocado/utils/network/interfaces.py:597:        except Exception as ex:
avocado/utils/network/interfaces.py:613:        except Exception as ex:
avocado/utils/network/interfaces.py:684:            except Exception as ex:
avocado/utils/network/interfaces.py:707:        except Exception as ex:
avocado/utils/network/interfaces.py:744:        except Exception as ex:
avocado/utils/software_manager/backends/yum.py:213:        except Exception as exc:  # pylint: disable=W0703
avocado/utils/genio.py:107:    except Exception:  # pylint: disable=W0703
avocado/utils/archive.py:299:                except Exception as e:
avocado/utils/archive.py:307:                except Exception as e:
avocado/utils/asset.py:214:        except Exception:  # pylint: disable=W0703
avocado/utils/asset.py:435:            except Exception:  # pylint: disable=W0703
avocado/utils/asset.py:693:        except Exception as e:
avocado/utils/filelock.py:58:            except Exception:  # pylint: disable=W0703
avocado/utils/filelock.py:73:                except Exception:  # pylint: disable=W0703
avocado/utils/gdb.py:385:            except Exception:  # pylint: disable=W0703
avocado/utils/process.py:167:    except Exception:  # pylint: disable=W0703
avocado/utils/stacktrace.py:92:    except Exception:  # pylint: disable=W0703
avocado/utils/sysinfo.py:187:        except Exception as exc:  # pylint: disable=W0703, W0612
avocado/utils/sysinfo.py:305:        except Exception as detail:  # pylint: disable=W0703
avocado/utils/sysinfo.py:318:            except Exception as detail:  # pylint: disable=W0703

@richtja richtja self-assigned this Oct 29, 2024
@richtja richtja moved this from Triage to Short Term (Current Q) Backlog in Default project Oct 29, 2024
@richtja richtja added this to the 109 - Codename TBD milestone Oct 29, 2024
@richtja richtja moved this from Short Term (Current Q) Backlog to In progress in Default project Oct 31, 2024
richtja added a commit to richtja/avocado that referenced this issue Oct 31, 2024
This commit changes the way how avocado instrumented runner handles test
timeouts.  For timeout handling, we used to use signals and raising
TestInterrupt error. Such solution has an issue that we can't control
where in the code the Error will be raised, and it can be handled before
it reaches the runner layer. More info about this issue in avocado-framework#6046.

This change removes the signal handling and uses threading instead. Now
each test method will be run in a separated thread and this thread will
be terminated if timeout is reached. This solution selves the raising
error issue and keeps the current test lifecycle untouched.

Reference: avocado-framework#6046
Signed-off-by: Jan Richter <[email protected]>
@richtja richtja linked a pull request Oct 31, 2024 that will close this issue
@richtja richtja linked a pull request Oct 31, 2024 that will close this issue
richtja added a commit to richtja/avocado that referenced this issue Oct 31, 2024
This commit changes the way how avocado instrumented runner handles test
timeouts.  For timeout handling, we used to use signals and raising
TestInterrupt error. Such solution has an issue that we can't control
where in the code the Error will be raised, and it can be handled before
it reaches the runner layer. More info about this issue in avocado-framework#6046.

This change removes the signal handling and uses threading instead. Now
each test method will be run in a separated thread and this thread will
be terminated if timeout is reached. This solution selves the raising
error issue and keeps the current test lifecycle untouched.

Reference: avocado-framework#6046
Signed-off-by: Jan Richter <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Status: In progress
Development

Successfully merging a pull request may close this issue.

1 participant