Skip to content

wait not found for raft request id ... #35290

Closed
Closed
wait not found for raft request id ...#35290
Labels
area/swarmversion/17.10
@sathieu

Description

@sathieu
sathieu
opened on Oct 25, 2017

Description

I have a 3 nodes swam cluster (uvinct636 to uvinct638) with Docker 17.10, My logs are full of raft problems and other issues

Steps to reproduce the issue:

  1. sudo docker stack deploy -c docker-compose-rocketchat-i.yml chat-i

Here is the compose file:

version: "3"

volumes:
  mongo-data:
    driver: convoy
  mongo-dump:
    driver: convoy
  uploads:
    driver: convoy

networks:
  privnet:
  traefik:
    external: true

services:
  mongo:
    image: 'mongo:3.4.6'
    volumes:
      - mongo-data:/data/db
      - mongo-dump:/dump
    command: mongod --smallfiles --oplogSize 128
    networks:
      - traefik
      - privnet
    ports:
      - '27017:27017'
    deploy:
      mode: 'replicated'
      replicas: 1

  rocketchat:
    image: 'rocket.chat:0.57.2'
    volumes:
      - uploads:/app/uploads
    environment:
      - PORT=3000
      - ROOT_URL=https://chat-i.example.org
      - MONGO_URL=mongodb://mongo:27017/rocketchat
      - MAIL_URL=smtp://postfix:25
      - HTTP_PROXY=http://proxy.nantes.net/
      - HTTPS_PROXY=proxy.nantes.net/
    networks:
      - traefik
      - privnet
    ports:
      - '3000'
    deploy:
      mode: 'replicated'
      replicas: 1
      labels:
        - "traefik.port=3000"
        - "traefik.frontend.rule=Host:chat-i.example.org, chat-api-i.example.org"
        - "traefik.docker.network=traefik"

  # hubot, the popular chatbot (add the bot user first and change the password before starting this image)
  hubot:
    image: 'rocketchat-hubot:rocketchat-v1.0.10'
    environment:
      - ROCKETCHAT_URL=rocketchat:3000
      - ROCKETCHAT_ROOM=
      - LISTEN_ON_ALL_PUBLIC=true
      - ROCKETCHAT_USER=bot
      - ROCKETCHAT_PASSWORD=SOMETHING
      - ROCKETCHAT_AUTH=password
      - BOT_NAME=bot
      - HTTP_PROXY=http://proxy:8080/
      - HTTPS_PROXY=http://proxy:8080/
      # you can add more scripts as you'd like here, they need to be installable by npm
      - EXTERNAL_SCRIPTS=hubot-help,hubot-seen,hubot-links,hubot-diagnostics
    networks:
      - privnet
    deploy:
      mode: 'replicated'
      replicas: 1

Describe the results you received:
Here are the 50 last lines of logs:

mparent@uvinct636:~$ tail -50 /var/log/daemon.log 
Oct 25 10:25:03 uvinct636 dockerd[35363]: time="2017-10-25T10:25:03.762514350+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7aa" raft_id=5598d2962227288f
Oct 25 10:25:03 uvinct636 dockerd[35363]: time="2017-10-25T10:25:03.771707348+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ab" raft_id=5598d2962227288f
Oct 25 10:25:03 uvinct636 dockerd[35363]: time="2017-10-25T10:25:03.782289364+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ac" raft_id=5598d2962227288f
Oct 25 10:25:03 uvinct636 dockerd[35363]: time="2017-10-25T10:25:03.840329841+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ad" raft_id=5598d2962227288f
Oct 25 10:25:03 uvinct636 dockerd[35363]: time="2017-10-25T10:25:03.969842357+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ae" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.040155393+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=8w6e6t3wpn7yvz8feks4a9fzc service.id=ij1w328oulrfu6x8mnutxpggp task.id=tdwnheh7wspshgszhe2m899jq
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.040239570+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.071110483+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7af" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.329996201+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b0" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.844229195+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b1" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.856177124+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b2" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.865701168+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b3" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.925675753+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b4" raft_id=5598d2962227288f
Oct 25 10:25:04 uvinct636 dockerd[35363]: time="2017-10-25T10:25:04.982248298+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b5" raft_id=5598d2962227288f
Oct 25 10:25:05 uvinct636 dockerd[35363]: time="2017-10-25T10:25:05.098626693+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b6" raft_id=5598d2962227288f
Oct 25 10:25:05 uvinct636 dockerd[35363]: time="2017-10-25T10:25:05.208816029+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b7" raft_id=5598d2962227288f
Oct 25 10:25:05 uvinct636 dockerd[35363]: time="2017-10-25T10:25:05.469582412+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b8" raft_id=5598d2962227288f
Oct 25 10:25:05 uvinct636 dockerd[35363]: time="2017-10-25T10:25:05.571038689+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.r2n44144gfqvpd5qf5hb4mu5z" error="No such container: chat-i_rocketchat.1.r2n44144gfqvpd5qf5hb4mu5z" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc
Oct 25 10:25:07 uvinct636 dockerd[35363]: time="2017-10-25T10:25:07.572969445+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc
Oct 25 10:25:07 uvinct636 dockerd[35363]: time="2017-10-25T10:25:07.573641032+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc task.id=r2n44144gfqvpd5qf5hb4mu5z
Oct 25 10:25:08 uvinct636 dockerd[35363]: time="2017-10-25T10:25:08.772579494+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7b9" raft_id=5598d2962227288f
Oct 25 10:25:08 uvinct636 dockerd[35363]: time="2017-10-25T10:25:08.779779777+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ba" raft_id=5598d2962227288f
Oct 25 10:25:08 uvinct636 dockerd[35363]: time="2017-10-25T10:25:08.787747407+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7bb" raft_id=5598d2962227288f
Oct 25 10:25:08 uvinct636 dockerd[35363]: time="2017-10-25T10:25:08.846425948+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7bc" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.034467237+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=8w6e6t3wpn7yvz8feks4a9fzc service.id=ij1w328oulrfu6x8mnutxpggp task.id=xoqvzmydzj50ea1ge4wqc8v37
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.035318190+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.035004277+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7bd" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.143011692+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7be" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.401514092+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7bf" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.502284653+02:00" level=warning msg="failed to deactivate service binding for container chat-i_mongo.1.tdwnheh7wspshgszhe2m899jq" error="No such container: chat-i_mongo.1.tdwnheh7wspshgszhe2m899jq" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.851651783+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c0" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.862638954+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c1" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.871253006+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c2" raft_id=5598d2962227288f
Oct 25 10:25:09 uvinct636 dockerd[35363]: time="2017-10-25T10:25:09.928040014+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c3" raft_id=5598d2962227288f
Oct 25 10:25:10 uvinct636 dockerd[35363]: time="2017-10-25T10:25:10.068870807+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c4" raft_id=5598d2962227288f
Oct 25 10:25:10 uvinct636 dockerd[35363]: time="2017-10-25T10:25:10.171509231+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c5" raft_id=5598d2962227288f
Oct 25 10:25:10 uvinct636 dockerd[35363]: time="2017-10-25T10:25:10.431323991+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c6" raft_id=5598d2962227288f
Oct 25 10:25:11 uvinct636 dockerd[35363]: time="2017-10-25T10:25:11.505014925+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc
Oct 25 10:25:11 uvinct636 dockerd[35363]: time="2017-10-25T10:25:11.505134338+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc task.id=tdwnheh7wspshgszhe2m899jq
Oct 25 10:25:13 uvinct636 dockerd[35363]: time="2017-10-25T10:25:13.811193063+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c7" raft_id=5598d2962227288f
Oct 25 10:25:13 uvinct636 dockerd[35363]: time="2017-10-25T10:25:13.849766487+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c8" raft_id=5598d2962227288f
Oct 25 10:25:13 uvinct636 dockerd[35363]: time="2017-10-25T10:25:13.867211329+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7c9" raft_id=5598d2962227288f
Oct 25 10:25:13 uvinct636 dockerd[35363]: time="2017-10-25T10:25:13.919801449+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ca" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.022820055+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7cb" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.123455276+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7cc" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.382854467+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7cd" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.484845871+02:00" level=warning msg="failed to deactivate service binding for container chat-i_mongo.1.xoqvzmydzj50ea1ge4wqc8v37" error="No such container: chat-i_mongo.1.xoqvzmydzj50ea1ge4wqc8v37" module=node/agent node.id=8w6e6t3wpn7yvz8feks4a9fzc
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.864390161+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7ce" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.882296645+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7cf" raft_id=5598d2962227288f
Oct 25 10:25:14 uvinct636 dockerd[35363]: time="2017-10-25T10:25:14.894359335+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd7d0" raft_id=5598d2962227288f

mparent@uvinct637:~$ tail -50 /var/log/daemon.log 
Oct 25 10:24:25 uvinct637 dockerd[46861]: time="2017-10-25T10:24:25.071242979+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=jrluqdllxheo8acdfeon1pe9d
Oct 25 10:24:25 uvinct637 dockerd[46861]: time="2017-10-25T10:24:25.072415935+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:24:30 uvinct637 dockerd[46861]: time="2017-10-25T10:24:30.920289946+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.jrluqdllxheo8acdfeon1pe9d" error="No such container: chat-i_rocketchat.1.jrluqdllxheo8acdfeon1pe9d" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:31 uvinct637 dockerd[46861]: time="2017-10-25T10:24:31.790803506+02:00" level=info msg="Node join event for b536be840319/10.201.2.37"
Oct 25 10:24:32 uvinct637 dockerd[46861]: time="2017-10-25T10:24:32.921859216+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:32 uvinct637 dockerd[46861]: time="2017-10-25T10:24:32.922633047+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=jrluqdllxheo8acdfeon1pe9d
Oct 25 10:24:33 uvinct637 dockerd[46861]: time="2017-10-25T10:24:33.954993676+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=ij1w328oulrfu6x8mnutxpggp task.id=t5fsdju65ukn9fqf6s9447iq1
Oct 25 10:24:33 uvinct637 dockerd[46861]: time="2017-10-25T10:24:33.955128104+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:24:39 uvinct637 dockerd[46861]: time="2017-10-25T10:24:39.450630465+02:00" level=warning msg="failed to deactivate service binding for container chat-i_mongo.1.t5fsdju65ukn9fqf6s9447iq1" error="No such container: chat-i_mongo.1.t5fsdju65ukn9fqf6s9447iq1" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:41 uvinct637 dockerd[46861]: time="2017-10-25T10:24:41.452776717+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:41 uvinct637 dockerd[46861]: time="2017-10-25T10:24:41.452863640+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=t5fsdju65ukn9fqf6s9447iq1
Oct 25 10:24:44 uvinct637 dockerd[46861]: time="2017-10-25T10:24:44.104126990+02:00" level=info msg="Node join event for 73c214075b05/10.201.2.51"
Oct 25 10:24:45 uvinct637 dockerd[46861]: time="2017-10-25T10:24:45.054407373+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=v40y2l90cwqqqyihhxjuy767m
Oct 25 10:24:45 uvinct637 dockerd[46861]: time="2017-10-25T10:24:45.054505520+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:24:50 uvinct637 dockerd[46861]: time="2017-10-25T10:24:50.539793985+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.v40y2l90cwqqqyihhxjuy767m" error="No such container: chat-i_rocketchat.1.v40y2l90cwqqqyihhxjuy767m" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:52 uvinct637 dockerd[46861]: time="2017-10-25T10:24:52.543245895+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:24:52 uvinct637 dockerd[46861]: time="2017-10-25T10:24:52.543346610+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=v40y2l90cwqqqyihhxjuy767m
Oct 25 10:24:59 uvinct637 dockerd[46861]: time="2017-10-25T10:24:59.023285877+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=ij1w328oulrfu6x8mnutxpggp task.id=lfjpyxls5ijjgyis1jgzpswyb
Oct 25 10:24:59 uvinct637 dockerd[46861]: time="2017-10-25T10:24:59.023417533+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:01 uvinct637 dockerd[46861]: time="2017-10-25T10:25:01.794716480+02:00" level=info msg="Node join event for 73c214075b05/10.201.2.51"
Oct 25 10:25:04 uvinct637 dockerd[46861]: time="2017-10-25T10:25:04.430462182+02:00" level=warning msg="failed to deactivate service binding for container chat-i_mongo.1.lfjpyxls5ijjgyis1jgzpswyb" error="No such container: chat-i_mongo.1.lfjpyxls5ijjgyis1jgzpswyb" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:05 uvinct637 dockerd[46861]: time="2017-10-25T10:25:05.126160026+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=yla9tcwm2juljkqetzwwwzzws
Oct 25 10:25:05 uvinct637 dockerd[46861]: time="2017-10-25T10:25:05.126220963+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:06 uvinct637 dockerd[46861]: time="2017-10-25T10:25:06.432873865+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:06 uvinct637 dockerd[46861]: time="2017-10-25T10:25:06.433770917+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=lfjpyxls5ijjgyis1jgzpswyb
Oct 25 10:25:10 uvinct637 dockerd[46861]: time="2017-10-25T10:25:10.114887831+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=ukwmggzot3cqkg6a9dvcts6am
Oct 25 10:25:10 uvinct637 dockerd[46861]: time="2017-10-25T10:25:10.115905899+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:10 uvinct637 dockerd[46861]: time="2017-10-25T10:25:10.532290765+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.yla9tcwm2juljkqetzwwwzzws" error="No such container: chat-i_rocketchat.1.yla9tcwm2juljkqetzwwwzzws" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:12 uvinct637 dockerd[46861]: time="2017-10-25T10:25:12.534245962+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:12 uvinct637 dockerd[46861]: time="2017-10-25T10:25:12.534407859+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=yla9tcwm2juljkqetzwwwzzws
Oct 25 10:25:14 uvinct637 dockerd[46861]: time="2017-10-25T10:25:14.106449197+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=ij1w328oulrfu6x8mnutxpggp task.id=0skyd7o8hg63w7j1pgzy9ta9x
Oct 25 10:25:14 uvinct637 dockerd[46861]: time="2017-10-25T10:25:14.107979244+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:15 uvinct637 dockerd[46861]: time="2017-10-25T10:25:15.614192951+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.ukwmggzot3cqkg6a9dvcts6am" error="No such container: chat-i_rocketchat.1.ukwmggzot3cqkg6a9dvcts6am" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:17 uvinct637 dockerd[46861]: time="2017-10-25T10:25:17.617520905+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:17 uvinct637 dockerd[46861]: time="2017-10-25T10:25:17.618962304+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=ukwmggzot3cqkg6a9dvcts6am
Oct 25 10:25:19 uvinct637 dockerd[46861]: time="2017-10-25T10:25:19.457760664+02:00" level=warning msg="failed to deactivate service binding for container chat-i_mongo.1.0skyd7o8hg63w7j1pgzy9ta9x" error="No such container: chat-i_mongo.1.0skyd7o8hg63w7j1pgzy9ta9x" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:20 uvinct637 dockerd[46861]: time="2017-10-25T10:25:20.143113269+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=5vh8zy8s6b81m8w4tygv6i4x4
Oct 25 10:25:20 uvinct637 dockerd[46861]: time="2017-10-25T10:25:20.143178449+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:21 uvinct637 dockerd[46861]: time="2017-10-25T10:25:21.459887594+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:21 uvinct637 dockerd[46861]: time="2017-10-25T10:25:21.459963137+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=0skyd7o8hg63w7j1pgzy9ta9x
Oct 25 10:25:25 uvinct637 dockerd[46861]: time="2017-10-25T10:25:25.657823164+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.5vh8zy8s6b81m8w4tygv6i4x4" error="No such container: chat-i_rocketchat.1.5vh8zy8s6b81m8w4tygv6i4x4" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:27 uvinct637 dockerd[46861]: time="2017-10-25T10:25:27.660804258+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:27 uvinct637 dockerd[46861]: time="2017-10-25T10:25:27.660883916+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=5vh8zy8s6b81m8w4tygv6i4x4
Oct 25 10:25:31 uvinct637 dockerd[46861]: time="2017-10-25T10:25:31.799174314+02:00" level=info msg="Node join event for b536be840319/10.201.2.37"
Oct 25 10:25:35 uvinct637 dockerd[46861]: time="2017-10-25T10:25:35.196996783+02:00" level=error msg="fatal task error" error="Unable to complete atomic operation, key modified" module=node/agent/taskmanager node.id=1bddmz7g7geri4x1zndjt9hl6 service.id=om71abdkxpfgoj7g8q4i5n45d task.id=p80kmb2fkxrmhdnoqq7l4k5rs
Oct 25 10:25:35 uvinct637 dockerd[46861]: time="2017-10-25T10:25:35.202774596+02:00" level=warning msg="Peer operation failed:Unable to find the peerDB for nid:1dg9umezsr0obr8kx8q5d92xw op:&{3 1dg9umezsr0obr8kx8q5d92xw  [] [] [] [] false false false DeleteNetwork}"
Oct 25 10:25:40 uvinct637 dockerd[46861]: time="2017-10-25T10:25:40.634558184+02:00" level=warning msg="failed to deactivate service binding for container chat-i_rocketchat.1.p80kmb2fkxrmhdnoqq7l4k5rs" error="No such container: chat-i_rocketchat.1.p80kmb2fkxrmhdnoqq7l4k5rs" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:42 uvinct637 dockerd[46861]: time="2017-10-25T10:25:42.636824330+02:00" level=error msg="network chat-i_privnet remove failed: No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6
Oct 25 10:25:42 uvinct637 dockerd[46861]: time="2017-10-25T10:25:42.636956382+02:00" level=error msg="remove task failed" error="No such network: chat-i_privnet" module=node/agent node.id=1bddmz7g7geri4x1zndjt9hl6 task.id=p80kmb2fkxrmhdnoqq7l4k5rs
Oct 25 10:25:44 uvinct637 dockerd[46861]: time="2017-10-25T10:25:44.109739573+02:00" level=info msg="Node join event for 73c214075b05/10.201.2.51"


mparent@uvinct638:~$ tail -50 /var/log/daemon.log 
Oct 25 10:25:45 uvinct638 convoy[7241]: time="2017-10-25T10:25:45+02:00" level=debug msg= event=umount object=volume pkg=daemon reason=complete volume="chat-i_uploads"
Oct 25 10:25:45 uvinct638 convoy[7241]: time="2017-10-25T10:25:45+02:00" level=debug msg="Response:  {}" pkg=daemon
Oct 25 10:25:45 uvinct638 dockerd[58256]: time="2017-10-25T10:25:45.920859288+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd827" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.681346047+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd828" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.690778925+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd829" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.699514384+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82a" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.757798068+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82b" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.838157172+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82c" raft_id=731b61ef39b8663e
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Handle plugin get volume: POST /VolumeDriver.Get" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Request from docker: &{chat-i_mongo-data map[]}" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg= event=mountpoint object=volume pkg=daemon reason=prepare volume="chat-i_mongo-data"
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg= event=mountpoint mountpoint= object=volume pkg=daemon reason=complete volume="chat-i_mongo-data"
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Found volume chat-i_mongo-data for docker" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Response:  {\n\t\"Volume\": {\n\t\t\"Name\": \"chat-i_mongo-data\"\n\t}\n}" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Handle plugin get volume: POST /VolumeDriver.Get" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Request from docker: &{chat-i_mongo-dump map[]}" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg= event=mountpoint object=volume pkg=daemon reason=prepare volume="chat-i_mongo-dump"
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg= event=mountpoint mountpoint= object=volume pkg=daemon reason=complete volume="chat-i_mongo-dump"
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Found volume chat-i_mongo-dump for docker" pkg=daemon
Oct 25 10:25:48 uvinct638 convoy[7241]: time="2017-10-25T10:25:48+02:00" level=debug msg="Response:  {\n\t\"Volume\": {\n\t\t\"Name\": \"chat-i_mongo-dump\"\n\t}\n}" pkg=daemon
Oct 25 10:25:48 uvinct638 dockerd[58256]: time="2017-10-25T10:25:48.954063009+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82d" raft_id=731b61ef39b8663e
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Handle plugin get volume: POST /VolumeDriver.Get" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Request from docker: &{chat-i_mongo-data map[]}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=mountpoint object=volume pkg=daemon reason=prepare volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=mountpoint mountpoint= object=volume pkg=daemon reason=complete volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Found volume chat-i_mongo-data for docker" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Response:  {\n\t\"Volume\": {\n\t\t\"Name\": \"chat-i_mongo-data\"\n\t}\n}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Handle plugin get volume: POST /VolumeDriver.Get" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Request from docker: &{chat-i_mongo-dump map[]}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=mountpoint object=volume pkg=daemon reason=prepare volume="chat-i_mongo-dump"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=mountpoint mountpoint= object=volume pkg=daemon reason=complete volume="chat-i_mongo-dump"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Found volume chat-i_mongo-dump for docker" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Response:  {\n\t\"Volume\": {\n\t\t\"Name\": \"chat-i_mongo-dump\"\n\t}\n}" pkg=daemon
Oct 25 10:25:49 uvinct638 dockerd[58256]: time="2017-10-25T10:25:49.224391270+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82e" raft_id=731b61ef39b8663e
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Handle plugin get volume: POST /VolumeDriver.Get" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Request from docker: &{77bbfa0901c1ae4eda4ed69e031bf35ade07bb85b11a9965f3bc7289439d0681 map[]}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Response:  {\n\t\"Err\": \"Could not find volume 77bbfa0901c1ae4eda4ed69e031bf35ade07bb85b11a9965f3bc7289439d0681.\"\n}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Handle plugin mount volume: POST /VolumeDriver.Mount" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Request from docker: &{chat-i_mongo-data map[]}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Mount volume: chat-i_mongo-data for docker" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=mount object=volume opts=map[MountPoint:] pkg=daemon reason=prepare volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=list mountpoint="/mnt/docker-pp/chat-i_mongo-data" object=volume pkg=daemon reason=complete volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Response:  {\n\t\"Mountpoint\": \"/mnt/docker-pp/chat-i_mongo-data\"\n}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Handle plugin unmount volume: POST /VolumeDriver.Unmount" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Request from docker: &{chat-i_mongo-data map[]}" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Unmount volume: chat-i_mongo-data for docker" pkg=daemon
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=umount object=volume pkg=daemon reason=prepare volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg= event=umount object=volume pkg=daemon reason=complete volume="chat-i_mongo-data"
Oct 25 10:25:49 uvinct638 convoy[7241]: time="2017-10-25T10:25:49+02:00" level=debug msg="Response:  {}" pkg=daemon
Oct 25 10:25:49 uvinct638 dockerd[58256]: time="2017-10-25T10:25:49.662428501+02:00" level=error msg="wait not found for raft request id 5f4eb4ffd82f" raft_id=731b61ef39b8663e

Describe the results you expected:

It seems that the raft is broken. I have deleted and recreated the whole swarm without success.

Additional information you deem important (e.g. issue happens only occasionally):

sudo docker stack rm chat-i stops the logs.

Output of docker version:

Client:
 Version:      17.10.0-ce
 API version:  1.33
 Go version:   go1.8.3
 Git commit:   f4ffd25
 Built:        Tue Oct 17 19:02:43 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.10.0-ce
 API version:  1.33 (minimum version 1.12)
 Go version:   go1.8.3
 Git commit:   f4ffd25
 Built:        Tue Oct 17 19:01:22 2017
 OS/Arch:      linux/amd64
 Experimental: false

Output of docker info:

Containers: 36
 Running: 2
 Paused: 0
 Stopped: 34
Images: 7
Server Version: 17.10.0-ce
Storage Driver: devicemapper
 Pool Name: docker-thinpool
 Pool Blocksize: 524.3kB
 Base Device Size: 10.74GB
 Backing Filesystem: xfs
 Data file: 
 Metadata file: 
 Data Space Used: 5.474GB
 Data Space Total: 40.8GB
 Data Space Available: 35.32GB
 Metadata Space Used: 2.777MB
 Metadata Space Total: 427.8MB
 Metadata Space Available: 425MB
 Thin Pool Minimum Free Space: 4.079GB
 Udev Sync Supported: true
 Deferred Removal Enabled: true
 Deferred Deletion Enabled: true
 Deferred Deleted Device Count: 0
 Library Version: 1.02.137 (2016-11-30)
Logging Driver: gelf
Cgroup Driver: cgroupfs
Plugins:
 Volume: convoy local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: active
 NodeID: l8l29zdddzcszpla84vnogvk3
 Is Manager: true
 ClusterID: jvlxv65j7a0zioikn3k9q4tv2
 Managers: 3
 Nodes: 3
 Orchestration:
  Task History Retention Limit: 5
 Raft:
  Snapshot Interval: 10000
  Number of Old Snapshots to Retain: 0
  Heartbeat Tick: 1
  Election Tick: 3
 Dispatcher:
  Heartbeat Period: 5 seconds
 CA Configuration:
  Expiry Duration: 3 months
  Force Rotate: 0
 Autolock Managers: false
 Root Rotation In Progress: false
 Node Address: 10.201.2.51
 Manager Addresses:
  10.201.2.37:2377
  10.201.2.44:2377
  10.201.2.51:2377
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 06b9cb35161009dcb7123345749fef02f7cea8e0
runc version: 0351df1c5a66838d0c392b4ac4cf9450de844e2d
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.9.0-4-amd64
Operating System: Debian GNU/Linux 9 (stretch)
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 5.823GiB
Name: uvinct638
ID: Y6XX:4SE2:JSKF:YH2P:ZO7X:PT5K:TWCQ:VFUL:5GOY:EZU4:ECI4:VNLZ
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
HTTP Proxy: http://proxy-pp.nantes.net:8080/
No Proxy: localhost,docker-registry.nantesmetropole.fr,gitlab.nantesmetropole.fr,10.201.2.37,10.201.2.44,10.201.2.51
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: No swap limit support

Additional environment details (AWS, VirtualBox, physical, etc.):

VMware ESXi

Metadata

Metadata

Assignees

No one assigned

    Labels

    area/swarmversion/17.10

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions