ICEpush
  1. ICEpush
  2. PUSH-165

fileEntry progress not pushed/pulled properly

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.0
    • Fix Version/s: 3.0.1, EE 3.0.0
    • Labels:
      None
    • Environment:
      ICEpush, ACE fileEntry. Firefox, Safari.

      Description

      From the server side, fileEntry tries to push updates after every 2 seconds, and only if the client has not fallen far behind in receiving the pushes, or else it freezes after the upload has completed, trying to catch-up on the queued push notifications.

      Right now I'm observing a behaviour where only the 100% progress is being shown, and possibly an early 1% progress, and maybe another sporadic update, on uploads that take 50+ seconds, for large files.


      Here's the raw log:

      tryPush() percent: 1
      updateResourceContents() contents: {"percent":1,"results":["example-form:file-entry"]}
      deltaGottenPushed: 2 lastDeltaGottenPushed: 0
      tryPush() Pushed progress update
      ProgressResource.getInputStream() progressInfo: {"percent":1,"results":["example-form:file-entry"]}
      ProgressResource.getInputStream() progressInfo: {"percent":1,"results":["example-form:file-entry"]}
      tryPush() percent: 29
      updateResourceContents() contents: {"percent":29,"results":["example-form:file-entry"]}
      deltaGottenPushed: 1 lastDeltaGottenPushed: 0
      tryPush() Pushed progress update
      tryPush() percent: 51
      updateResourceContents() contents: {"percent":51,"results":["example-form:file-entry"]}
      deltaGottenPushed: 2 lastDeltaGottenPushed: 0
      tryPush() Pushed progress update
      tryPush() percent: 66
      updateResourceContents() contents: {"percent":66,"results":["example-form:file-entry"]}
      deltaGottenPushed: 3 lastDeltaGottenPushed: 0
      tryPush() percent: 79
      updateResourceContents() contents: {"percent":79,"results":["example-form:file-entry"]}
      deltaGottenPushed: 4 lastDeltaGottenPushed: 3
      tryPush() Pushed progress update
      tryPush() percent: 98
      updateResourceContents() contents: {"percent":98,"results":["example-form:file-entry"]}
      deltaGottenPushed: 5 lastDeltaGottenPushed: 3
      ProgressResource.getInputStream() progressInfo: {"percent":98,"results":["example-form:file-entry"]}
      ProgressResource.getInputStream() progressInfo: {"percent":98,"results":["example-form:file-entry"]}
      tryPush() percent: 100
      updateResourceContents() contents: {"percent":100,"results":["example-form:file-entry"]}
      deltaGottenPushed: 4 lastDeltaGottenPushed: 5
      tryPush() Pushed progress update
      ProgressResource.getInputStream() progressInfo: {"percent":100,"results":["example-form:file-entry"]}
      ProgressResource.getInputStream() progressInfo: {"percent":100,"results":["example-form:file-entry"]}
      ProgressResource.getInputStream() progressInfo: {"percent":100,"results":["example-form:file-entry"]}
      ProgressResource.getInputStream() progressInfo: {"percent":100,"results":["example-form:file-entry"]}


      What that actually meant was that:

      2 second rate limited code path at 1%
      - Updated progress resource to contain 1%
      - The progress resource reads aren't too far behind the pushes, so do a push of 1%

      Progress resource being read twice in rapid succession, possibly framework itself causing double access for single GET. For 1%

      2 second rate limited code path at 29%
      - Updated progress resource to contain 29%
      - The progress resource reads aren't too far behind the pushes, so do a push of 29%

      2 second rate limited code path at 51%
      - Updated progress resource to contain 51%
      - The progress resource reads aren't too far behind the pushes, so do a push of 51%

      2 second rate limited code path at 66%
      - Updated progress resource to contain 66%
      - The progress resource reads have fallen behind the pushes, so do not do a push of 66%

      2 second rate limited code path at 79%
      - Updated progress resource to contain 79%
      - The progress resource reads have fallen behind the pushes, so do not do a push of 79%

      2 second rate limited code path at 98%
      - Updated progress resource to contain 98%
      - The progress resource reads have fallen behind the pushes, so do not do a push of 98%

      Progress resource being read twice in rapid succession, possibly framework itself causing double access for single GET. For 98%

      Final update code path at 100%
      - Updated progress resource to contain 100%
      - Force a push of 100%

      Progress resource being read twice in rapid succession, possibly framework itself causing double access for single GET. For 100%

      Progress resource being read twice in rapid succession, possibly framework itself causing double access for single GET. For 100%


      So, we did a total of 4 pushes and there were 4 reads. The rate limiting worked, where we didn't flood the pushes too frequently, and adapt to the browser not reading frequently. But, the problem we do have, is that the browser is not reading the progress resource soon enough. The browser should be able to read the progress resource more than 4x in almost a minute. It's not clear to me if the server is taking too long to notify the browser of a push, or if the browser is taking too long to respond to a push that it has received. Or both.

        Activity

        Hide
        Mark Collette added a comment -

        Further testing shows a large inconsistency between progress being granular and not. Safari seems to outperform Firefox.

        Show
        Mark Collette added a comment - Further testing shows a large inconsistency between progress being granular and not. Safari seems to outperform Firefox.
        Hide
        Mark Collette added a comment -

        If you test with showcase, make sure you disable the maximum file size properties set on the fileEntry.

        Show
        Mark Collette added a comment - If you test with showcase, make sure you disable the maximum file size properties set on the fileEntry.
        Hide
        Mircea Toma added a comment -

        The ice.ace.fileentry.onProgress callback is re-registered every time an upload is executed. So after each upload when a push notification is received there is an additional request made by the component code.
        The fix applied moves the onProgress callback registration into the captureFormOnsubmit() function (wich is invoked once).

        Show
        Mircea Toma added a comment - The ice.ace.fileentry.onProgress callback is re-registered every time an upload is executed. So after each upload when a push notification is received there is an additional request made by the component code. The fix applied moves the onProgress callback registration into the captureFormOnsubmit() function (wich is invoked once).
        Hide
        Mircea Toma added a comment -

        After applying the fix FF seems to behave quite well. Uploading locally a 400Mb file shows about 18-24 increments in the progress bar.
        The browser does choke towards the end of the upload though, FF's cpu usage spikes to 98% with an abrupt decrease after a few second, the hard disk is also working hard giving an indication that FF is doing some cleanup at the end of the upload.

        Show
        Mircea Toma added a comment - After applying the fix FF seems to behave quite well. Uploading locally a 400Mb file shows about 18-24 increments in the progress bar. The browser does choke towards the end of the upload though, FF's cpu usage spikes to 98% with an abrupt decrease after a few second, the hard disk is also working hard giving an indication that FF is doing some cleanup at the end of the upload.
        Hide
        Ken Fyten added a comment -

        Please commit this change to the icefaces-3.0.x-maintenance branch.

        Show
        Ken Fyten added a comment - Please commit this change to the icefaces-3.0.x-maintenance branch.

          People

          • Assignee:
            Mircea Toma
            Reporter:
            Mark Collette
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: