Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

busyloop in @grpc/grpc-js v0.6.x #1061

Closed
alexander-fenster opened this issue Oct 2, 2019 · 0 comments · Fixed by #1062
Closed

busyloop in @grpc/grpc-js v0.6.x #1061

alexander-fenster opened this issue Oct 2, 2019 · 0 comments · Fixed by #1062

Comments

@alexander-fenster
Copy link
Contributor

alexander-fenster commented Oct 2, 2019

Problem description

When I run gRPC client with @grpc/grpc-js v0.6.3, the run time is exponential depending on number of concurrent requests sent, and the code is in the busyloop, blocking the event loop and causing 100% CPU usage.

It all works in @grpc/grpc-js v0.5.4.

Reproduction steps

Repro with using Firestore client:

npm install @google-cloud/firestore @grpc/grpc-js
export GOOGLE_APPLICATION_CREDENTIALS=/path/to/service_account_key.json
const fs = require('fs');
const firestore = require('@google-cloud/firestore');
const grpc = require('@grpc/grpc-js');

const COUNT = 25; // 25 is already slow, 100 will never finish

const project = JSON.parse(fs.readFileSync(process.env['GOOGLE_APPLICATION_CREDENTIALS'])).project_id;
const collectionId = 'test-collection'; 
const documentIdPrefix = 'document-id-';

function createDoc(client) {
    const documentId = documentIdPrefix + Math.random();
    const document = {};
    const request = {
        parent: `projects/${project}/databases/(default)/documents`,
        collectionId,
        documentId,
        document,
    };
    return client.createDocument(request);
}

async function test() {
    const p = [];
    const client = new firestore.v1.FirestoreClient({grpc});
    for (let i = 0; i < COUNT; ++i) {
        p.push(createDoc(client));
    }
    await Promise.all(p);
    console.log('Done!');
}

test().catch(err => { console.error('Error!', err); });

Environment

  • OS name, version and architecture: OS X 10.14.6, but reproduces in Kokoro on Linux as well
  • Node version: 12.1.0
  • Node installation method: homebrew
  • If applicable, compiler version: N/A
  • Package name and version: @grpc/grpc-js v0.6.3

Additional context

When I use node --inspect to see what's going on, it shows the CPU time is spent in these deep recursive calls. Below is the console.trace() output:

VM734:1 console.trace
(anonymous) @ VM734:1
tryPick @ channel.js:123
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
updateState @ channel.js:59
exitIdle @ resolving-load-balancer.js:262
pick @ picker.js:68
tryPick @ channel.js:96
_startCallStream @ channel.js:155
sendMetadata @ call-stream.js:296
makeUnaryRequest @ client.js:130
(anonymous) @ make-client.js:92
(anonymous) @ firestore_client.js:149
(anonymous) @ timeout.ts:69
call @ call.ts:97
call @ normalApiCaller.ts:60
(anonymous) @ createApiCall.ts:114
processTicksAndRejections @ internal/process/task_queues.js:89
Promise.then (async)
(anonymous) @ createApiCall.ts:113
createDocument @ firestore_client.js:553
(anonymous) @ index.ts:44
Promise @ index.ts:33
createDoc @ index.ts:44
foo @ index.ts:44
(anonymous) @ index.ts:44
Module._compile @ internal/modules/cjs/loader.js:756
Module._extensions..js @ internal/modules/cjs/loader.js:770
Module.load @ internal/modules/cjs/loader.js:628
Module._load @ internal/modules/cjs/loader.js:555
Module.runMain @ internal/modules/cjs/loader.js:824
(anonymous) @ internal/main/run_main_module.js:17
Show 18 more frames

Cc: @schmidt-sebastian

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant