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

@firebase/database@0.5.13 ref.update is very slow/unusable #2487

Closed
jmschae opened this issue Jan 3, 2020 · 4 comments · Fixed by #2500
Closed

@firebase/database@0.5.13 ref.update is very slow/unusable #2487

jmschae opened this issue Jan 3, 2020 · 4 comments · Fixed by #2500
Assignees
Labels

Comments

@jmschae
Copy link

@jmschae jmschae commented Jan 3, 2020

[REQUIRED] Describe your environment

  • Operating System version: docker - node alpine 12
  • Browser version: n/a
  • Firebase SDK version: 0.5.13
  • Firebase Product: database (auth, database, storage, etc)

[REQUIRED] Describe the problem

When updating from @firebase/database@0.5.12 to @firebase/database@0.5.13 updates became very slow. We operate in a relatively high write environment, and are streaming state updates into firebase. When upgrading from 0.5.12 to 0.5.13 we began seeing not just slow downs, but issues with ack'ing messages to pub/sub. We tracked this down to a change in the @firebase/database library, specifically commit 86971ea. A change occurred in src/core/Repo.ts that added:

this.serverSyncTree_.calcCompleteEventCache(path)

to the Repo.update function. This update changed the time it took this loop:

each(childrenToMerge, (changedKey: string, changedValue: unknown) => {
  empty = false;
  const newNodeUnresolved = nodeFromJSON(changedValue);
  changedChildren[changedKey] = resolveDeferredValueSnapshot(
    newNodeUnresolved,
    this.serverSyncTree_.calcCompleteEventCache(path),
    serverValues
  );
});

to complete from an average of 0ms to 750ms. This average of 750ms spans a range of about 5ms to upwards of 10,000ms. We believe this slowdown to be the cause of both our increase in observed update time, and our issues ack'ing message to pub/sub, since this piece of code seemingly never releases the event loop.

Steps to reproduce:

Write ~100 updates continuously as fast as you can, and track the time it takes to complete an update.

@jmschae jmschae changed the title @firebase/database@0.5.13 ref.update is very slow @firebase/database@0.5.13 ref.update is very slow/unusable Jan 3, 2020
@katowulf

This comment has been minimized.

Copy link
Member

@katowulf katowulf commented Jan 3, 2020

@jmschae thanks for this, could I ask you to go a bit further and provide a working repro, with sample data and rules, we can run locally that shows the comparison?

The code snippet is useful, but this is likely to be nuanced and hard to repro, so getting a complete mcve will be a necessary starting point.

@schmidt-sebastian

This comment has been minimized.

Copy link
Member

@schmidt-sebastian schmidt-sebastian commented Jan 3, 2020

@inlined - Do you have time to look at this?

86971ea was merged in preparation for a new feature. Until this feature is released, I would recommend staying on 0.5.12 if the performance of 0.5.13 does not meet your needs.

@jmschae

This comment has been minimized.

Copy link
Author

@jmschae jmschae commented Jan 3, 2020

Hey, heres some reproducible code. I added a timer into the @firebase/app code to just console.log how long that loop takes.

in 0.5.13 and above (this is 0.5.17 I believe):

const thisIsNow = Date.now();
each(childrenToMerge, function (changedKey, changedValue) {
    empty = false;
    var newNodeUnresolved = nodeFromJSON$1(changedValue);
    changedChildren[changedKey] = resolveDeferredValueSnapshot(newNodeUnresolved, _this.serverSyncTree_.calcCompleteEventCache(path), serverValues);
});
console.log( 'time: ', Date.now() - thisIsNow );

in 0.5.12:

const thisIsNow = Date.now();
each(childrenToMerge, function (changedKey, changedValue) {
    empty = false;
    var newNodeUnresolved = nodeFromJSON$1(changedValue);
    changedChildren[changedKey] = resolveDeferredValueSnapshot(newNodeUnresolved, serverValues);
});
console.log( 'time: ', Date.now() - thisIsNow );

I have two files (could be one) to reproduce the slowdowns.

index.js

const firebase = require( 'firebase-admin' )
const fs = require( 'fs' )

const data = require( './fakeData' )

const serviceAccount = JSON.parse( fs.readFileSync( 'service-account.json' ) )
const databaseURL = 'databaseurl.firebaseio.com'

const app = firebase.initializeApp( {
  credential : firebase.credential.cert( serviceAccount ),
  databaseURL
}, databaseURL )
const db = app.database()
const promises = []

async function main() {
  for ( let i = 0; i < data.length; i++ ) {
    promises.push( db.ref( '/' ).update( data[i] ) )
  }
}

main()

fakeData.js:

const a = []

for ( let i = 0; i < 100; i++ ) {
  const p = {}
  for ( let j = 0; j < 100; j++ ) {
    p[`a/b/c/d/test-${j}`] = i
  }
  a.push( p )
}

module.exports = a

the console log in 0.5.12 reliably logs 0ms times of duration for that loop, while 0.5.13 and above quickly slows down to a crawl on the scale of seconds.

@inlined

This comment has been minimized.

Copy link
Member

@inlined inlined commented Jan 6, 2020

I'll look into it today.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.