[release/3.1] [coreclr] Fix FileStream.Dispose silently fails on Dispose when disk has run out of space

[carlossanlop]

Backporting PR dotnet/runtime#38742

The test goes into corefx: dotnet/corefx#42988

Fixes: dotnet/runtime#42360

Customer Impact

A customer hit this issue in 3.1 when trying to deploy to AzureStorage: dotnet/runtime#42360

On Unix, when the disk runs out of space before a FileStream is disposed and the buffer is flushed to disk, Dispose silently succeeds, causing files to be corrupted and preventing the user from taking corrective action.

On Windows, we throw at the expected moment, allowing the user to react appropriately.

The suggested fix is to save any error thrown when the SafeFileHandle.ReleaseHandle method is called when the handle is disposed, then check that saved error in FileStream.Dispose, and throw an exception if there was an error.

The customer who reported this issue stated they will not be able to migrate to 5.0 soon.

Testing

• Manually verified using the provided manual test introduced in the corefx change.
• The customer verified the behavior in 5.0 and confirmed that their issue is gone in that version, which justifies the backport ([3.1] [Linux] Writing a file that takes you over the storage quota in Azure file storage silently fails runtime#42360 (comment))
• The customer that reported the issue for 3.1 verified this code fix with a private DLL sent to them, and verified the exception is now being thrown as expected ([3.1] [Linux] Writing a file that takes you over the storage quota in Azure file storage silently fails runtime#42360 (comment))

Risk

Low.

This is a straight port of code already proven in 5.0. The code is simply doing an additional check that will ensure an exception is thrown so the user can be notified of failure.

[danmoseley]

@dotnet/dnceng can you please help with the Helix internal server error 500's here?

[MattGal]

@dotnet/dnceng can you please help with the Helix internal server error 500's here?

Taking a quick peek, likely fallout from flipping over to the new Helix API earlier.

[MattGal]

@danmosemsft filed https://github.com/dotnet/core-eng/issues/10854 and flipped the API back to the old one; we'll take another swing at keeping the old APIs working next week.

[danmoseley]

thanks. let's try again

[jozkee]

Lgtm, given that it is a direct port.

[carlossanlop]

The unit test failure is unrelated to my changes:

System.Text.RegularExpressions

Executed on a0041PO
+ export __TestEnv=/home/helixbot/work/A3890931/p/SetStressModes_no_tiered_compilation.sh
+ cat /home/helixbot/work/A3890931/p/SetStressModes_no_tiered_compilation.sh
#!/usr/bin/env bash
export COMPlus_TieredCompilation=0
+ . /home/helixbot/work/A3890931/p/SetStressModes_no_tiered_compilation.sh
+ export COMPlus_TieredCompilation=0
+ printenv
+ grep COMPlus
COMPlus_TieredCompilation=0
+ ./RunTests.sh -r /home/helixbot/work/A3890931/p --rsp-file /home/helixbot/work/A3890931/p/CoreFX.issues.rsp
----- start Sat Sep 19 01:46:31 UTC 2020 =============== To repro directly: =====================================================
pushd .
/home/helixbot/work/A3890931/p/dotnet exec --runtimeconfig System.Text.RegularExpressions.Tests.runtimeconfig.json xunit.console.dll System.Text.RegularExpressions.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing @/home/helixbot/work/A3890931/p/CoreFX.issues.rsp
popd
===========================================================================================================
~/work/A3890931/w/B06109AA/e ~/work/A3890931/w/B06109AA/e
Discovering: System.Text.RegularExpressions.Tests (method display = ClassAndMethod, method display options = None)
Discovered:  System.Text.RegularExpressions.Tests (found 134 of 135 test cases)
Starting:    System.Text.RegularExpressions.Tests (parallel test collections = on, max threads = 2)
./RunTests.sh: line 161: 22885 Killed                  "$RUNTIME_PATH/dotnet" exec --runtimeconfig System.Text.RegularExpressions.Tests.runtimeconfig.json xunit.console.dll System.Text.RegularExpressions.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing $RSP_FILE
~/work/A3890931/w/B06109AA/e
----- end Sat Sep 19 01:47:41 UTC 2020 ----- exit code 137 ----------------------------------------------------------
exit code 137 means SIGKILL Killed eg by kill
Looking around for any Linux dump...
... found no dump in /home/helixbot/work/A3890931/w/B06109AA/e
+ export _commandExitCode=137
+ /bin/sh /home/helixbot/work/A3890931/p/reporter/run.sh https://dev.azure.com/dnceng/ public 26144188 eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6Im9PdmN6NU1fN3AtSGpJS2xGWHo5M3VfVjBabyJ9.eyJuYW1laWQiOiJlNDI4NWM4Yy0zZmQ1LTQyNjctOWIxYy00MjE5NWM0N2E1NTMiLCJzY3AiOiJMb2NhdGlvblNlcnZpY2UuQ29ubmVjdCBQaXBlbGluZUNhY2hlLlJlYWRXcml0ZVJvb3RBY2Nlc3MgUmVhZEFuZFB1Ymxpc2hUZXN0OjllZTZkNDc4LWQyODgtNDdmNy1hYWNjLWY2ZTZkMDgyYWU2ZCBSZWFkQW5kVXBkYXRlQnVpbGRCeVVyaTo5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQvZG90bmV0L2NvcmVjbHIvMjI4OkJ1aWxkL0J1aWxkLzgyMDE5OCIsImF1aSI6ImYyMWI1MGNkLWI0YmEtNDY4Yi04ZGNmLTkyOWY3YTVjYjQ5NSIsInNpZCI6IjlhYzM0OWNmLTI5MzktNDA3My05NjljLWM5ZjI5N2ExNzZmMSIsIkJ1aWxkSWQiOiI5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQ7ODIwMTk4Iiwib3JjaGlkIjoiNGU5OTE1NTUtMjdjMi00ZTZhLTlkYWMtYzYwNjU3ZGQxYzgwLnRlc3RfcDBfY29yZWZ4X2xpbnV4X3g2NF9jaGVja2VkLl9fZGVmYXVsdC4yIiwiaXNzIjoiYXBwLnZzdG9rZW4udmlzdWFsc3R1ZGlvLmNvbSIsImF1ZCI6ImFwcC52c3Rva2VuLnZpc3VhbHN0dWRpby5jb218dnNvOmI1NWRlNGVkLTRiNWEtNDIxNS1hOGU0LTBhMGE1ZjcxZTdkOCIsIm5iZiI6MTYwMDQ2OTQ4MywiZXhwIjoxNjAwNDg1MDgzfQ.rvxe8aTZKVMnyQGIyXXrfVp7kF81auzYYs6aY7D7whTxyGgewiURc_YWC3aAUs1YI8BxTuJFZQ_oed-40HY-nN3z9fcFtxmH1Ow3vOkHSUSDUGeAykFE4aQDcO04-jBwLEbQuVvZI2IdUQvsRR_wMLwKHA2JXOxsZ9ngHGlTxq9SRhqpbVX131gSRfFfRT5cRl3g8TYlnOY8iImAocOSwUfnbU9RRrCsWwFTGh4n99BH-5lEouGGuIwhCtEF2onuU7JyMJJHFqAknBFGNEzqsIq7amvymG94BNITgGqDgcipBCrzhEv_J5q_YYl0QF-AuS7UeSpHkAeFu0dvB5ogBA
+ whoami
+ [ helixbot = root ]
+ exec sudo -E /home/helixbot/work/A3890931/p/reporter/run.sh https://dev.azure.com/dnceng/ public 26144188 eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6Im9PdmN6NU1fN3AtSGpJS2xGWHo5M3VfVjBabyJ9.eyJuYW1laWQiOiJlNDI4NWM4Yy0zZmQ1LTQyNjctOWIxYy00MjE5NWM0N2E1NTMiLCJzY3AiOiJMb2NhdGlvblNlcnZpY2UuQ29ubmVjdCBQaXBlbGluZUNhY2hlLlJlYWRXcml0ZVJvb3RBY2Nlc3MgUmVhZEFuZFB1Ymxpc2hUZXN0OjllZTZkNDc4LWQyODgtNDdmNy1hYWNjLWY2ZTZkMDgyYWU2ZCBSZWFkQW5kVXBkYXRlQnVpbGRCeVVyaTo5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQvZG90bmV0L2NvcmVjbHIvMjI4OkJ1aWxkL0J1aWxkLzgyMDE5OCIsImF1aSI6ImYyMWI1MGNkLWI0YmEtNDY4Yi04ZGNmLTkyOWY3YTVjYjQ5NSIsInNpZCI6IjlhYzM0OWNmLTI5MzktNDA3My05NjljLWM5ZjI5N2ExNzZmMSIsIkJ1aWxkSWQiOiI5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQ7ODIwMTk4Iiwib3JjaGlkIjoiNGU5OTE1NTUtMjdjMi00ZTZhLTlkYWMtYzYwNjU3ZGQxYzgwLnRlc3RfcDBfY29yZWZ4X2xpbnV4X3g2NF9jaGVja2VkLl9fZGVmYXVsdC4yIiwiaXNzIjoiYXBwLnZzdG9rZW4udmlzdWFsc3R1ZGlvLmNvbSIsImF1ZCI6ImFwcC52c3Rva2VuLnZpc3VhbHN0dWRpby5jb218dnNvOmI1NWRlNGVkLTRiNWEtNDIxNS1hOGU0LTBhMGE1ZjcxZTdkOCIsIm5iZiI6MTYwMDQ2OTQ4MywiZXhwIjoxNjAwNDg1MDgzfQ.rvxe8aTZKVMnyQGIyXXrfVp7kF81auzYYs6aY7D7whTxyGgewiURc_YWC3aAUs1YI8BxTuJFZQ_oed-40HY-nN3z9fcFtxmH1Ow3vOkHSUSDUGeAykFE4aQDcO04-jBwLEbQuVvZI2IdUQvsRR_wMLwKHA2JXOxsZ9ngHGlTxq9SRhqpbVX131gSRfFfRT5cRl3g8TYlnOY8iImAocOSwUfnbU9RRrCsWwFTGh4n99BH-5lEouGGuIwhCtEF2onuU7JyMJJHFqAknBFGNEzqsIq7amvymG94BNITgGqDgcipBCrzhEv_J5q_YYl0QF-AuS7UeSpHkAeFu0dvB5ogBA
+ whoami
+ [ root = root ]
+ dirname -- /home/helixbot/work/A3890931/p/reporter/run.sh
+ CDPATH= cd -- /home/helixbot/work/A3890931/p/reporter
+ pwd
+ script_path=/home/helixbot/work/A3890931/p/reporter
+ ENV_PATH=/home/helixbot/.vsts-env
+ TMP_ENV_PATH=/home/helixbot/.vsts-env-tmp
+ date -u +%FT%TZ
2020-09-19T01:47:41Z
+ [ ! -f /home/helixbot/.vsts-env/bin/python ]
+ /home/helixbot/.vsts-env/bin/python -c import azure.devops
+ echo azure-devops module already available
azure-devops module already available
+ /home/helixbot/.vsts-env/bin/python -c import future
+ echo future module already available
future module already available
+ date -u +%FT%TZ
2020-09-19T01:47:41Z
+ /home/helixbot/.vsts-env/bin/python /home/helixbot/work/A3890931/p/reporter/run.py https://dev.azure.com/dnceng/ public 26144188 eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiIsIng1dCI6Im9PdmN6NU1fN3AtSGpJS2xGWHo5M3VfVjBabyJ9.eyJuYW1laWQiOiJlNDI4NWM4Yy0zZmQ1LTQyNjctOWIxYy00MjE5NWM0N2E1NTMiLCJzY3AiOiJMb2NhdGlvblNlcnZpY2UuQ29ubmVjdCBQaXBlbGluZUNhY2hlLlJlYWRXcml0ZVJvb3RBY2Nlc3MgUmVhZEFuZFB1Ymxpc2hUZXN0OjllZTZkNDc4LWQyODgtNDdmNy1hYWNjLWY2ZTZkMDgyYWU2ZCBSZWFkQW5kVXBkYXRlQnVpbGRCeVVyaTo5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQvZG90bmV0L2NvcmVjbHIvMjI4OkJ1aWxkL0J1aWxkLzgyMDE5OCIsImF1aSI6ImYyMWI1MGNkLWI0YmEtNDY4Yi04ZGNmLTkyOWY3YTVjYjQ5NSIsInNpZCI6IjlhYzM0OWNmLTI5MzktNDA3My05NjljLWM5ZjI5N2ExNzZmMSIsIkJ1aWxkSWQiOiI5ZWU2ZDQ3OC1kMjg4LTQ3ZjctYWFjYy1mNmU2ZDA4MmFlNmQ7ODIwMTk4Iiwib3JjaGlkIjoiNGU5OTE1NTUtMjdjMi00ZTZhLTlkYWMtYzYwNjU3ZGQxYzgwLnRlc3RfcDBfY29yZWZ4X2xpbnV4X3g2NF9jaGVja2VkLl9fZGVmYXVsdC4yIiwiaXNzIjoiYXBwLnZzdG9rZW4udmlzdWFsc3R1ZGlvLmNvbSIsImF1ZCI6ImFwcC52c3Rva2VuLnZpc3VhbHN0dWRpby5jb218dnNvOmI1NWRlNGVkLTRiNWEtNDIxNS1hOGU0LTBhMGE1ZjcxZTdkOCIsIm5iZiI6MTYwMDQ2OTQ4MywiZXhwIjoxNjAwNDg1MDgzfQ.rvxe8aTZKVMnyQGIyXXrfVp7kF81auzYYs6aY7D7whTxyGgewiURc_YWC3aAUs1YI8BxTuJFZQ_oed-40HY-nN3z9fcFtxmH1Ow3vOkHSUSDUGeAykFE4aQDcO04-jBwLEbQuVvZI2IdUQvsRR_wMLwKHA2JXOxsZ9ngHGlTxq9SRhqpbVX131gSRfFfRT5cRl3g8TYlnOY8iImAocOSwUfnbU9RRrCsWwFTGh4n99BH-5lEouGGuIwhCtEF2onuU7JyMJJHFqAknBFGNEzqsIq7amvymG94BNITgGqDgcipBCrzhEv_J5q_YYl0QF-AuS7UeSpHkAeFu0dvB5ogBA
2020-09-19 01:47:41,786: INFO: 140322331100992: run(82): main: Main thread starting 10 workers
Worker 0: starting...
Worker 1: starting...
Worker 2: starting...
Worker 3: starting...
Worker 4: starting...
Worker 5: starting...
Worker 6: starting...
Worker 7: starting...
Worker 8: starting...
Worker 9: starting...
2020-09-19 01:47:41,788: INFO: 140322331100992: run(89): main: Beginning reading of test results.
2020-09-19 01:47:41,788: INFO: 140322331100992: run(95): main: Uploading results in batches of size 1000
2020-09-19 01:47:41,789: INFO: 140322331100992: run(100): main: Main thread finished queueing batches
2020-09-19 01:47:41,789: INFO: 140322331100992: run(104): main: Main thread exiting
Searching '/home/helixbot/work/A3890931/w/B06109AA/e/..' for log files
Found log '/home/helixbot/work/A3890931/w/B06109AA/e/../console.4ce075d6.log'
Uri 'https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-coreclr-refs-pull-28099-merge-36c3676c5a994386b8/System.Text.RegularExpressions.Tests/console.4ce075d6.log?sv=2019-02-02&se=2020-10-08T23%3A06%3A58Z&sr=c&sp=rl&sig=82sGTqBnjRKXnaYIHDTTqPxDlM2NG1gSH00wpb%2FPJ5I%3D'
Generated log list: <ul><li><a href='https://helixre107v0xdeko0k025g8.blob.core.windows.net/dotnet-coreclr-refs-pull-28099-merge-36c3676c5a994386b8/System.Text.RegularExpressions.Tests/console.4ce075d6.log?sv=2019-02-02&se=2020-10-08T23%3A06%3A58Z&sr=c&sp=rl&sig=82sGTqBnjRKXnaYIHDTTqPxDlM2NG1gSH00wpb%2FPJ5I%3D' target='_blank'>console.4ce075d6.log</a></li></ul>
Searching '/home/helixbot/work/A3890931/w/B06109AA/e' for test results files
No results file found in any of the following formats: xunit, junit, trx
+ date -u +%FT%TZ
2020-09-19T01:47:41Z
+ /usr/bin/python3 /home/helixbot/work/A3890931/p/xunit-reporter.py
2020-09-19T01:47:42.242Z	ERROR  	xunit-reporter.py	xunit-reporter(69)	main	Unable to report xunit results: no test results xml file found.
+ exit 137