Cancel build from UI but it still running on Background!

Drone Support
1

Hi @bradrydzewski
I am using Drone 1.0+ with Kubernetes
There is a serious problem when I cancel a build from the UI, its says it killed but the pod is still running! yesterday our developer stop build but it still running and I verify it today, pls help!

Screen Shot 2020-09-08 at 8.21.18 PM
Screen Shot 2020-09-08 at 8.21.18 PM2020×1288 187 KB

Screen Shot 2020-09-08 at 8.27.33 PM
Screen Shot 2020-09-08 at 8.27.33 PM1664×132 24.9 KB

Screen Shot 2020-09-08 at 8.21.30 PM
Screen Shot 2020-09-08 at 8.21.30 PM1664×972 448 KB

2

@bradrydzewski, @ashwilliams1 any update regarding this? its critical!

3

I am using Drone 1.0+ with Kubernetes

What version of the drone server, which version of the drone runner, and which drone runner image? Also can you please provide runner logs with trace logging enabled for the time period where you tried to cancel.

4

@ashwilliams1 ,

Drone server:
repository: drone/drone
tag: 1.9.0

Runner:
repository: drone/drone-runner-kube
tag: latest

Server log:
{“fields.time”:“2020-09-09T07:55:14Z”,“latency”:1224026,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57100”,“request”:"/",“request-id”:“1hGWsKyMMQ3P9zqfuOu1H6gmHgG”,“time”:“2020-09-09T07:55:14Z”}
{“fields.time”:“2020-09-09T07:55:24Z”,“latency”:1248209,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57128”,“request”:"/",“request-id”:“1hGWteNAUpMdC7ibWN76MEW22ya”,“time”:“2020-09-09T07:55:24Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:55:28Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:55:34Z”,“latency”:1296979,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57168”,“request”:"/",“request-id”:“1hGWutuuQ3nfdO56STapqE2QumW”,“time”:“2020-09-09T07:55:34Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:55:38Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:55:44Z”,“latency”:1239176,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57206”,“request”:"/",“request-id”:“1hGWwAn5k9pKnt0uHsCLPUSzaGw”,“time”:“2020-09-09T07:55:44Z”}
{“admin”:true,“level”:“debug”,“msg”:“api: sync repository permissions”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“read”:true,“request-id”:“82df34f1b13cc09cb40c310aa740c9c7”,“time”:“2020-09-09T07:55:53Z”,“user.admin”:true,“user.login”:“ihakimi”,“write”:true}
{“admin”:true,“level”:“debug”,“msg”:“api: repository permissions synchronized”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“read”:true,“request-id”:“82df34f1b13cc09cb40c310aa740c9c7”,“time”:“2020-09-09T07:55:53Z”,“user.admin”:true,“user.login”:“ihakimi”,“write”:true}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“82df34f1b13cc09cb40c310aa740c9c7”,“time”:“2020-09-09T07:55:53Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“82df34f1b13cc09cb40c310aa740c9c7”,“time”:“2020-09-09T07:55:53Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“debug”,“msg”:“trigger: received”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:53Z”}
{“fields.time”:“2020-09-09T07:55:54Z”,“latency”:1329556,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57236”,“request”:"/",“request-id”:“1hGWxLllAn5ft4uIRcSjjcoouI4”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match event”,“pipeline”:“default”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match event”,“pipeline”:“stage”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match deploy target”,“pipeline”:“dogfood”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match deploy target”,“pipeline”:“early”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match deploy target”,“pipeline”:“general-1”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match deploy target”,“pipeline”:“general-2”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“commit”:“c3da4ead12cd7661fd714fe5775ca88813490dbc”,“event”:“promote”,“level”:“info”,“msg”:“trigger: skipping pipeline, does not match deploy target”,“pipeline”:“rollback”,“ref”:“refs/heads/check-drone-cancel”,“repo”:“tlv-opsys/quadra-test-service”,“time”:“2020-09-09T07:55:54Z”}
{“fields.time”:“2020-09-09T07:55:55Z”,“latency”:1746110938,“level”:“debug”,“method”:“POST”,“msg”:"",“remote”:“192.168.16.1:43576”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/90/promote?target=dev\u0026USER_POOL=ipapoush",“request-id”:“82df34f1b13cc09cb40c310aa740c9c7”,“time”:“2020-09-09T07:55:55Z”}
{“level”:“debug”,“machine”:“opsys-kube-drone-runner-kube-666c4cbff9-8dsfq”,“msg”:“manager: accept stage”,“stage-id”:9064,“time”:“2020-09-09T07:55:55Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:55:55Z”,“type”:“kubernetes”,“variant”:""}
{“level”:“debug”,“machine”:“opsys-kube-drone-runner-kube-666c4cbff9-8dsfq”,“msg”:“manager: stage accepted”,“stage-id”:9064,“time”:“2020-09-09T07:55:55Z”}
{“level”:“debug”,“msg”:“manager: fetching stage details”,“step-id”:9064,“time”:“2020-09-09T07:55:55Z”}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44249,“step.name”:“clone”,“step.status”:“running”,“time”:“2020-09-09T07:55:56Z”}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44249,“step.name”:“clone”,“step.status”:“success”,“time”:“2020-09-09T07:56:01Z”}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44250,“step.name”:“toml”,“step.status”:“running”,“time”:“2020-09-09T07:56:01Z”}
{“fields.time”:“2020-09-09T07:56:04Z”,“latency”:1353523,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57288”,“request”:"/",“request-id”:“1hGWygly8NhcnDxvjodRZlPLEam”,“time”:“2020-09-09T07:56:04Z”}
{“fields.time”:“2020-09-09T07:56:05Z”,“latency”:1461781,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/",“request-id”:“db55f857d26d72578991f792cdcc21b6”,“time”:“2020-09-09T07:56:05Z”}
{“fields.time”:“2020-09-09T07:56:05Z”,“latency”:1295859,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/",“request-id”:“c058c1774c709233c903352d363eb9c9”,“time”:“2020-09-09T07:56:05Z”}
{“level”:“debug”,“msg”:“api: authentication required”,“request-id”:“a5a162c8d80df598423183cbb9bde805”,“time”:“2020-09-09T07:56:05Z”}
{“level”:“debug”,“msg”:“api: guest access”,“request-id”:“a5a162c8d80df598423183cbb9bde805”,“time”:“2020-09-09T07:56:05Z”}
{“fields.time”:“2020-09-09T07:56:05Z”,“latency”:126662,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/user",“request-id”:“a5a162c8d80df598423183cbb9bde805”,“time”:“2020-09-09T07:56:05Z”}
{“fields.time”:“2020-09-09T07:56:05Z”,“latency”:52623,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/login",“request-id”:“97821453a4232b2530ba84758c269a58”,“time”:“2020-09-09T07:56:05Z”}
{“level”:“debug”,“msg”:“events: stream opened”,“request-id”:“fd7f0389009492d5d8e60ccddb77362a”,“time”:“2020-09-09T07:56:05Z”}
{“level”:“debug”,“login”:“ihakimi”,“msg”:“attempting authentication”,“time”:“2020-09-09T07:56:07Z”}
{“level”:“debug”,“login”:“ihakimi”,“msg”:“authentication successful”,“time”:“2020-09-09T07:56:07Z”}
{“fields.time”:“2020-09-09T07:56:07Z”,“latency”:620662833,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/login?code=a32f72783973a08e5c64\u0026state=430c8b35bb9457d8",“request-id”:“0adf6c3fe01e4f3808b8715bbf3c9414”,“time”:“2020-09-09T07:56:07Z”}
{“fields.time”:“2020-09-09T07:56:07Z”,“latency”:2506850,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/",“request-id”:“e023066866cfd21f70b584e1cbf5f681”,“time”:“2020-09-09T07:56:07Z”}
{“fields.time”:“2020-09-09T07:56:08Z”,“latency”:1486015,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43662”,“request”:"/api/user",“request-id”:“78ee7c92e8ce5ab0e1b5cc115c7d87aa”,“time”:“2020-09-09T07:56:08Z”}
{“fields.time”:“2020-09-09T07:56:08Z”,“latency”:19137036,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/user/repos?latest=true",“request-id”:“8d04482cc3d8d2c35d9cb60a3d62ca31”,“time”:“2020-09-09T07:56:08Z”}
{“fields.time”:“2020-09-09T07:56:08Z”,“latency”:4454259,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/user/builds/recent",“request-id”:“88712f81f3d5697c5d0098cbd360d5ab”,“time”:“2020-09-09T07:56:08Z”}
{“level”:“debug”,“msg”:“events: stream opened”,“request-id”:“711ee60d95ee4b2a1a5cecdf05f696bf”,“time”:“2020-09-09T07:56:08Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:08Z”,“latency”:16533657,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43662”,“request”:"/api/user/repos?latest=true",“request-id”:“5537b3739bf6aa013a86ab65152880e3”,“time”:“2020-09-09T07:56:08Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“3fc4108a9eb32dcc5de896ac2a6ac577”,“time”:“2020-09-09T07:56:09Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:09Z”,“latency”:3760900,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/repos/tlv-opsys/quadra-test-service",“request-id”:“3fc4108a9eb32dcc5de896ac2a6ac577”,“time”:“2020-09-09T07:56:09Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“9febfa58c9c73282b507a1202783b207”,“time”:“2020-09-09T07:56:09Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:09Z”,“latency”:6443426,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57336”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds?page=1",“request-id”:“9febfa58c9c73282b507a1202783b207”,“time”:“2020-09-09T07:56:09Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“6e07789e494a39e4ef43abe5923bac85”,“time”:“2020-09-09T07:56:10Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:10Z”,“latency”:3685214,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43662”,“request”:"/api/repos/tlv-opsys/quadra-test-service",“request-id”:“6e07789e494a39e4ef43abe5923bac85”,“time”:“2020-09-09T07:56:10Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“fcf2dd981fdcd70b476976029797bb83”,“time”:“2020-09-09T07:56:10Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:10Z”,“latency”:7430741,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43674”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106",“request-id”:“fcf2dd981fdcd70b476976029797bb83”,“time”:“2020-09-09T07:56:10Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“6c1ff9eea9e7344a70828717872959de”,“time”:“2020-09-09T07:56:11Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:11Z”,“latency”:9094157,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57336”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106/logs/1/1",“request-id”:“6c1ff9eea9e7344a70828717872959de”,“time”:“2020-09-09T07:56:11Z”}
{“fields.time”:“2020-09-09T07:56:14Z”,“latency”:1189381,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57342”,“request”:"/",“request-id”:“1hGWzvclVjvR9pI14C6svoejXAN”,“time”:“2020-09-09T07:56:14Z”}
{“fields.time”:“2020-09-09T07:56:24Z”,“latency”:1209323,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57370”,“request”:"/",“request-id”:“1hGX1BY8E7rnMzW7Gq32FFcTOzw”,“time”:“2020-09-09T07:56:24Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:56:25Z”,“type”:“kubernetes”,“variant”:""}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44250,“step.name”:“toml”,“step.status”:“success”,“time”:“2020-09-09T07:56:31Z”}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44251,“step.name”:“deploy”,“step.status”:“running”,“time”:“2020-09-09T07:56:31Z”}
{“fields.time”:“2020-09-09T07:56:34Z”,“latency”:1375957,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57410”,“request”:"/",“request-id”:“1hGX2NpT2M7w08Gk9vrenAt6uBf”,“time”:“2020-09-09T07:56:34Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:56:35Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:56:44Z”,“latency”:1570729,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57450”,“request”:"/",“request-id”:“1hGX3cA6JA5gR9stpVuPM7gbTsE”,“time”:“2020-09-09T07:56:44Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“ce5cd0d5c79c456f9d9c3dc5b836c615”,“time”:“2020-09-09T07:56:44Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:44Z”,“latency”:3729511,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57336”,“request”:"/api/repos/tlv-opsys/quadra-test-service",“request-id”:“ce5cd0d5c79c456f9d9c3dc5b836c615”,“time”:“2020-09-09T07:56:44Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“e8df2ce75da0d239d3783e49598e8461”,“time”:“2020-09-09T07:56:44Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“a78cc316e801562f7b1e5f7655980607”,“time”:“2020-09-09T07:56:44Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:56:44Z”,“latency”:10150847,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43674”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106",“request-id”:“e8df2ce75da0d239d3783e49598e8461”,“time”:“2020-09-09T07:56:44Z”}
{“fields.time”:“2020-09-09T07:56:54Z”,“latency”:1288968,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57478”,“request”:"/",“request-id”:“1hGX4tLKRgcKvPO1Syb8S7W2yLa”,“time”:“2020-09-09T07:56:54Z”}
{“fields.time”:“2020-09-09T07:57:04Z”,“latency”:1267148,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57518”,“request”:"/",“request-id”:“1hGX68FXOi4E1reyiQQ9Nw5nd8o”,“time”:“2020-09-09T07:57:04Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“40f523f4e9b5ccc7668267b3dc395075”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:05Z”,“latency”:3783012,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57336”,“request”:"/api/repos/tlv-opsys/quadra-test-service",“request-id”:“40f523f4e9b5ccc7668267b3dc395075”,“time”:“2020-09-09T07:57:05Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“7eaa35071bc10e90e602eccab4e03bec”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:05Z”,“latency”:7543359,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106",“request-id”:“7eaa35071bc10e90e602eccab4e03bec”,“time”:“2020-09-09T07:57:05Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:57:05Z”,“type”:“kubernetes”,“variant”:""}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“c42ff81766f1f7825aae398e781f6677”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:05Z”,“latency”:9117694,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43674”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106/logs/1/2",“request-id”:“c42ff81766f1f7825aae398e781f6677”,“time”:“2020-09-09T07:57:05Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“dc95aa83357015aba61a70fdc921a79a”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:05Z”,“latency”:3436739,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:43674”,“request”:"/api/repos/tlv-opsys/quadra-test-service",“request-id”:“dc95aa83357015aba61a70fdc921a79a”,“time”:“2020-09-09T07:57:05Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“c06ffe2f2608b57c83908f2868b7437b”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:05Z”,“latency”:7078018,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106",“request-id”:“c06ffe2f2608b57c83908f2868b7437b”,“time”:“2020-09-09T07:57:05Z”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“6e29d13ecacb173c297a4a2180f58939”,“time”:“2020-09-09T07:57:05Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:57:14Z”,“latency”:1422989,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57576”,“request”:"/",“request-id”:“1hGX7NyWBoEMVy4qVzcDREcmJTX”,“time”:“2020-09-09T07:57:14Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:57:15Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:57:24Z”,“latency”:1282010,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57604”,“request”:"/",“request-id”:“1hGX8iaQE47PocpJYprA3yvOXLA”,“time”:“2020-09-09T07:57:24Z”}
{“fields.time”:“2020-09-09T07:57:34Z”,“latency”:1289311,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57644”,“request”:"/",“request-id”:“1hGX9wQ0X3sfexRnB4rkIArBThk”,“time”:“2020-09-09T07:57:34Z”}
{“fields.time”:“2020-09-09T07:57:44Z”,“latency”:5484213,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57672”,“request”:"/",“request-id”:“1hGXBFwYgBL7GPU2R0fSjPulfl0”,“time”:“2020-09-09T07:57:44Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:57:45Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:57:54Z”,“latency”:1226820,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57692”,“request”:"/",“request-id”:“1hGXCPXqMYNnFiJKQIrLnNpJT4w”,“time”:“2020-09-09T07:57:54Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:57:55Z”,“type”:“kubernetes”,“variant”:""}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“30e7928c128cc1320519828bd215b878”,“time”:“2020-09-09T07:58:00Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“level”:“debug”,“msg”:“api: root access granted”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“30e7928c128cc1320519828bd215b878”,“time”:“2020-09-09T07:58:00Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“build”:106,“level”:“debug”,“msg”:“api: successfully cancelled build”,“name”:“quadra-test-service”,“namespace”:“tlv-opsys”,“request-id”:“30e7928c128cc1320519828bd215b878”,“time”:“2020-09-09T07:58:01Z”,“user.admin”:true,“user.login”:“ihakimi”}
{“fields.time”:“2020-09-09T07:58:01Z”,“latency”:577589055,“level”:“debug”,“method”:“DELETE”,“msg”:"",“remote”:“192.168.208.12:57324”,“request”:"/api/repos/tlv-opsys/quadra-test-service/builds/106",“request-id”:“30e7928c128cc1320519828bd215b878”,“time”:“2020-09-09T07:58:01Z”}
{“fields.time”:“2020-09-09T07:58:04Z”,“latency”:1254001,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57734”,“request”:"/",“request-id”:“1hGXDkhj4LAfBjyHdx3DMInZuRh”,“time”:“2020-09-09T07:58:04Z”}
{“fields.time”:“2020-09-09T07:58:14Z”,“latency”:1257620,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57772”,“request”:"/",“request-id”:“1hGXExykjMJ04ZC3XqREHF964FY”,“time”:“2020-09-09T07:58:14Z”}
{“fields.time”:“2020-09-09T07:58:24Z”,“latency”:1261220,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57800”,“request”:"/",“request-id”:“1hGXGBn04RMGJ908d3OjMvrmCID”,“time”:“2020-09-09T07:58:24Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:58:25Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:58:34Z”,“latency”:1214850,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57840”,“request”:"/",“request-id”:“1hGXHWC8yUy2HyKmFDf3RUTPIgR”,“time”:“2020-09-09T07:58:34Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:58:35Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:58:44Z”,“latency”:1296222,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57878”,“request”:"/",“request-id”:“1hGXIn14okQ6zpSt7dJgGnOVZfI”,“time”:“2020-09-09T07:58:44Z”}
{“fields.time”:“2020-09-09T07:58:54Z”,“latency”:1267135,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57906”,“request”:"/",“request-id”:“1hGXJydo310GW09KoIP0vZPZydH”,“time”:“2020-09-09T07:58:54Z”}
{“fields.time”:“2020-09-09T07:59:04Z”,“latency”:1312379,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57946”,“request”:"/",“request-id”:“1hGXLG33vh91dw2lPccox6YIJ4v”,“time”:“2020-09-09T07:59:04Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: context canceled”,“os”:"",“time”:“2020-09-09T07:59:05Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:59:14Z”,“latency”:1447743,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:57984”,“request”:"/",“request-id”:“1hGXMZ1MFh7j2apDLwP27i8gSYi”,“time”:“2020-09-09T07:59:14Z”}
{“arch”:"",“kernel”:"",“kind”:“pipeline”,“level”:“debug”,“msg”:“manager: request queue item”,“os”:"",“time”:“2020-09-09T07:59:15Z”,“type”:“kubernetes”,“variant”:""}
{“fields.time”:“2020-09-09T07:59:24Z”,“latency”:1277782,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:58012”,“request”:"/",“request-id”:“1hGXNiRIO0myim9er3oEFZjro2L”,“time”:“2020-09-09T07:59:24Z”}
{“fields.time”:“2020-09-09T07:59:34Z”,“latency”:1301642,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.176.0:58054”,“request”:"/",“request-id”:“1hGXP03Z27sW3lGeI1nU8abD11W”,“time”:“2020-09-09T07:59:34Z”}
{“level”:“debug”,“msg”:“manager: updating step status”,“step.id”:44251,“step.name”:“deploy”,“step.status”:“error”,“time”:“2020-09-09T08:09:44Z”}
{“error”:“Optimistic Lock Error”,“level”:“warning”,“msg”:“manager: cannot update step”,“step.id”:44251,“step.name”:“deploy”,“step.status”:“error”,“time”:“2020-09-09T08:09:44Z”}
{“error”:“Optimistic Lock Error”,“level”:“warning”,“msg”:“manager: cannot update step”,“step.id”:44251,“step.name”:“deploy”,“step.status”:“error”,“time”:“2020-09-09T08:09:44Z”}
{“fields.time”:“2020-09-09T08:09:44Z”,“latency”:277047140335,“level”:“debug”,“method”:“GET”,“msg”:"",“remote”:“192.168.16.1:46402”,“request”:"/api/stream/tlv-opsys/quadra-test-service/106/1/3",“request-id”:“89a912d9dcbd4df55e3baf580285a119”,“time”:“2020-09-09T08:09:44Z”}
{“level”:“debug”,“msg”:“manager: stage is complete. teardown”,“stage.id”:9064,“time”:“2020-09-09T08:09:44Z”}
{“build.id”:7872,“build.number”:106,“error”:“Optimistic Lock Error”,“level”:“warning”,“msg”:“manager: cannot persist the step”,“repo.id”:3712,“stage.id”:9064,“stage.status”:“error”,“step.id”:44251,“step.name”:“deploy”,“time”:“2020-09-09T08:09:44Z”}

Runner log:
time=“2020-09-09T07:55:28Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:55:55Z” level=debug msg=“stage received” stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T07:55:55Z” level=debug msg=“stage accepted” stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T07:55:56Z” level=debug msg=“stage details fetched” build.id=7872 build.number=106 repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T07:55:56Z” level=trace msg=“environment: external: environment variable list returned” thread=100
time=“2020-09-09T07:55:56Z” level=trace msg=“secret: database: found matching secret” kind=secret name=QUADRA_TOKEN thread=100
time=“2020-09-09T07:55:56Z” level=trace msg=“secret: database: found matching secret” kind=secret name=QUADRA_USERNAME thread=100
time=“2020-09-09T07:55:56Z” level=trace msg=“secret: database: found matching secret” kind=secret name=WEBEX_ACCESS_TOKEN thread=100
time=“2020-09-09T07:55:56Z” level=trace msg=“registry: external: received credentials” address=xxxx.xxxx.xxxx thread=100 username=xxxxxxx.id.xxxx.xxxx.net
time=“2020-09-09T07:55:56Z” level=trace msg=“registry: external: received credentials” address=xxxxxxxxx.dkr.ecr.us-east-1.amazonaws.com thread=100 username=AWS
time=“2020-09-09T07:55:56Z” level=trace msg=“registry: external: received credentials” address=xxxxxxxxx.dkr.ecr.us-west-1.amazonaws.com thread=100 username=AWS
time=“2020-09-09T07:55:56Z” level=debug msg=“updated stage to running” build.id=7872 build.number=106 repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T07:56:25Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:56:26Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:57:05Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:57:06Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:57:45Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:57:46Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T07:58:00Z” level=debug msg=“received cancellation” build.id=7872 build.number=106 repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T07:58:25Z” level=trace msg=“http: no content returned: re-connect and re-try”

time=“2020-09-09T08:00:25Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T08:01:05Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T08:01:45Z” level=trace msg=“http: no content returned: re-connect and re-try”
…
…
time=“2020-09-09T08:09:45Z” level=trace msg=“http: no content returned: re-connect and re-try”
time=“2020-09-09T08:09:49Z” level=debug msg=“stage failed” build.id=7872 build.number=106 duration=828 error=“2 errors occurred:\n\t* 1 error occurred:\n\t* Optimistic Lock Error\n\n\n\t* Optimistic Lock Error\n\n” repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
time=“2020-09-09T08:09:49Z” level=debug msg=“poller: request stage from remote server” thread=100
time=“2020-09-09T08:10:25Z” level=trace msg=“http: no content returned: re-connect and re-try”

*time=“2020-09-09T08:09:49Z” level=debug msg=“stage failed” build - this error appear after container finish its running long long after the cancellation.

5

@ashwilliams1 more finidings
when running it with docker-runner it stop the build+container!
when running it with drone/agent (old config) the build continue to run!

6

Thanks for providing the logs. I will analyze to see if they provide any useful details, as I was unable to reproduce the issue on my cluster. At a minimum, perhaps we can add some better logging to the runner.

Two questions. First, can you confirm you are running a new version of the kubernetes image? It is difficult to know if the :latest tag represents a new build or an old build since it could have been served from your docker cache. Second, does the runner have adequate permissions to delete the pod? https://docs.drone.io/runner/kubernetes/installation/#installation

note that drone/agent is deprecated and is no longer supported. If you are using the docker runner you should only use the drone/drone-runner-docker image. Have you tried running drone/drone-runner-docker in production given the kubernetes runner is still beta?

7

Thanks for the quick response,
for the tag I am using latest because I don’t see you generate new tags for kube-runner, and for kuberenetes when you use latest its always pull pullPolicy: Always
I am using helm chart to install all sever+runner and I saw the RBAC

Look on the runner logs
time=“2020-09-09T07:58:00Z” level=debug msg=“received cancellation” build.id=7872 build.number=106 repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
(this is the time when press cancel)

time=“2020-09-09T08:09:49Z” level=debug msg=“stage failed” build.id=7872 build.number=106 duration=828 error=“2 errors occurred:\n\t* 1 error occurred:\n\t* Optimistic Lock Error\n\n\n\t* Optimistic Lock Error\n\n” repo.id=3712 repo.name=quadra-test-service repo.namespace=tlv-opsys stage.id=9064 stage.name=dev stage.number=1 thread=100
this is the time when container finish the running with deployment and exit

8

another symptom I am seeing is that the step which I cancel is continue but after is not continue

9

@ashwilliams1 any update regarding this?

10

I’ll run some tests tomorrow to try and reproduce. I am also working on an update to the runner to hopefully bring it one step closer to moving of beta … should have a new release candidate ready next week for testing.

11

Thanks @bradrydzewski really appreciate it

12

@bradrydzewski any update regarding this? I also set
terminationGracePeriodSeconds: 10

but its not helpful

13

@ashwilliams1, @bradrydzewski any update for that issue?

14

@bradrydzewski any update regarding this??? its still happen with latest version?

15

@bradrydzewski @ashwilliams1 We are also facing the same issue with drone-runner-kube:latest

The pods get deleted when the test fails or passes. But when we are manually cancelling the tests, the pods are still running in the background.

16

Fix for the issue has been merged in drone/drone-runner-kube latest master.

17

Hi, what is the tag of the drone/drone-runner-kube with this fix ?
Facing the same issue with drone/drone-runner-docker internal dind containr is not killed/stoped.
and continue to run. I m using drone/drone-runner-docker:1.6.3