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.

Sign up for GitHub

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

Jump to bottom

Fix integration test "FreeText Editor Paste some html must check that pasting html just keep the text" #17931

Closed
timvandermeij opened this issue Apr 11, 2024 · 5 comments
Closed

Fix integration test "FreeText Editor Paste some html must check that pasting html just keep the text" #17931

timvandermeij opened this issue Apr 11, 2024 · 5 comments
Assignees
@timvandermeij
Labels
intermittent test

Comments

@timvandermeij
Copy link
Contributor

timvandermeij commented Apr 11, 2024 •
edited
Loading

This integration test is quite new, but has failed a couple of times on (as far as I have seen only) the Windows bot now with the following traceback:

1) FreeText Editor Paste some html must check that pasting html just keep the text
  Message:
�[31m    In firefox:
        Expected 'FooFooBar
        OofHello PDF.js World !!' to equal 'FooBar
        OofHello PDF.js World !!'.�[0m
  Stack:
        at <Jasmine>
        at file:///C:/pdfjs/botio-files-pdfjs/private/d21e23ccf06497a/test/integration/freetext_editor_spec.mjs:3667:57
        at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
        at async Promise.all (index 0)
        at async UserContext.<anonymous> (file:///C:/pdfjs/botio-files-pdfjs/private/d21e23ccf06497a/test/integration/freetext_editor_spec.mjs:3567:7)

The most recent logs can be found here: http://54.193.163.58:8877/d21e23ccf06497a/output.txt

It was introduced in commit 2dbd7ac and it fails at https://github.com/mozilla/pdf.js/blob/master/test/integration/freetext_editor_spec.mjs#L3666-L3667.

@calixteman Do you have an idea why this could be failing intermittently?
@calixteman
Copy link
Contributor

It seems that Foo is pasted several times which means that we try to paste the string but nothing happened before 100ms and then another paste is triggered but finally we've two pasted strings.

pdf.js/test/integration/freetext_editor_spec.mjs

Line 3622 in e78ce74

await pasteFromClipboard(

and

pdf.js/test/integration/test_utils.mjs

Line 235 in e78ce74

while (!hasPasteEvent) {

We could try to increase the default timeout to 500ms.
I know that having hardcoded timeout isn't ideal but I cannot image an other solution, I'll try to think about that.

@timvandermeij
Copy link
Contributor Author

timvandermeij commented Apr 12, 2024 •
edited
Loading

I think, to buy us time and reduce how often this occurs since it just happened again at http://54.193.163.58:8877/f423fd1265d6552/output.txt, increasing the timeouts in that test to e.g. 200 ms or more could work as a temporary measure. I would feel a bit better about that if the current failures can be reproduced on a Windows system (I currently don't have one around) and to verify that a higher timeout value indeed "fixes" it, instead of us having to try various timeout values experimentally.

For the proper fix, we should probably try to remove the waitForTimeout usage by changing the test to not have to wait for something that won't happen. Maybe that can be done by changing the order of operations in the tests, i.e. by putting the pastes where no action is expected at the very end so a valid paste in between cannot mess up the assertions, or by splitting off the pastes where nothing is expected to happen into another test so they can't conflict? I don't know the details of this particular test, but hopefully something like that should be doable.

timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Apr 16, 2024
@timvandermeij
Increase timeouts in the "must check that pasting html just keep the …
a2e9c82 
…txt" integration test

This is temporary fix to reduce the number of intermittent failures for
this test until we have the permanent fix tracked in mozilla#17931.
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Apr 16, 2024
@timvandermeij
Increase timeouts in the "must check that pasting html just keep the …
310f7a9 
…text" integration test

This is temporary fix to reduce the number of intermittent failures for
this test until we have the permanent fix tracked in mozilla#17931.
@timvandermeij timvandermeij mentioned this issue Apr 16, 2024
Closed
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Apr 16, 2024
@timvandermeij
Increase timeouts in the "must check that pasting html just keep the …
4c55877 
…text" integration test

This is temporary fix to reduce the number of intermittent failures for
this test until we have the permanent fix tracked in mozilla#17931.
@timvandermeij
Copy link
Contributor Author

The temporary fix of increasing the timeouts sadly didn't do as much as I had hoped (see the PR above), so it looks like we'll have to keep is as is for now and indeed think about the proper fix in the meantime.

This was referenced Apr 19, 2024
Open
Merged
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue May 2, 2024
@timvandermeij
Remove most waitForTimeout usage from the freetext editor integrati…
09b409c 
…on tests

This commit replaces a `waitForTimeout` occurrence with an equivalent
`waitForSelector` expression, and removes two other `waitForTimeout`
occurrences that are obsolete because we already wait for an observable
event to trigger or class change to happen.

Note that the other `waitForTimeout` occurrences in this file are either
part of mozilla#17931 or remain until we find a good way to ensure that nothing
happened (because currently there is nothing we can await there).
@timvandermeij timvandermeij mentioned this issue May 2, 2024
Merged
@timvandermeij
Copy link
Contributor Author

Note that, while this test fails intermittently most often on Windows, it can also occur on Linux. However, the traceback is slightly different and includes an IndexSizeError that I haven't seen in the Windows logs yet. Snippet from http://54.241.84.105:8877/4205770be581237/output.txt:

Failures:
1) FreeText Editor Paste some html must check that pasting html just keep the text
  Message:
�[31m    In firefox:
        Expected 'Foo
        Bar
        OofHello PDF.js World !!' to equal 'FooHello PDF.js World !!'.�[0m
  Stack:
        at <Jasmine>
        at file:///home/ubuntu/pdfjs/botio-files-pdfjs/private/4205770be581237/test/integration/freetext_editor_spec.mjs:3645:57
        at async Promise.all (index 0)
        at async UserContext.<anonymous> (file:///home/ubuntu/pdfjs/botio-files-pdfjs/private/4205770be581237/test/integration/freetext_editor_spec.mjs:3576:7)
  Message:
�[31m    IndexSizeError: Selection.setPosition: The offset is out of range.�[0m
  Stack:
        at evaluate (evaluate at select (file:///home/ubuntu/pdfjs/botio-files-pdfjs/private/4205770be581237/test/integration/freetext_editor_spec.mjs:3621:18), <anonymous>:2:40)
        at evaluate (evaluate at select (file:///home/ubuntu/pdfjs/botio-files-pdfjs/private/4205770be581237/test/integration/freetext_editor_spec.mjs:3621:18), <anonymous>:5:

@timvandermeij timvandermeij mentioned this issue May 6, 2024
Merged
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue May 6, 2024
@timvandermeij
Remove most waitForTimeout usage from the freetext editor integrati…
5c5c107 
…on tests

This commit replaces a `waitForTimeout` occurrence with an equivalent
`waitForSelector` expression, and removes two other `waitForTimeout`
occurrences that are obsolete because we already wait for an observable
event to trigger or class change to happen.

Note that the other `waitForTimeout` occurrences in this file are either
part of mozilla#17931 or remain until we find a good way to ensure that nothing
happened (because currently there is nothing we can await there).
@timvandermeij timvandermeij mentioned this issue May 29, 2024
Merged
@nicolo-ribaudo nicolo-ribaudo mentioned this issue Jun 21, 2024
Merged
@timvandermeij timvandermeij self-assigned this Jun 23, 2024
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 24, 2024
@timvandermeij
Fix the timeout logic in the waitForEvent integration test helper f…
51dcd6a 
…unction

Debugging mozilla#17931, by printing all parts of the event lifecycle including
timestamps, uncovered that some events for which a timeout was logged
actually did get triggered correctly in the browser. Going over the code
and discovering https://stackoverflow.com/questions/47107465/puppeteer-how-to-listen-to-object-events#comment117661238_65534026
showed what went wrong: if the event we wait for is triggered then
`Promise.race` resolves, but that doesn't automatically cancel the
timeout. The tests didn't fail on this because `Promise.race` resolved
correctly, but slightly later once the timeout was reached we would see
spurious log lines about timeouts for the already-triggered events.

This commit fixes the issue by canceling the timeout if the event we're
waiting for has triggered.
This was referenced Jun 24, 2024
Merged
Merged
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 25, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
4ca71a8 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do actions to trigger the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by turning `waitForEvent` into a generator,
which allows us to only give control back to the caller when the event
listener is fully registered. Now the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We call `next()` to advance to the `yield` in `waitForEvent`, which
   effectively waits until the event listener is registered and it's
   safe to return control to the caller.
3. We do actions to trigger the event.
4. We call `generator.next()` to finish the logic after the `yield` in
   `waitForEvent` so that the generator is exhausted and we wait for the
   event or a timeout.

This should make sure that we always register the event listener before
triggering the event, which in itself fixes intermittent issues, but
because we shouldn't miss events anymore we can also remove the retry
logic for e.g. pasting, which fixes the issues we have seen in mozilla#17931
where pasting could happen multiple times.
@timvandermeij timvandermeij mentioned this issue Jun 25, 2024
Merged
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 25, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
ae4e8d5 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do actions to trigger the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by turning `waitForEvent` into a generator,
which allows us to only give control back to the caller when the event
listener is fully registered. Now the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We call `next()` to advance to the `yield` in `waitForEvent`, which
   effectively waits until the event listener is registered and it's
   safe to return control to the caller.
3. We do actions to trigger the event.
4. We call `generator.next()` to finish the logic after the `yield` in
   `waitForEvent` so that the generator is exhausted and we wait for the
   event or a timeout.

This should make sure that we always register the event listener before
triggering the event, which in itself fixes intermittent issues, but
because we shouldn't miss events anymore we can also remove the retry
logic for e.g. pasting, which fixes the issues we have seen in mozilla#17931
where pasting could happen multiple times.
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 25, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
488e47b 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do actions to trigger the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by turning `waitForEvent` into a generator,
which allows us to only give control back to the caller when the event
listener is fully registered. Now the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We call `next()` to advance to the `yield` in `waitForEvent`, which
   effectively waits until the event listener is registered and it's
   safe to return control to the caller.
3. We do actions to trigger the event.
4. We call `generator.next()` to finish the logic after the `yield` in
   `waitForEvent` so that the generator is exhausted and we wait for the
   event or a timeout.

This should make sure that we always register the event listener before
triggering the event, which in itself fixes intermittent issues, but
because we shouldn't miss events anymore we can also remove the retry
logic for e.g. pasting, which fixes the issues we have seen in mozilla#17931
where pasting could happen multiple times.
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 25, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
0e1997d 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do actions to trigger the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by turning `waitForEvent` into a generator,
which allows us to only give control back to the caller when the event
listener is fully registered. Now the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We call `next()` to advance to the `yield` in `waitForEvent`, which
   effectively waits until the event listener is registered and it's
   safe to return control to the caller.
3. We do actions to trigger the event.
4. We call `generator.next()` to finish the logic after the `yield` in
   `waitForEvent` so that the generator is exhausted and we wait for the
   event or a timeout.

This should make sure that we always register the event listener before
triggering the event, but because we shouldn't miss events anymore we
can also remove the retry logic for pasting.
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 25, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
385550f 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do actions to trigger the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by turning `waitForEvent` into a generator,
which allows us to only give control back to the caller when the event
listener is fully registered. Now the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We call `next()` to advance to the `yield` in `waitForEvent`, which
   effectively waits until the event listener is registered and it's
   safe to return control to the caller.
3. We do actions to trigger the event.
4. We call `generator.next()` to finish the logic after the `yield` in
   `waitForEvent` so that the generator is exhausted and we wait for the
   event or a timeout.

This should make sure that we always register the event listener before
triggering the event, but because we shouldn't miss events anymore we
can also remove the retry logic for pasting.
timvandermeij added a commit to timvandermeij/pdf.js that referenced this issue Jun 26, 2024
@timvandermeij
Fix a race condition involving the waitForEvent integration test he…
7128b95 
…lper function

Debugging mozilla#17931 uncovered a race condition in the way we use the
`waitForEvent` function. Currently the following happens:

1. We call `waitForEvent`, which starts execution of the function body
   and immediately returns a promise.
2. We do the action that triggers the event.
3. We await the promise, which resolves if the event is triggered or
   the timeout is reached.

The problem is in step 1: function body execution has started, but not
necessarily completed. Given that we don't await the promise, we
immediately trigger step 2 and it's not unlikely that the event we
trigger arrives before the event listener is actually registered in the
function body of `waitForEvent` (which is slower because it needs to be
evaluated in the page context and there is some other logic before the
actual `addEventListener` call).

This commit fixes the issue by passing the action to `waitForEvent` as
a callback so `waitForEvent` itself can call it once it's safe to do so.
This should make sure that we always register the event listener before
triggering the event, and because we shouldn't miss events anymore we
can also remove the retry logic for pasting.
@timvandermeij
Copy link
Contributor Author

Closing since this is fixed by the PRs above and #18338 🎉

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@timvandermeij timvandermeij

Labels
intermittent test
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@timvandermeij @calixteman