Node-osmium run out of memory

[matiasdahl]

I have previously ran various node-osmium scripts that extract data from the full OpenStreetMap history. I have previously run these on an m3.medium instance on AWS with 3.75G of memory without any problems. Lately, however, these scripts run out of memory. Is it possible that some recent update has introduced a memory leak somewhere?

The instance setup is described here, and below is a simple example script that run out of memory:

"use strict";

var osmium = require('osmium');
var reader = new osmium.Reader("../history-160502.osm.pbf");
var handler = new osmium.Handler();

var object_handler = function(map_obj) {
  /* dummy handler. Print map id. */
  console.log(map_obj.id)
};

handler.on("node", object_handler);
osmium.apply(reader, handler);

By running top, I found that the script starts with around 25% of memory usage (out of 3.75G) and this slowly increases. After c. 20 mins, it is around 95% and a few minutes after that the process is aborted.

This is with Ubuntu 14.04.3 LTS (trusty), node version v0.10.25, and with the following npm packages installed:

├── js-string-escape@1.0.1
├─┬ osmium@0.5.0
│ ├── nan@2.2.1
│ └─┬ node-pre-gyp@0.6.25
│   ├─┬ mkdirp@0.5.1
│   │ └── minimist@0.0.8
│   ├─┬ nopt@3.0.6
│   │ └── abbrev@1.0.7
│   ├─┬ npmlog@2.0.3
│   │ ├── ansi@0.3.1
│   │ ├─┬ are-we-there-yet@1.1.2
│   │ │ ├── delegates@1.0.0
│   │ │ └─┬ readable-stream@2.0.6
│   │ │   ├── core-util-is@1.0.2
│   │ │   ├── inherits@2.0.1
│   │ │   ├── isarray@1.0.0
│   │ │   ├── process-nextick-args@1.0.6
│   │ │   ├── string_decoder@0.10.31
│   │ │   └── util-deprecate@1.0.2
│   │ └─┬ gauge@1.2.7
│   │   ├── has-unicode@2.0.0
│   │   ├─┬ lodash.pad@4.1.0
│   │   │ ├── lodash.repeat@4.0.0
│   │   │ └── lodash.tostring@4.1.2
│   │   ├─┬ lodash.padend@4.2.0
│   │   │ ├── lodash.repeat@4.0.0
│   │   │ └── lodash.tostring@4.1.2
│   │   └─┬ lodash.padstart@4.2.0
│   │     ├── lodash.repeat@4.0.0
│   │     └── lodash.tostring@4.1.2
│   ├─┬ rc@1.1.6
│   │ ├── deep-extend@0.4.1
│   │ ├── ini@1.3.4
│   │ ├── minimist@1.2.0
│   │ └── strip-json-comments@1.0.4
│   ├─┬ request@2.69.0
│   │ ├── aws-sign2@0.6.0
│   │ ├─┬ aws4@1.3.2
│   │ │ └─┬ lru-cache@4.0.1
│   │ │   ├── pseudomap@1.0.2
│   │ │   └── yallist@2.0.0
│   │ ├─┬ bl@1.0.3
│   │ │ └─┬ readable-stream@2.0.6
│   │ │   ├── core-util-is@1.0.2
│   │ │   ├── inherits@2.0.1
│   │ │   ├── isarray@1.0.0
│   │ │   ├── process-nextick-args@1.0.6
│   │ │   ├── string_decoder@0.10.31
│   │ │   └── util-deprecate@1.0.2
│   │ ├── caseless@0.11.0
│   │ ├─┬ combined-stream@1.0.5
│   │ │ └── delayed-stream@1.0.0
│   │ ├── extend@3.0.0
│   │ ├── forever-agent@0.6.1
│   │ ├─┬ form-data@1.0.0-rc4
│   │ │ └── async@1.5.2
│   │ ├─┬ har-validator@2.0.6
│   │ │ ├─┬ chalk@1.1.3
│   │ │ │ ├── ansi-styles@2.2.1
│   │ │ │ ├── escape-string-regexp@1.0.5
│   │ │ │ ├─┬ has-ansi@2.0.0
│   │ │ │ │ └── ansi-regex@2.0.0
│   │ │ │ ├─┬ strip-ansi@3.0.1
│   │ │ │ │ └── ansi-regex@2.0.0
│   │ │ │ └── supports-color@2.0.0
│   │ │ ├─┬ commander@2.9.0
│   │ │ │ └── graceful-readlink@1.0.1
│   │ │ ├─┬ is-my-json-valid@2.13.1
│   │ │ │ ├── generate-function@2.0.0
│   │ │ │ ├─┬ generate-object-property@1.2.0
│   │ │ │ │ └── is-property@1.0.2
│   │ │ │ ├── jsonpointer@2.0.0
│   │ │ │ └── xtend@4.0.1
│   │ │ └─┬ pinkie-promise@2.0.0
│   │ │   └── pinkie@2.0.4
│   │ ├─┬ hawk@3.1.3
│   │ │ ├── boom@2.10.1
│   │ │ ├── cryptiles@2.0.5
│   │ │ ├── hoek@2.16.3
│   │ │ └── sntp@1.0.9
│   │ ├─┬ http-signature@1.1.1
│   │ │ ├── assert-plus@0.2.0
│   │ │ ├─┬ jsprim@1.2.2
│   │ │ │ ├── extsprintf@1.0.2
│   │ │ │ ├── json-schema@0.2.2
│   │ │ │ └── verror@1.3.6
│   │ │ └─┬ sshpk@1.7.4
│   │ │   ├── asn1@0.2.3
│   │ │   ├─┬ dashdash@1.13.0
│   │ │   │ └── assert-plus@1.0.0
│   │ │   ├── ecc-jsbn@0.1.1
│   │ │   ├── jodid25519@1.0.2
│   │ │   ├── jsbn@0.1.0
│   │ │   └── tweetnacl@0.14.3
│   │ ├── is-typedarray@1.0.0
│   │ ├── isstream@0.1.2
│   │ ├── json-stringify-safe@5.0.1
│   │ ├─┬ mime-types@2.1.10
│   │ │ └── mime-db@1.22.0
│   │ ├── node-uuid@1.4.7
│   │ ├── oauth-sign@0.8.1
│   │ ├── qs@6.0.2
│   │ ├── stringstream@0.0.5
│   │ ├── tough-cookie@2.2.2
│   │ └── tunnel-agent@0.4.2
│   ├─┬ rimraf@2.5.2
│   │ └─┬ glob@7.0.3
│   │   ├─┬ inflight@1.0.4
│   │   │ └── wrappy@1.0.1
│   │   ├── inherits@2.0.1
│   │   ├─┬ minimatch@3.0.0
│   │   │ └─┬ brace-expansion@1.1.3
│   │   │   ├── balanced-match@0.3.0
│   │   │   └── concat-map@0.0.1
│   │   ├─┬ once@1.3.3
│   │   │ └── wrappy@1.0.1
│   │   └── path-is-absolute@1.0.0
│   ├── semver@5.1.0
│   ├─┬ tar@2.2.1
│   │ ├── block-stream@0.0.8
│   │ ├─┬ fstream@1.0.8
│   │ │ └── graceful-fs@4.1.3
│   │ └── inherits@2.0.1
│   └─┬ tar-pack@3.1.3
│     ├─┬ debug@2.2.0
│     │ └── ms@0.7.1
│     ├─┬ fstream@1.0.8
│     │ ├── graceful-fs@4.1.3
│     │ └── inherits@2.0.1
│     ├─┬ fstream-ignore@1.0.3
│     │ ├── inherits@2.0.1
│     │ └─┬ minimatch@3.0.0
│     │   └─┬ brace-expansion@1.1.3
│     │     ├── balanced-match@0.3.0
│     │     └── concat-map@0.0.1
│     ├─┬ once@1.3.3
│     │ └── wrappy@1.0.1
│     ├─┬ readable-stream@2.0.6
│     │ ├── core-util-is@1.0.2
│     │ ├── inherits@2.0.1
│     │ ├── isarray@1.0.0
│     │ ├── process-nextick-args@1.0.6
│     │ ├── string_decoder@0.10.31
│     │ └── util-deprecate@1.0.2
│     └── uid-number@0.0.6
└── underscore@1.8.3

Please let me know if I can provide further details.

Thank you!

[matiasdahl]

A workaround seems to use node-osmium v. 0.4.5 (and not the latest 0.5.0 used above). After running the above example script listed above for 25+ minutes, memory usage is stably around 23%.

[springmeyer]

Is it possible that some recent update has introduced a memory leak somewhere?

Seems unlikely. Usually large memory growth is due to lots of objects being allocated in JS and the node.js/v8 garbage collector not cleaning them up in time before high memory usage occurs.

A workaround seems to use node-osmium v. 0.4.5 (and not the latest 0.5.0 used above).

Interesting - as long as you are using the same version of node that seems to indicate a leak could have been introduced in v0.5.0. What changed in v0.5.0 was 1) upgrade of libosmium from 2.6.0 to 2.6.1 and 2) ported the codebase to https://github.com/nodejs/nan. The port to nan is a much more likely culprit for memory leaks.

[matiasdahl]

Yes, I used the same setup as before (node v.0.10.25 on an m3.medium running Ubuntu 14.04.3 LTS, trusty). The only exception was to use node-osmium v. 0.4.5 and not 0.5.0. Once I switched to 0.4.5 the memory problems disappeared (*).

(*) I ran this script on the full OSM history database without memory problems. This took around 45 hours.

[joto]

I think there are two different issue here. The first, missing HandleScopes, I have fixed in master. With this fix your test program runs okay without the console.log() call. With the console.log() call, the program will stop outputting anything at some point but keep drawing memory. I am not sure what is happening here, but it does not happen when using the Stream interface instead of the Handler interface. This might have something to do with how node does I/O asynchronously, but console.log() should be synchronous, so I am not sure.

@matiasdahl can you check how the current version works for you?

[springmeyer]

@matiasdahl - osmium@0.5.2 is now published and ready for you to test.

[matiasdahl]

Thank you very much. I did some testing, and the new 0.5.2 version of node-osmium seems to have fixed the memory issue in 0.5.0.

Using node-osmium 0.5.2 (installed via npm), I ran the short example script listed above that prints the id:s for all elements for around 40 mins using the same setup as earlier. Previously this ran out of memory after around 20 minutes. Now memory usage was rather constant and at around 25%.

@joto: I redirected the output to a file and I did notice that output would stop.

Thank you again, and let me know if I can provide other details.

[joto]

I have opened a new issue #85 for the remaining problem and will close this one.

[springmeyer]

👍 @joto