Add 'watch' console message on files update

[etino]

Problem

I faced an unexpected fastify-cli forced end during my development activity after calling a route.
The endpoint response was successfully executed by the server and sent to the client, but the process ends and restarts without any problem.
This got me into trouble to understand the reason.

Troubleshooting

In my development environment, I use a sqlite3 database stored in the data/ directory inside my project.

After some troubleshooting, I found that the problem comes from watch option in the run dev script

"dev": "fastify start -w -l info -P app.js",

It should have the --ignore-watch option set with the data directory

"dev": "fastify start -w --ignore-watch='data' -l info -P app.js",

Suggestion

New feature - Add console message output on files update before restarting fastify.

I think that the logging should provide more useful information to avoid thinking that the forced end is an error.

I suggest adding a console message that prints events triggered by watch to understand the reason why the process is ended and restarted.

New Output example (Standard)

18:09:27 ✨ Server listening at http://127.0.0.1:3000
[fastify-cli] watch - 'change' occurred on 'services\users\index.js'
18:09:31 ✨ Server listening at http://127.0.0.1:3000
[fastify-cli] watch - 'change' occurred on 'package.json'
18:09:54 ✨ Server listening at http://127.0.0.1:3000

New output example (useful to troubleshoot my problem)

18:09:54 ✨ Server listening at http://127.0.0.1:3000
18:10:05 ✨ incoming request POST xxx /users/login
[fastify-cli] watch - 'add' occurred on 'data\dev.sqlite3-journal'
[fastify-cli] watch - 'change' occurred on 'data\dev.sqlite3'
18:10:05 ✨ request completed 392ms
[fastify-cli] watch - 'unlink' occurred on 'data\dev.sqlite3-journal'
18:10:09 ✨ Server listening at http://127.0.0.1:3000
[fastify-cli] process forced end

Checklist

• run npm run test and npm run benchmark
• tests and/or benchmarks are included
• documentation is changed or added
• commit message and code follows the Developer's Certification of Origin
  and the Code of conduct

[mcollina]

CI is failing, could you check your linting?

[climba03003]

It is better to add an option verbose to show those log or show it when debug is passed.
Because it will spam the logging during development. Only show it when it is needed.

[etino]

It is better to add an option verbose to show those log or show it when debug is passed.
Because it will spam the logging during development. Only show it when it is needed.

Being debug an option related to node debugging tool, I added a --verbose-watch option watch.

I resolved the lint problem (thank you @mcollina) but I still have some problem with tests.

Test errors seams related to test/print-routes.test.js not to this PR. Could you help me?

 FAIL  test/print-routes.test.js
 ✖ expect truthy value

  test/print-routes.test.js
  20 |   await fastify.close()
  21 |   t.ok(spy.called)
> 22 |   t.ok(spy.calledWithMatch('debug', '└── / (GET|POST)\n'))
     | ----^
  23 | })
  24 |
  25 | test('should print routes via cli', async t => {

  test: test/print-routes.test.js should print routes
  stack: |
    Test.<anonymous> (test/print-routes.test.js:22:5)

 FAIL  test/print-routes.test.js
 ✖ expect truthy value

  test/print-routes.test.js
  33 |
  34 |   t.ok(spy.called)
> 35 |   t.ok(spy.calledWithMatch('debug', '└── / (GET|POST)\n'))
     | ----^
  36 | })
  37 |
  38 | test('should warn on file not found', t => {

  test: test/print-routes.test.js should print routes via cli
  stack: |
    Test.<anonymous> (test/print-routes.test.js:35:5)
. . . [cut] . . .
 FAIL  test/print-routes.test.js 2 failed of 11 338.568ms
 ✖ expect truthy value
 ✖ expect truthy value

[mcollina]

This does the trick:

$ git diff
diff --git a/test/print-routes.test.js b/test/print-routes.test.js
index a76a88c..eaef1c7 100644
--- a/test/print-routes.test.js
+++ b/test/print-routes.test.js
@@ -19,7 +19,7 @@ test('should print routes', async t => {

   await fastify.close()
   t.ok(spy.called)
-  t.ok(spy.calledWithMatch('debug', '└── / (GET|POST)\n'))
+  t.ok(spy.calledWithMatch('debug', '└── / (GET)\n    / (POST)\n'))
 })

 test('should print routes via cli', async t => {
@@ -32,7 +32,7 @@ test('should print routes via cli', async t => {
   await command.cli(['./examples/plugin.js'])

   t.ok(spy.called)
-  t.ok(spy.calledWithMatch('debug', '└── / (GET|POST)\n'))
+  t.ok(spy.calledWithMatch('debug', '└── / (GET)\n    / (POST)\n'))
 })

 test('should warn on file not found', t => {

[mcollina]

can you add a test for the new feature? I have opened #325 to fix the tests., you might want to rebase after it lands

[etino]

can you add a test for the new feature? I have opened #325 to fix the tests., you might want to rebase after it lands

• test fix rebased in the PR
• I modified the args.test.js adding the new --verbose-watch option into the existing test. Is it enough?

[mcollina]

We need a test that verifies that the said output is emitted.

[etino]

We need a test that verifies that the said output is emitted.

I'm so sorry, but I'm still a newbie with unit tests and tap

With the last commit, I add the function to test --verbose-watch option. It works (the wanted console message is printed in the test output ) but I don't know how to store this output and test it with tap.

The message is fired by this code inside test function

  await writeFile(tmpjs, 'hello fastify', { flag: 'a+' })

Do you have any suggestion?

Test output (as you can see after 3 result the message is printed in the console

# Subtest: should start the server with watch and verbose-watch options that the child process restart when directory changed with console message about changes
    1..4
    ok 1 - should receive start event
    ok 2 - should receive ready event
    ok 3 - change tmpjs
[fastify-cli] watch - 'change' occurred on 'test\fixtures\test_3edc1c2a3363632d6b2f0603bdad3561.js'
    ok 4 - should receive restart event
ok 26 - should start the server with watch and verbose-watch options that the child process restart when directory changed with console message about changes # time=916.487ms

[mcollina]

lgtm

[mcollina]

@climba03003 could you take a look?

[climba03003]

LGTM.

[etino]

It's the first time writing a unit test, so I don't know if it could need some optimization.
I'm proud of the work :-D. It was challenging for me, but I have learned something new.
Many thanks to @mcollina for the feedback and @climba03003 for the help in the fastify discord channel.