Skip to content

Remove 1s minimum delay in Invoke-WebRequest for small files, and prevent file-download-error suppression.#17896

Merged
iSazonov merged 10 commits intoPowerShell:masterfrom
AAATechGuy:master
Aug 23, 2022
Merged

Remove 1s minimum delay in Invoke-WebRequest for small files, and prevent file-download-error suppression.#17896
iSazonov merged 10 commits intoPowerShell:masterfrom
AAATechGuy:master

Conversation

@AAATechGuy
Copy link
Contributor

@AAATechGuy AAATechGuy commented Aug 14, 2022

PR Summary

Fix #17893

Both Invoke-RestMethod and Invoke-WebRequest showed 20x latency of 1000ms when downloading a web item via pscore 7, that typically takes ~60ms in ps 5, In StreamHelper there is a constant minimum delay of 1s for any calls to StreamHelper.WriteToStream. This is not expected.

If Invoke-WebRequest / Invoke-RestMethod are used in parallel and for large volume of items, the 1s delay adds up.

We fix this issue by replacing Task.Delay check with copyTask.Wait.

The change does take into consideration,

  • to exit immediately if copyTask succeeds.
  • to wait for 1s, for progress update, in case task takes longer.
  • to throw exception, in case task fails [although, I think this may not have the right parity with earlier code]

Fix #17931

We also fix the issue where failure in download results in partial file being saved, and exception being suppressed.

PR Context

Tested that perf improves after fix, locally,
image

Earlier, latency was as follows,
image

PR Checklist

@AAATechGuy AAATechGuy requested a review from PaulHigin as a code owner August 14, 2022 08:23
@ghost ghost assigned iSazonov Aug 14, 2022
@iSazonov iSazonov added the CL-General Indicates that a PR should be marked as a general cmdlet change in the Change Log label Aug 14, 2022
@iSazonov iSazonov requested a review from SteveL-MSFT August 14, 2022 08:55
@SteveL-MSFT SteveL-MSFT added this to the 7.3-Consider milestone Aug 14, 2022
@ghost ghost removed this from the 7.3-Consider milestone Aug 14, 2022
@ghost
Copy link

ghost commented Aug 14, 2022

Open PRs should not be assigned to milestone, so they are not assigned to the wrong milestone after they are merged. For backport consideration, use a backport label.

@AAATechGuy AAATechGuy changed the title Remove 1s minimum delay when calling Invoke-WebRequest or Invoke-RestMethod with response to file. Remove 1s minimum delay when calling Invoke-WebRequest or Invoke-RestMethod with response written to file. Aug 14, 2022
@iSazonov
Copy link
Collaborator

iSazonov commented Aug 15, 2022

Hmm, looking how Task.Wait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken) method works, I think we could refactor the cycle condition (we can not check cancelation since it throws):

                while (!copyTask.Wait(1000, cancellationToken))
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestProgressStatus, output.Position);
                    cmdlet.WriteProgress(record);
                };

                record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestComplete, output.Position);
                cmdlet.WriteProgress(record);

@AAATechGuy
Copy link
Contributor Author

Hmm, looking how Task.Wait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken) method works, I think we could refactor the cycle condition (we can not check cancelation since it throws):

                while (!copyTask.Wait(1000, cancellationToken))
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestProgressStatus, output.Position);
                    cmdlet.WriteProgress(record);
                };

                record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestComplete, output.Position);
                cmdlet.WriteProgress(record);

In addition to modifying the loop logic, I added a catch for AggregateException to handle the specific scenario where copyTask throws any exception.
Previously, no exception is thrown. I kept that behavior,

I have tested on mock code here: AAATechGuy/AbinzSharedTools@e9dbe47
Output below.


[06:41:08.643] *** Execute.start
[06:41:08.667] .
[06:41:08.698] task-begin
[06:41:08.762] task-end
[06:41:09.694] Completed
[06:41:09.694] *** Execute.complete : elapsed 1043 ms


[06:41:09.695] *** Execute.start
[06:41:09.696] task-begin
[06:41:09.771] task-end
[06:41:09.772] Completed
[06:41:09.772] *** Execute.complete : elapsed 77 ms


[06:41:09.772] *** Execute.start
[06:41:09.773] .
[06:41:09.773] task-begin
[06:41:10.774] .
[06:41:10.837] task-end
[06:41:11.777] Completed
[06:41:11.778] *** Execute.complete : elapsed 2004 ms


[06:41:11.778] *** Execute.start
[06:41:11.779] task-begin
[06:41:12.781] .
[06:41:12.842] task-end
[06:41:12.843] Completed
[06:41:12.843] *** Execute.complete : elapsed 1064 ms


[06:41:12.845] *** Execute.start
[06:41:12.845] .
[06:41:12.846] task-begin
[06:41:13.846] Completed
[06:41:13.846] *** Execute.complete : elapsed 1001 ms


[06:41:13.847] *** Execute.start
[06:41:13.848] task-begin
[06:41:14.010] AggregateException
[06:41:14.010] *** Execute.complete : elapsed 162 ms


[06:41:14.011] *** Execute.start
[06:41:14.011] .
[06:41:14.011] task-begin
[06:41:14.171] OperationCanceledException
[06:41:14.171] *** Execute.complete : elapsed 160 ms


[06:41:14.172] *** Execute.start
[06:41:14.173] task-begin
[06:41:14.319] OperationCanceledException
[06:41:14.320] *** Execute.complete : elapsed 147 ms

[06:41:15.083] task-end
[06:41:15.241] task-end

@iSazonov
Copy link
Collaborator

@AAATechGuy Please rename the PR to something like "Remove 1s minimum delay in Invoke-WebRequest for small files."

@AAATechGuy AAATechGuy changed the title Remove 1s minimum delay when calling Invoke-WebRequest or Invoke-RestMethod with response written to file. Remove 1s minimum delay in Invoke-WebRequest for small files. Aug 15, 2022
Copy link
Member

@SteveL-MSFT SteveL-MSFT left a comment

Choose a reason for hiding this comment

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

Agree that we shouldn't ignore download exceptions

@ghost ghost added the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Aug 15, 2022
Copy link
Contributor

@PaulHigin PaulHigin left a comment

Choose a reason for hiding this comment

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

LGTM after addressing @iSazonov comment.

@iSazonov
Copy link
Collaborator

@AAATechGuy You comment in review mode - open Files changed tab and cancel review mode on top right.

Previously we catch and ignore only OperationCanceledException. You added AggregateException - please revert this.

@ghost ghost removed the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Aug 16, 2022
…Cmdlet/StreamHelper.cs

Co-authored-by: Ilya <darpa@yandex.ru>
@SteveL-MSFT
Copy link
Member

SteveL-MSFT commented Aug 17, 2022

I discussed this with @AAATechGuy and what we agreed is that for 7.3 we should not change the current behavior which is an exception during the copy task is ignored. For 7.4, we should take another change that does not ignore the exception and see if there are any unanticipated side effects as this seems to be the correct change for the long term.

…lity/WebCmdlet/StreamHelper.cs"

This reverts commit d172ef0.
@iSazonov
Copy link
Collaborator

iSazonov commented Aug 18, 2022

My understanding was that we don't ignore exceptions from the copy task. It was my mistake and it is a regression.

It is not easy to get an exception from the copy task. I disconnected network for ~1 minutes and restore it. Original cmdlet waits some seconds and silently stop with semi-downloaded file. With the change (without catching AggregateException) user get follow error:
image

I think it is right behavior and we should remove the regression.


There is also another issue with CopyToAsync(). If I disconnected network for long time (2 minutes in my experiment) the cmdlet hangs unlimitedly. It is not a problem in interactive scenario since user see a progress bar, but it is huge problem for script scenario since the script can hangs infinitely.
Related issue dotnet/runtime#36822. I think we need to support the cmdlet Timeout parameter here by checking output Stream.Position (or Stream.Length) or we could put the functionality (throw a timeout exception) in WebResponseContentMemoryStream class. Or better use the code example https://github.com/dotnet/runtime/blob/e71a9583b4d6c9bd97edd87cda7f98f232f63530/src/libraries/System.Net.Requests/src/System/Net/HttpWebRequest.cs#L1666-L1702

GitHub
.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps. - runtime/HttpWebRequest.cs at e71a9583b4d6c9bd97edd87cda7f98f232f63530 · dotnet/runtime

@SteveL-MSFT
Copy link
Member

Talking to @PaulHigin, let's defer taking any change here for 7.3 and make what we agree is the right change (throwing the inner exception from the aggregate) for 7.4 so we have opportunity to see if there's side effects.

@AAATechGuy
Copy link
Contributor Author

  • we do not check-in any fix for 7.3 as it's too late in the cycle.

So we should add catch (AggregateException) {}, don't it?

7.3 - no change.

7.4 - we fix two issues:
a. copyTask.Wait - improve perf.
b. we fix earlier issue that partial download silently fails.
a is the fix. Newly changed behavior will throw AggregateException for any download/disk-space issues. This ex is not suppressed and shown to the ps-user.

Copy link
Member

@daxian-dbw daxian-dbw left a comment

Choose a reason for hiding this comment

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

According to Steve's comment #17896 (comment) (quoted below), the changes from this PR will not be included in 7.3.

Talking to @PaulHigin, let's defer taking any change here for 7.3 and make what we agree is the right change (throwing the inner exception from the aggregate) for 7.4 so we have opportunity to see if there's side effects.

So, we should go with the desired behavior -- throwing inner exceptions from the aggregate exception.

@ghost ghost added the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Aug 19, 2022
@AAATechGuy
Copy link
Contributor Author

According to Steve's comment #17896 (comment) (quoted below), the changes from this PR will not be included in 7.3.

Talking to @PaulHigin, let's defer taking any change here for 7.3 and make what we agree is the right change (throwing the inner exception from the aggregate) for 7.4 so we have opportunity to see if there's side effects.

So, we should go with the desired behavior -- throwing inner exceptions from the aggregate exception.

@daxian-dbw , throwing inner exceptions from the aggregate exception, what does this mean - could you suggest a code sample?

My thought is ...
The script will throw an AggregateException which is the right behavior, we do not suppress any exception. There could be multiple exceptions thrown by copyTask, for which I do not have the whole list.

From a PS-user perspective, as @iSazonov tested out here #17896 (comment) , AggregateException does display a sensible error.

@ghost ghost removed the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Aug 20, 2022
@iSazonov
Copy link
Collaborator

could you suggest a code sample?

As I understand @SteveL-MSFT, for 7.3 we do semi perf fix with preserving current behavior:

            try
            {
                while (!copyTask.Wait(1000, cancellationToken))
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestProgressStatus, output.Position);
                    cmdlet.WriteProgress(record);
                }

                if (copyTask.IsCompleted)
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestComplete, output.Position);
                    cmdlet.WriteProgress(record);
                }
            }
            catch (OperationCanceledException)
            {
            }
            catch (AggregateException ae)
            {
            }

and for 7.4 we do full fix:

            try
            {
                while (!copyTask.Wait(1000, cancellationToken))
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestProgressStatus, output.Position);
                    cmdlet.WriteProgress(record);
                }

                if (copyTask.IsCompleted)
                {
                    record.StatusDescription = StringUtil.Format(WebCmdletStrings.WriteRequestComplete, output.Position);
                    cmdlet.WriteProgress(record);
                }
            }
            catch (OperationCanceledException)
            {
            }
            catch (AggregateException)
            {
                ae.Handle((x) =>
                {
                    return false;  // Let all wrapped exceptions throw and be handled in calling layers
                });
            }

and also address second issue (hang) I mentioned above.

@AAATechGuy
Copy link
Contributor Author

AAATechGuy commented Aug 21, 2022

As I understand @SteveL-MSFT, for 7.3 we do semi perf fix with preserving current behavior:

No,

That was a previous/ stale suggestion here - comment1.

In the latest comment here - comment2, it was discussed, no fix will be taken for 7.3. Hence, the confusion.
Fix for both issues ( #17893 and #17931 ) will be checked-in together for 7.4 (Oct-Nov timeframe).

        catch (AggregateException)
        {
            ae.Handle((x) =>
            {
                return false;  // Let all wrapped exceptions throw and be handled in calling layers
            });
        }

Now, for 7.4, I discussed with @PaulHigin and agreed offline, there is no need to catch AggregateException and use ae.Handle. ae.Handle does not unwrap the exception, instead it just throws another AggregateException based on the filter provided. There is no point in handling it, if we do not want to suppress any exception.

Hope this clarifies.

@AAATechGuy AAATechGuy requested review from daxian-dbw and iSazonov and removed request for daxian-dbw and iSazonov August 21, 2022 08:06
@PaulHigin
Copy link
Contributor

We can only throw one exception, so it will have to be the AggregateException, if it contains more than one inner exception. I don't think it is worth checking and we just allow the AggregateException to propagate.

Copy link
Member

@daxian-dbw daxian-dbw left a comment

Choose a reason for hiding this comment

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

throwing inner exceptions from the aggregate exception, what does this mean - could you suggest a code sample?

I was repeating @SteveL-MSFT's comment and thought that was the conclusion made.
Not catch the exception looks correct to me.

@iSazonov
Copy link
Collaborator

@daxian-dbw Can we merge this now or do we wait 7.4?

@SteveL-MSFT
Copy link
Member

@iSazonov I believe we've branched for 7.3, so master branch is effectively 7.4 now and should be ok to merge. We cherry pick for 7.3 at this point.

@AAATechGuy
Copy link
Contributor Author

@iSazonov I believe we've branched for 7.3, so master branch is effectively 7.4 now and should be ok to merge. We cherry pick for 7.3 at this point.

nice. Can someone help merge this PR then. I don't appear to have permissions. thanks!

@iSazonov iSazonov merged commit fdf3c9a into PowerShell:master Aug 23, 2022
@iSazonov
Copy link
Collaborator

@SteveL-MSFT Thanks for clarify!

@AAATechGuy thanks for your contribution! Do you have plans to continue with fixing socket timeout #17896 (comment)?

@AAATechGuy
Copy link
Contributor Author

@SteveL-MSFT Thanks for clarify!

@AAATechGuy thanks for your contribution! Do you have plans to continue with fixing socket timeout #17896 (comment)?

Thanks for the merge, and for all the reviews, discussions and testing.

@iSazonov , no, I don't plan to fix socket timeout issue, at the moment.

@adityapatwardhan
Copy link
Member

/backport to release/v7.2.7

@ghost
Copy link

ghost commented Dec 20, 2022

🎉v7.4.0-preview.1 has been released which incorporates this pull request.:tada:

Handy links:

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

Labels

Backport-7.2.x-Done CL-General Indicates that a PR should be marked as a general cmdlet change in the Change Log Extra Small

Projects

None yet

7 participants