[BUG] Compose Watch With “node –watch” Only Reloads First Time

[adamjberg]

Description

I am trying to use compose watch to get a node server to reload on change using "node --watch"

Current Behaviour:

Server correctly reloads on first change. On subsequent changes, the logs show the file has been synced and I can see the file in the container is updated, but the server does not reload.

Expected Behaviour

Server correctly reloads on all changes.

Steps To Reproduce

1. Create simple node server

// src/index.mjs
import express from "express";

const app = express();

app.get("/", async (req, res) => {
  res.send("Hello");
});

app.listen(8000);

2. Create Dockerfile

# syntax=docker/dockerfile:1

ARG NODE_VERSION=20.4.0

FROM node:${NODE_VERSION}-alpine

ENV NODE_ENV production

WORKDIR /usr/src/app

RUN --mount=type=bind,source=package.json,target=package.json \
    --mount=type=bind,source=package-lock.json,target=package-lock.json \
    --mount=type=cache,target=/root/.npm \
    npm ci --omit=dev

COPY . .

EXPOSE 8000

CMD node --watch src/index.mjs

3. Create Compose Yaml

services:
  be:
    build:
      context: ./
    develop:
      watch:
        - action: sync
          path: ./src
          target: /usr/src/app/src
        - action: rebuild
          path: ./package.json
    environment:
      NODE_ENV: production
    ports:
      - 8000:8000

4. npm init && npm i express
5. docker compose build
6. docker compose watch
7. Open http://localhost:8000, then make a change to the index.mjs and confirm first one was picked up
8. Make a second change and see that change does not cause server to reload

Compose Version

Docker Compose version v2.22.0-desktop.2

Docker Environment

Client: Docker Engine - Community
 Version:    24.0.6
 Context:    desktop-linux
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.11.2-desktop.5
    Path:     /usr/lib/docker/cli-plugins/docker-buildx
  compose: Docker Compose (Docker Inc.)
    Version:  v2.22.0-desktop.2
    Path:     /usr/lib/docker/cli-plugins/docker-compose
  dev: Docker Dev Environments (Docker Inc.)
    Version:  v0.1.0
    Path:     /usr/lib/docker/cli-plugins/docker-dev
  extension: Manages Docker extensions (Docker Inc.)
    Version:  v0.2.20
    Path:     /usr/lib/docker/cli-plugins/docker-extension
  init: Creates Docker-related starter files for your project (Docker Inc.)
    Version:  v0.1.0-beta.8
    Path:     /usr/lib/docker/cli-plugins/docker-init
  sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
    Version:  0.6.0
    Path:     /usr/lib/docker/cli-plugins/docker-sbom
  scan: Docker Scan (Docker Inc.)
    Version:  v0.26.0
    Path:     /usr/lib/docker/cli-plugins/docker-scan
  scout: Docker Scout (Docker Inc.)
    Version:  v1.0.7
    Path:     /usr/lib/docker/cli-plugins/docker-scout

Server:
 Containers: 5
  Running: 3
  Paused: 0
  Stopped: 2
 Images: 31
 Server Version: 24.0.6
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 8165feabfdfe38c65b599c4993d227328c231fca
 runc version: v1.1.8-0-g82f18fe
 init version: de40ad0
 Security Options:
  seccomp
   Profile: unconfined
  cgroupns
 Kernel Version: 6.4.16-linuxkit
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 8
 Total Memory: 3.721GiB
 Name: docker-desktop
 ID: 2470e225-662f-42f4-8d74-ea0fbd559efb
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http.docker.internal:3128
 HTTPS Proxy: http.docker.internal:3128
 No Proxy: hubproxy.docker.internal
 Username: devtails
 Experimental: false
 Insecure Registries:
  hubproxy.docker.internal:5555
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: daemon is not using the default seccomp profile

Anything else?

The link below goes directly to the part of the video where I demonstrate this issue.

https://youtu.be/HkLR26VY07c?t=675

[adamoceallaigh]

+1, experienced this exact scenario with my local project too.

[mbrevda]

is there any way to help move forward with this?

[ndeloof]

I can reproduce this scenario, investigating...

[ndeloof]

Seems to me this is a node --watch bug/limitation, see my reproduction example:

1. run the illustration example container (docker build -t t . && docker run --rm -it -p 8000:8000 t)
2. in another terminal, docker exec inside container
3. copy file to a temporary name cp src/index.mjs test.mjs
4. edit test.mjs to change message
5. cp test.mjs src/index.mjs - node show "Restarting 'src/index.mjs'"
6. edit test.mjs again
7. cp test.mjs src/index.mjs - node doesn't detect changes

AFAICT the reason for this is that after a cp (or compose watch sync) the monitored file is rewritten and get a new inode assigned. I assume node watch monitors file by inode, and then don't get any new file event detected. The initial sync works as the file is overridden (inode is deleted)

[mbrevda]

Interesting... what do you propose?

[ndeloof]

I need to check the same applies to a plain Linux hosts, then if confirmed, this issue should be reported to nodeJS.
The other option would require to design an alternative approach for compose watch to sync files.

[ndeloof]

I can't reproduce file inode change when running on a plain Linux VM. I wonder this issue could be a side effect for overlay filesystem used by container, but unclear to me

[ndeloof]

I used strace to check how doing a cp inside container is implemented at system level:

execve("/bin/cp", ["cp", "test", "src/index.mjs"], 0xffffcfdaefa0 /* 9 vars */) = 0
set_tid_address(0xffffabefde58)         = 18
brk(NULL)                               = 0xaaaaf3c9a000
brk(0xaaaaf3c9c000)                     = 0xaaaaf3c9c000
mmap(0xaaaaf3c9a000, 4096, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xaaaaf3c9a000
mprotect(0xaaaad462c000, 16384, PROT_READ) = 0
getuid()                                = 0
newfstatat(AT_FDCWD, "test", {st_mode=S_IFREG|0644, st_size=189, ...}, 0) = 0
newfstatat(AT_FDCWD, "src/index.mjs", {st_mode=S_IFREG|0644, st_size=189, ...}, 0) = 0
newfstatat(AT_FDCWD, "test", {st_mode=S_IFREG|0644, st_size=189, ...}, 0) = 0
newfstatat(AT_FDCWD, "src/index.mjs", {st_mode=S_IFREG|0644, st_size=189, ...}, AT_SYMLINK_NOFOLLOW) = 0
openat(AT_FDCWD, "test", O_RDONLY|O_LARGEFILE) = 3
openat(AT_FDCWD, "src/index.mjs", O_WRONLY|O_CREAT|O_EXCL|O_LARGEFILE, 0100644) = -1 EEXIST (File exists)
unlinkat(AT_FDCWD, "src/index.mjs", 0)  = 0
openat(AT_FDCWD, "src/index.mjs", O_WRONLY|O_CREAT|O_EXCL|O_LARGEFILE, 0100644) = 4
sendfile(4, 3, NULL, 16777216)          = 189
sendfile(4, 3, NULL, 16777216)          = 0
close(4)                                = 0
close(3)                                = 0
exit_group(0)                           = ?

Note the unlinkat then openat calls with O_CREAT, which basically means file is recreated. Seems to confirm my assumption overlayfs used for container layering doesn't work well with inotify, which expect a fixed inode for monitored file.

As this issue is not specific to Docker Compose I created moby/moby#47061 and will close this one. If some workaround is suggested there we can apply to compose, we obviously would adopt it.

[mbrevda]

Thanks for looking into this. Can you explain why the first change is detected?

[ndeloof]

unlinkat (file delete) triggers an inotify event, then nodejs reload the file (which has been recreated in the meantime)

[mbrevda]

ah! Makes sense. Thanks! 🙏 🙏

[mbrevda]

Node issue: nodejs/node#51621