This one has me totally baffled because it occurs seemingly at random. I have a Node.js app that streams tweets (using ntwitter), adding hundreds of rows per second to a mongodb. This part always works fine and memory use is steady. BUT recently I've started getting the URL of twitter avatars and saving them to our rackspace CDN (using "request" and "pkgcloud" modules). I cycle thru a max of 10 at a time (but usually way less) every 20 seconds and run this code:
request(idocs[ikey].tweet.user.profile_image_url.replace('_normal.', '_bigger.')).on('response', function(response) {
console.log(response.request.path);
avatars.push(path.basename(path.dirname(response.request.path)) + '/' + path.basename(response.request.path));
var headers = {};
if (response.headers && response.headers['content-type']) {
headers['content-type'] = response.headers['content-type'];
}
if (response.headers && response.headers['content-length']) {
headers['content-length'] = response.headers['content-length'];
}
response.headers = headers;
}).pipe(client.upload({
container: process.env.RACKSPACE_CONTAINER,
remote: path.basename(path.dirname(idocs[ikey].tweet.user.profile_image_url)) + '/'
+ path.basename(idocs[ikey].tweet.user.profile_image_url.replace('_normal.', '_bigger.'))
}));
Everything works okay for a while, but then I get the following madness in Nodetime:
And here's the output of "heroku logs -p worker -t" when things suddenly go haywire (notice how it's going along fine at around 600 MB then leaps to over 1GB after one particular image--and BTW all the images are standard twitter dimensions of 73x73, so it can't be a file size issue):
2014-03-10T00:27:28.425915+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.50 sample#load_avg_5m=0.24 sample#load_avg_15m=0.12
2014-03-10T00:27:28.426216+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=630.87MB sample#memory_rss=599.24MB sample#memory_cache=0.00MB sample#memory_swap=31.63MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33324565pages
2014-03-10T00:27:48.353902+00:00 app[worker.1]: /profile_images/434575414246539265/Noy_bE24_bigger.jpeg
2014-03-10T00:27:48.570496+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.36 sample#load_avg_5m=0.22 sample#load_avg_15m=0.12
2014-03-10T00:27:48.570793+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=638.78MB sample#memory_rss=607.07MB sample#memory_cache=0.00MB sample#memory_swap=31.71MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33403153pages
2014-03-10T00:28:08.451643+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.54 sample#load_avg_5m=0.27 sample#load_avg_15m=0.14
2014-03-10T00:28:08.452211+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=601.35MB sample#memory_rss=569.55MB sample#memory_cache=0.00MB sample#memory_swap=31.79MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33482782pages
2014-03-10T00:28:28.616784+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.67 sample#load_avg_5m=0.32 sample#load_avg_15m=0.16
2014-03-10T00:28:28.617032+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=605.14MB sample#memory_rss=573.27MB sample#memory_cache=0.00MB sample#memory_swap=31.87MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33560778pages
2014-03-10T00:28:48.332406+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.76 sample#load_avg_5m=0.36 sample#load_avg_15m=0.18
2014-03-10T00:28:48.332628+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=594.71MB sample#memory_rss=562.75MB sample#memory_cache=0.00MB sample#memory_swap=31.95MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33647657pages
2014-03-10T00:29:08.501121+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.83 sample#load_avg_5m=0.40 sample#load_avg_15m=0.20
2014-03-10T00:29:08.501351+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=599.86MB sample#memory_rss=567.83MB sample#memory_cache=0.00MB sample#memory_swap=32.03MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33730317pages
2014-03-10T00:29:28.606331+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.88 sample#load_avg_5m=0.44 sample#load_avg_15m=0.21
2014-03-10T00:29:28.606565+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=630.37MB sample#memory_rss=598.26MB sample#memory_cache=0.00MB sample#memory_swap=32.11MB sample#memory_pgpgin=14872576pages sample#memory_pgpgout=33823519pages
2014-03-10T00:29:29.054831+00:00 app[worker.1]: /profile_images/1857857435/251396_10150278547536115_50300066114_9027856_3493590_n_bigger.jpg
2014-03-10T00:29:48.392172+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.91 sample#load_avg_5m=0.48 sample#load_avg_15m=0.23
2014-03-10T00:29:48.392490+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=1056.09MB sample#memory_rss=1023.97MB sample#memory_cache=0.00MB sample#memory_swap=32.13MB sample#memory_pgpgin=28008448pages sample#memory_pgpgout=33948237pages
2014-03-10T00:29:48.392958+00:00 heroku[worker.1]: Process running mem=1056M(103.1%)
2014-03-10T00:29:48.393236+00:00 heroku[worker.1]: Error R14 (Memory quota exceeded)
2014-03-10T00:30:08.453128+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#load_avg_1m=0.65 sample#load_avg_5m=0.45 sample#load_avg_15m=0.23
2014-03-10T00:30:08.453346+00:00 heroku[worker.1]: source=worker.1 dyno=heroku.18856063.9fde816b-1162-457c-aba0-b9b73584f61b sample#memory_total=1055.90MB sample#memory_rss=1023.71MB sample#memory_cache=0.00MB sample#memory_swap=32.19MB sample#memory_pgpgin=177823744pages sample#memory_pgpgout=34011963pages
2014-03-10T00:30:08.453806+00:00 heroku[worker.1]: Process running mem=1055M(103.1%)
2014-03-10T00:30:08.454034+00:00 heroku[worker.1]: Error R14 (Memory quota exceeded)
So I ask you, ladies and gentlemen: WTF!!!