Skip to content

test: fix wait_until_change_detection_event_completes for change detection < 1s#2971

Closed
ap-wtioit wants to merge 2 commits intodocker-mailserver:masterfrom
ap-wtioit:master-fix_wait_until_change_detection_event_completes
Closed

test: fix wait_until_change_detection_event_completes for change detection < 1s#2971
ap-wtioit wants to merge 2 commits intodocker-mailserver:masterfrom
ap-wtioit:master-fix_wait_until_change_detection_event_completes

Conversation

@ap-wtioit
Copy link
Copy Markdown
Contributor

@ap-wtioit ap-wtioit commented Jan 2, 2023

Description

in case the change detection happens within one tick __change_event_status might return CHANGE_EVENT_END right after the previous tick returned an empty string ""

also reduce ticks in docker container to .1 s (we can expect an up-to-date bash inside the container)

on our CI systems and DEV machines the change detection happen well bellow 1s:

[  DEBUG  ]  2023-01-02 09:30:30  Starting changedetector
[  DEBUG  ]  2023-01-02 09:30:40  Changedetector is ready
[   INF   ]  2023-01-02 09:30:40  Change detected
[  DEBUG  ]  Creating master user 'masterusername'
[  DEBUG  ]  Creating user 'user1' for domain 'localhost.localdomain'
[  DEBUG  ]  Creating user 'user2' for domain 'otherdomain.tld'
[  DEBUG  ]  Creating user 'user3' for domain 'localhost.localdomain' with attributes 'userdb_mail=mbox:~/mail:INBOX=~/inbox'
[  DEBUG  ]  Creating user 'user' for domain 'example.com'
[  DEBUG  ]  Adding alias '[email protected]' for user '[email protected]' to Dovecot's userdb
[  DEBUG  ]  Alias '[email protected]' is non-local (or mapped to a non-existing account) and will not be added to Dovecot's userdb
[  DEBUG  ]  Adding alias '@localdomain2.com' for user '[email protected]' to Dovecot's userdb
[  DEBUG  ]  2023-01-02 09:30:40  Reloading services due to detected changes
[  DEBUG  ]  2023-01-02 09:30:40  Completed handling of detected change

which lead to tests failing most of the times the as one output of the tail -1 was `` followed by the next output being Completed handling of detected change and the following never being true within the timeout:

[[ Completed handling of detected change == \C\h\a\n\g\e\ \d\e\t\e\c\t\e\d ]]

Output of failed tests:

not ok 212 setup_file failed
# (from function `repeat_until_success_or_timeout' in file test/test_helper/common.bash, line 43,
#  from function `wait_until_change_detection_event_completes' in file test/test_helper/common.bash, line 208,
#  from function `setup_file' in test file test/tests/serial/tests.bats, line 50)
#   `wait_until_change_detection_event_completes mail' failed
# 675cd226dc803f82837b33fc6109ee21ff5191d576e890ffa33ae212510845b0
# [   INF   ]  mail.my-domain.com is up and running
# Timed out on command: __is_changedetector_processing
# mail
# bats warning: Executed 212 instead of expected 309 tests

Type of change

  • Bug fix (non-breaking change which fixes an issue)

Checklist:

  • My code follows the style guidelines of this project
  • I have performed a self-review of my own code
  • I have commented my code, particularly in hard-to-understand areas
  • I have made corresponding changes to the documentation (README.md or the documentation under docs/)
  • If necessary I have added tests that prove my fix is effective or that my feature works
  • New and existing unit tests pass locally with my changes

Info @wt-io-it


MAINTAINER EDIT (by @georglauterbach): Fixes #2966

…< 1s

in case the change detection happens within one tick __change_event_status
might return CHANGE_EVENT_END right after the previous tick returned an empty
string ""

also reduce ticks in docker container to .1 s (we can expect an up-to-date bash
inside the container)
Copy link
Copy Markdown
Member

@georglauterbach georglauterbach left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM 👍🏼 Thank you very much for taking the time!

Comment on lines +197 to +198
[[ $(__change_event_status) == "${CHANGE_EVENT_START}" ]] \
|| [[ $(__change_event_status) == "${CHANGE_EVENT_END}" ]]
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@polarathene could you please double-check this for me? I think it's fine but not 100% sure whether the logic checks out - it should though, just making sure here.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

CHANGE_EVENT_END implies the changedetector service is no longer processing the event. This would risk causing false positives.

The correct approach to resolve the bug is described in my comment on a related issue.

I should have time to look into resolving this myself today or tomorrow.


I wasn't aware that sleep could use non-integer values for sub-second delays. That alone would probably be enough in most cases. If not adding in the counting mechanism should do the trick, possibly also adding a way to increase the polling window of the change detector service itself (for the purpose of tests at least).

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sound's good. @polarathene it's not the polling interval of the changedetector that's interfering here, it's the time to process a change event. if it takes less time to process the event than the interval that checks it the changedetector has started processing the event, in the current code this causes the event status to be CHANGE_EVENT_END before it ever returned CHANGE_EVENT_START.

However i think the counting option would be a better solution for sure.

@georglauterbach georglauterbach changed the title test: fix wait_until_change_detection_event_completes for change detection < 1s test: fix wait_until_change_detection_event_completes for change detection < 1s Jan 2, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[BUG] Weird but semi-consistent test failures

3 participants