Using one of the standard Node examples for downloading to a file (http://docs.aws.amazon.com/de_de/sdk-for-javascript/v2/developer-guide/requests-using-stream-objects.html), I am seeing frequent "write after end" errors. Using aws-sdk 2.7.21, Node 7.4.0 and running on Mac OS 10.11.6 – same happens on Ubuntu 16.04. Having searched through the issues here, I notice that there are quite a large number of issues related to getObject, of which some are similar to this one. Most of them are old, and some of them are resolved in the "_well, we'll try this and close this for now ..._" way. Hence, I can't tell for sure if this issue duplicates any other issue.
The described happens somewhat randomly, but the below code snippet can be used to reproduce the issue. It seems to happen more often the more concurrent files I am downloading. It also seems to happen more frequently when downloading from a geographically close bucket, i.e. when transfer rate is higher. Surprisingly, the error event is emitted by the read stream – that is, the stream returned by the call to createReadStream(). I am not sure who or what attempts to write to that stream, especially "after end".
"use strict";
const AWS = require('aws-sdk');
const createWriteStream = require('fs').createWriteStream;
const s3 = new AWS.S3({region: 'ap-southeast-2', sslEnabled: true, maxRetries: 0});
const download = (key) => {
console.log(`Starting download of ${key}`);
const file = createWriteStream(`/tmp/${key}`);
s3.getObject({Bucket: 'b7f', Key: key, RequestPayer: 'requester'}, (err, data) => {
if (err) throw new Error(`Unable to download ${key}: ${err}`);
console.log(`Successfully downloaded ${key}`);
}).createReadStream().pipe(file);
};
s3.listObjectsV2({Bucket: 'b7f', RequestPayer: 'requester'}, (err, data) => {
if (err) throw err;
data.Contents.forEach((key) => download(key.Key));
});
```Starting download of 13a69rk6ifb40wk8oc4o4wkgk
Starting download of 19bsdj5ghpmo008ogck4kg4cc
Starting download of 1ioz372xmx8g48ocsgk0k0gok
Starting download of 1j0lmsd3ucxs0w8g0o0wo800o
Starting download of 1wr9ryp33i74kcgksw4c0c0k8
Starting download of 293etv4hbvms4wok0wwwos8ww
Starting download of 2ffrnrhiymascccogssc4w80g
Starting download of 2kfldsy50xwks4w0ocowkwwww
Starting download of 2vlzsu13aqio4owowwcocwwgc
Starting download of 31p1jpmax3c4k88sk40gs04ow
Starting download of 38m8wp03h50ksooos8gc0skg4
Starting download of 38w1wgi3r8kkkcsk8goooks8o
Starting download of 3dkomp6ijcyswwoo4kw8g4c8
Starting download of 3x2qg6p73u80o4o0gk8cckk4w
Starting download of 41pa7c7mj90kw888cskgkcwow
Starting download of 4e8lq2w1degw8skw4gkcwc440
Starting download of 4nu8l0i0w84kk0ss0s00wkk04
Starting download of 4w0sqjcs0veogcg4wcg8ckc0s
Starting download of 52r4ib76a60wgsco08wscw000
Starting download of 5aboyxyj1n4soo8cks40s800c
Starting download of 5aigz17z3ukgskko8k8kckck0
Starting download of 5ay9kqexokw8s48gccc40ws84
Starting download of 5dmbvh3azdwkggsowwggss0w4
Starting download of 5kieamfse50ckg0w848o48sgc
Starting download of 5szadrkari0wwk00gogoccsk0
Starting download of 64uov4stlt0kgoow0wckccs0g
Starting download of 69sa4mvht6gwgookkgs40occg
Starting download of 6f143zbft484ck4c40wcgosgs
Starting download of 6q8iqzhs9fcww8k4oo8ogcg8c
Starting download of 6sqe4htsh2g4o48os0co88k8k
Starting download of 77lfuttrkocogk4sw8gkw0sgk
Starting download of 78jk7jwdvxsswosowkwcg4gc4
Starting download of 7av7k48y3bc4wkssswocsk4go
Starting download of 7b0py1btnw4c88sg4c8c4o0ow
Starting download of 7sy7brnnhq0wks8gg0o4go8k4
Starting download of 7uwtr3c7gaw44gwk000ww44cg
Starting download of 86fuy0w5o8w00ogk0ccc8kwcg
Starting download of 89bju7u44gsg4ogog8oscw8g8
Starting download of 8kvgfuo4z3sw4kgc8sskowk4w
Starting download of 8nrtaoyymggsgwsgk4808gco0
Starting download of 8wn7ul824oow0sgoocw48ww88
Starting download of 8ymomzzg66g444k0os0o0ww4o
Starting download of 92f7ruaalp0c8wkckw8k08kws
Starting download of 97jd41usu7swgw4gg0g8ok4ok
Starting download of 9inmtfdhxvk0ooc4s48kwoks8
Starting download of 9j53bt7k75kw08www4s0o80sk
Starting download of a160ktt8ivk8s044kk0os8c04
Starting download of a6fdo1a0eio0w0ckk0ssoggk
Starting download of a9p28yg7cw4o4sgc808oc04sk
Starting download of awmos06kc2gcocokk0s8s04wk
Starting download of b3wt9khgcf4gow48w808kokwg
Starting download of bgmdi055xkw0kskckc8cco04o
Starting download of bq8asp4lof4gggksw0koso4kk
Starting download of bsm5bd7bay0o4kw8s0kgcgsgo
Starting download of bt8fcdls4koo4gokwsg40o8wk
Starting download of c0a3bdzmemg4okswck0o0w04k
Starting download of c1zkkek2r6gco4scskowg4kow
Starting download of c2ahmq8usug4gwk08wo4ogw44
Starting download of c58kmj2huzkkk0ss8oo8ksggc
Starting download of c6gc15o0vvkgko0kk4sk088c0
Starting download of c8elt0apo2884kkcw4skgs080
Starting download of cjjsmcrfnzcow0884ggsss44g
Starting download of cph2z1txkhs0s48gcgo8w0cck
Starting download of cqykvxv4pncc40kcwsk84c8s8
Starting download of crjsa26x6aokcw8o80gckc444
Starting download of cwpuc12t8so40cww44s8g0swg
Starting download of d22bjv76y144skg8gs8w4w8k
Starting download of d7howk3t3g0scs000ogogsww8
Starting download of db856jb4so0g0oc84o80s8o8o
Starting download of dn24c19z8gg8s04g4os0gs8ck
Starting download of dvrkmm58ek8w4s8www0cwow0c
Starting download of dvvz1ubleggssksc0wosgoc84
Starting download of dx3t7fubxlsgg888wswcgck4o
Starting download of e09ttmjyci04s8o0wws448ksc
Starting download of e74fd2m3jww80swsww804ocss
Starting download of ece8smc6u5cg8ok8gw4kgokcw
Starting download of eurqa5wo63soks04os4800co0
Starting download of jtskili8fkwkgocscksgcgkg
Starting download of kf4lbkv3qkg4o0wksc804o44
Starting download of oczmcievti8ggc0ggk0ckko0
Successfully downloaded 5aigz17z3ukgskko8k8kckck0
Successfully downloaded 5dmbvh3azdwkggsowwggss0w4
Successfully downloaded 5szadrkari0wwk00gogoccsk0
Successfully downloaded 19bsdj5ghpmo008ogck4kg4cc
Successfully downloaded 4e8lq2w1degw8skw4gkcwc440
Successfully downloaded 4w0sqjcs0veogcg4wcg8ckc0s
Successfully downloaded 41pa7c7mj90kw888cskgkcwow
Successfully downloaded 1wr9ryp33i74kcgksw4c0c0k8
Successfully downloaded 4nu8l0i0w84kk0ss0s00wkk04
Successfully downloaded 2kfldsy50xwks4w0ocowkwwww
Successfully downloaded 38w1wgi3r8kkkcsk8goooks8o
Successfully downloaded 1ioz372xmx8g48ocsgk0k0gok
Successfully downloaded 5kieamfse50ckg0w848o48sgc
Successfully downloaded 13a69rk6ifb40wk8oc4o4wkgk
Successfully downloaded 3x2qg6p73u80o4o0gk8cckk4w
Successfully downloaded 52r4ib76a60wgsco08wscw000
Successfully downloaded 3dkomp6ijcyswwoo4kw8g4c8
Successfully downloaded 293etv4hbvms4wok0wwwos8ww
Successfully downloaded 38m8wp03h50ksooos8gc0skg4
Successfully downloaded 2vlzsu13aqio4owowwcocwwgc
Successfully downloaded 5ay9kqexokw8s48gccc40ws84
Successfully downloaded 2ffrnrhiymascccogssc4w80g
Successfully downloaded 31p1jpmax3c4k88sk40gs04ow
Successfully downloaded 1j0lmsd3ucxs0w8g0o0wo800o
Successfully downloaded 5aboyxyj1n4soo8cks40s800c
Successfully downloaded 64uov4stlt0kgoow0wckccs0g
Successfully downloaded 69sa4mvht6gwgookkgs40occg
Successfully downloaded 6q8iqzhs9fcww8k4oo8ogcg8c
Successfully downloaded 6sqe4htsh2g4o48os0co88k8k
Successfully downloaded 6f143zbft484ck4c40wcgosgs
Successfully downloaded 77lfuttrkocogk4sw8gkw0sgk
Successfully downloaded 7av7k48y3bc4wkssswocsk4go
Successfully downloaded 7uwtr3c7gaw44gwk000ww44cg
Successfully downloaded 78jk7jwdvxsswosowkwcg4gc4
Successfully downloaded 7b0py1btnw4c88sg4c8c4o0ow
Successfully downloaded 7sy7brnnhq0wks8gg0o4go8k4
Successfully downloaded 86fuy0w5o8w00ogk0ccc8kwcg
Successfully downloaded 8wn7ul824oow0sgoocw48ww88
Successfully downloaded 8kvgfuo4z3sw4kgc8sskowk4w
Successfully downloaded 89bju7u44gsg4ogog8oscw8g8
Successfully downloaded 8nrtaoyymggsgwsgk4808gco0
Successfully downloaded 8ymomzzg66g444k0os0o0ww4o
Successfully downloaded 92f7ruaalp0c8wkckw8k08kws
Successfully downloaded 97jd41usu7swgw4gg0g8ok4ok
Successfully downloaded 9inmtfdhxvk0ooc4s48kwoks8
Successfully downloaded a160ktt8ivk8s044kk0os8c04
Successfully downloaded 9j53bt7k75kw08www4s0o80sk
Successfully downloaded a6fdo1a0eio0w0ckk0ssoggk
events.js:160
throw er; // Unhandled 'error' event
^
Error: write after end
at writeAfterEnd (_stream_writable.js:191:12)
at PassThrough.Writable.write (_stream_writable.js:242:5)
at PassThrough.ondata (_stream_readable.js:555:20)
at emitOne (events.js:96:13)
at PassThrough.emit (events.js:188:7)
at PassThrough.Readable.read (_stream_readable.js:381:10)
at flow (_stream_readable.js:761:34)
at PassThrough.
at emitNone (events.js:91:20)
at PassThrough.emit (events.js:185:7)
Poking around further and effectively ignoring that error, I noticed that the other transfers would hang. The below code demonstrates that problem. The application hangs forever (I left it a few hours) and only a subset of the files are downloaded; except for the files that failed with the "write after end" error, all the transfers that were in progress at the time that that error happened seem to have hung.
"use strict";
const AWS = require('aws-sdk');
const createWriteStream = require('fs').createWriteStream;
const s3 = new AWS.S3({region: 'ap-southeast-2', sslEnabled: true, maxRetries: 0});
const status = {};
const download = (key) => {
console.log(Starting download of ${key});
status[key] = 'starting';
const writeStream = createWriteStream(/tmp/${key});
const readStream = s3.getObject({Bucket: 'b7f', Key: key, RequestPayer: 'requester'}, (err, data) => {
if (err) throw new Error(Unable to download ${key}: ${err});
console.log(Successfully downloaded ${key});
status[key] = 'completed';
}).createReadStream();
readStream.on('error', (err) => {
status[key] = ${err};
console.log(<${key}> Error on read stream: ${err});
});
readStream.pipe(writeStream);
readStream.on('data', (chunk) => {
status[key] = read ${chunk.byteLength} bytes @ ${Date.now()};
});
status[key] = 'piping';
};
s3.listObjectsV2({Bucket: 'b7f', RequestPayer: 'requester'}, (err, data) => {
if (err) throw err;
data.Contents.sort(() => .5 - Math.random()).forEach((key) => download(key.Key));
});
const printStatus = () => {
console.log('nn=====================================================');
Object.keys(status).forEach((k) => {
console.log(${k}: ${status[k]});
});
};
setInterval(printStatus, 10e3);
In the output I observe that after an error has been reported, the other downloads get stuck.
... thousands of similar lines ...
=====================================================
7uwtr3c7gaw44gwk000ww44cg: completed
jtskili8fkwkgocscksgcgkg: completed
64uov4stlt0kgoow0wckccs0g: completed
d22bjv76y144skg8gs8w4w8k: completed
a6fdo1a0eio0w0ckk0ssoggk: completed
52r4ib76a60wgsco08wscw000: completed
6q8iqzhs9fcww8k4oo8ogcg8c: completed
ece8smc6u5cg8ok8gw4kgokcw: completed
kf4lbkv3qkg4o0wksc804o44: completed
77lfuttrkocogk4sw8gkw0sgk: completed
5aboyxyj1n4soo8cks40s800c: completed
cqykvxv4pncc40kcwsk84c8s8: completed
dx3t7fubxlsgg888wswcgck4o: completed
69sa4mvht6gwgookkgs40occg: completed
e09ttmjyci04s8o0wws448ksc: completed
2kfldsy50xwks4w0ocowkwwww: completed
8kvgfuo4z3sw4kgc8sskowk4w: completed
c58kmj2huzkkk0ss8oo8ksggc: completed
6sqe4htsh2g4o48os0co88k8k: completed
dn24c19z8gg8s04g4os0gs8ck: completed
c6gc15o0vvkgko0kk4sk088c0: completed
5szadrkari0wwk00gogoccsk0: completed
cjjsmcrfnzcow0884ggsss44g: completed
b3wt9khgcf4gow48w808kokwg: completed
crjsa26x6aokcw8o80gckc444: completed
4nu8l0i0w84kk0ss0s00wkk04: completed
oczmcievti8ggc0ggk0ckko0: completed
dvvz1ubleggssksc0wosgoc84: read 9920 bytes @ 1484537172865
c0a3bdzmemg4okswck0o0w04k: completed
9j53bt7k75kw08www4s0o80sk: completed
e74fd2m3jww80swsww804ocss: completed
31p1jpmax3c4k88sk40gs04ow: completed
d7howk3t3g0scs000ogogsww8: completed
dvrkmm58ek8w4s8www0cwow0c: completed
7sy7brnnhq0wks8gg0o4go8k4: completed
9inmtfdhxvk0ooc4s48kwoks8: completed
4e8lq2w1degw8skw4gkcwc440: completed
7av7k48y3bc4wkssswocsk4go: completed
4w0sqjcs0veogcg4wcg8ckc0s: completed
1j0lmsd3ucxs0w8g0o0wo800o: completed
1ioz372xmx8g48ocsgk0k0gok: completed
7b0py1btnw4c88sg4c8c4o0ow: completed
5aigz17z3ukgskko8k8kckck0: completed
bgmdi055xkw0kskckc8cco04o: completed
13a69rk6ifb40wk8oc4o4wkgk: completed
awmos06kc2gcocokk0s8s04wk: read 9920 bytes @ 1484537186655
bq8asp4lof4gggksw0koso4kk: completed
5ay9kqexokw8s48gccc40ws84: completed
bsm5bd7bay0o4kw8s0kgcgsgo: completed
db856jb4so0g0oc84o80s8o8o: completed
1wr9ryp33i74kcgksw4c0c0k8: completed
293etv4hbvms4wok0wwwos8ww: Error: write after end
19bsdj5ghpmo008ogck4kg4cc: piping
3dkomp6ijcyswwoo4kw8g4c8: piping
78jk7jwdvxsswosowkwcg4gc4: piping
a9p28yg7cw4o4sgc808oc04sk: piping
5dmbvh3azdwkggsowwggss0w4: piping
6f143zbft484ck4c40wcgosgs: piping
97jd41usu7swgw4gg0g8ok4ok: piping
8wn7ul824oow0sgoocw48ww88: piping
cph2z1txkhs0s48gcgo8w0cck: piping
eurqa5wo63soks04os4800co0: piping
2vlzsu13aqio4owowwcocwwgc: piping
8ymomzzg66g444k0os0o0ww4o: piping
92f7ruaalp0c8wkckw8k08kws: piping
bt8fcdls4koo4gokwsg40o8wk: piping
c2ahmq8usug4gwk08wo4ogw44: piping
a160ktt8ivk8s044kk0os8c04: piping
41pa7c7mj90kw888cskgkcwow: piping
8nrtaoyymggsgwsgk4808gco0: piping
5kieamfse50ckg0w848o48sgc: piping
cwpuc12t8so40cww44s8g0swg: piping
86fuy0w5o8w00ogk0ccc8kwcg: piping
2ffrnrhiymascccogssc4w80g: piping
89bju7u44gsg4ogog8oscw8g8: piping
c8elt0apo2884kkcw4skgs080: piping
38w1wgi3r8kkkcsk8goooks8o: piping
38m8wp03h50ksooos8gc0skg4: piping
c1zkkek2r6gco4scskowg4kow: piping
3x2qg6p73u80o4o0gk8cckk4w: piping
```
@perhallstroem
Thanks for the very detailed code example, it made reproducing the issue easy.
It looks like this line is causing the problem:
https://github.com/aws/aws-sdk-js/blob/master/lib/request.js#L623
If I remove the pipe to the passthrough stream, the error you're seeing goes away. I still have to dig deeper to find a resolution, I'll update when I have a PR ready.
@chrisradek Great, happy to hear you could reproduce! I am not familiar at all with the SDK code so I will leave it up to you to figure things out from here, but please let me know if there is any more information you might need.
@perhallstroem
Can you try removing the callback function you're passing into getObject? Our examples actually exclude this as well, you should be able to listen for the end and error events on the stream instead.
I originally thought removing the callback didn't have an affect on the errors, but when I just tried testing some code changes for this issue, I noticed that removing the callback made the errors go away, even without my changes.
If that works for you, I think we can update the docs to point out that a callback shouldn't be provided when using streams.
@chrisradek
Sorry for the delay – had a couple of days off + weekend. I have removed the callback. The observed problem is a little bit different. Some of the streams now hang indefinitely, i.e. they just stop receiving data, but the outcome is the same: downloading never completes. The number of "stuck" streams vary in my experiments from 2 up to 10. The "stuck" streams are present even if there are no socket hangups or similar. When I say "stuck", I just mean that there is no error emitted and end has not been emitted either.
I started this about ten minutes ago and after an initial burst of 10+ megs/sec, network activity went down to just some background noise and these streams were stuck:
ece8smc6u5cg8ok8gw4kgokcw: read 2558560 bytes @ Mon Jan 23 2017 08:47:55 GMT+1100 (AEDT)
3dkomp6ijcyswwoo4kw8g4c8: read 2854496 bytes @ Mon Jan 23 2017 08:47:58 GMT+1100 (AEDT)
2vlzsu13aqio4owowwcocwwgc: read 1026656 bytes @ Mon Jan 23 2017 08:48:02 GMT+1100 (AEDT)
The exact code I am using now is
"use strict";
const AWS = require('aws-sdk');
const createWriteStream = require('fs').createWriteStream;
const s3 = new AWS.S3({region: 'ap-southeast-2', sslEnabled: true, maxRetries: 0});
const status = {};
const download = (key) => {
console.log(`Starting download of ${key}`);
status[key] = 'starting';
let downloaded = 0;
const writeStream = createWriteStream(`/tmp/${key}`);
const readStream = s3.getObject({Bucket: 'b7f', Key: key, RequestPayer: 'requester'}).createReadStream();
readStream.on('end', () => {
console.log(`Successfully downloaded ${key}`);
status[key] = 'completed';
});
readStream.on('error', (err) => {
status[key] = `${err}`;
console.log(`<${key}> Error on read stream: ${err}`);
});
readStream.pipe(writeStream);
readStream.on('data', (chunk) => {
downloaded += chunk.byteLength;
status[key] = `read ${downloaded} bytes @ ${new Date().toString()}`;
});
status[key] = 'piping';
};
s3.listObjectsV2({Bucket: 'b7f', RequestPayer: 'requester'}, (err, data) => {
if (err) throw err;
data.Contents.sort(() => .5 - Math.random()).forEach((key) => download(key.Key));
});
const printStatus = () => {
console.log('\n\n=====================================================');
Object.keys(status).forEach((k) => {
if(status[k] !== 'completed') {
console.log(`${k}: ${status[k]}`);
}
});
};
setInterval(printStatus, 10e3);
@perhallstroem
Thanks for providing a new script, I'll take a look.
@perhallstroem
How long do you have to run your script before encountering these hung streams? I've taken your script and modified it slightly to try and reproduce your issue but haven't been able to yet.
The only thing I might be doing differently is after I download everything from listObjectsV2, I don't attempt to download again unless in the printStatus method, every object is marked as complete.
@chrisradek This script hangs on every single run for me, except at home on my legendarily slow DSL connection. I wonder if it could be related to connection speed. I'll see if I can get someone else to reproduce the issue independently for additional clues.
I can reproduce the problem running the script above on node v7.4.0.
Has hung for 30 mins and counting...
+1 to reproducing the problem on node v7.3.0. Hanging for 25 mins +
@dunkstewart
@rusteyy
Any idea how many items are downloaded before seeing this issue? Do you have any pauses where you wait for existing downloads to finish before downloading more, or is it continuous? Also, do you know how large your files are that you're downloading, on average?
I've been having difficulty reproducing this locally, so any further information you can provide is helpful.
I wanted to give an update. I was able to reproduce this issue when downloading 1k objects concurrently, each about 5 MB in size.
The interesting piece is that this issue only happens for me when on WiFi, not when using ethernet. I noticed when running my tests that my WiFi connection would sometimes temporarily disconnect. It seems like when this happens, some of the sockets aren't able to report an error and simple stay assigned.
For anyone that's seeing this issue, are you on a stable, ethernet connection? I want to dig in further, but at this point in means digging into Node.js internals.
@chrisradek
I haven't seen my WiFi connection disconnect during the tests. If I manually turn my WiFi off and back on, downloads will recover normally. By "normally" I mean that if I download one file concurrently I have never seen the problem described and if I turn WiFi off and on again, it will recover. If I download a hundred files concurrently I would expect a couple to get "stuck" and if I turn WiFi off and on again I will see maybe 3 or maybe 1 file stuck, i.e. within normal ranges.
I have seen this problem on Ethernet-connected machines as well, but it is possible that it is somehow related to the stability of the connection since this tends to happen only at higher levels of concurrency.
@perhallstroem
I did some more testing and it doesn't appear that the issue is caused by anything the SDK is doing.
One work-around would be to pass an agent into your S3 client, then after some time has passed either destroy all the sockets or just the ones that have hung.
We can look into adding this logic into the SDK as well, but we'll need to come up with a plan on how to do this for the general use case.
Example:
var https = require('https');
var agent = new https.Agent({
rejectUnauthorized: true,
maxSockets: 50 // default
});
var AWS = require('aws-sdk');
var s3 = new AWS.S3({
httpOptions: {
timeout: 2000,
agent: agent
}
});
// sometime when application should be finished
agent.destroy(); // destroys all sockets in use
Thanks, @chrisradek. Such an interesting problem! I'll do some experiments with instantiating an agent and an AWS.S3 instance for each call instead; for our application the additional resource overhead is not much of a concern.
@chrisradek 's workaround seems to fix the issue for us.
In addition, some errors (i.e bucket doesn't exist) aren't piped through to the stream but are passed to the callback, which means omitting it causes them to be swallowed and the stream to hang.
@perhallstroem,
Did you get this resolved? Or are you still seeing the same problem? If it's been resolved for you, I'd like to close out this issue.
@srchase, I haven't seen this issue for a while. Reran the same test as above today, with no hung downloads. Feel free to close it. Thanks!
This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs and link to relevant comments in this thread.
Most helpful comment
@perhallstroem
I did some more testing and it doesn't appear that the issue is caused by anything the SDK is doing.
One work-around would be to pass an agent into your S3 client, then after some time has passed either destroy all the sockets or just the ones that have hung.
We can look into adding this logic into the SDK as well, but we'll need to come up with a plan on how to do this for the general use case.
Example: