Traceback (most recent call last):
  File "/usr/lib/python2.7/unittest/case.py", line 329, in run
    testMethod()
  File "/go/src/github.com/elastic/beats/filebeat/tests/system/test_registrar.py", line 902, in test_clean_removed
    assert len(data) == 1
AssertionError

2018-07-21T00:51:58.364Z    DEBUG   [input] input/input.go:152  Run input
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:174    Start next scan
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input1
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:555    Ignore file because ignore_older reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input1
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:567    Do not write state for ignore_older because clean_inactive reached
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input2
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:555    Ignore file because ignore_older reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input2
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:567    Do not write state for ignore_older because clean_inactive reached
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:477    Start harvester for new file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [harvester] log/harvester.go:486    Setting offset for file based on seek: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [harvester] log/harvester.go:472    Setting offset for file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3. Offset: 0
2018-07-21T00:51:58.364Z    DEBUG   [harvester] log/harvester.go:387    Update state: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3, offset: 0
2018-07-21T00:51:58.364Z    DEBUG   [input] file/states.go:68   New state added for /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [input] log/input.go:195    input states cleaned up. Before: 1, After: 1, Pending: 1
2018-07-21T00:51:58.364Z    DEBUG   [acker] beater/acker.go:64  stateful ack    {"count": 1}
2018-07-21T00:51:58.364Z    DEBUG   [registrar] registrar/registrar.go:345  Processing 1 events
2018-07-21T00:51:58.364Z    DEBUG   [input] file/states.go:68   New state added for /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [registrar] registrar/registrar.go:315  Registrar state updates processed. Count: 1
2018-07-21T00:51:58.364Z    DEBUG   [state] file/states.go:118  State removed for /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input1 because of older: 4s
2018-07-21T00:51:58.364Z    DEBUG   [state] file/states.go:118  State removed for /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input2 because of older: 4s
2018-07-21T00:51:58.364Z    DEBUG   [registrar] registrar/registrar.go:335  Registrar states cleaned up. Before: 3, After: 1, Pending: 1
2018-07-21T00:51:58.364Z    DEBUG   [registrar] registrar/registrar.go:400  Write registry file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/registry
2018-07-21T00:51:58.364Z    INFO    log/harvester.go:251    Harvester started for file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.364Z    DEBUG   [publish]   pipeline/processor.go:308   Publish event: {
  "@timestamp": "2018-07-21T00:51:58.364Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "doc",
    "version": "7.0.0-alpha1"
  },
  "message": "2",
  "source": "/go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3",
  "offset": 0,
  "prospector": {
    "type": "log"
  },
  "input": {
    "type": "log"
  },
  "beat": {
    "name": "79ecf000efcd",
    "hostname": "79ecf000efcd",
    "version": "7.0.0-alpha1"
  },
  "host": {
    "name": "79ecf000efcd"
  }
}
2018-07-21T00:51:58.364Z    DEBUG   [harvester] log/log.go:102  End of file reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3; Backoff now.
2018-07-21T00:51:58.367Z    DEBUG   [registrar] registrar/registrar.go:393  Registry file updated. 1 states written.
2018-07-21T00:51:58.464Z    DEBUG   [input] input/input.go:152  Run input
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:174    Start next scan
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input1
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:555    Ignore file because ignore_older reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input1
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:567    Do not write state for ignore_older because clean_inactive reached
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input2
2018-07-21T00:51:58.464Z    DEBUG   [input] log/input.go:555    Ignore file because ignore_older reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input2
2018-07-21T00:51:58.465Z    DEBUG   [input] log/input.go:567    Do not write state for ignore_older because clean_inactive reached
2018-07-21T00:51:58.465Z    DEBUG   [input] log/input.go:404    Check file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.465Z    DEBUG   [input] log/input.go:494    Update existing file for harvesting: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3, offset: 2
2018-07-21T00:51:58.465Z    DEBUG   [input] log/input.go:546    Harvester for file is still running: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.465Z    DEBUG   [input] log/input.go:195    input states cleaned up. Before: 1, After: 1, Pending: 1
2018-07-21T00:51:58.465Z    DEBUG   [harvester] log/log.go:102  End of file reached: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3; Backoff now.
2018-07-21T00:51:58.465Z    DEBUG   [memqueue]  memqueue/ackloop.go:160 ackloop: receive ack [1: 0, 1]
2018-07-21T00:51:58.465Z    DEBUG   [memqueue]  memqueue/eventloop.go:535   broker ACK events: count=1, start-seq=3, end-seq=3

2018-07-21T00:51:58.465Z    DEBUG   [memqueue]  memqueue/ackloop.go:128 ackloop: return ack to broker loop:1
2018-07-21T00:51:58.465Z    DEBUG   [memqueue]  memqueue/ackloop.go:131 ackloop:  done send ack
2018-07-21T00:51:58.465Z    DEBUG   [acker] beater/acker.go:64  stateful ack    {"count": 1}
2018-07-21T00:51:58.465Z    DEBUG   [registrar] registrar/registrar.go:345  Processing 1 events
2018-07-21T00:51:58.465Z    DEBUG   [registrar] registrar/registrar.go:315  Registrar state updates processed. Count: 1
2018-07-21T00:51:58.465Z    DEBUG   [registrar] registrar/registrar.go:335  Registrar states cleaned up. Before: 1, After: 1, Pending: 1
2018-07-21T00:51:58.465Z    DEBUG   [registrar] registrar/registrar.go:400  Write registry file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/registry
2018-07-21T00:51:58.468Z    DEBUG   [registrar] registrar/registrar.go:393  Registry file updated. 1 states written.
2018-07-21T00:51:58.546Z    DEBUG   [service]   service/service.go:51   Received sigterm/sigint, stopping
2018-07-21T00:51:58.546Z    INFO    beater/filebeat.go:437  Stopping filebeat
2018-07-21T00:51:58.546Z    INFO    crawler/crawler.go:139  Stopping Crawler
2018-07-21T00:51:58.546Z    INFO    crawler/crawler.go:149  Stopping 1 inputs
2018-07-21T00:51:58.546Z    INFO    input/input.go:149  input ticker stopped
2018-07-21T00:51:58.546Z    INFO    input/input.go:167  Stopping Input: 3186646878776396347
2018-07-21T00:51:58.546Z    INFO    log/harvester.go:272    Reader was closed: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3. Closing.
2018-07-21T00:51:58.546Z    DEBUG   [harvester] log/harvester.go:507    Stopping harvester for file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.546Z    DEBUG   [harvester] log/harvester.go:517    Closing file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.546Z    DEBUG   [harvester] log/harvester.go:387    Update state: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3, offset: 2
2018-07-21T00:51:58.546Z    DEBUG   [harvester] log/harvester.go:528    harvester cleanup finished for file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/log/input3
2018-07-21T00:51:58.546Z    DEBUG   [publish]   pipeline/client.go:148  client: closing acker
2018-07-21T00:51:58.546Z    DEBUG   [publish]   pipeline/client.go:150  client: done closing acker
2018-07-21T00:51:58.546Z    DEBUG   [publish]   pipeline/client.go:154  client: cancelled 0 events
2018-07-21T00:51:58.546Z    INFO    crawler/crawler.go:165  Crawler stopped
2018-07-21T00:51:58.546Z    INFO    registrar/registrar.go:356  Stopping Registrar
2018-07-21T00:51:58.546Z    INFO    registrar/registrar.go:282  Ending Registrar
2018-07-21T00:51:58.546Z    DEBUG   [registrar] registrar/registrar.go:400  Write registry file: /go/src/github.com/elastic/beats/filebeat/build/system-tests/run/test_registrar.Test.test_clean_inactive/registry
2018-07-21T00:51:58.549Z    DEBUG   [registrar] registrar/registrar.go:393  Registry file updated. 1 states written.
2018-07-21T00:51:58.551Z    INFO    [monitoring]    log/log.go:149  Total non-zero metrics  {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":20,"time":{"ms":28}},"total":{"ticks":40,"time":{"ms":52},"value":40},"user":{"ticks":20,"time":{"ms":24}}},"info":{"ephemeral_id":"b952d3e2-00ca-44a0-ade8-c7c76d
b421de","uptime":{"ms":4520}},"memstats":{"gc_next":4194304,"memory_alloc":1527304,"memory_total":4595688,"rss":23306240}},"filebeat":{"events":{"added":8,"done":8},"harvester":{"closed":3,"open_files":0,"running":0,"started":3}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":3,"batches":
2,"total":3},"type":"file","write":{"bytes":1303}},"pipeline":{"clients":0,"events":{"active":0,"filtered":5,"published":3,"total":8},"queue":{"acked":3}}},"registrar":{"states":{"cleanup":2,"current":1,"update":8},"writes":{"success":8,"total":8}},"system":{"cpu":{"cores":4},"load":{"1":1.35,"15":3.35,"5":4.5,"no
rm":{"1":0.3375,"15":0.8375,"5":1.125}}}}}}
2018-07-21T00:51:58.551Z    INFO    [monitoring]    log/log.go:150  Uptime: 4.5217286s
2018-07-21T00:51:58.551Z    INFO    [monitoring]    log/log.go:127  Stopping metrics logging.
2018-07-21T00:51:58.551Z    INFO    instance/beat.go:373    filebeat stopped.