robotframework-browser icon indicating copy to clipboard operation
robotframework-browser copied to clipboard

Promise To Wait For Download never finished

Open saussact opened this issue 4 years ago • 15 comments

Describe the bug

  Configurations click on export button
      ${dl_promise}        Promise To Wait For Download    ${download_dir}
      Wait For Elements State       ${xp_welcome_user_get_first_ack_date}
      Click    ${xp_welcome_user_configurations_export_button}
      log to console    ${dl_promise}
      ${file_obj}=         Wait For     ${dl_promise}
      File Should Exist    ${file_obj}[saveAs]
      Should Be True       ${file_obj.suggestedFilename}

${file_obj}= Wait For ${dl_promise} --> NEVER exited

After 10 minutes file is downloaded but Wait For is stille executed.

To Reproduce see above

Desktop (please complete the following information):

  • OS: MacOS
  • Browser [chromium]

saussact avatar Apr 09 '21 18:04 saussact

I do not see anything wrong in your keyword usage. Only thing which can not be seen from the example that when the new context is opened and how it is configured. Also please remember that new context may be automatically closed and new one is automatically opened, but without the acceptDownloads=True. Please check the https://marketsquare.github.io/robotframework-browser/Browser.html#Automatic%20page%20and%20context%20closing for more details.

aaltat avatar Apr 09 '21 19:04 aaltat

Yes thanks but browser setted with context and parameter acceptDownloads=True

saussact avatar Apr 09 '21 20:04 saussact

It's not only about acceptDownloads=True, it's also when the context was created and what is auto_closing_level. Could tell what is auto_closing_level value and where the context is created (suite setup or in test and which suite/test) and where the download happens (test and suite)

aaltat avatar Apr 10 '21 09:04 aaltat

Hi, thanks ! auto_closing_level is not setted, so 'TEST' value is by default.

*** Settings ***
Library           Browser
Resource          variables.robot
Test Teardown     Close Browser  ALL

*** Test Cases ***
Exporter function has to export all the table columns including Dernier acquittement du device
    Configurations click on export button

*** Keywords ***

Configurations click on export button
    ${dl_promise}        Promise To Wait For Download    ${download_dir}
    Wait For Elements State       ${xp_welcome_user_get_first_ack_date}
    Click    ${xp_welcome_user_configurations_export_button}
    log to console    ${dl_promise}
    ${file_obj}=         Wait For     ${dl_promise}
    File Should Exist    ${file_obj}[saveAs]
    Should Be True       ${file_obj.suggestedFilename}

saussact avatar Apr 12 '21 07:04 saussact

But where the New Browser/Context/Page keywords gets called, that test does not work as standalone.

aaltat avatar Apr 12 '21 08:04 aaltat

Yes, updated =

*** Settings ***
Library           Browser
Resource          variables.robot
Test Teardown     Close Browser  ALL

*** Test Cases ***
Exporter function has to export all the table columns including Dernier acquittement du device
    connect to papyrus cc
    Configurations click on export button

*** Keywords ***
Connect to papyrusCC
    [Arguments]    ${browser}=chromium
    Set Browser Timeout     20
    New Browser    ${browser}   %{HEADLESS=false}    downloadsPath=${download_dir}   
    New Context    locale=fr   acceptDownloads=True   extraHTTPHeaders={'xxx': 'xxx', 'xxx': 'John', 'xxxx': 'xxxxx', 'xxxx' : 'xxxx'}
    New Page       http://xxxxxxx:9081/xxxxx/

Configurations click on export button
    ${dl_promise}        Promise To Wait For Download    ${download_dir}
    Wait For Elements State       ${xp_welcome_user_get_first_ack_date}
    Click    ${xp_welcome_user_configurations_export_button}
    log to console    ${dl_promise}
    ${file_obj}=         Wait For     ${dl_promise}
    File Should Exist    ${file_obj}[saveAs]
    Should Be True       ${file_obj.suggestedFilename}

saussact avatar Apr 12 '21 08:04 saussact

If you test is written like that, Browser, Context and Page are opened in same test, then download should work, but for some reason it does not. Next step would be to look at playwright debug logs. Could you enable enable_playwright_debug=True in you library import and show us the playwright-log.txt file from the output directory. Please note that the log file contains everything as plain text, so remove sensitive information before downloading.

aaltat avatar Apr 12 '21 10:04 aaltat

Yes,

As follow : (note that never ending... :o )

{"level":30,"time":"2021-04-12T12:24:22.454Z","pid":50630,"hostname":"MacBook-Pro-de-Thibault.local","msg":"Listening on 60348"}
================= Original suppressed error =================
Error: Browser has been closed.
    at PlaywrightState.getActiveBrowser (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:69302:23)
    at PlaywrightServer.getActiveBrowser (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67370:79)
    at PlaywrightServer.<anonymous> (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67723:98)
    at step (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67341:23)
    at Object.next (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67322:53)
    at /Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67316:71
    at new Promise (<anonymous>)
    at __webpack_modules__../node/playwright-wrapper/grpc-service.ts.__awaiter (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67312:12)
    at PlaywrightServer.__webpack_modules__../node/playwright-wrapper/grpc-service.ts.PlaywrightServer.setTimeout (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:67714:16)
    at handleUnary (/Users/thibaultsaussac/Library/Python/3.8/lib/python/site-packages/Browser/wrapper/index.js:17039:13)
=============================================================
2021-04-12T12:24:22.553Z pw:api => browserType.launch started
2021-04-12T12:24:23.181Z pw:api <= browserType.launch succeeded
2021-04-12T12:24:23.210Z pw:api => browser.newContext started
2021-04-12T12:24:23.236Z pw:api <= browser.newContext succeeded
2021-04-12T12:24:23.247Z pw:api => browserContext.addInitScript started
2021-04-12T12:24:23.248Z pw:api <= browserContext.addInitScript succeeded
{"level":30,"time":"2021-04-12T12:24:23.273Z","pid":50630,"hostname":"MacBook-Pro-de-Thibault.local","msg":"Changed active context"}
2021-04-12T12:24:23.302Z pw:api => browserContext.newPage started
2021-04-12T12:24:23.969Z pw:api <= browserContext.newPage succeeded
{"level":30,"time":"2021-04-12T12:24:23.969Z","pid":50630,"hostname":"MacBook-Pro-de-Thibault.local","msg":"Video path: undefined"}
{"level":30,"time":"2021-04-12T12:24:23.969Z","pid":50630,"hostname":"MacBook-Pro-de-Thibault.local","msg":"Changed active page"}
2021-04-12T12:24:23.970Z pw:api => page.goto started
2021-04-12T12:24:23.972Z pw:api navigating to "xxxx", waiting until "load"
2021-04-12T12:24:24.109Z pw:api   navigated to "xxxxxx"
2021-04-12T12:24:30.965Z pw:api   "domcontentloaded" event fired
2021-04-12T12:24:31.060Z pw:api   navigated to "xxxxx"
2021-04-12T12:24:32.293Z pw:api   "domcontentloaded" event fired
2021-04-12T12:24:32.299Z pw:api   "load" event fired
2021-04-12T12:24:32.299Z pw:api <= page.goto succeeded
2021-04-12T12:24:32.306Z pw:api => page.waitForSelector started
2021-04-12T12:24:32.309Z pw:api waiting for selector "//td" to be visible
2021-04-12T12:24:32.944Z pw:api   navigated to "http://xxxxxx"
2021-04-12T12:24:33.012Z pw:api   selector resolved to visible <td height="22" align="left" class="papyrusNodeBaseS…>…</td>
2021-04-12T12:24:33.069Z pw:api <= page.waitForSelector succeeded
2021-04-12T12:24:33.073Z pw:api => page.click started
2021-04-12T12:24:33.074Z pw:api waiting for selector "//td[contains(.,'Configurations')]"
2021-04-12T12:24:33.076Z pw:api   selector resolved to visible <td height="22" align="left" class="papyrusNodeBaseS…>…</td>
2021-04-12T12:24:33.079Z pw:api attempting click action
2021-04-12T12:24:33.079Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.116Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.116Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.117Z pw:api   done scrolling
2021-04-12T12:24:33.119Z pw:api   checking that element receives pointer events at (130.47,156)
2021-04-12T12:24:33.122Z pw:api   element does receive pointer events
2021-04-12T12:24:33.122Z pw:api   performing click action
2021-04-12T12:24:33.175Z pw:api   navigated to "http://xxxxx:9081/xxxx/#Configurations"
2021-04-12T12:24:33.202Z pw:api   click action done
2021-04-12T12:24:33.204Z pw:api   waiting for scheduled navigations to finish
2021-04-12T12:24:33.213Z pw:api   navigations have finished
2021-04-12T12:24:33.214Z pw:api <= page.click succeeded
2021-04-12T12:24:33.220Z pw:api => page.click started
2021-04-12T12:24:33.220Z pw:api waiting for selector "//*[@id="isc_3S"]"
2021-04-12T12:24:33.239Z pw:api   selector resolved to visible <span id="isc_3S" $9a="picker" role="button" tabindex=…>…</span>
2021-04-12T12:24:33.242Z pw:api attempting click action
2021-04-12T12:24:33.242Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.265Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.265Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.265Z pw:api   done scrolling
2021-04-12T12:24:33.266Z pw:api   checking that element receives pointer events at (629,141)
2021-04-12T12:24:33.270Z pw:api   <div id="isc_1" class="normal" eventproxy="isc_Canvas…>…</div> intercepts pointer events
2021-04-12T12:24:33.270Z pw:api retrying click action, attempt #1
2021-04-12T12:24:33.270Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.300Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.300Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.303Z pw:api   done scrolling
2021-04-12T12:24:33.304Z pw:api   checking that element receives pointer events at (629,141)
2021-04-12T12:24:33.306Z pw:api   <div id="isc_1" class="normal" eventproxy="isc_Canvas…>…</div> intercepts pointer events
2021-04-12T12:24:33.306Z pw:api retrying click action, attempt #2
2021-04-12T12:24:33.306Z pw:api   waiting 20ms
2021-04-12T12:24:33.328Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.333Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.334Z pw:api element was detached from the DOM, retrying
2021-04-12T12:24:33.334Z pw:api waiting for selector "//*[@id="isc_3S"]"
2021-04-12T12:24:33.335Z pw:api   selector resolved to visible <span id="isc_3S" $9a="picker" role="button" tabindex=…>…</span>
2021-04-12T12:24:33.337Z pw:api attempting click action
2021-04-12T12:24:33.337Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.366Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.366Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.367Z pw:api   done scrolling
2021-04-12T12:24:33.368Z pw:api   checking that element receives pointer events at (603,141)
2021-04-12T12:24:33.370Z pw:api   element does receive pointer events
2021-04-12T12:24:33.370Z pw:api   performing click action
2021-04-12T12:24:33.401Z pw:api   click action done
2021-04-12T12:24:33.401Z pw:api   waiting for scheduled navigations to finish
2021-04-12T12:24:33.414Z pw:api   navigations have finished
2021-04-12T12:24:33.415Z pw:api <= page.click succeeded
2021-04-12T12:24:33.418Z pw:api => page.click started
2021-04-12T12:24:33.419Z pw:api waiting for selector "text="AID""
2021-04-12T12:24:33.428Z pw:api   selector resolved to visible <nobr>AID</nobr>
2021-04-12T12:24:33.430Z pw:api attempting click action
2021-04-12T12:24:33.430Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.448Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.448Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.448Z pw:api   done scrolling
2021-04-12T12:24:33.449Z pw:api   checking that element receives pointer events at (478.17,193)
2021-04-12T12:24:33.451Z pw:api   element does receive pointer events
2021-04-12T12:24:33.451Z pw:api   performing click action
2021-04-12T12:24:33.462Z pw:api   click action done
2021-04-12T12:24:33.462Z pw:api   waiting for scheduled navigations to finish
2021-04-12T12:24:33.464Z pw:api   navigations have finished
2021-04-12T12:24:33.464Z pw:api <= page.click succeeded
2021-04-12T12:24:33.467Z pw:api => page.waitForSelector started
2021-04-12T12:24:33.468Z pw:api waiting for selector "//*[@id="xxx"]" to be visible
2021-04-12T12:24:33.470Z pw:api   selector resolved to visible <input $9a="$9b" type="TEXT" id="xx" tabindex="1712…/>
2021-04-12T12:24:33.473Z pw:api <= page.waitForSelector succeeded
2021-04-12T12:24:33.476Z pw:api => page.fill started
2021-04-12T12:24:33.477Z pw:api waiting for selector "//*[@id="xx"]"
2021-04-12T12:24:33.480Z pw:api   selector resolved to visible <input $9a="$9b" type="TEXT" id="xx" tabindex="1712…/>
2021-04-12T12:24:33.482Z pw:api elementHandle.fill("xx")
2021-04-12T12:24:33.482Z pw:api   waiting for element to be visible, enabled and editable
2021-04-12T12:24:33.486Z pw:api   element is visible, enabled and editable
2021-04-12T12:24:33.504Z pw:api <= page.fill succeeded
2021-04-12T12:24:33.507Z pw:api => page.click started
2021-04-12T12:24:33.507Z pw:api waiting for selector "//*[@id="xx"]"
2021-04-12T12:24:33.510Z pw:api   selector resolved to visible <div id="xx">…</div>
2021-04-12T12:24:33.511Z pw:api attempting click action
2021-04-12T12:24:33.511Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.531Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.531Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.531Z pw:api   done scrolling
2021-04-12T12:24:33.532Z pw:api   checking that element receives pointer events at (797.99,213)
2021-04-12T12:24:33.534Z pw:api   element does receive pointer events
2021-04-12T12:24:33.534Z pw:api   performing click action
2021-04-12T12:24:33.558Z pw:api   click action done
2021-04-12T12:24:33.558Z pw:api   waiting for scheduled navigations to finish
2021-04-12T12:24:33.562Z pw:api   navigations have finished
2021-04-12T12:24:33.562Z pw:api <= page.click succeeded
2021-04-12T12:24:33.584Z pw:api => page.waitForSelector started
2021-04-12T12:24:33.584Z pw:api waiting for selector "//*[@class="xxx"]//tr[x]/td[x]/div" to be visible
2021-04-12T12:24:33.586Z pw:api => page.waitForEvent started
2021-04-12T12:24:33.588Z pw:api waiting for event "download"
2021-04-12T12:24:33.825Z pw:api   selector resolved to visible <div cellclipdiv="true" role="presentation">…</div>
2021-04-12T12:24:33.831Z pw:api <= page.waitForSelector succeeded
2021-04-12T12:24:33.835Z pw:api => page.click started
2021-04-12T12:24:33.835Z pw:api waiting for selector "//*[@name="xxxx"]"
2021-04-12T12:24:33.838Z pw:api   selector resolved to visible <img width="16" border="0" height="16" align="TEXTTOP…/>
2021-04-12T12:24:33.843Z pw:api attempting click action
2021-04-12T12:24:33.843Z pw:api   waiting for element to be visible, enabled and stable
2021-04-12T12:24:33.865Z pw:api   element is visible, enabled and stable
2021-04-12T12:24:33.865Z pw:api   scrolling into view if needed
2021-04-12T12:24:33.865Z pw:api   done scrolling
2021-04-12T12:24:33.866Z pw:api   checking that element receives pointer events at (1182.37,697)
2021-04-12T12:24:33.868Z pw:api   element does receive pointer events
2021-04-12T12:24:33.868Z pw:api   performing click action
2021-04-12T12:24:33.883Z pw:api   click action done
2021-04-12T12:24:33.883Z pw:api   waiting for scheduled navigations to finish
2021-04-12T12:24:33.886Z pw:api   navigations have finished
2021-04-12T12:24:33.887Z pw:api <= page.click succeeded
2021-04-12T12:24:34.211Z pw:api   "domcontentloaded" event fired
2021-04-12T12:24:34.212Z pw:api   "load" event fired
2021-04-12T12:24:34.472Z pw:api <= page.waitForEvent succeeded
2021-04-12T12:24:34.499Z pw:api => download.saveAs started

saussact avatar Apr 12 '21 12:04 saussact

Interesting, last lines of logs indicates that download did start, but it does not end. Interesting, which means that I am out of ideas... Will ask from rest of the team do they have better ideas.

aaltat avatar Apr 12 '21 18:04 aaltat

exactly... not understandable :(

saussact avatar Apr 12 '21 19:04 saussact

Maybe related to this playwright problem? https://github.com/microsoft/playwright/issues/5962

emakaay avatar Apr 15 '21 20:04 emakaay

Promise to Wait for download seems to have an internal timeout.

mkorpela avatar Apr 19 '21 06:04 mkorpela

I have the same issue in headful mode (chromium, robotframework==4.0.3, robotframework-browser==5.0.1), in headless mode it just fails with Error: .saveAs: EPERM: operation not permitted, copyfile '...\robot_downloads\02ce5a1e-bfdf-4be9-977b-71daa7112eec' -> '...\robot_downloads' error

apple-blossom avatar Jun 08 '21 11:06 apple-blossom

Just a check. Did you enable downloading by adding the option acceptDownload=True when creating new context?

Otherwise downloading is not possible at all

emakaay avatar Jun 08 '21 12:06 emakaay

Just a check. Did you enable downloading by adding the option acceptDownload=True when creating new context?

Otherwise downloading is not possible at all

Yes, I'm using Wait For Download keyword rn and it works, but with Promise To Wait For Download it doesn't (used it same as in docs example)

apple-blossom avatar Jun 08 '21 13:06 apple-blossom

image

Here, delete downloadsPath=${download_dir} try again

xsxy5437 avatar Feb 22 '23 03:02 xsxy5437

As if i see it correctly this has been solved on the Playwright side. Therefore closing this issue. I tested it and imho it works fine now.

Snooz82 avatar Nov 08 '23 15:11 Snooz82