[storage-blob] blobClient.download does not close network connection if the stream is not fully read

[dcegress]

• Package Name: storage-blob
• Package Version: 12.2.1
• Operating system: Centos 7/Windows 10
• nodejs
  • version: 12.19.0
• browser
  • name/version: Any
• typescript
  • version:
• Is the bug related to documentation in
  • README.md
  • source code documentation
  • SDK API docs on https://docs.microsoft.com

Describe the bug
When opening a blobClient to a video file on Azure Blob Storage and using pipe() to stream it to the response with

blobStream.pipe(res)

When the browser prematurely closes the response (as it does when HTML5 video tag is used to get the thumbnail/metadata) the stream is closed, but the underlying network connection to Azure Storage stays open and ESTABLISHED with keep alive traffic.

blobStream.unpipe() and blobStream.destroy() do not cause it to be removed.

Eventually the operating system runs out of TCP Memory as all these ESTABLISHED connections have date in the Recv-Q.

To Reproduce
Steps to reproduce the behavior:
1.

Expected behavior
A clear and concise description of what you expected to happen.

Screenshots
If applicable, add screenshots to help explain your problem.

Additional context
Add any other context about the problem here.

[dcegress]

Sample code...

'use strict'

const express = require('express')
const router = require('express').Router()
const { BlobServiceClient, StorageSharedKeyCredential } = require('@azure/storage-blob')

const storageAccount ='XXXX' // Storage Account Name
const storageKey='XXXX' // Storage Account Key
const storageContainer='test' // Container name
const storageFile='WRoutro.MOV' // File name
const storageFileSize=20474703 // Need file size for test to avoid another Blob call to get it

const storageURL = 'http://' + storageAccount +'.blob.core.windows.net'

function SRCalc (req, size) {
var sr = req.range(size)

if (sr === undefined) {
sr = {}
sr.stream_status = 200
sr['Content-Length'] = size
sr['Content-Range'] = ''
} else {
sr = sr[0]
sr.stream_status = 206
sr['Content-Length'] = (sr.end - sr.start) + 1
sr['Content-Range'] = 'bytes ' + sr.start + '-' + sr.end + '/' + size
}
return sr
}

function azureBlobStream(req, cb) {

const credentials = new StorageSharedKeyCredential(storageAccount, storageKey)
const blobService = new BlobServiceClient(storageURL,credentials,{ keepAliveOptions: { enable: false } } )
const blobClient = blobService.getContainerClient(storageContainer).getBlockBlobClient(storageFile)

const streamRange = SRCalc(req, storageFileSize)
  
return blobClient.download(streamRange.start, (streamRange.end - streamRange.start) + 1 ).then(function (response) {
    cb(null, response.readableStreamBody, streamRange)
})

}

function filestream (req, res) {
azureBlobStream(req, function (err, stream, streamRange) {

if (err) {
  res.status(500).send(err)
} else {

  const streamHead = {
    'Accept-Ranges': 'bytes',
    'Content-Length': streamRange['Content-Length'],
  	'Cache-Control': 'no-cache'
  }
  if (streamRange['Content-Range']) {
    streamHead['Content-Range'] = streamRange['Content-Range']
  }
  if (req.headers['x-req-content-type']) {
    streamHead['Content-Type'] = req.headers['x-req-content-type']
  }

  res.writeHead(streamRange.stream_status, streamHead)

  if (streamRange.end === undefined) {
    console.log('No range specified')
    stream.pipe(res)
  } else {
    console.log('Response Range = %s',streamRange['Content-Range'])
    console.log('Response Length = %s',streamRange['Content-Length'])

    stream.pipe(res)
    res.on('close', function () {
        console.log("Response closed, destroying stream")
        stream.unpipe()
        stream.resume()
        stream.destroy()
    })

// stream.on('data', function (chunk) {
// res.write(chunk)
// })
}
}
})
}

function serveRoutes () {

router.get('/video', function (req, res) {
res.send('\n\n\n\n\n');
})

router.get('/file', function (req, res) {
console.log("Request range =",req.headers['range'])
filestream(req,res)
})

return router
}

const api = express().use('/serve/', serveRoutes())
api.listen(2323)
console.log("Ready")

Then in browser open http://localhost:2323/serve/video and observe via netstat that a connection remains open to the blob endpoint with data "stuck" even though the stream was destroyed.

[dcegress]

The alternate method of

stream.on('data', function (chunk) {
res.write(chunk)
})

Does close the connection, however it causes delay because it continues to read from the Azure blob stream even though the response is closed rather than terminating the request.

[jiacfan]

Hey, @dcegress

In the mentioned case, is "Response closed, destroying stream" printed?

res.on('close', function () {
        console.log("Response closed, destroying stream")
        stream.unpipe()
        stream.resume()
        stream.destroy()
    }

When using stream.unpipe() and stream.destroy():

        stream.unpipe()
        stream.destroy()

Will you be able to recieve close event on stream?

Drain the buffer with stream.on('data', function...) with ensuring stream can get properly closed may be a good state, which ensures no memory and TCP connection leak.

Thanks,
Jiachen

[ljian3377]

@jeremymeng for visibility as well.

[dcegress]

Yes the close event triggers and with the unpipe() and destroy() we can see in the debugger the stream itself is destroyed but the network connection remains ESTABLISHED.

Draining the stream with on.data allows the stream to reach its end() event and properly close down and close the network connection, however this means for a very large file we have to consume all the data unnecessarily.

[ljian3377]

@dcegress
Jiachen means drain the internal buffer of the stream rather than the whole stream. But it is irrelevant now since you mentioned the close event is triggered.
Could you elaborate on how you tell "the stream itself is destroyed"?

And we will look into this.

[dcegress]

Sure - I ran the code via a debugger (Visual Studio Code) with a breakpoint. At the point after stream.destroy() is executed I can see that stream.destroyed returns true and any further operation on the stream is not possible.

If you run the code above, open a browser to localhost:2323/serve/video, wait for the page to load then check your netstat you will see that although the Browser has closed the connection after getting the first few MB, their is an ESTABLISED connection on https to the blob store.

[dcegress]

There is an even simpler way to reproduce. Using the below code to stream a large file from Azure Blob to the browser in a download link, then click cancel half way through. The res is closed, but the network connection remains from node to blob.

blobClient.download(streamRange.start, (streamRange.end - streamRange.start) + 1).then ( function (response) {
var stream=response.readableStreamBody
const streamHead = {
'Accept-Ranges': 'bytes',
'Content-Length': streamRange['Content-Length'],
'Cache-Control': 'no-cache'
}
if (req.headers['x-req-content-type']) {
streamHead['Content-Type'] = req.headers['x-req-content-type']
}

    res.writeHead(streamRange.stream_status, streamHead)
    stream.pipe(res)

[ljian3377]

Wait a minute. Are you using our library in browser or Node.js?
response.readableStreamBody is not available in browser so I assumed Node.js.

[dcegress]

Node,js

[dcegress]

The comment about browser was just to illustrate the problem. Browser-> Node.js -> Azure Blob when Browser closes the connection to Node, Node does not close it to Azure.

[ljian3377]

Got it. Recreated locally with following code. Manually GC didn't help. @jeremymeng please take a look.

import { BlobClient } from "@azure/storage-blob";
import { Readable } from "stream";

import * as dotenv from "dotenv";
dotenv.config();

function scheduleGc() {
  if (!global.gc) {
    console.log("Garbage collection is not exposed");
    return;
  }

  setTimeout(function () {
    global.gc();
    console.log("Manual gc", process.memoryUsage());
    scheduleGc();
  }, 10 * 1000);
}

scheduleGc();

async function main() {
  const blobURLWithSAS = process.env.BLOB_URL || "";
  const blobClient = new BlobClient(blobURLWithSAS);

  for (let i = 0; i < 1000; i++) {
    const res = await blobClient.download();
    console.log(`download call done for ${i}`);

    const stream: Readable = res.readableStreamBody as any;

    stream.on("close", () => {
      console.log(`stream ${i} closed`);
    });
    stream.destroy();
  }
}

main();

[jeremymeng]

@dcegress I see that you are are specifying a pipeline option { keepAliveOptions: { enable: false } }. I would expect that with keepAlive disabled, after the stream.destroy(), the TCP connection would be in CLOSE_WAIT state, and after a certain time, those CLOSE_WAIT connection would be gone. That's what I saw at least on my Linux machine. Are you seeing the connections remain as ESTABLISHED?

@ljian3377 your repro code is using the default pipeline, so keepAlive is enabled, and the underlying HTTP client is kept for reuse. We currently don't have a way to configure how many TCP connections the HTTP client can use.

[dcegress]

Yes the connections stay ESTABLISHED. It makes no difference what KeepAlive is set to.

I don’t think it’s just connection re use because there is unread data in the Recv-Q of the socket. If it was just sat waiting to be used for another request that wouldn’t be the case.

[dcegress]

It's worth noting we have shifted the stream to use the got module instead of BlobClient and the problem doesn't happen, however we obviously have to handle a lot more of the API than we need to if we could use the modules instead.

[jeremymeng]

@dcegress you are right. The file I was downloading in my test is small so downloading finished and the connections move to CLOSE_WAIT state.

Looking at our core-http code, we pass a abortSignal to node-fetch, however, after we got response back, we removed the listener. It seems an issue to me, as we would want to the ability to cancel the underlying download stream. I will investigate further.

[jeremymeng]

Logged issue #12029 and submitted a PR #12038 to fix it. with that, users can use aborter.abort() to terminate the node-fetch download stream, with code like:

        const aborter = new AbortController();
        const res = await blobClient.download(0, undefined, {
          abortSignal: aborter.signal,
        });
        console.log(`download call done for ${i}`);

        const stream = res.readableStreamBody;

        stream.on("close", () => {
          console.log(`stream ${i} closed`);
          aborter.abort();
        });
        stream.on("error", (error) => {
          console.log(`stream ${i} on error`);
          console.log(error.message);
        });

[ljian3377]

@jeremymeng @XiaoningLiu @jiacfan @bterlson @xirzec
Is it better to abort when the stream is closed in core-http, rather than users have to manually do this?

[dcegress]

That is strange. How big is your video file - mine is about 1GB to allow for enough scrubbing before the whole file is cached

[jeremymeng]

I tried on a 250 MB video. Will try on a bigger file

[ghost]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @xgithubtriage.

Issue Details

---

• Package Name: storage-blob
• Package Version: 12.2.1
• Operating system: Centos 7/Windows 10
• nodejs
  • version: 12.19.0
• browser
  • name/version: Any
• typescript
  • version:
• Is the bug related to documentation in
  • README.md
  • source code documentation
  • SDK API docs on https://docs.microsoft.com

Describe the bug
When opening a blobClient to a video file on Azure Blob Storage and using pipe() to stream it to the response with

blobStream.pipe(res)

When the browser prematurely closes the response (as it does when HTML5 video tag is used to get the thumbnail/metadata) the stream is closed, but the underlying network connection to Azure Storage stays open and ESTABLISHED with keep alive traffic.

blobStream.unpipe() and blobStream.destroy() do not cause it to be removed.

Eventually the operating system runs out of TCP Memory as all these ESTABLISHED connections have date in the Recv-Q.

To Reproduce
Steps to reproduce the behavior:
1.

Expected behavior
A clear and concise description of what you expected to happen.

Screenshots
If applicable, add screenshots to help explain your problem.

Additional context
Add any other context about the problem here.

Author:	dcegress
Assignees:	EmmaZhu
Labels:	bug, customer-reported, Client, Storage, Service Attention, needs-team-attention
Milestone:	-

[github-actions]

Hi @dcegress, we deeply appreciate your input into this project. Regrettably, this issue has remained inactive for over 2 years, leading us to the decision to close it. We've implemented this policy to maintain the relevance of our issue queue and facilitate easier navigation for new contributors. If you still believe this topic requires attention, please feel free to create a new issue, referencing this one. Thank you for your understanding and ongoing support.