[Fleet] HandlerUnknown type: UNKNOWN (original type: INTERNAL_POLICY_REASSIGN)' received

[mtojek]

Blocker for: elastic/elastic-package#278

Kibana reports policy_revision: null for agent:

I looked into logs and found this problem:

{"log.level":"info","@timestamp":"2021-03-24T10:47:45.426Z","log.origin":{"file.name":"log/reporter.go","file.line":40},"message":"2021-03-24T10:47:45Z: type: 'STATE': sub_type: 'CONFIG' message: Application: fleet-server--7.13.0-SNAPSHOT[8d2dffd0-f97e-4149-9432-3b64f86fc36e]: State changed to CONFIG: Re-configuring","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-03-24T10:47:45.455Z","log.origin":{"file.name":"operation/operator.go","file.line":259},"message":"operation 'operation-install' skipped for metricbeat.7.13.0-SNAPSHOT","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-03-24T10:47:45.455Z","log.origin":{"file.name":"operation/operator.go","file.line":259},"message":"operation 'operation-start' skipped for metricbeat.7.13.0-SNAPSHOT","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-03-24T10:47:45.456Z","log.origin":{"file.name":"stateresolver/stateresolver.go","file.line":66},"message":"Updating internal state","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-03-24T10:49:35.515Z","log.origin":{"file.name":"log/reporter.go","file.line":40},"message":"2021-03-24T10:49:35Z: type: 'STATE': sub_type: 'RUNNING' message: Application: fleet-server--7.13.0-SNAPSHOT[8d2dffd0-f97e-4149-9432-3b64f86fc36e]: State changed to RUNNING: Running on policy with Fleet Server integration: 3b5df4b0-8c8e-11eb-96d7-c5e1b4f97a11","ecs.version":"1.6.0"}
{"log.level":"error","@timestamp":"2021-03-24T10:50:11.136Z","log.origin":{"file.name":"application/handler_unknown.go","file.line":18},"message":"HandlerUnknown: action 'action_id: b3f19210-8c8e-11eb-96d7-c5e1b4f97a11, type: UNKNOWN (original type: INTERNAL_POLICY_REASSIGN)' received","ecs.version":"1.6.0"}
{"log.level":"error","@timestamp":"2021-03-24T10:55:12.370Z","log.origin":{"file.name":"application/fleet_gateway.go","file.line":217},"message":"Could not communicate with Checking API will retry, error: fail to checkin to fleet: Post \"http://localhost:8220/api/fleet/agents/8d2dffd0-f97e-4149-9432-3b64f86fc36e/checkin?\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)","ecs.version":"1.6.0"}

[elasticmachine]

Pinging @elastic/fleet (Team:Fleet)

[ph]

@mtojek I see this fixed in #24616 is there a version mismatch? @nchaulet

[nchaulet]

I merged this yesterday that should fix it elastic/kibana#94116

[ph]

@mtojek I am going to close as fixed, please reconfirm with the above PR?

[mtojek]

I can confirm that I don't see the error message, but the problem still persists: elastic/elastic-package#279 (comment)

I tried to reassign a different policy to the agent.

[mtojek]

I can see in logs following problem as well:

�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-29T13:26:29+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":919,"message":"ResponseError: security_exception\n    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)\n    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)\n    at IncomingMessage.emit (events.js:327:22)\n    at endReadableNT (internal/streams/readable.js:1327:12)\n    at processTicksAndRejections (internal/process/task_queues.js:80:21) {\n  meta: {\n    body: { error: [Object], status: 401 },\n    statusCode: 401,\n    headers: {\n      'x-opaque-id': '875056e3-a38b-45f6-9380-b021a696d5c3',\n      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',\n      'content-type': 'application/json; charset=UTF-8',\n      'content-length': '463'\n    },\n    meta: {\n      context: null,\n      request: [Object],\n      name: 'elasticsearch-js',\n      connection: [Object],\n      attempts: 0,\n      aborted: false\n    }\n  },\n  isBoom: true,\n  isServer: true,\n  data: null,\n  output: {\n    statusCode: 500,\n    payload: {\n      statusCode: 500,\n      error: 'Internal Server Error',\n      message: 'An internal server error occurred'\n    },\n    headers: {}\n  },\n  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'\n}"}

[mtojek]

Here is the docker-compose definition it uses:

  elastic-agent:
    image: ${ELASTIC_AGENT_IMAGE_REF}
    depends_on:
      fleet-server:
        condition: service_healthy
    healthcheck:
      test: "sh -c 'grep \"Agent is starting\" /usr/share/elastic-agent/elastic-agent.log*'"
      retries: 90
      interval: 1s
    hostname: docker-fleet-agent
    environment:
    - "FLEET_ENROLL=1"
    - "FLEET_INSECURE=1"
    - "FLEET_URL=http://fleet-server:8220"
    volumes:
    - type: bind
      source: ../tmp/service_logs/
      target: /tmp/service_logs/

and for the fleet-server:

  fleet-server:
    image: ${ELASTIC_AGENT_IMAGE_REF}
    depends_on:
      elasticsearch:
        condition: service_healthy
      kibana:
        condition: service_healthy
    healthcheck:
      test: "curl -f http://127.0.0.1:8220/api/status | grep HEALTHY 2>&1 >/dev/null"
      retries: 12
      interval: 5s
    hostname: docker-fleet-server
    environment:
    - "FLEET_SERVER_ENABLE=1"
    - "FLEET_SERVER_INSECURE_HTTP=1"
    - "KIBANA_FLEET_SETUP=1"
    - "KIBANA_FLEET_HOST=http://kibana:5601"
    - "FLEET_SERVER_HOST=0.0.0.0"
    ports:
      - "127.0.0.1:8220:8220"

Is there something missing?

[nchaulet]

No it looks good and I just tested your PR locally and reassigning to a new policy worked well

[mtojek]

Hm.. did you update docker images?

elastic-package stack update -v

EDIT:

You can try this actions:

make build # build elastic-package from the relevant branch
cd test/packages/apache
elastic-package build # to rebuild the apache package
elastic-package stack up -v -d # to start the stack considering the above package
elastic-package test system -v
elastic-package test system -v (try multiple times...)

The last one should hang on reassigning policy.

EDIT2:

With above steps I can reproduce the problem that CI encounters.

[nchaulet]

Looks like there is a bug when creating a policy without system package it's tracked here elastic/fleet-server#176

[ph]

@nchaulet Is elastic/fleet-server#176 the root cause of the issue reported by @mtojek ?

[nchaulet]

Yes looks like after creating a policy without integrations the fleet server coordinator is in a stuck place.

[ph]

@mtojek We can close this one and follow the other?

[mtojek]

Sure, please close it. Thank you for taking a look.