contentful.getEntries() throws "Error: unexpected end of file at Zlib._handle.onerror (zlib.js:370:17)"

[andrewodri]

• Node Version: v6.9.4
• Npm Version: 3.10.10
• Platform: Linux 2109406ca117 4.4.16-boot2docker Use proper HTTP Content-Type #1 SMP Fri Jul 29 00:13:24 UTC 2016 x86_64 GNU/Linux (Official debian:jessie-slim image from https://hub.docker.com/_/debian/)
• Package Version: [email protected]

I am building within a Docker container pulled from the official debian:jessie-slim image, with Node v6.9.4 installed from http://deb.nodesource.com/node_6.x. I have been getting the following error on on ~90% builds:

root@2109406ca117:/investors# node app.js
events.js:160
      throw er; // Unhandled 'error' event
      ^

Error: unexpected end of file
    at Zlib._handle.onerror (zlib.js:370:17)

The simplest code to reproduce this issue is below; interestingly, when the client.getContentTypes() call is removed, the error occurs with noticeably less frequency:

const contentful = require('contentful');

let client = contentful.createClient({
  accessToken: '',
  space: ''
});

client.getContentTypes().then(values => {
  client.getEntries({content_type: 'page'}).then(entries => console.log(entries));
});

From what I can tell, this seems to be an issue when chunks of data are dropped from gzipped responses and/or gzip response aren't properly deflated. This would seem to align with the reduced error rate when the additional API call is removed. Here are a few issues that reported similar issues, with fixes referenced:

• Error: incorrect header check at Zlib._handle.onerror when POST in axios axios/axios#435
• incorrect header check when deal with deflate content encoding request/request#2197
• Unexpected Z_BUF_ERROR when using zlib nodejs/node#8701

Some solutions have included more lenient gzip decompression, and providing an option to disable gzip.

[Khaledgarbaya]

Hi @andrewodri ,
This is really weird I never seen this happening, I will try to reproduce this using Docker and come back to you asap, but mostly could be related to axios.
Best,
Khaled

[andrewodri]

Awesome, thanks @Khaledgarbaya!

If it helps, this is the minimum Dockerfile I am using to reproduce the issue:

FROM debian:jessie-slim

################################################################################
# The commands below configure the image with the latest versions of Nginx and
# NodeJS.
################################################################################

RUN apt-get update -y && \
    apt-get install -y --no-install-recommends --no-install-suggests build-essential ca-certificates curl imagemagick git tar && \
    echo "deb http://nginx.org/packages/mainline/debian/ jessie nginx" >> /etc/apt/sources.list.d/nginx.list && \
    echo "deb-src http://nginx.org/packages/mainline/debian/ jessie nginx" >> /etc/apt/sources.list.d/nginx.list && \
    curl -s http://nginx.org/keys/nginx_signing.key | apt-key add - && \
    echo "deb http://deb.nodesource.com/node_6.x jessie main" >> /etc/apt/sources.list.d/nodesource.list && \
    echo "deb-src http://deb.nodesource.com/node_6.x jessie main" >> /etc/apt/sources.list.d/nodesource.list && \
    curl -s http://deb.nodesource.com/gpgkey/nodesource.gpg.key | apt-key add - && \
    apt-get update -y && \
    apt-get install -y --no-install-recommends --no-install-suggests nginx nodejs

CMD [ "/bin/bash" ]

[Khaledgarbaya]

I used this docker image which is basically the same, I think, you can find them here
and it works fine for me

[Khaledgarbaya]

@andrewodri ,
Sorry I used the same exact Dockerfile you sent and still getting the data correctly.

[andrewodri]

So strange... I tried the exact Dockerfile you sent, and I still get the issue... I removed all dependencies and still get inconsistent results.

I tried running a number of times to gauge how often the call is failing, and I did get a slightly different error in one case:

root@4036af539957:/investors# node app.js
(node:1165) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 1): Error: read ECONNRESET
events.js:160
      throw er; // Unhandled 'error' event
      ^

Error: unexpected end of file
    at Zlib._handle.onerror (zlib.js:370:17)

I've tried installing with contentful defined in package.json, as well as install completely fresh.

[andrewodri]

Just an update; the following code works no problem:

const contentful = require('contentful');

let client = contentful.createClient({
  accessToken: '5139e8976eb6b294a77a606f70f524a970a269a2aa5ab6f09911c1b3d031ccf4',
  space: '20580h26mi6y'
});

let contentTypes = [ 'event',
  'pressRelease',
  'page',
  'profileGroup',
  'presentation',
  'financialReport',
  'profile' ];

console.log(contentTypes);

client.getEntries({content_type: 'page'}).then(entries => console.log(entries));

Which produces the following output:

root@4036af539957:/investors# node app.js
[ 'event',
  'pressRelease',
  'page',
  'profileGroup',
  'presentation',
  'financialReport',
  'profile' ]
{ sys: { type: 'Array' },
  total: 5,
  skip: 0,
  limit: 100,
  items: 
   [ { sys: [Object], fields: [Object] },
     { sys: [Object], fields: [Object] },
     { sys: [Object], fields: [Object] },
     { sys: [Object], fields: [Object] },
     { sys: [Object], fields: [Object] } ] }

However, the following code, which returns the exact same result to contentTypes seems to be failing:

const contentful = require('contentful');

let client = contentful.createClient({
  accessToken: '',
  space: ''
});

client.getContentTypes().then(values => {
  let contentTypes = values.items.map(element => element.sys.id);

  console.log(contentTypes);

  client.getEntries({content_type: 'page'}).then(entries => console.log(entries));
});

This produces the following output:

root@4036af539957:/investors# node app.js 
[ 'event',
  'pressRelease',
  'page',
  'profileGroup',
  'presentation',
  'financialReport',
  'profile' ]
events.js:160
      throw er; // Unhandled 'error' event
      ^

Error: unexpected end of file
    at Zlib._handle.onerror (zlib.js:370:17)

[Khaledgarbaya]

@andrewodri ,
I used the same snippet of code you shared and couldn't reproduce it 😞😞 .
I am really sorry

[andrewodri]

Another update:

I ran this code in with the debugger active, and tried finding exactly where the error is throwing... It seems to be related timers associated with DNS resolution. (So possibly a race condition?)

I added in the following code to try and dump a full stack, however, then stack is only one item deep which doesn't really help :P (Without the error handler, the execution stops at break in timers.js:228 before throwing)

process.on('uncaughtException', function(err){
  console.error(err.stack);
});

And the fully stepped execution:

  connecting to 127.0.0.1:5858 ... ok
  break in /app.js:1
  > 1 const contentful = require('contentful');
    2 
    3 process.on('uncaughtException', function(err){

  break in /app.js:3
    1 const contentful = require('contentful');
    2 
  > 3 process.on('uncaughtException', function(err){
    4   console.error(err.stack);
    5 });

  break in /app.js:7
    5 });
    6 
  > 7 let client = contentful.createClient({
    8   accessToken: '5139e8976eb6b294a77a606f70f524a970a269a2aa5ab6f09911c1b3d031ccf4',
    9   space: '20580h26mi6y'

  break in /app.js:12
   10 });
   11 
  >12 client.getContentTypes().then(values => {
   13   client.getEntries({content_type: 'page'}).then(entries => console.log(entries));
   14 });

  break in /app.js:16
   14 });
   15 
  >16 });

  break in module.js:571
   569   if (depth === 0) stat.cache = new Map();
   570   var result = compiledWrapper.apply(this.exports, args);
  >571   if (depth === 0) stat.cache = null;
   572   return result;
   573 };

  break in module.js:580
   578   var content = fs.readFileSync(filename, 'utf8');
   579   module._compile(internalModule.stripBOM(content), filename);
  >580 };
   581 
   582 

  break in module.js:488
   486   if (!Module._extensions[extension]) extension = '.js';
   487   Module._extensions[extension](this, filename);
  >488   this.loaded = true;
   489 };
   490 

  break in module.js:447
   445   try {
   446     module.load(filename);
  >447     threw = false;
   448   } finally {
   449     if (threw) {

  break in module.js:449
   447     threw = false;
   448   } finally {
  >449     if (threw) {
   450       delete Module._cache[filename];
   451     }

  break in module.js:453
   451     }
   452   }
  >453 }
   454 
   455 Module._resolveFilename = function(request, parent, isMain) {

  break in module.js:440
   438   tryModuleLoad(module, filename);
   439 
  >440   return module.exports;
   441 };
   442 

  break in module.js:606
   604   Module._load(process.argv[1], null, true);
   605   // Handle any nextTicks added in the first tick of the program
  >606   process._tickCallback();
   607 };
   608 

  break in timers.js:381
   379     }
   380   }
  >381   if (timer._repeat)
   382     rearm(timer);
   383 }

  break in timers.js:238
   236   try {
   237     ontimeout(timer);
  >238     threw = false;
   239   } finally {
   240     if (!threw) return;

  break in timers.js:240
   238     threw = false;
   239   } finally {
  >240     if (!threw) return;
   241 
   242     // We need to continue processing after domain error handling

  break in timers.js:240
   238     threw = false;
   239   } finally {
  >240     if (!threw) return;
   241 
   242     // We need to continue processing after domain error handling

  break in timers.js:251
   249     process.domain = domain;
   250   }
  >251 }
   252 
   253 

  break in timers.js:209
   207     tryOnTimeout(timer, list);
   208 
  >209     if (domain)
   210       domain.exit();
   211   }

  break in timers.js:171
   169 
   170   var diff, timer;
  >171   while (timer = L.peek(list)) {
   172     diff = now - timer._idleStart;
   173 

  break in timers.js:216
   214   // called all of the timer timeouts.
   215   // As such, we can remove the list and clean up the TimerWrap C++ handle.
  >216   debug('%d list empty', msecs);
   217   assert(L.isEmpty(list));
   218   this.close();

  break in timers.js:223
   221   // recreated since the reference to `list` was created. Make sure they're
   222   // the same instance of the list before destroying.
  >223   if (list._unrefed === true && list === unrefedLists[msecs]) {
   224     delete unrefedLists[msecs];
   225   } else if (list === refedLists[msecs]) {

  break in timers.js:225
   223   if (list._unrefed === true && list === unrefedLists[msecs]) {
   224     delete unrefedLists[msecs];
  >225   } else if (list === refedLists[msecs]) {
   226     delete refedLists[msecs];
   227   }

  break in timers.js:226
   224     delete unrefedLists[msecs];
   225   } else if (list === refedLists[msecs]) {
  >226     delete refedLists[msecs];
   227   }
   228 }

  break in timers.js:228
   226     delete refedLists[msecs];
   227   }
  >228 }
   229 
   230 

  break in dns.js:75
   73 
   74 function onlookup(err, addresses) {
  >75   if (err) {
   76     return this.callback(errnoException(err, 'getaddrinfo', this.hostname));
   77   }

  break in dns.js:78
   76     return this.callback(errnoException(err, 'getaddrinfo', this.hostname));
   77   }
  >78   if (this.family) {
   79     this.callback(null, addresses[0], this.family);
   80   } else {

  break in dns.js:81
   79     this.callback(null, addresses[0], this.family);
   80   } else {
  >81     this.callback(null, addresses[0], addresses[0].indexOf(':') >= 0 ? 6 : 4);
   82   }
   83 }

  break in dns.js:83
   81     this.callback(null, addresses[0], addresses[0].indexOf(':') >= 0 ? 6 : 4);
   82   }
  >83 }
   84 
   85 

  < Error: unexpected end of file
  <     at Zlib._handle.onerror (zlib.js:370:17)

[Khaledgarbaya]

@andrewodri what happen if you do a simple curl command the get entries like

curl -v -XGET -H 'Authorization: Bearer ACCESS_TOKEN' 'http://cdn.contentful.com/spaces/SPACE_ID/entries'

this could be related to the CDN server in your region, I am not sure I have to check with our backend engineers

[andrewodri]

@Khaledgarbaya That command seems to work fine; in fact, so does the following:

curl -H 'Accept-Encoding: gzip' -H 'Authorization: Bearer ACCESS_TOKEN' 'http://cdn.contentful.com/spaces/SPACE_ID/entries' | gunzip

If I send a series of $.ajax() requests and wait for the promises to resolve, that works too (although we don't get the functionality from params.resolveLinks).

I noticed that this pull request (axios/axios#303) resolves the same issue we were having (axios/axios#435). It seems that contentful-sdk-core uses axios 0.9.1, and this patch was only included 0.12.0... Could we try creating a branch of contentful.js that includes the latest version of axios? I've built this locally and it working well, although the Docker build is taking some time...

[andrewodri]

@Khaledgarbaya One more thing... This issue also appear in the request npm module, and was resolved with this pull request:

request/request#2492 (comment)

From the description:

The behavioural difference is that on Node ≥ 6, which has a slightly
stricter gzip decoding process than previous Node versions, malformed
but otherwise acceptable server responses are still properly
decompressed (the most common example being a missing checksum
at the stream end).

It seems that axios is also using the zlib functions, but these are not passing in the flush parameters, https://github.com/mzabriskie/axios/blob/master/lib/adapters/http.js#L145.

I tried changing this line in node_modules/contentful-sdk-core/vendor-node/adapters to pass in the options object {flush: zlib.Z_SYNC_FLUSH, finishFlush: zlib.Z_SYNC_FLUSH}. Instead of throwing and unhandled exception, I now get the following:

(node:258) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 1): TypeError: Object.defineProperty called on non-object

[Khaledgarbaya]

hey @andrefs ,
I already had such a pull request for updating dependencies and improving the build process feel free to build from there, also make sure to checkout this branch of the contentful-sdk-core. Make sure to checkout both branches next to each other, cd to contentful.js folder and run npm install and then run the following command

npm run devdep:build && npm run devdep:install && npm run build

[andrewodri]

@Khaledgarbaya Well it seems that the issue is partly 1) gzip inflation handling, and 2) environmental. We ran tests on other development machines, in our CI, and in our staging environments, and the issue is not occurring there. I suspect it may be be either an issue with the docker network bridging or our network content filtering truncating the data, or making modifications that aren't reflected in the checksum.

Thanks so much for your help on this!

[Khaledgarbaya]

@andrewodri any time, I will close this issue for and feel free to create a new issue whenever you have a problem to report