twolfson / pixelsmith

Node based engine for `spritesmith` built of top of `get-pixels` and `save-pixels`.
The Unlicense
24 stars 10 forks source link

ArrayBuffer of an image data leaks somewhere in bowels of Pixelsmith#createImages #11

Open ilyazub opened 7 years ago

ilyazub commented 7 years ago

Spritesmith#processImages not freeing memory over time when creating multiple sprite images. vinyl files with Buffer in contents and plain file paths results in the same memory usage.

Related issue in spritesmith: Ensighten/spritesmith#72

I'm asking for help in leak detection in modules used in pixelsmith.

Simplified script to reproduce an issue

'use strict';

const fs = require('fs');

// const File = require('vinyl');
const Spritesmith = require('spritesmith');
const pixelsmith = require('pixelsmith');

const sources = [
    "./sprite/NRL-Canberra-Raiders__569847503__1493152203.png",
    "./sprite/apple_ex.png",
    "./sprite/insta-web.png",
    "./sprite/cart.png",
    "./sprite/jpg.jpg"
];

/*const sourcesContent = sources.map(imagePath =>
    new File({
        path: imagePath,
        history: [],
        content: fs.readFileSync(`${process.cwd()}/${imagePath}`)
    }));*/

const spritesmith = new Spritesmith({
    engine: pixelsmith
});

const ITERATIONS = 150;

process.nextTick(function printMemoryUsage() {
    console.log(JSON.stringify(process.memoryUsage()));
});

for (let i = 0; i < ITERATIONS; i++) {
    spritesmith.createImages(sources, (err, images) => {
        spritesmith.processImages(images);

        process.nextTick(function printMemoryUsage() {
            console.log(JSON.stringify(process.memoryUsage()));

            if (i % 50 === 0) {
                global.gc();
            }
        });

    });
}

Memory usage

{"rss":54697984,"heapTotal":36393760,"heapUsed":21949752}
{"rss":620531712,"heapTotal":65287968,"heapUsed":29065104}
{"rss":646225920,"heapTotal":64256032,"heapUsed":28251352}
{"rss":647573504,"heapTotal":64256032,"heapUsed":28290648}
{"rss":650907648,"heapTotal":64256032,"heapUsed":28326320}
{"rss":654422016,"heapTotal":64256032,"heapUsed":28348720}
{"rss":657559552,"heapTotal":64256032,"heapUsed":28380736}
{"rss":661073920,"heapTotal":64256032,"heapUsed":28401936}
{"rss":664236032,"heapTotal":64256032,"heapUsed":28430416}
{"rss":667480064,"heapTotal":64256032,"heapUsed":28447160}
{"rss":670859264,"heapTotal":64256032,"heapUsed":28473880}
{"rss":674373632,"heapTotal":64256032,"heapUsed":28489664}
{"rss":677515264,"heapTotal":64256032,"heapUsed":28517184}
{"rss":681029632,"heapTotal":64256032,"heapUsed":28532968}
{"rss":684163072,"heapTotal":64256032,"heapUsed":28559616}
{"rss":687677440,"heapTotal":64256032,"heapUsed":28575848}
{"rss":690810880,"heapTotal":64256032,"heapUsed":28602352}
{"rss":694325248,"heapTotal":64256032,"heapUsed":28618136}
{"rss":697442304,"heapTotal":64256032,"heapUsed":28653776}
{"rss":700956672,"heapTotal":64256032,"heapUsed":28672832}
{"rss":704200704,"heapTotal":64256032,"heapUsed":28688536}
{"rss":707444736,"heapTotal":64256032,"heapUsed":28706136}
{"rss":710959104,"heapTotal":64256032,"heapUsed":28721840}
{"rss":714203136,"heapTotal":64256032,"heapUsed":28737544}
{"rss":717717504,"heapTotal":64256032,"heapUsed":28753248}
{"rss":720850944,"heapTotal":64256032,"heapUsed":28778688}
{"rss":724365312,"heapTotal":64256032,"heapUsed":28799680}
{"rss":727609344,"heapTotal":64256032,"heapUsed":28825664}
{"rss":731123712,"heapTotal":64256032,"heapUsed":28841216}
{"rss":734367744,"heapTotal":64256032,"heapUsed":28856768}
{"rss":737882112,"heapTotal":64256032,"heapUsed":28872320}
{"rss":741126144,"heapTotal":64256032,"heapUsed":28887872}
{"rss":744640512,"heapTotal":64256032,"heapUsed":28906144}
{"rss":747884544,"heapTotal":64256032,"heapUsed":28921696}
{"rss":751398912,"heapTotal":64256032,"heapUsed":28937248}
{"rss":754642944,"heapTotal":64256032,"heapUsed":28952800}
{"rss":757886976,"heapTotal":64256032,"heapUsed":28968352}
{"rss":761401344,"heapTotal":64256032,"heapUsed":28983904}
{"rss":764645376,"heapTotal":64256032,"heapUsed":28999456}
{"rss":768159744,"heapTotal":64256032,"heapUsed":29015008}
{"rss":771403776,"heapTotal":64256032,"heapUsed":29030560}
{"rss":774918144,"heapTotal":64256032,"heapUsed":29046112}
{"rss":778162176,"heapTotal":64256032,"heapUsed":29061664}
{"rss":781406208,"heapTotal":64256032,"heapUsed":29077216}
{"rss":784920576,"heapTotal":64256032,"heapUsed":29093720}
{"rss":788434944,"heapTotal":64256032,"heapUsed":29109272}
{"rss":791678976,"heapTotal":64256032,"heapUsed":29124824}
{"rss":794923008,"heapTotal":64256032,"heapUsed":29140376}
{"rss":798437376,"heapTotal":64256032,"heapUsed":29155928}
{"rss":801681408,"heapTotal":64256032,"heapUsed":29171480}
{"rss":804925440,"heapTotal":64256032,"heapUsed":29187032}
{"rss":808439808,"heapTotal":64256032,"heapUsed":29202584}
{"rss":814039040,"heapTotal":65287968,"heapUsed":28634656}
{"rss":817278976,"heapTotal":65287968,"heapUsed":28656736}
{"rss":820748288,"heapTotal":65287968,"heapUsed":28672456}
{"rss":823992320,"heapTotal":65287968,"heapUsed":28688176}
{"rss":827236352,"heapTotal":65287968,"heapUsed":28703896}
{"rss":830750720,"heapTotal":65287968,"heapUsed":28719616}
{"rss":833994752,"heapTotal":65287968,"heapUsed":28735336}
{"rss":837509120,"heapTotal":65287968,"heapUsed":28751056}
{"rss":840753152,"heapTotal":65287968,"heapUsed":28766776}
{"rss":843997184,"heapTotal":65287968,"heapUsed":28785464}
{"rss":847511552,"heapTotal":65287968,"heapUsed":28805632}
{"rss":850755584,"heapTotal":65287968,"heapUsed":28821352}
{"rss":853999616,"heapTotal":65287968,"heapUsed":28837072}
{"rss":857513984,"heapTotal":65287968,"heapUsed":28852792}
{"rss":860758016,"heapTotal":65287968,"heapUsed":28872776}
{"rss":864272384,"heapTotal":65287968,"heapUsed":28888496}
{"rss":867516416,"heapTotal":65287968,"heapUsed":28904216}
{"rss":870760448,"heapTotal":65287968,"heapUsed":28922496}
{"rss":874156032,"heapTotal":65287968,"heapUsed":28945168}
{"rss":877670400,"heapTotal":65287968,"heapUsed":28960808}
{"rss":880914432,"heapTotal":65287968,"heapUsed":28976448}
{"rss":884158464,"heapTotal":65287968,"heapUsed":28992088}
{"rss":887672832,"heapTotal":65287968,"heapUsed":29007728}
{"rss":890916864,"heapTotal":65287968,"heapUsed":29023368}
{"rss":894160896,"heapTotal":65287968,"heapUsed":29039008}
{"rss":897675264,"heapTotal":65287968,"heapUsed":29062360}
{"rss":900919296,"heapTotal":65287968,"heapUsed":29077912}
{"rss":904433664,"heapTotal":65287968,"heapUsed":29093464}
{"rss":907677696,"heapTotal":65287968,"heapUsed":29109016}
{"rss":911192064,"heapTotal":65287968,"heapUsed":29124568}
{"rss":914436096,"heapTotal":65287968,"heapUsed":29140120}
{"rss":917950464,"heapTotal":65287968,"heapUsed":29155672}
{"rss":921194496,"heapTotal":65287968,"heapUsed":29171224}
{"rss":924708864,"heapTotal":65287968,"heapUsed":29186776}
{"rss":927952896,"heapTotal":65287968,"heapUsed":29202328}
{"rss":931467264,"heapTotal":65287968,"heapUsed":29217880}
{"rss":1087750144,"heapTotal":34329888,"heapUsed":28902344}
{"rss":1090994176,"heapTotal":34329888,"heapUsed":28924368}
{"rss":1094508544,"heapTotal":34329888,"heapUsed":28940048}
{"rss":1097752576,"heapTotal":34329888,"heapUsed":28955728}
{"rss":1100996608,"heapTotal":34329888,"heapUsed":28971408}
{"rss":1104621568,"heapTotal":34329888,"heapUsed":30436208}
{"rss":1107861504,"heapTotal":34329888,"heapUsed":30451888}
{"rss":1111105536,"heapTotal":34329888,"heapUsed":30467568}
{"rss":1114619904,"heapTotal":34329888,"heapUsed":30483248}
{"rss":1117863936,"heapTotal":34329888,"heapUsed":30498928}
{"rss":1121378304,"heapTotal":34329888,"heapUsed":30514608}
{"rss":1124622336,"heapTotal":34329888,"heapUsed":30530288}
{"rss":1128136704,"heapTotal":34329888,"heapUsed":30545968}
{"rss":1131380736,"heapTotal":34329888,"heapUsed":30561648}
{"rss":1134624768,"heapTotal":34329888,"heapUsed":30577328}
{"rss":1138139136,"heapTotal":34329888,"heapUsed":30139696}
{"rss":1143013376,"heapTotal":30214176,"heapUsed":23720136}
{"rss":1143013376,"heapTotal":30214176,"heapUsed":23742160}
{"rss":1143099392,"heapTotal":30214176,"heapUsed":23757840}
{"rss":1143099392,"heapTotal":30214176,"heapUsed":23773520}
{"rss":1144176640,"heapTotal":30214176,"heapUsed":23789200}
{"rss":1147420672,"heapTotal":30214176,"heapUsed":23804880}
{"rss":1150664704,"heapTotal":30214176,"heapUsed":23820560}
{"rss":1154179072,"heapTotal":30214176,"heapUsed":23836240}
{"rss":1157423104,"heapTotal":30214176,"heapUsed":23851920}
{"rss":1160667136,"heapTotal":30214176,"heapUsed":23870208}
{"rss":1164173312,"heapTotal":30214176,"heapUsed":23891360}
{"rss":1167417344,"heapTotal":30214176,"heapUsed":23912256}
{"rss":1170931712,"heapTotal":30214176,"heapUsed":23927872}
{"rss":1174175744,"heapTotal":30214176,"heapUsed":23943488}
{"rss":1177419776,"heapTotal":30214176,"heapUsed":23959104}
{"rss":1180934144,"heapTotal":30214176,"heapUsed":23974720}
{"rss":1184178176,"heapTotal":30214176,"heapUsed":23990336}
{"rss":1187422208,"heapTotal":30214176,"heapUsed":24005952}
{"rss":1190936576,"heapTotal":30214176,"heapUsed":24024448}
{"rss":1194180608,"heapTotal":30214176,"heapUsed":24040064}
{"rss":1197694976,"heapTotal":30214176,"heapUsed":24055680}
{"rss":1200939008,"heapTotal":30214176,"heapUsed":24071296}
{"rss":1204183040,"heapTotal":30214176,"heapUsed":24086912}
{"rss":1207697408,"heapTotal":30214176,"heapUsed":24102528}
{"rss":1210941440,"heapTotal":30214176,"heapUsed":24118144}
{"rss":1214320640,"heapTotal":30214176,"heapUsed":24140120}
{"rss":1217564672,"heapTotal":30214176,"heapUsed":24155736}
{"rss":1221079040,"heapTotal":30214176,"heapUsed":24171352}
{"rss":1224241152,"heapTotal":31246112,"heapUsed":24263000}
{"rss":1227722752,"heapTotal":31246112,"heapUsed":24301600}
{"rss":1231237120,"heapTotal":31246112,"heapUsed":24316952}
{"rss":1234481152,"heapTotal":31246112,"heapUsed":24332304}
{"rss":1237725184,"heapTotal":31246112,"heapUsed":24347656}
{"rss":1241239552,"heapTotal":31246112,"heapUsed":24363008}
{"rss":1244483584,"heapTotal":31246112,"heapUsed":24378360}
{"rss":1247727616,"heapTotal":31246112,"heapUsed":24393712}
{"rss":1251241984,"heapTotal":31246112,"heapUsed":24409064}
{"rss":1254486016,"heapTotal":31246112,"heapUsed":24424416}
{"rss":1258000384,"heapTotal":31246112,"heapUsed":24439768}
{"rss":1261244416,"heapTotal":31246112,"heapUsed":24455120}
{"rss":1264488448,"heapTotal":31246112,"heapUsed":24470472}
{"rss":1268002816,"heapTotal":31246112,"heapUsed":24485824}
{"rss":1271246848,"heapTotal":31246112,"heapUsed":24501176}
{"rss":1274761216,"heapTotal":31246112,"heapUsed":24516528}
{"rss":1278005248,"heapTotal":31246112,"heapUsed":24531880}
{"rss":1281249280,"heapTotal":31246112,"heapUsed":24547232}
{"rss":1284763648,"heapTotal":31246112,"heapUsed":24562584}

4 heap snapshots were captured over time shows huge amount of system/JSArrayBufferData allocations.

New objects diff screenshot

I'm assuming that images are leaking in streams of get-pixels, ndarray or pngjs-nozlib modules, being used in process.nextTick() in smith.js.

canvassmith doesn't result in memory leak, so it's an issue of pixelsmith

doesn't result in memory leak

Heap snapshots with canvassmith: canvassmith_heapsnapshots.tar.gz

Packages versions spritesmith@3.1.1 vinyl@2.1.0 pixelsmith@2.1.1 canvassmith@1.1.0

twolfson commented 7 years ago

Wow, great issue content. Thanks!

Would it be possible to get the error-prone images as well?

ilyazub commented 7 years ago

Unfortunately, it doesn't depend on images. There are 81K+ sources for 800+ destination sprites in the project I'm working on, and the issue reproduces with any combination of images.

Anyway, images were used in the script above: sprite_images.tar.gz

ilyazub commented 7 years ago

I've run that sample script through valgrind and examined output output.tar.gz with massif-visualizer

valgrind --tool=massif node ./test.js

Here is a screenshot of the heap usage of C++ calls. I haven't understand yet how to get JS stack from valgrind output. It shows that leak is near to zlibusage. valgrind_massif

And run Valgrind's leak-detector shows that leaks are near to node::ZCtx::New(v8::FunctionCallbackInfo<v8::Value> const&) and node::ZCtx::Init(v8::FunctionCallbackInfo<v8::Value> const&)

valgrind --leak-check=full --show-leak-kinds=all node ./test.js

Full valgrind output: valgrind_leaks.log.tar.gz

Now I'm trying to get JS stack from the valgrind trace. Probably, it should be done with lldb or something similar.

twolfson commented 7 years ago

Cool, thanks for digging into this so much. I don't have time over the next few days to take a look at this. My recommendation is to isolate which of the libraries in get-pixels is causing the issue by using only JPGs or only PNGs and seeing when it occurs

Also, it looks like global.gc() is being run every 50 iterations. Shouldn't it be run every iteration and memory usage be dumped after that? We want to verify a leak, not worry about uncollected variables

twolfson commented 7 years ago

Also, we should probably be using a callback function instead of a for loop. With this current variant, we are running all of the spritesmith actions in parallel instead of in series. I imagine we want to see the leak grow over time