Wednesday 30 November 2016

mysqljs/mysql stream processing blocks event loop at the end

I have a problem with app execution hanging for 12 seconds after a mysql call. During that time event loop is blocked and other events (like heartbeat) are not processed, which causes app to disconect from rabbitmq.The app:I'm using mysqljs/mysql to fetch records from a local mysql database, process them and save to mongo. A simplified version is pasted below. I've replaced asynchronous mongo call with a dummy, and eventually removed it as it turned out setTimeout(() => connection.resume(), 1) reproduces the problem.main filereturn Q() .then(() => mysqlq.each(query, [customer_id])) .tap(() => console.log('after each')) mysqlq wrapperconst connection = mysql.createConnection(settings); this.each = (sql, values, cb) => new Promise((resolve, reject) => { let i = 0; connection.query(sql, values) .on('error', reject) .on('result', (row) => { connection.pause(); //actual processing is normally taking place here setTimeout(() => connection.resume(), 1); }) .on('end', () => { console.log('on end'); resolve(); console.log('after resolve'); }); }); The problem:For a query that returns about 130000 rows the application hangs between "after resolve" and "after each" for about 12 seconds (Shorter result sets don't have that problem). It doesn't process anything else, including heartbeats. I've even tried to send a signal to invoke heap dump, but it's not being processed during that time.[2016-11-30 17:05:30.171 UTC] [LOG] on end [2016-11-30 17:05:30.179 UTC] [LOG] after resolve [2016-11-30 17:05:42.281 UTC] [LOG] after each There's no delay when setTimeout(() => connection.resume(), 1); is replaced with connection.resume()[2016-11-30 17:01:45.390 UTC] [LOG] on end [2016-11-30 17:01:45.395 UTC] [LOG] after resolve [2016-11-30 17:01:45.395 UTC] [LOG] after each Heap size looks stable. GC tracking does not show any runs after "on end". Profiling showed that during that time _ZN2v88internal4Heap12MoveElementsEPNS0_10FixedArrayEiii was being executed (link to flame chart below).Does anyone have any idea what might be causing the problem?Flame chart from the last 20 seconds of execution: http://ift.tt/2gVUOOK'm using:Docker: 1.12.3Ubuntu: 14.04.5 LTSnode: v6.9.1mysql: 5.5.49mysqljs/mysql (node lib): 2.11.1

Submitted November 30, 2016 at 06:22PM by wtfisthiswitchery

No comments:

Post a Comment