Client Sync operation takes min. 30 seconds

[muralikr]

In watch mode: whenever developer modifies any file, client has to sync with daemon process. As of now, sync takes min. 30 seconds. This is impacting developer productivity.

We should reduce this delay as much as possible.

[irae]

Have you tried without React Atomic CSS? I believe it is part of your plugins, not part of mendel itself. We might need improvements in Mendel for GST transforms, but then the issue could be named differently too.

[stephanwlee]

Sharing the analytics would be nice. Also try not to have anything Yahoo specific in this repo please.

[muralikr]

I am still trying to capture more analytics and helpful debug cases for this. So, please bare with me.

For debugging purpose, I have completely removed our css plugin from .mendelrc. Sync operation is taking 15-20 seconds now. I ran mendel client in debug mode. Here are the debug logs I see.

In below scenario, client got new entries from daemon only after 15 seconds.

Tue, 06 Jun 2017 19:52:51 GMT mendel:base:client [Mendel] File change detected.
Tue, 06 Jun 2017 19:53:06 GMT verbose:mendel:net:client got ./src/components/foo/index.js
Tue, 06 Jun 2017 19:53:06 GMT verbose:mendel:net:client got ./src/components/bar/index.js
Tue, 06 Jun 2017 19:53:06 GMT ...

Sometimes, client gets first set of entries from daemon instantly. After some entries, this gets stuck for 15 seconds and resumes.

Tue, 06 Jun 2017 21:32:51 GMT mendel:base:client [Mendel] File change detected.
Tue, 06 Jun 2017 21:32:51 GMT verbose:mendel:net:client got ./src/components/foo1/index.js
Tue, 06 Jun 2017 21:32:51 GMT verbose:mendel:net:client got ./src/components/bar1/index.js
Tue, 06 Jun 2017 21:32:51 GMT ...
Tue, 06 Jun 2017 21:33:06 GMT verbose:mendel:net:client got ./src/components/foo/index.js
Tue, 06 Jun 2017 21:33:06 GMT verbose:mendel:net:client got ./src/components/bar/index.js
Tue, 06 Jun 2017 21:33:06 GMT ...

I still have to find out why daemon is not sending entries to client for 15 seconds. I will update this issue once I found something.

[irae]

Hey @muralikr. I think you should debug with less stuff so it is more clear what happens.

For example, I tried to see the steps only:

DEBUG=verbose:mendel:filestep:* npm run daemon

And I waited, tested app, cleared the console. After that I changed 1 file. Look what happens:

  verbose:mendel:filestep:Initialize done ./isomorphic/base/components/app.js +3m
  verbose:mendel:filestep:Initialize done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:Initialize done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:FileReader done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:FileReader done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:FileReader done ./isomorphic/base/components/app.js +7ms
  verbose:mendel:filestep:IndependentSourceTransform done ./isomorphic/base/components/app.js +42ms
  verbose:mendel:filestep:Waiter wait ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/about/package.json +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/message_board.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/feature_B/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/partner_C/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/feature_B/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/_test_/button_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/partner_C/components/button.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/footer.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/main.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/partner_C/components/dropdown.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/bucket_D/components/dropdown.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/lazy.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/bucket_A/components/_test_/button_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/bucket_D/components/lazy.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/bucket_A/components/button.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/message.js +0ms
  
  .....

  verbose:mendel:filestep:Waiter done ./node_modules/asn1/lib/ber/writer.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/jodid25519/lib/core.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/reporter.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/buffer.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/node.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/constants/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/decoders/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/about/package.json +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/about/package.json +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/message_board.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/message_board.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/variations/feature_B/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/variations/feature_B/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/toolbar.js +1ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/toolbar.js +0ms
  
  ......

  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:IndependentSourceTransform done ./isomorphic/base/components/app.js +6ms
  verbose:mendel:filestep:Waiter wait ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/about/package.json +1ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/message_board.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/feature_B/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/_test_/toolbar_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/partner_C/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/feature_B/components/toolbar.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/_test_/button_test.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/variations/partner_C/components/button.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/footer.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/main.js +0ms
  
  ...........

  verbose:mendel:filestep:Waiter done ./node_modules/asn1/lib/ber/writer.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/jodid25519/lib/core.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/reporter.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/buffer.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/base/node.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/constants/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/decoders/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:Waiter done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:Waiter done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/about/package.json +1ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/about/package.json +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/message_board.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/message_board.js +0ms

  .....

  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/decoders/der.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/decoders/pem.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/encoders/der.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:End done ./node_modules/asn1.js/lib/asn1/encoders/pem.js +0ms
  verbose:mendel:filestep:GraphSourceTransform done ./isomorphic/base/components/app.js +0ms
  verbose:mendel:filestep:End done ./isomorphic/base/components/app.js +0ms

And there you can start to find something:

1. I don't think `full-example even have a "Graph Transform" so I don't know why this step is even initialized.
2. I don't know why it does the cycle twice. Maybe it is doing development and production? IDK. Need to debug this.
3. Right now looks like the problem is not with pushing the entries to the client. The problem is that we are running the whole pipeline again once file saves. We should run only for one file and maybe for it's deps if changed.

Either way, it is blazing fast for me.
Just don't forget that with debug it takes way longer anyway.
Also, my debug might be wrong, maybe "filestep" logs even if the file pass through with no operation whatsoever, than we might need to debug other stuff. Just use the DEBUG variable in different ways and you might find problems.