| 2020-04-17 15:39:12 |
Michael Skalka |
description |
During this test run: https://solutions.qa.canonical.com/#/qa/testRun/5135ff55-420e-4d56-bed8-1b3701ebdf2b while waiting for a model to settle the controller unexpected reported the model to be dropped.
Looking in the controller logs before that timestamp the controller's machine-0 worker start to error a minute or so before:
2020-04-16 16:35:53 INFO juju.worker.logger logger.go:118 logger worker started 2020-04-16 16:45:04 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:04 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:13 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:23 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:23 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:33 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:33 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:43 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:48 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "e081baef-037d-45e7-8a71-cc66adc9ccf6" "e081baef-037d-45e7-8a71-cc66adc9ccf6"} for "machine-0" 2020-04-16 16:45:48 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:45:55 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:55 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:03 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43710->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:05 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:32974->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:09 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:46:09 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:12 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "08dd5d4f-a07e-428b-81f7-7bf6142b6d50"} for "machine-0" 2020-04-16 16:46:12 ERROR juju.worker.dependency engine.go:662 "is-primary-controller-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:14 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43650->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:14 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33018->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:15 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43714->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33228->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43672->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33220->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:17 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43712->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:17 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33224->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:18 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "582bddfa-0b76-41c0-8ccb-3f207775be84" "582bddfa-0b76-41c0-8ccb-3f207775be84"} for "machine-0" 2020-04-16 16:46:18 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388"} for "machine-0" 2020-04-16 16:46:18 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:18 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:19 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43674->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:20 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33012->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:23 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43632->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:25 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:26 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43648->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:29 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:33572->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:30 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:33044->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:41 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "e081baef-037d-45e7-8a71-cc66adc9ccf6" "e081baef-037d-45e7-8a71-cc66adc9ccf6"} for "machine-0" 2020-04-16 16:46:41 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:41 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:48 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43716->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:59 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:46:59 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:47:05 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "08dd5d4f-a07e-428b-81f7-7bf6142b6d50"} for "machine-0" 2020-04-16 16:47:05 ERROR juju.worker.dependency engine.go:662 "is-primary-controller-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:11 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388"} for "machine-0" 2020-04-16 16:47:11 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:11 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "582bddfa-0b76-41c0-8ccb-3f207775be84" "582bddfa-0b76-41c0-8ccb-3f207775be84"} for "machine-0" 2020-04-16 16:47:11 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:20 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "migration-master" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "unit-assigner" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "metric-worker" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "instance-poller" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "storage-provisioner" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "application-scaler" manifold worker returned unexpected error: fortress worker shutting down
... Long list of workers shutting down ...
This is followed by a number of i/o timeouts connecting to itself. |
During this test run: https://solutions.qa.canonical.com/#/qa/testRun/5135ff55-420e-4d56-bed8-1b3701ebdf2b while waiting for a model to settle the controller unexpectedly reports the model to be dropped.
Looking in the controller logs before that timestamp the controller's machine-0 worker start to error a minute or so before:
2020-04-16 16:35:53 INFO juju.worker.logger logger.go:118 logger worker started 2020-04-16 16:45:04 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:04 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:13 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:23 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:23 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:33 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:33 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:43 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:45:48 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "e081baef-037d-45e7-8a71-cc66adc9ccf6" "e081baef-037d-45e7-8a71-cc66adc9ccf6"} for "machine-0" 2020-04-16 16:45:48 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:45:55 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:45:55 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:03 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43710->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:05 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:32974->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:09 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:46:09 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:12 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "08dd5d4f-a07e-428b-81f7-7bf6142b6d50"} for "machine-0" 2020-04-16 16:46:12 ERROR juju.worker.dependency engine.go:662 "is-primary-controller-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:14 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43650->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:14 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33018->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:15 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43714->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33228->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43672->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:16 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33220->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:17 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43712->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:17 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33224->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:18 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "582bddfa-0b76-41c0-8ccb-3f207775be84" "582bddfa-0b76-41c0-8ccb-3f207775be84"} for "machine-0" 2020-04-16 16:46:18 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388"} for "machine-0" 2020-04-16 16:46:18 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:18 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:19 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43674->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:20 ERROR juju.state status.go:549 failed to update status history: read tcp 10.245.201.151:33012->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:23 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43632->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:25 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:26 ERROR juju.state status.go:558 failed to write status history: read tcp 127.0.0.1:43648->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:29 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:33572->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:30 ERROR juju.state status.go:558 failed to write status history: read tcp 10.245.201.151:33044->10.245.201.151:37017: i/o timeout 2020-04-16 16:46:41 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "e081baef-037d-45e7-8a71-cc66adc9ccf6" "e081baef-037d-45e7-8a71-cc66adc9ccf6"} for "machine-0" 2020-04-16 16:46:41 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:46:41 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:46:48 ERROR juju.state status.go:549 failed to update status history: read tcp 127.0.0.1:43716->127.0.0.1:37017: i/o timeout 2020-04-16 16:46:59 WARNING juju.worker.globalclockupdater.raft worker.go:122 timed out updating clock, retrying in 1s 2020-04-16 16:46:59 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:47:05 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "08dd5d4f-a07e-428b-81f7-7bf6142b6d50"} for "machine-0" 2020-04-16 16:47:05 ERROR juju.worker.dependency engine.go:662 "is-primary-controller-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:11 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388" "95ce81b7-40a0-4dc7-84c5-5e78e8bae388"} for "machine-0" 2020-04-16 16:47:11 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:11 WARNING juju.worker.lease.raft manager.go:303 [08dd5d] retrying timed out while handling claim {"singular-controller" "582bddfa-0b76-41c0-8ccb-3f207775be84" "582bddfa-0b76-41c0-8ccb-3f207775be84"} for "machine-0" 2020-04-16 16:47:11 ERROR juju.worker.dependency engine.go:662 "is-responsible-flag" manifold worker returned unexpected error: lease operation timed out 2020-04-16 16:47:20 ERROR juju.worker.dependency engine.go:662 "raft-forwarder" manifold worker returned unexpected error: applying command: timed out enqueuing operation 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "migration-master" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "unit-assigner" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "metric-worker" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "instance-poller" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "storage-provisioner" manifold worker returned unexpected error: fortress worker shutting down 2020-04-16 16:47:21 ERROR juju.worker.dependency engine.go:662 "application-scaler" manifold worker returned unexpected error: fortress worker shutting down
... Long list of workers shutting down ...
This is followed by a number of i/o timeouts connecting to itself. |
|
