cockroach-operator
cockroach-operator copied to clipboard
Published
20 hours ago âĸ
cockroachdb
cockroachdb
Decommission e2e possible timing issue
2021-06-11T17:18:22.7554480Z ##[section]Starting: Request a runner to run this job
2021-06-11T17:18:23.2802666Z Can't find any online and idle self-hosted runner in current repository that matches the required labels: 'ubuntu-latest'
2021-06-11T17:18:23.3338704Z Can't find any online and idle self-hosted runner in current repository's organization account that matches the required labels: 'ubuntu-latest'
2021-06-11T17:18:23.4760680Z Found online and idle hosted runner in current repository's organization account that matches the required labels: 'ubuntu-latest'
2021-06-11T17:18:23.6817393Z ##[section]Finishing: Request a runner to run this job
2021-06-11T17:18:31.7107649Z Current runner version: '2.278.0'
2021-06-11T17:18:31.7137562Z ##[group]Operating System
2021-06-11T17:18:31.7138533Z Ubuntu
2021-06-11T17:18:31.7138973Z 20.04.2
2021-06-11T17:18:31.7139507Z LTS
2021-06-11T17:18:31.7139953Z ##[endgroup]
2021-06-11T17:18:31.7140476Z ##[group]Virtual Environment
2021-06-11T17:18:31.7141307Z Environment: ubuntu-20.04
2021-06-11T17:18:31.7141853Z Version: 20210606.1
2021-06-11T17:18:31.7142920Z Included Software: https://github.com/actions/virtual-environments/blob/ubuntu20/20210606.1/images/linux/Ubuntu2004-README.md
2021-06-11T17:18:31.7144307Z Image Release: https://github.com/actions/virtual-environments/releases/tag/ubuntu20%2F20210606.1
2021-06-11T17:18:31.7145274Z ##[endgroup]
2021-06-11T17:18:31.7147235Z ##[group]GITHUB_TOKEN Permissions
2021-06-11T17:18:31.7148435Z Actions: read
2021-06-11T17:18:31.7148985Z Checks: read
2021-06-11T17:18:31.7149476Z Contents: read
2021-06-11T17:18:31.7150089Z Deployments: read
2021-06-11T17:18:31.7150758Z Discussions: read
2021-06-11T17:18:31.7151330Z Issues: read
2021-06-11T17:18:31.7151882Z Metadata: read
2021-06-11T17:18:31.7152402Z Packages: read
2021-06-11T17:18:31.7152990Z PullRequests: read
2021-06-11T17:18:31.7153658Z RepositoryProjects: read
2021-06-11T17:18:31.7154256Z SecurityEvents: read
2021-06-11T17:18:31.7154734Z Statuses: read
2021-06-11T17:18:31.7155361Z ##[endgroup]
2021-06-11T17:18:31.7159978Z Prepare workflow directory
2021-06-11T17:18:31.7817101Z Prepare all required actions
2021-06-11T17:18:31.7827114Z Getting action download info
2021-06-11T17:18:32.1929120Z Download action repository 'actions/checkout@v2'
2021-06-11T17:18:34.2409208Z Download action repository 'abhinavsingh/setup-bazel@v3'
2021-06-11T17:18:34.7249347Z ##[group]Run actions/checkout@v2
2021-06-11T17:18:34.7250016Z with:
2021-06-11T17:18:34.7250648Z repository: cockroachdb/cockroach-operator
2021-06-11T17:18:34.7251768Z token: ***
2021-06-11T17:18:34.7252283Z ssh-strict: true
2021-06-11T17:18:34.7252716Z persist-credentials: true
2021-06-11T17:18:34.7253155Z clean: true
2021-06-11T17:18:34.7253506Z fetch-depth: 1
2021-06-11T17:18:34.7253866Z lfs: false
2021-06-11T17:18:34.7254212Z submodules: false
2021-06-11T17:18:34.7254585Z ##[endgroup]
2021-06-11T17:18:34.9633123Z Syncing repository: cockroachdb/cockroach-operator
2021-06-11T17:18:34.9674869Z ##[group]Getting Git version info
2021-06-11T17:18:34.9676620Z Working directory is '/home/runner/work/cockroach-operator/cockroach-operator'
2021-06-11T17:18:34.9716420Z [command]/usr/bin/git version
2021-06-11T17:18:34.9839871Z git version 2.31.1
2021-06-11T17:18:34.9865469Z ##[endgroup]
2021-06-11T17:18:34.9875303Z Deleting the contents of '/home/runner/work/cockroach-operator/cockroach-operator'
2021-06-11T17:18:34.9882958Z ##[group]Initializing the repository
2021-06-11T17:18:34.9889006Z [command]/usr/bin/git init /home/runner/work/cockroach-operator/cockroach-operator
2021-06-11T17:18:34.9960048Z hint: Using 'master' as the name for the initial branch. This default branch name
2021-06-11T17:18:34.9960999Z hint: is subject to change. To configure the initial branch name to use in all
2021-06-11T17:18:34.9962040Z hint: of your new repositories, which will suppress this warning, call:
2021-06-11T17:18:34.9962951Z hint:
2021-06-11T17:18:34.9963805Z hint: git config --global init.defaultBranch <name>
2021-06-11T17:18:34.9964467Z hint:
2021-06-11T17:18:34.9965308Z hint: Names commonly chosen instead of 'master' are 'main', 'trunk' and
2021-06-11T17:18:34.9966441Z hint: 'development'. The just-created branch can be renamed via this command:
2021-06-11T17:18:34.9967166Z hint:
2021-06-11T17:18:34.9968016Z hint: git branch -m <name>
2021-06-11T17:18:34.9973918Z Initialized empty Git repository in /home/runner/work/cockroach-operator/cockroach-operator/.git/
2021-06-11T17:18:34.9983540Z [command]/usr/bin/git remote add origin https://github.com/cockroachdb/cockroach-operator
2021-06-11T17:18:35.0024869Z ##[endgroup]
2021-06-11T17:18:35.0025814Z ##[group]Disabling automatic garbage collection
2021-06-11T17:18:35.0029512Z [command]/usr/bin/git config --local gc.auto 0
2021-06-11T17:18:35.0070717Z ##[endgroup]
2021-06-11T17:18:35.0075144Z ##[group]Setting up auth
2021-06-11T17:18:35.0082314Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2021-06-11T17:18:35.0112038Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :
2021-06-11T17:18:35.6937436Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2021-06-11T17:18:35.6988873Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :
2021-06-11T17:18:35.6991221Z [command]/usr/bin/git config --local http.https://github.com/.extraheader AUTHORIZATION: basic ***
2021-06-11T17:18:35.6992456Z ##[endgroup]
2021-06-11T17:18:35.6993235Z ##[group]Fetching the repository
2021-06-11T17:18:35.6995133Z [command]/usr/bin/git -c protocol.version=2 fetch --no-tags --prune --progress --no-recurse-submodules --depth=1 origin +86e92034c35efa1362928d205b69e9d108e48856:refs/remotes/pull/547/merge
2021-06-11T17:18:35.6996671Z remote: Enumerating objects: 474, done.
2021-06-11T17:18:35.6997489Z remote: Counting objects: 0% (1/474)
2021-06-11T17:18:35.6998268Z remote: Counting objects: 1% (5/474)
2021-06-11T17:18:35.6999039Z remote: Counting objects: 2% (10/474)
2021-06-11T17:18:35.6999931Z remote: Counting objects: 3% (15/474)
2021-06-11T17:18:35.7000854Z remote: Counting objects: 4% (19/474)
2021-06-11T17:18:35.7001602Z remote: Counting objects: 5% (24/474)
2021-06-11T17:18:35.7002331Z remote: Counting objects: 6% (29/474)
2021-06-11T17:18:35.7003043Z remote: Counting objects: 7% (34/474)
2021-06-11T17:18:35.7003770Z remote: Counting objects: 8% (38/474)
2021-06-11T17:18:35.7004503Z remote: Counting objects: 9% (43/474)
2021-06-11T17:18:35.7005214Z remote: Counting objects: 10% (48/474)
2021-06-11T17:18:35.7005948Z remote: Counting objects: 11% (53/474)
2021-06-11T17:18:35.7006658Z remote: Counting objects: 12% (57/474)
2021-06-11T17:18:35.7008691Z remote: Counting objects: 13% (62/474)
2021-06-11T17:18:35.7009720Z remote: Counting objects: 14% (67/474)
2021-06-11T17:18:35.7010351Z remote: Counting objects: 15% (72/474)
2021-06-11T17:18:35.7010992Z remote: Counting objects: 16% (76/474)
2021-06-11T17:18:35.7011644Z remote: Counting objects: 17% (81/474)
2021-06-11T17:18:35.7012275Z remote: Counting objects: 18% (86/474)
2021-06-11T17:18:35.7012911Z remote: Counting objects: 19% (91/474)
2021-06-11T17:18:35.7013539Z remote: Counting objects: 20% (95/474)
2021-06-11T17:18:35.7014370Z remote: Counting objects: 21% (100/474)
2021-06-11T17:18:35.7015114Z remote: Counting objects: 22% (105/474)
2021-06-11T17:18:35.7015911Z remote: Counting objects: 23% (110/474)
2021-06-11T17:18:35.7016641Z remote: Counting objects: 24% (114/474)
2021-06-11T17:18:35.7017356Z remote: Counting objects: 25% (119/474)
2021-06-11T17:18:35.7018409Z remote: Counting objects: 26% (124/474)
2021-06-11T17:18:35.7019153Z remote: Counting objects: 27% (128/474)
2021-06-11T17:18:35.7019865Z remote: Counting objects: 28% (133/474)
2021-06-11T17:18:35.7020595Z remote: Counting objects: 29% (138/474)
2021-06-11T17:18:35.7021334Z remote: Counting objects: 30% (143/474)
2021-06-11T17:18:35.7022049Z remote: Counting objects: 31% (147/474)
2021-06-11T17:18:35.7022779Z remote: Counting objects: 32% (152/474)
2021-06-11T17:18:35.7023492Z remote: Counting objects: 33% (157/474)
2021-06-11T17:18:35.7024392Z remote: Counting objects: 34% (162/474)
2021-06-11T17:18:35.7025583Z remote: Counting objects: 35% (166/474)
2021-06-11T17:18:35.7026313Z remote: Counting objects: 36% (171/474)
2021-06-11T17:18:35.7027040Z remote: Counting objects: 37% (176/474)
2021-06-11T17:18:35.7027753Z remote: Counting objects: 38% (181/474)
2021-06-11T17:18:35.7028600Z remote: Counting objects: 39% (185/474)
2021-06-11T17:18:35.7029330Z remote: Counting objects: 40% (190/474)
2021-06-11T17:18:35.7030045Z remote: Counting objects: 41% (195/474)
2021-06-11T17:18:35.7030769Z remote: Counting objects: 42% (200/474)
2021-06-11T17:18:35.7031511Z remote: Counting objects: 43% (204/474)
2021-06-11T17:18:35.7033060Z remote: Counting objects: 44% (209/474)
2021-06-11T17:18:35.7034398Z remote: Counting objects: 45% (214/474)
2021-06-11T17:18:35.7035062Z remote: Counting objects: 46% (219/474)
2021-06-11T17:18:35.7035734Z remote: Counting objects: 47% (223/474)
2021-06-11T17:18:35.7036599Z remote: Counting objects: 48% (228/474)
2021-06-11T17:18:35.7037389Z remote: Counting objects: 49% (233/474)
2021-06-11T17:18:35.7038180Z remote: Counting objects: 50% (237/474)
2021-06-11T17:18:35.7038946Z remote: Counting objects: 51% (242/474)
2021-06-11T17:18:35.7039726Z remote: Counting objects: 52% (247/474)
2021-06-11T17:18:35.7040497Z remote: Counting objects: 53% (252/474)
2021-06-11T17:18:35.7041274Z remote: Counting objects: 54% (256/474)
2021-06-11T17:18:35.7042055Z remote: Counting objects: 55% (261/474)
2021-06-11T17:18:35.7042825Z remote: Counting objects: 56% (266/474)
2021-06-11T17:18:35.7043760Z remote: Counting objects: 57% (271/474)
2021-06-11T17:18:35.7044651Z remote: Counting objects: 58% (275/474)
2021-06-11T17:18:35.7045372Z remote: Counting objects: 59% (280/474)
2021-06-11T17:18:35.7046094Z remote: Counting objects: 60% (285/474)
2021-06-11T17:18:35.7046811Z remote: Counting objects: 61% (290/474)
2021-06-11T17:18:35.7047698Z remote: Counting objects: 62% (294/474)
2021-06-11T17:18:35.7048434Z remote: Counting objects: 63% (299/474)
2021-06-11T17:18:35.7049148Z remote: Counting objects: 64% (304/474)
2021-06-11T17:18:35.7049877Z remote: Counting objects: 65% (309/474)
2021-06-11T17:18:35.7050588Z remote: Counting objects: 66% (313/474)
2021-06-11T17:18:35.7051381Z remote: Counting objects: 67% (318/474)
2021-06-11T17:18:35.7052016Z remote: Counting objects: 68% (323/474)
2021-06-11T17:18:35.7052641Z remote: Counting objects: 69% (328/474)
2021-06-11T17:18:35.7053288Z remote: Counting objects: 70% (332/474)
2021-06-11T17:18:35.7054161Z remote: Counting objects: 71% (337/474)
2021-06-11T17:18:35.7054885Z remote: Counting objects: 72% (342/474)
2021-06-11T17:18:35.7055611Z remote: Counting objects: 73% (347/474)
2021-06-11T17:18:35.7056323Z remote: Counting objects: 74% (351/474)
2021-06-11T17:18:35.7057064Z remote: Counting objects: 75% (356/474)
2021-06-11T17:18:35.7057772Z remote: Counting objects: 76% (361/474)
2021-06-11T17:18:35.7058500Z remote: Counting objects: 77% (365/474)
2021-06-11T17:18:35.7059231Z remote: Counting objects: 78% (370/474)
2021-06-11T17:18:35.7059939Z remote: Counting objects: 79% (375/474)
2021-06-11T17:18:35.7060677Z remote: Counting objects: 80% (380/474)
2021-06-11T17:18:35.7061399Z remote: Counting objects: 81% (384/474)
2021-06-11T17:18:35.7062110Z remote: Counting objects: 82% (389/474)
2021-06-11T17:18:35.7062852Z remote: Counting objects: 83% (394/474)
2021-06-11T17:18:35.7063558Z remote: Counting objects: 84% (399/474)
2021-06-11T17:18:35.7064454Z remote: Counting objects: 85% (403/474)
2021-06-11T17:18:35.7065233Z remote: Counting objects: 86% (408/474)
2021-06-11T17:18:35.7065996Z remote: Counting objects: 87% (413/474)
2021-06-11T17:18:35.7066967Z remote: Counting objects: 88% (418/474)
2021-06-11T17:18:35.7067680Z remote: Counting objects: 89% (422/474)
2021-06-11T17:18:35.7068672Z remote: Counting objects: 90% (427/474)
2021-06-11T17:18:35.7069404Z remote: Counting objects: 91% (432/474)
2021-06-11T17:18:35.7070132Z remote: Counting objects: 92% (437/474)
2021-06-11T17:18:35.7070843Z remote: Counting objects: 93% (441/474)
2021-06-11T17:18:35.7071566Z remote: Counting objects: 94% (446/474)
2021-06-11T17:18:35.7072280Z remote: Counting objects: 95% (451/474)
2021-06-11T17:18:35.7073012Z remote: Counting objects: 96% (456/474)
2021-06-11T17:18:35.7073740Z remote: Counting objects: 97% (460/474)
2021-06-11T17:18:35.7074453Z remote: Counting objects: 98% (465/474)
2021-06-11T17:18:35.7075215Z remote: Counting objects: 99% (470/474)
2021-06-11T17:18:35.7075991Z remote: Counting objects: 100% (474/474)
2021-06-11T17:18:35.7076660Z remote: Counting objects: 100% (474/474), done.
2021-06-11T17:18:35.7077338Z remote: Compressing objects: 0% (1/381)
2021-06-11T17:18:35.7078000Z remote: Compressing objects: 1% (4/381)
2021-06-11T17:18:35.7078680Z remote: Compressing objects: 2% (8/381)
2021-06-11T17:18:35.7079348Z remote: Compressing objects: 3% (12/381)
2021-06-11T17:18:35.7080032Z remote: Compressing objects: 4% (16/381)
2021-06-11T17:18:35.7080716Z remote: Compressing objects: 5% (20/381)
2021-06-11T17:18:35.7081378Z remote: Compressing objects: 6% (23/381)
2021-06-11T17:18:35.7082148Z remote: Compressing objects: 7% (27/381)
2021-06-11T17:18:35.7082841Z remote: Compressing objects: 8% (31/381)
2021-06-11T17:18:35.7083504Z remote: Compressing objects: 9% (35/381)
2021-06-11T17:18:35.7084180Z remote: Compressing objects: 10% (39/381)
2021-06-11T17:18:35.7084840Z remote: Compressing objects: 11% (42/381)
2021-06-11T17:18:35.7085521Z remote: Compressing objects: 12% (46/381)
2021-06-11T17:18:35.7086194Z remote: Compressing objects: 13% (50/381)
2021-06-11T17:18:35.7086852Z remote: Compressing objects: 14% (54/381)
2021-06-11T17:18:35.7087895Z remote: Compressing objects: 15% (58/381)
2021-06-11T17:18:35.7088660Z remote: Compressing objects: 16% (61/381)
2021-06-11T17:18:35.7089435Z remote: Compressing objects: 17% (65/381)
2021-06-11T17:18:35.7090386Z remote: Compressing objects: 18% (69/381)
2021-06-11T17:18:35.7091196Z remote: Compressing objects: 19% (73/381)
2021-06-11T17:18:35.7092040Z remote: Compressing objects: 20% (77/381)
2021-06-11T17:18:35.7092866Z remote: Compressing objects: 21% (81/381)
2021-06-11T17:18:35.7093678Z remote: Compressing objects: 22% (84/381)
2021-06-11T17:18:35.7094506Z remote: Compressing objects: 23% (88/381)
2021-06-11T17:18:35.7095322Z remote: Compressing objects: 24% (92/381)
2021-06-11T17:18:35.7096145Z remote: Compressing objects: 25% (96/381)
2021-06-11T17:18:35.7096975Z remote: Compressing objects: 26% (100/381)
2021-06-11T17:18:35.7097789Z remote: Compressing objects: 27% (103/381)
2021-06-11T17:18:35.7098612Z remote: Compressing objects: 28% (107/381)
2021-06-11T17:18:35.7099427Z remote: Compressing objects: 29% (111/381)
2021-06-11T17:18:35.7100346Z remote: Compressing objects: 30% (115/381)
2021-06-11T17:18:35.7101112Z remote: Compressing objects: 31% (119/381)
2021-06-11T17:18:35.7101879Z remote: Compressing objects: 32% (122/381)
2021-06-11T17:18:35.7102910Z remote: Compressing objects: 33% (126/381)
2021-06-11T17:18:35.7103666Z remote: Compressing objects: 34% (130/381)
2021-06-11T17:18:35.7104444Z remote: Compressing objects: 35% (134/381)
2021-06-11T17:18:35.7105213Z remote: Compressing objects: 36% (138/381)
2021-06-11T17:18:35.7106081Z remote: Compressing objects: 37% (141/381)
2021-06-11T17:18:35.7106854Z remote: Compressing objects: 38% (145/381)
2021-06-11T17:18:35.7107623Z remote: Compressing objects: 39% (149/381)
2021-06-11T17:18:35.7108373Z remote: Compressing objects: 40% (153/381)
2021-06-11T17:18:35.7109149Z remote: Compressing objects: 41% (157/381)
2021-06-11T17:18:35.7109900Z remote: Compressing objects: 42% (161/381)
2021-06-11T17:18:35.7110670Z remote: Compressing objects: 43% (164/381)
2021-06-11T17:18:35.7111439Z remote: Compressing objects: 44% (168/381)
2021-06-11T17:18:35.7112202Z remote: Compressing objects: 45% (172/381)
2021-06-11T17:18:35.7112973Z remote: Compressing objects: 46% (176/381)
2021-06-11T17:18:35.7113728Z remote: Compressing objects: 47% (180/381)
2021-06-11T17:18:35.7114499Z remote: Compressing objects: 48% (183/381)
2021-06-11T17:18:35.7115496Z remote: Compressing objects: 49% (187/381)
2021-06-11T17:18:35.7116268Z remote: Compressing objects: 50% (191/381)
2021-06-11T17:18:35.7117038Z remote: Compressing objects: 51% (195/381)
2021-06-11T17:18:35.7117806Z remote: Compressing objects: 52% (199/381)
2021-06-11T17:18:35.7118564Z remote: Compressing objects: 53% (202/381)
2021-06-11T17:18:35.7119331Z remote: Compressing objects: 54% (206/381)
2021-06-11T17:18:35.7120081Z remote: Compressing objects: 55% (210/381)
2021-06-11T17:18:35.7120852Z remote: Compressing objects: 56% (214/381)
2021-06-11T17:18:35.7121615Z remote: Compressing objects: 57% (218/381)
2021-06-11T17:18:35.7122466Z remote: Compressing objects: 58% (221/381)
2021-06-11T17:18:35.7123257Z remote: Compressing objects: 59% (225/381)
2021-06-11T17:18:35.7124012Z remote: Compressing objects: 60% (229/381)
2021-06-11T17:18:35.7124776Z remote: Compressing objects: 61% (233/381)
2021-06-11T17:18:35.7125554Z remote: Compressing objects: 62% (237/381)
2021-06-11T17:18:35.7126390Z remote: Compressing objects: 63% (241/381)
2021-06-11T17:18:35.7127067Z remote: Compressing objects: 64% (244/381)
2021-06-11T17:18:35.7127851Z remote: Compressing objects: 65% (248/381)
2021-06-11T17:18:35.7128529Z remote: Compressing objects: 66% (252/381)
2021-06-11T17:18:35.7129204Z remote: Compressing objects: 67% (256/381)
2021-06-11T17:18:35.7129869Z remote: Compressing objects: 68% (260/381)
2021-06-11T17:18:35.7130545Z remote: Compressing objects: 69% (263/381)
2021-06-11T17:18:35.7131227Z remote: Compressing objects: 70% (267/381)
2021-06-11T17:18:35.7131893Z remote: Compressing objects: 71% (271/381)
2021-06-11T17:18:35.7132564Z remote: Compressing objects: 72% (275/381)
2021-06-11T17:18:35.7134105Z remote: Compressing objects: 73% (279/381)
2021-06-11T17:18:35.7135782Z remote: Compressing objects: 74% (282/381)
2021-06-11T17:18:35.7136658Z remote: Compressing objects: 75% (286/381)
2021-06-11T17:18:35.7137474Z remote: Compressing objects: 76% (290/381)
2021-06-11T17:18:35.7138311Z remote: Compressing objects: 77% (294/381)
2021-06-11T17:18:35.7139130Z remote: Compressing objects: 78% (298/381)
2021-06-11T17:18:35.7139954Z remote: Compressing objects: 79% (301/381)
2021-06-11T17:18:35.7140785Z remote: Compressing objects: 80% (305/381)
2021-06-11T17:18:35.7141596Z remote: Compressing objects: 81% (309/381)
2021-06-11T17:18:35.7142421Z remote: Compressing objects: 82% (313/381)
2021-06-11T17:18:35.7143261Z remote: Compressing objects: 83% (317/381)
2021-06-11T17:18:35.7144076Z remote: Compressing objects: 84% (321/381)
2021-06-11T17:18:35.7144910Z remote: Compressing objects: 85% (324/381)
2021-06-11T17:18:35.7145725Z remote: Compressing objects: 86% (328/381)
2021-06-11T17:18:35.7146552Z remote: Compressing objects: 87% (332/381)
2021-06-11T17:18:35.7147554Z remote: Compressing objects: 88% (336/381)
2021-06-11T17:18:35.7148364Z remote: Compressing objects: 89% (340/381)
2021-06-11T17:18:35.7149193Z remote: Compressing objects: 90% (343/381)
2021-06-11T17:18:35.7150014Z remote: Compressing objects: 91% (347/381)
2021-06-11T17:18:35.7150928Z remote: Compressing objects: 92% (351/381)
2021-06-11T17:18:35.7151906Z remote: Compressing objects: 93% (355/381)
2021-06-11T17:18:35.7152719Z remote: Compressing objects: 94% (359/381)
2021-06-11T17:18:35.7153559Z remote: Compressing objects: 95% (362/381)
2021-06-11T17:18:35.7154391Z remote: Compressing objects: 96% (366/381)
2021-06-11T17:18:35.7155575Z remote: Compressing objects: 97% (370/381)
2021-06-11T17:18:35.7156494Z remote: Compressing objects: 98% (374/381)
2021-06-11T17:18:35.7158070Z remote: Compressing objects: 99% (378/381)
2021-06-11T17:18:35.7159044Z remote: Compressing objects: 100% (381/381)
2021-06-11T17:18:35.7159912Z remote: Compressing objects: 100% (381/381), done.
2021-06-11T17:18:35.7160705Z Receiving objects: 0% (1/474)
2021-06-11T17:18:35.7161426Z Receiving objects: 1% (5/474)
2021-06-11T17:18:35.7162141Z Receiving objects: 2% (10/474)
2021-06-11T17:18:35.7162865Z Receiving objects: 3% (15/474)
2021-06-11T17:18:35.7163587Z Receiving objects: 4% (19/474)
2021-06-11T17:18:35.7164297Z Receiving objects: 5% (24/474)
2021-06-11T17:18:35.7165021Z Receiving objects: 6% (29/474)
2021-06-11T17:18:35.7165733Z Receiving objects: 7% (34/474)
2021-06-11T17:18:35.7166599Z Receiving objects: 8% (38/474)
2021-06-11T17:18:35.7167482Z Receiving objects: 9% (43/474)
2021-06-11T17:18:35.7168211Z Receiving objects: 10% (48/474)
2021-06-11T17:18:35.7168941Z Receiving objects: 11% (53/474)
2021-06-11T17:18:35.7169678Z Receiving objects: 12% (57/474)
2021-06-11T17:18:35.7170402Z Receiving objects: 13% (62/474)
2021-06-11T17:18:35.7171153Z Receiving objects: 14% (67/474)
2021-06-11T17:18:35.7171883Z Receiving objects: 15% (72/474)
2021-06-11T17:18:35.7172623Z Receiving objects: 16% (76/474)
2021-06-11T17:18:35.7173358Z Receiving objects: 17% (81/474)
2021-06-11T17:18:35.7174064Z Receiving objects: 18% (86/474)
2021-06-11T17:18:35.7174787Z Receiving objects: 19% (91/474)
2021-06-11T17:18:35.7175516Z Receiving objects: 20% (95/474)
2021-06-11T17:18:35.7176226Z Receiving objects: 21% (100/474)
2021-06-11T17:18:35.7176953Z Receiving objects: 22% (105/474)
2021-06-11T17:18:35.7177661Z Receiving objects: 23% (110/474)
2021-06-11T17:18:35.7178385Z Receiving objects: 24% (114/474)
2021-06-11T17:18:35.7179119Z Receiving objects: 25% (119/474)
2021-06-11T17:18:35.7179832Z Receiving objects: 26% (124/474)
2021-06-11T17:18:35.7180563Z Receiving objects: 27% (128/474)
2021-06-11T17:18:35.7181385Z Receiving objects: 28% (133/474)
2021-06-11T17:18:35.7182072Z Receiving objects: 29% (138/474)
2021-06-11T17:18:35.7182747Z Receiving objects: 30% (143/474)
2021-06-11T17:18:35.7183414Z Receiving objects: 31% (147/474)
2021-06-11T17:18:35.7184092Z Receiving objects: 32% (152/474)
2021-06-11T17:18:35.7184750Z Receiving objects: 33% (157/474)
2021-06-11T17:18:35.7185421Z Receiving objects: 34% (162/474)
2021-06-11T17:18:35.7186098Z Receiving objects: 35% (166/474)
2021-06-11T17:18:35.7186759Z Receiving objects: 36% (171/474)
2021-06-11T17:18:35.7187435Z Receiving objects: 37% (176/474)
2021-06-11T17:18:35.7188097Z Receiving objects: 38% (181/474)
2021-06-11T17:18:35.7188771Z Receiving objects: 39% (185/474)
2021-06-11T17:18:35.7189447Z Receiving objects: 40% (190/474)
2021-06-11T17:18:35.7190164Z Receiving objects: 41% (195/474)
2021-06-11T17:18:35.7190842Z Receiving objects: 42% (200/474)
2021-06-11T17:18:35.7191496Z Receiving objects: 43% (204/474)
2021-06-11T17:18:35.7192178Z Receiving objects: 44% (209/474)
2021-06-11T17:18:35.7192856Z Receiving objects: 45% (214/474)
2021-06-11T17:18:35.7193512Z Receiving objects: 46% (219/474)
2021-06-11T17:18:35.7194312Z Receiving objects: 47% (223/474)
2021-06-11T17:18:35.7194967Z Receiving objects: 48% (228/474)
2021-06-11T17:18:35.7195643Z Receiving objects: 49% (233/474)
2021-06-11T17:18:35.7196318Z Receiving objects: 50% (237/474)
2021-06-11T17:18:35.7196979Z Receiving objects: 51% (242/474)
2021-06-11T17:18:35.7197653Z Receiving objects: 52% (247/474)
2021-06-11T17:18:35.7198307Z Receiving objects: 53% (252/474)
2021-06-11T17:18:35.7198980Z Receiving objects: 54% (256/474)
2021-06-11T17:18:35.7199658Z Receiving objects: 55% (261/474)
2021-06-11T17:18:35.7200317Z Receiving objects: 56% (266/474)
2021-06-11T17:18:35.7200995Z Receiving objects: 57% (271/474)
2021-06-11T17:18:35.7201665Z Receiving objects: 58% (275/474)
2021-06-11T17:18:35.7202861Z Receiving objects: 59% (280/474)
2021-06-11T17:18:35.7203643Z Receiving objects: 60% (285/474)
2021-06-11T17:18:35.7204301Z Receiving objects: 61% (290/474)
2021-06-11T17:18:35.7204980Z Receiving objects: 62% (294/474)
2021-06-11T17:18:35.7205668Z Receiving objects: 63% (299/474)
2021-06-11T17:18:35.7206328Z Receiving objects: 64% (304/474)
2021-06-11T17:18:35.7207005Z Receiving objects: 65% (309/474)
2021-06-11T17:18:35.7207785Z Receiving objects: 66% (313/474)
2021-06-11T17:18:35.7208461Z Receiving objects: 67% (318/474)
2021-06-11T17:18:35.7209143Z Receiving objects: 68% (323/474)
2021-06-11T17:18:35.7209805Z Receiving objects: 69% (328/474)
2021-06-11T17:18:35.7210680Z Receiving objects: 70% (332/474)
2021-06-11T17:18:35.7211391Z Receiving objects: 71% (337/474)
2021-06-11T17:18:35.7212116Z Receiving objects: 72% (342/474)
2021-06-11T17:18:35.7212950Z Receiving objects: 73% (347/474)
2021-06-11T17:18:35.7213684Z Receiving objects: 74% (351/474)
2021-06-11T17:18:35.7214410Z Receiving objects: 75% (356/474)
2021-06-11T17:18:35.7215119Z Receiving objects: 76% (361/474)
2021-06-11T17:18:35.7215845Z Receiving objects: 77% (365/474)
2021-06-11T17:18:35.7216570Z Receiving objects: 78% (370/474)
2021-06-11T17:18:35.7217296Z Receiving objects: 79% (375/474)
2021-06-11T17:18:35.7218031Z Receiving objects: 80% (380/474)
2021-06-11T17:18:35.7218737Z Receiving objects: 81% (384/474)
2021-06-11T17:18:35.7219460Z Receiving objects: 82% (389/474)
2021-06-11T17:18:35.7220182Z Receiving objects: 83% (394/474)
2021-06-11T17:18:35.7220893Z Receiving objects: 84% (399/474)
2021-06-11T17:18:35.7221612Z Receiving objects: 85% (403/474)
2021-06-11T17:18:35.7222323Z Receiving objects: 86% (408/474)
2021-06-11T17:18:35.7223046Z Receiving objects: 87% (413/474)
2021-06-11T17:18:35.7223773Z Receiving objects: 88% (418/474)
2021-06-11T17:18:35.7224490Z Receiving objects: 89% (422/474)
2021-06-11T17:18:35.7225220Z Receiving objects: 90% (427/474)
2021-06-11T17:18:35.7226502Z remote: Total 474 (delta 193), reused 205 (delta 67), pack-reused 0
2021-06-11T17:18:35.7227380Z Receiving objects: 91% (432/474)
2021-06-11T17:18:35.7228107Z Receiving objects: 92% (437/474)
2021-06-11T17:18:35.7228817Z Receiving objects: 93% (441/474)
2021-06-11T17:18:35.7229556Z Receiving objects: 94% (446/474)
2021-06-11T17:18:35.7230264Z Receiving objects: 95% (451/474)
2021-06-11T17:18:35.7230987Z Receiving objects: 96% (456/474)
2021-06-11T17:18:35.7231713Z Receiving objects: 97% (460/474)
2021-06-11T17:18:35.7232425Z Receiving objects: 98% (465/474)
2021-06-11T17:18:35.7233151Z Receiving objects: 99% (470/474)
2021-06-11T17:18:35.7233967Z Receiving objects: 100% (474/474)
2021-06-11T17:18:35.7234712Z Receiving objects: 100% (474/474), 431.54 KiB | 3.57 MiB/s, done.
2021-06-11T17:18:35.7236536Z Resolving deltas: 0% (0/193)
2021-06-11T17:18:35.7237256Z Resolving deltas: 1% (2/193)
2021-06-11T17:18:35.7237987Z Resolving deltas: 2% (4/193)
2021-06-11T17:18:35.7238680Z Resolving deltas: 3% (6/193)
2021-06-11T17:18:35.7239392Z Resolving deltas: 4% (8/193)
2021-06-11T17:18:35.7240100Z Resolving deltas: 5% (10/193)
2021-06-11T17:18:35.7240789Z Resolving deltas: 6% (12/193)
2021-06-11T17:18:35.7241502Z Resolving deltas: 7% (14/193)
2021-06-11T17:18:35.7242378Z Resolving deltas: 8% (16/193)
2021-06-11T17:18:35.7243084Z Resolving deltas: 9% (18/193)
2021-06-11T17:18:35.7243797Z Resolving deltas: 10% (20/193)
2021-06-11T17:18:35.7244488Z Resolving deltas: 11% (22/193)
2021-06-11T17:18:35.7245194Z Resolving deltas: 12% (24/193)
2021-06-11T17:18:35.7245888Z Resolving deltas: 13% (26/193)
2021-06-11T17:18:35.7246591Z Resolving deltas: 14% (28/193)
2021-06-11T17:18:35.7247591Z Resolving deltas: 15% (29/193)
2021-06-11T17:18:35.7248265Z Resolving deltas: 16% (31/193)
2021-06-11T17:18:35.7248933Z Resolving deltas: 17% (33/193)
2021-06-11T17:18:35.7249576Z Resolving deltas: 18% (35/193)
2021-06-11T17:18:35.7250250Z Resolving deltas: 19% (37/193)
2021-06-11T17:18:35.7250909Z Resolving deltas: 20% (39/193)
2021-06-11T17:18:35.7251555Z Resolving deltas: 21% (41/193)
2021-06-11T17:18:35.7252218Z Resolving deltas: 22% (43/193)
2021-06-11T17:18:35.7252861Z Resolving deltas: 23% (45/193)
2021-06-11T17:18:35.7253519Z Resolving deltas: 24% (47/193)
2021-06-11T17:18:35.7254192Z Resolving deltas: 25% (49/193)
2021-06-11T17:18:35.7254835Z Resolving deltas: 26% (51/193)
2021-06-11T17:18:35.7255497Z Resolving deltas: 27% (53/193)
2021-06-11T17:18:35.7256144Z Resolving deltas: 28% (55/193)
2021-06-11T17:18:35.7256802Z Resolving deltas: 29% (56/193)
2021-06-11T17:18:35.7257512Z Resolving deltas: 30% (58/193)
2021-06-11T17:18:35.7258081Z Resolving deltas: 31% (60/193)
2021-06-11T17:18:35.7258931Z Resolving deltas: 32% (62/193)
2021-06-11T17:18:35.7259575Z Resolving deltas: 33% (64/193)
2021-06-11T17:18:35.7260241Z Resolving deltas: 34% (66/193)
2021-06-11T17:18:35.7260996Z Resolving deltas: 35% (68/193)
2021-06-11T17:18:35.7261662Z Resolving deltas: 36% (70/193)
2021-06-11T17:18:35.7262323Z Resolving deltas: 37% (72/193)
2021-06-11T17:18:35.7262966Z Resolving deltas: 38% (74/193)
2021-06-11T17:18:35.7263621Z Resolving deltas: 39% (76/193)
2021-06-11T17:18:35.7264277Z Resolving deltas: 40% (78/193)
2021-06-11T17:18:35.7264932Z Resolving deltas: 41% (80/193)
2021-06-11T17:18:35.7265804Z Resolving deltas: 42% (82/193)
2021-06-11T17:18:35.7266494Z Resolving deltas: 43% (83/193)
2021-06-11T17:18:35.7267197Z Resolving deltas: 44% (85/193)
2021-06-11T17:18:35.7267899Z Resolving deltas: 45% (87/193)
2021-06-11T17:18:35.7268593Z Resolving deltas: 46% (89/193)
2021-06-11T17:18:35.7269338Z Resolving deltas: 47% (91/193)
2021-06-11T17:18:35.7270032Z Resolving deltas: 48% (93/193)
2021-06-11T17:18:35.7270741Z Resolving deltas: 49% (95/193)
2021-06-11T17:18:35.7271450Z Resolving deltas: 50% (97/193)
2021-06-11T17:18:35.7272141Z Resolving deltas: 51% (99/193)
2021-06-11T17:18:35.7272862Z Resolving deltas: 52% (101/193)
2021-06-11T17:18:35.7273561Z Resolving deltas: 53% (103/193)
2021-06-11T17:18:35.7274273Z Resolving deltas: 54% (105/193)
2021-06-11T17:18:35.7274982Z Resolving deltas: 55% (107/193)
2021-06-11T17:18:35.7275681Z Resolving deltas: 56% (109/193)
2021-06-11T17:18:35.7276481Z Resolving deltas: 57% (111/193)
2021-06-11T17:18:35.7277136Z Resolving deltas: 58% (112/193)
2021-06-11T17:18:35.7277801Z Resolving deltas: 59% (114/193)
2021-06-11T17:18:35.7278446Z Resolving deltas: 60% (116/193)
2021-06-11T17:18:35.7279113Z Resolving deltas: 61% (118/193)
2021-06-11T17:18:35.7279779Z Resolving deltas: 62% (120/193)
2021-06-11T17:18:35.7280427Z Resolving deltas: 63% (122/193)
2021-06-11T17:18:35.7281093Z Resolving deltas: 64% (124/193)
2021-06-11T17:18:35.7281739Z Resolving deltas: 65% (126/193)
2021-06-11T17:18:35.7282402Z Resolving deltas: 66% (128/193)
2021-06-11T17:18:35.7283068Z Resolving deltas: 67% (130/193)
2021-06-11T17:18:35.7283719Z Resolving deltas: 68% (132/193)
2021-06-11T17:18:35.7284389Z Resolving deltas: 69% (134/193)
2021-06-11T17:18:35.7285036Z Resolving deltas: 70% (136/193)
2021-06-11T17:18:35.7285701Z Resolving deltas: 71% (138/193)
2021-06-11T17:18:35.7286362Z Resolving deltas: 72% (139/193)
2021-06-11T17:18:35.7287011Z Resolving deltas: 73% (141/193)
2021-06-11T17:18:35.7287787Z Resolving deltas: 74% (143/193)
2021-06-11T17:18:35.7288565Z Resolving deltas: 75% (145/193)
2021-06-11T17:18:35.7289227Z Resolving deltas: 76% (147/193)
2021-06-11T17:18:35.7289888Z Resolving deltas: 77% (149/193)
2021-06-11T17:18:35.7290538Z Resolving deltas: 78% (151/193)
2021-06-11T17:18:35.7291248Z Resolving deltas: 79% (153/193)
2021-06-11T17:18:35.7291817Z Resolving deltas: 80% (155/193)
2021-06-11T17:18:35.7292398Z Resolving deltas: 81% (157/193)
2021-06-11T17:18:35.7292984Z Resolving deltas: 82% (159/193)
2021-06-11T17:18:35.7293550Z Resolving deltas: 83% (161/193)
2021-06-11T17:18:35.7294133Z Resolving deltas: 84% (163/193)
2021-06-11T17:18:35.7294706Z Resolving deltas: 85% (165/193)
2021-06-11T17:18:35.7295294Z Resolving deltas: 86% (166/193)
2021-06-11T17:18:35.7295874Z Resolving deltas: 87% (168/193)
2021-06-11T17:18:35.7296441Z Resolving deltas: 88% (170/193)
2021-06-11T17:18:35.7297023Z Resolving deltas: 89% (172/193)
2021-06-11T17:18:35.7297591Z Resolving deltas: 90% (174/193)
2021-06-11T17:18:35.7298182Z Resolving deltas: 91% (176/193)
2021-06-11T17:18:35.7298761Z Resolving deltas: 92% (178/193)
2021-06-11T17:18:35.7299324Z Resolving deltas: 93% (180/193)
2021-06-11T17:18:35.7299910Z Resolving deltas: 94% (182/193)
2021-06-11T17:18:35.7300479Z Resolving deltas: 95% (184/193)
2021-06-11T17:18:35.7301062Z Resolving deltas: 96% (186/193)
2021-06-11T17:18:35.7301646Z Resolving deltas: 97% (189/193)
2021-06-11T17:18:35.7302400Z Resolving deltas: 98% (190/193)
2021-06-11T17:18:35.7303062Z Resolving deltas: 99% (192/193)
2021-06-11T17:18:35.7303708Z Resolving deltas: 100% (193/193)
2021-06-11T17:18:35.7304400Z Resolving deltas: 100% (193/193), done.
2021-06-11T17:18:35.7305750Z From https://github.com/cockroachdb/cockroach-operator
2021-06-11T17:18:35.7307094Z * [new ref] 86e92034c35efa1362928d205b69e9d108e48856 -> pull/547/merge
2021-06-11T17:18:35.7308013Z ##[endgroup]
2021-06-11T17:18:35.7308736Z ##[group]Determining the checkout info
2021-06-11T17:18:35.7309423Z ##[endgroup]
2021-06-11T17:18:35.7310082Z ##[group]Checking out the ref
2021-06-11T17:18:35.7311162Z [command]/usr/bin/git checkout --progress --force refs/remotes/pull/547/merge
2021-06-11T17:18:35.7312287Z Note: switching to 'refs/remotes/pull/547/merge'.
2021-06-11T17:18:35.7312831Z
2021-06-11T17:18:35.7313795Z You are in 'detached HEAD' state. You can look around, make experimental
2021-06-11T17:18:35.7314786Z changes and commit them, and you can discard any commits you make in this
2021-06-11T17:18:35.7315959Z state without impacting any branches by switching back to a branch.
2021-06-11T17:18:35.7316592Z
2021-06-11T17:18:35.7317375Z If you want to create a new branch to retain commits you create, you may
2021-06-11T17:18:35.7318574Z do so (now or later) by using -c with the switch command. Example:
2021-06-11T17:18:35.7319181Z
2021-06-11T17:18:35.7320036Z git switch -c <new-branch-name>
2021-06-11T17:18:35.7320584Z
2021-06-11T17:18:35.7321236Z Or undo this operation with:
2021-06-11T17:18:35.7321729Z
2021-06-11T17:18:35.7322477Z git switch -
2021-06-11T17:18:35.7322933Z
2021-06-11T17:18:35.7323811Z Turn off this advice by setting config variable advice.detachedHead to false
2021-06-11T17:18:35.7324523Z
2021-06-11T17:18:35.7325681Z HEAD is now at 86e9203 Merge 7914cbbf9b4f85475b4304082f3fa8a4ff2534d8 into a4caa2ac9f75a12d6adc217270bc92cb7f252429
2021-06-11T17:18:35.7326969Z ##[endgroup]
2021-06-11T17:18:35.7328000Z [command]/usr/bin/git log -1 --format='%H'
2021-06-11T17:18:35.7329008Z '86e92034c35efa1362928d205b69e9d108e48856'
2021-06-11T17:18:35.7453116Z ##[group]Run abhinavsingh/setup-bazel@v3
2021-06-11T17:18:35.7453722Z with:
2021-06-11T17:18:35.7454184Z version: 4.0.0
2021-06-11T17:18:35.7454655Z ##[endgroup]
2021-06-11T17:18:37.0765438Z ##[group]Run make test/e2e/kind-decomission
2021-06-11T17:18:37.0766422Z [36;1mmake test/e2e/kind-decomission[0m
2021-06-11T17:18:37.0813581Z shell: /usr/bin/bash -e {0}
2021-06-11T17:18:37.0814278Z ##[endgroup]
2021-06-11T17:18:37.0923095Z bazel build //hack/bin/...
2021-06-11T17:18:37.1044705Z Extracting Bazel installation...
2021-06-11T17:18:39.1714601Z Starting local Bazel server and connecting to it...
2021-06-11T17:18:40.8483041Z Loading:
2021-06-11T17:18:40.8604952Z Loading: 0 packages loaded
2021-06-11T17:18:41.8635873Z Loading: 0 packages loaded
2021-06-11T17:18:42.8660482Z Loading: 0 packages loaded
2021-06-11T17:18:43.8652681Z Loading: 0 packages loaded
2021-06-11T17:18:44.8879561Z Loading: 0 packages loaded
2021-06-11T17:18:45.8497287Z Analyzing: 21 targets (1 packages loaded, 0 targets configured)
2021-06-11T17:18:46.4117726Z INFO: SHA256 (https://golang.org/dl/?mode=json&include=all) = 6efc06a1bd0a710df5cbaa2fd314f9a3f702f7d9cd59ee2bd53c2a02aa8c4475
2021-06-11T17:18:46.8656323Z Analyzing: 21 targets (5 packages loaded, 12 targets configured)
2021-06-11T17:18:47.8700173Z Analyzing: 21 targets (6 packages loaded, 16 targets configured)
2021-06-11T17:18:48.9484810Z Analyzing: 21 targets (7 packages loaded, 19 targets configured)
2021-06-11T17:18:50.3256161Z Analyzing: 21 targets (8 packages loaded, 22 targets configured)
2021-06-11T17:18:51.8936158Z Analyzing: 21 targets (9 packages loaded, 25 targets configured)
2021-06-11T17:18:53.5761077Z Analyzing: 21 targets (10 packages loaded, 28 targets configured)
2021-06-11T17:18:55.5636545Z Analyzing: 21 targets (10 packages loaded, 28 targets configured)
2021-06-11T17:18:58.7227676Z Analyzing: 21 targets (10 packages loaded, 28 targets configured)
2021-06-11T17:19:01.4454190Z Analyzing: 21 targets (10 packages loaded, 28 targets configured)
2021-06-11T17:19:05.3809236Z Analyzing: 21 targets (10 packages loaded, 28 targets configured)
2021-06-11T17:19:09.1198723Z Analyzing: 21 targets (24 packages loaded, 53 targets configured)
2021-06-11T17:19:14.0736499Z Analyzing: 21 targets (50 packages loaded, 1222 targets configured)
2021-06-11T17:19:20.2275508Z Analyzing: 21 targets (77 packages loaded, 7480 targets configured)
2021-06-11T17:19:26.2888549Z Analyzing: 21 targets (77 packages loaded, 7480 targets configured)
2021-06-11T17:19:33.1824785Z INFO: Analyzed 21 targets (165 packages loaded, 8456 targets configured).
2021-06-11T17:19:33.1860752Z
2021-06-11T17:19:33.1886943Z INFO: Found 21 targets...
2021-06-11T17:19:33.2898886Z [0 / 1] [Prepa] BazelWorkspaceStatusAction stable-status.txt
2021-06-11T17:19:41.2293773Z [43 / 57] GoCompilePkg external/com_github_modern_go_reflect2/reflect2.a; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:19:51.4502050Z [103 / 112] GoCompilePkg external/io_k8s_apiextensions_apiserver/pkg/apis/apiextensions/v1/apiextensions.a; 1s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:20:05.2214915Z [151 / 155] [Prepa] GoCompilePkg external/bazel_gazelle/language/go/go.a
2021-06-11T17:20:06.5994706Z INFO: Elapsed time: 89.443s, Critical Path: 15.98s
2021-06-11T17:20:06.6006768Z INFO: 155 processes: 9 internal, 146 linux-sandbox.
2021-06-11T17:20:06.6013547Z INFO: Build completed successfully, 155 total actions
2021-06-11T17:20:06.6058061Z INFO: Build completed successfully, 155 total actions
2021-06-11T17:20:06.6153820Z PATH=/home/linuxbrew/.linuxbrew/bin:/home/linuxbrew/.linuxbrew/sbin:/home/runner/.local/bin:/opt/pipx_bin:/usr/share/rust/.cargo/bin:/home/runner/.config/composer/vendor/bin:/usr/local/.ghcup/bin:/home/runner/.dotnet/tools:/snap/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:bazel-bin/hack/bin kubetest2 kind --cluster-name=bazel-test \
2021-06-11T17:20:06.6156367Z --up --down -v 10 --test=exec -- make test/e2e/testrunner-kind-decomission
2021-06-11T17:20:06.6394186Z I0611 17:20:06.639129 5748 app.go:59] RunDir for this run: "/home/runner/work/cockroach-operator/cockroach-operator/_artifacts/3d3f9734-3518-492f-b876-3ef823ae37e7"
2021-06-11T17:20:06.6396323Z I0611 17:20:06.639309 5748 app.go:90] ID for this run: "3d3f9734-3518-492f-b876-3ef823ae37e7"
2021-06-11T17:20:06.6397397Z I0611 17:20:06.639324 5748 up.go:62] Up(): creating kind cluster...
2021-06-11T17:20:07.2219889Z Creating cluster "bazel-test" ...
2021-06-11T17:20:07.2223691Z âĸ Ensuring node image (kindest/node:v1.21.1) đŧ ...
2021-06-11T17:20:27.4166169Z â Ensuring node image (kindest/node:v1.21.1) đŧ
2021-06-11T17:20:27.4168074Z âĸ Preparing nodes đĻ ...
2021-06-11T17:20:31.8409107Z â Preparing nodes đĻ
2021-06-11T17:20:31.9555998Z âĸ Writing configuration đ ...
2021-06-11T17:20:32.6392412Z â Writing configuration đ
2021-06-11T17:20:32.6394399Z âĸ Starting control-plane đšī¸ ...
2021-06-11T17:20:58.4756738Z â Starting control-plane đšī¸
2021-06-11T17:20:58.4757597Z âĸ Installing CNI đ ...
2021-06-11T17:20:59.1629749Z â Installing CNI đ
2021-06-11T17:20:59.1630623Z âĸ Installing StorageClass đž ...
2021-06-11T17:20:59.7357949Z â Installing StorageClass đž
2021-06-11T17:21:00.2684258Z Set kubectl context to "kind-bazel-test"
2021-06-11T17:21:00.2690960Z You can now use your cluster with:
2021-06-11T17:21:00.2691609Z
2021-06-11T17:21:00.2692823Z kubectl cluster-info --context kind-bazel-test
2021-06-11T17:21:00.2693446Z
2021-06-11T17:21:00.2694808Z Not sure what to do next? đ
Check out https://kind.sigs.k8s.io/docs/user/quick-start/
2021-06-11T17:21:00.2702883Z I0611 17:21:00.269969 5748 local.go:42] âī¸ bazel-bin/hack/bin/kubetest2-tester-exec make test/e2e/testrunner-kind-decomission
2021-06-11T17:21:00.2755342Z make[1]: Entering directory '/home/runner/work/cockroach-operator/cockroach-operator'
2021-06-11T17:21:00.2756549Z bazel-bin/hack/bin/kind export kubeconfig --name bazel-test
2021-06-11T17:21:00.7839997Z Set kubectl context to "kind-bazel-test"
2021-06-11T17:21:00.7846824Z bazel run //hack/k8s:k8s -- -type kind
2021-06-11T17:21:01.1348970Z Loading:
2021-06-11T17:21:01.1349971Z Loading: 0 packages loaded
2021-06-11T17:21:01.1718869Z Analyzing: target //hack/k8s:k8s (1 packages loaded, 0 targets configured)
2021-06-11T17:21:02.5330799Z Analyzing: target //hack/k8s:k8s (13 packages loaded, 6 targets configured)
2021-06-11T17:21:03.7429658Z Analyzing: target //hack/k8s:k8s (40 packages loaded, 59 targets configured)
2021-06-11T17:21:04.8277892Z Analyzing: target //hack/k8s:k8s (108 packages loaded, 470 targets configured)
2021-06-11T17:21:05.8599823Z Analyzing: target //hack/k8s:k8s (144 packages loaded, 536 targets configured)
2021-06-11T17:21:06.8871895Z Analyzing: target //hack/k8s:k8s (221 packages loaded, 1077 targets configured)
2021-06-11T17:21:08.0329057Z Analyzing: target //hack/k8s:k8s (235 packages loaded, 1338 targets configured)
2021-06-11T17:21:09.1271057Z Analyzing: target //hack/k8s:k8s (252 packages loaded, 1816 targets configured)
2021-06-11T17:21:10.4231737Z Analyzing: target //hack/k8s:k8s (292 packages loaded, 2090 targets configured)
2021-06-11T17:21:10.4828297Z INFO: Analyzed target //hack/k8s:k8s (292 packages loaded, 2090 targets configured).
2021-06-11T17:21:10.4850135Z INFO: Found 1 target...
2021-06-11T17:21:10.5624305Z [0 / 1] [Prepa] BazelWorkspaceStatusAction stable-status.txt
2021-06-11T17:21:12.2888019Z [53 / 79] GoCompilePkg external/io_k8s_api/core/v1/core.a; 1s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:21:14.3000551Z [63 / 87] GoCompilePkg external/io_k8s_api/core/v1/core.a; 3s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:21:17.0553032Z [72 / 92] GoCompilePkg external/io_k8s_api/core/v1/core.a; 6s linux-sandbox ... (2 actions running)
2021-06-11T17:21:19.4873082Z [77 / 136] GoCompilePkg external/io_k8s_api/core/v1/core.a; 8s linux-sandbox ... (2 actions running)
2021-06-11T17:21:22.2812639Z [86 / 136] GoCompilePkg external/io_k8s_api/apps/v1/apps.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:25.4959903Z [97 / 136] GoCompilePkg external/io_k8s_api/extensions/v1beta1/v1beta1.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:29.1929743Z [111 / 136] GoCompilePkg external/io_k8s_api/apps/v1beta2/v1beta2.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:33.4436779Z [148 / 214] GoCompilePkg external/io_k8s_api/admission/v1beta1/v1beta1.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:38.3426163Z [190 / 243] GoCompilePkg external/com_github_googleapis_gnostic/compiler/compiler.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:43.9684314Z [220 / 267] GoCompilePkg external/io_k8s_client_go/kubernetes/typed/core/v1/core.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:50.4363698Z [287 / 329] GoCompilePkg external/io_k8s_client_go/kubernetes/kubernetes.a; 0s linux-sandbox ... (2 actions running)
2021-06-11T17:21:57.2584084Z Target //hack/k8s:k8s up-to-date:
2021-06-11T17:21:57.2609867Z bazel-bin/hack/k8s/k8s_/k8s
2021-06-11T17:21:57.2790277Z INFO: Elapsed time: 56.440s, Critical Path: 19.63s
2021-06-11T17:21:57.2792675Z INFO: 291 processes: 3 internal, 288 linux-sandbox.
2021-06-11T17:21:57.2812393Z INFO: Build completed successfully, 291 total actions
2021-06-11T17:21:57.3188089Z INFO: Running command line: bazel-bin/hack/k8s/k8s_/k8s -type kind
2021-06-11T17:21:57.3276029Z INFO: Build completed successfully, 291 total actions
2021-06-11T17:21:57.3560176Z I0611 17:21:57.354941 7484 verify_k8s_running.go:227] Checking that kind k8s cluster has started completely
2021-06-11T17:21:57.3944157Z I0611 17:21:57.388365 7484 verify_k8s_running.go:139] component=etcd is runnning
2021-06-11T17:21:57.3954569Z I0611 17:21:57.395162 7484 verify_k8s_running.go:139] component=kube-apiserver is runnning
2021-06-11T17:21:57.4003847Z I0611 17:21:57.398215 7484 verify_k8s_running.go:139] component=kube-controller-manager is runnning
2021-06-11T17:21:57.4021231Z I0611 17:21:57.401947 7484 verify_k8s_running.go:139] component=kube-scheduler is runnning
2021-06-11T17:21:57.4072313Z I0611 17:21:57.404659 7484 verify_k8s_running.go:139] k8s-app=kindnet is runnning
2021-06-11T17:21:57.4075087Z I0611 17:21:57.407340 7484 verify_k8s_running.go:139] k8s-app=kube-proxy is runnning
2021-06-11T17:21:57.4076420Z I0611 17:21:57.407352 7484 verify_k8s_running.go:265] kind k8s cluster is up and running
2021-06-11T17:21:57.4093218Z bazel test --stamp //e2e/decomission/... --test_arg=-test.parallel=8 --test_arg=parallel=true
2021-06-11T17:21:57.6048510Z WARNING: Streamed test output requested. All tests will be run locally, without sharding, one at a time
2021-06-11T17:21:57.6137851Z Loading:
2021-06-11T17:21:57.6151240Z Loading: 0 packages loaded
2021-06-11T17:21:57.6677253Z INFO: Build options --stamp, --test_arg, and --test_sharding_strategy have changed, discarding analysis cache.
2021-06-11T17:21:57.6887232Z Analyzing: 3 targets (1 packages loaded, 0 targets configured)
2021-06-11T17:21:58.6967964Z Analyzing: 3 targets (12 packages loaded, 6787 targets configured)
2021-06-11T17:21:59.7191636Z Analyzing: 3 targets (16 packages loaded, 7211 targets configured)
2021-06-11T17:22:00.7205266Z Analyzing: 3 targets (26 packages loaded, 7578 targets configured)
2021-06-11T17:22:01.9132428Z Analyzing: 3 targets (26 packages loaded, 7578 targets configured)
2021-06-11T17:22:03.3223826Z Analyzing: 3 targets (26 packages loaded, 7578 targets configured)
2021-06-11T17:22:04.3350214Z Analyzing: 3 targets (33 packages loaded, 9382 targets configured)
2021-06-11T17:22:05.3716848Z Analyzing: 3 targets (37 packages loaded, 9514 targets configured)
2021-06-11T17:22:06.7280461Z Analyzing: 3 targets (106 packages loaded, 10774 targets configured)
2021-06-11T17:22:08.1481794Z Analyzing: 3 targets (125 packages loaded, 10991 targets configured)
2021-06-11T17:22:08.9592991Z INFO: Analyzed 3 targets (140 packages loaded, 11241 targets configured).
2021-06-11T17:22:08.9667261Z INFO: Found 2 targets and 1 test target...
2021-06-11T17:22:09.0203421Z [0 / 2] [Prepa] BazelWorkspaceStatusAction stable-status.txt
2021-06-11T17:22:11.0352558Z [12 / 17] Executing genrule //hack/bin:io_kubernetes_kube-apiserver; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:13.1310225Z [360 / 374] GoCompilePkg external/com_github_stretchr_testify/assert/assert.a; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:15.5117527Z [392 / 415] GoCompilePkg external/org_golang_x_text/encoding/simplifiedchinese/simplifiedchinese.a; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:18.2458958Z [428 / 438] GoCompilePkg external/com_github_jackc_pgconn/pgconn.a; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:21.4037385Z [437 / 472] GoCompilePkg external/com_github_jackc_pgtype/pgtype.a; 3s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:25.1358771Z [475 / 483] GoCompilePkg pkg/healthchecker/go_default_library.a; 0s linux-sandbox ... (2 actions, 1 running)
2021-06-11T17:22:29.5297311Z [487 / 488] Testing //e2e/decomission:go_default_test; 0s linux-sandbox
2021-06-11T17:22:35.7044460Z === RUN TestDecommissionFunctionality
2021-06-11T17:22:36.3055348Z W0611 17:22:36.294315 24 warnings.go:70] extensions/v1beta1 Ingress is deprecated in v1.14+, unavailable in v1.22+; use networking.k8s.io/v1 Ingress
2021-06-11T17:22:36.4059560Z === RUN TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:22:36.7072568Z W0611 17:22:36.643154 24 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
2021-06-11T17:22:36.7074938Z W0611 17:22:36.644082 24 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
2021-06-11T17:22:36.8074591Z === CONT TestDecommissionFunctionality
2021-06-11T17:22:36.8078378Z logger.go:130: 2021-06-11T17:22:36.742Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.8081919Z logger.go:130: 2021-06-11T17:22:36.748Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.8085790Z logger.go:130: 2021-06-11T17:22:36.748Z INFO Running action with index: 1 and name: VersionCheckerAction {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.8090443Z logger.go:130: 2021-06-11T17:22:36.748Z WARN starting to check the crdb version of the container provided {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.8093147Z logger.go:130: 2021-06-11T17:22:36.748Z WARN User set image.name, using that field instead of cockroachDBVersion {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9075913Z logger.go:130: 2021-06-11T17:22:36.879Z WARN created/updated job, stopping request processing {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9078580Z logger.go:130: 2021-06-11T17:22:36.879Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9084970Z logger.go:130: 2021-06-11T17:22:36.879Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9088031Z logger.go:130: 2021-06-11T17:22:36.879Z INFO Running action with index: 1 and name: VersionCheckerAction {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9090320Z logger.go:130: 2021-06-11T17:22:36.879Z WARN starting to check the crdb version of the container provided {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9092645Z logger.go:130: 2021-06-11T17:22:36.879Z WARN User set image.name, using that field instead of cockroachDBVersion {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:36.9095227Z logger.go:130: 2021-06-11T17:22:36.884Z ERROR failed to reconcile job only err {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb", "error": "jobs.batch \"crdb-vcheck-27057202\" already exists"}
2021-06-11T17:22:36.9097970Z logger.go:130: 2021-06-11T17:22:36.884Z WARN version checker {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb", "job": "crdb-vcheck-27057202"}
2021-06-11T17:22:36.9099871Z logger.go:130: 2021-06-11T17:22:36.896Z WARN job pods are not running yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:37.8093689Z logger.go:130: 2021-06-11T17:22:37.738Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:38.8110437Z logger.go:130: 2021-06-11T17:22:38.727Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:39.6118791Z logger.go:130: 2021-06-11T17:22:39.535Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:41.1133474Z logger.go:130: 2021-06-11T17:22:41.024Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:43.1171776Z logger.go:130: 2021-06-11T17:22:43.099Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:46.4187951Z === CONT TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:22:46.4189538Z require.go:65: stateful set is not found
2021-06-11T17:22:47.0197061Z === CONT TestDecommissionFunctionality
2021-06-11T17:22:47.0198764Z logger.go:130: 2021-06-11T17:22:46.994Z WARN job pod is not ready yet waiting longer {"action": "Crdb Version Validator"}
2021-06-11T17:22:51.5309866Z logger.go:130: 2021-06-11T17:22:51.457Z WARN job pod is ready {"action": "Crdb Version Validator"}
2021-06-11T17:22:51.5311797Z logger.go:130: 2021-06-11T17:22:51.500Z WARN completed version checker {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb", "calVersion": "v20.2.5", "containerImage": "cockroachdb/cockroach:v20.2.5"}
2021-06-11T17:22:51.5313758Z logger.go:130: 2021-06-11T17:22:51.500Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.5315321Z logger.go:130: 2021-06-11T17:22:51.500Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.5316977Z logger.go:130: 2021-06-11T17:22:51.500Z INFO Running action with index: 1 and name: VersionCheckerAction {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.5318872Z logger.go:130: 2021-06-11T17:22:51.500Z WARN starting to check the crdb version of the container provided {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.5320907Z logger.go:130: 2021-06-11T17:22:51.500Z WARN User set image.name, using that field instead of cockroachDBVersion {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.5322918Z logger.go:130: 2021-06-11T17:22:51.503Z WARN version checker {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb", "job": "crdb-vcheck-27057202"}
2021-06-11T17:22:51.5324408Z logger.go:130: 2021-06-11T17:22:51.507Z WARN job pod is ready {"action": "Crdb Version Validator"}
2021-06-11T17:22:51.6263216Z logger.go:130: 2021-06-11T17:22:51.540Z WARN completed version checker {"action": "Crdb Version Validator", "CrdbCluster": "crdb-test-vrt8wt/crdb", "calVersion": "v20.2.5", "containerImage": "cockroachdb/cockroach:v20.2.5"}
2021-06-11T17:22:51.6265927Z logger.go:130: 2021-06-11T17:22:51.540Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.6268023Z logger.go:130: 2021-06-11T17:22:51.540Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.6270195Z logger.go:130: 2021-06-11T17:22:51.540Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.6272327Z logger.go:130: 2021-06-11T17:22:51.540Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.9267160Z logger.go:130: 2021-06-11T17:22:51.830Z WARN generated and saved ca key {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:51.9276951Z logger.go:130: 2021-06-11T17:22:51.830Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.1269163Z logger.go:130: 2021-06-11T17:22:52.094Z WARN generated and saved node certificate and key {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.1291233Z logger.go:130: 2021-06-11T17:22:52.094Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.1294563Z logger.go:130: 2021-06-11T17:22:52.094Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.1296674Z logger.go:130: 2021-06-11T17:22:52.094Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5286243Z logger.go:130: 2021-06-11T17:22:52.447Z WARN generated and saved client certificate and key {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5304134Z logger.go:130: 2021-06-11T17:22:52.462Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5306239Z logger.go:130: 2021-06-11T17:22:52.462Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5310651Z logger.go:130: 2021-06-11T17:22:52.473Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5312039Z 26257
2021-06-11T17:22:52.5313525Z logger.go:130: 2021-06-11T17:22:52.477Z INFO created/updated discovery service, stopping request processing {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5315323Z logger.go:130: 2021-06-11T17:22:52.478Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5317140Z logger.go:130: 2021-06-11T17:22:52.478Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5318878Z logger.go:130: 2021-06-11T17:22:52.478Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5320747Z logger.go:130: 2021-06-11T17:22:52.478Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5323781Z logger.go:130: 2021-06-11T17:22:52.478Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5326001Z logger.go:130: 2021-06-11T17:22:52.478Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5328726Z logger.go:130: 2021-06-11T17:22:52.478Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5331245Z logger.go:130: 2021-06-11T17:22:52.478Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5333197Z logger.go:130: 2021-06-11T17:22:52.478Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.5335040Z logger.go:130: 2021-06-11T17:22:52.478Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5336733Z logger.go:130: 2021-06-11T17:22:52.478Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5338325Z logger.go:130: 2021-06-11T17:22:52.494Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5341107Z logger.go:130: 2021-06-11T17:22:52.494Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5343334Z logger.go:130: 2021-06-11T17:22:52.498Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5344569Z 26257
2021-06-11T17:22:52.5346049Z logger.go:130: 2021-06-11T17:22:52.506Z INFO created/updated public service, stopping request processing {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5347685Z logger.go:130: 2021-06-11T17:22:52.506Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5349137Z logger.go:130: 2021-06-11T17:22:52.507Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5350721Z logger.go:130: 2021-06-11T17:22:52.507Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5352268Z logger.go:130: 2021-06-11T17:22:52.507Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5353848Z logger.go:130: 2021-06-11T17:22:52.507Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5355496Z logger.go:130: 2021-06-11T17:22:52.507Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5357189Z logger.go:130: 2021-06-11T17:22:52.507Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5359409Z logger.go:130: 2021-06-11T17:22:52.507Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5361504Z logger.go:130: 2021-06-11T17:22:52.507Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.5363179Z logger.go:130: 2021-06-11T17:22:52.507Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5364732Z logger.go:130: 2021-06-11T17:22:52.507Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5366684Z logger.go:130: 2021-06-11T17:22:52.518Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5368405Z logger.go:130: 2021-06-11T17:22:52.518Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5370081Z logger.go:130: 2021-06-11T17:22:52.523Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.5370934Z 26257
2021-06-11T17:22:52.6282367Z logger.go:130: 2021-06-11T17:22:52.549Z INFO created/updated statefulset, stopping request processing {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6287050Z logger.go:130: 2021-06-11T17:22:52.550Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6290307Z logger.go:130: 2021-06-11T17:22:52.551Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6300672Z logger.go:130: 2021-06-11T17:22:52.551Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6302329Z logger.go:130: 2021-06-11T17:22:52.551Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6303891Z logger.go:130: 2021-06-11T17:22:52.551Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6305757Z logger.go:130: 2021-06-11T17:22:52.551Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6307471Z logger.go:130: 2021-06-11T17:22:52.551Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6309178Z logger.go:130: 2021-06-11T17:22:52.551Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6311223Z logger.go:130: 2021-06-11T17:22:52.551Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.6313024Z logger.go:130: 2021-06-11T17:22:52.551Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6314704Z logger.go:130: 2021-06-11T17:22:52.551Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6316298Z logger.go:130: 2021-06-11T17:22:52.569Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6341662Z logger.go:130: 2021-06-11T17:22:52.569Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6343394Z logger.go:130: 2021-06-11T17:22:52.585Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6344251Z 26257
2021-06-11T17:22:52.6345304Z W0611 17:22:52.618696 24 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
2021-06-11T17:22:52.6347197Z logger.go:130: 2021-06-11T17:22:52.618Z INFO created/updated pdb, stopping request processing {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6348748Z logger.go:130: 2021-06-11T17:22:52.618Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6350202Z logger.go:130: 2021-06-11T17:22:52.618Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6351734Z logger.go:130: 2021-06-11T17:22:52.618Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6353284Z logger.go:130: 2021-06-11T17:22:52.619Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6354841Z logger.go:130: 2021-06-11T17:22:52.619Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6356441Z logger.go:130: 2021-06-11T17:22:52.619Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6358142Z logger.go:130: 2021-06-11T17:22:52.619Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6359858Z logger.go:130: 2021-06-11T17:22:52.619Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6361890Z logger.go:130: 2021-06-11T17:22:52.619Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.6363719Z logger.go:130: 2021-06-11T17:22:52.619Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.6365387Z logger.go:130: 2021-06-11T17:22:52.619Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7331409Z logger.go:130: 2021-06-11T17:22:52.647Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7333389Z logger.go:130: 2021-06-11T17:22:52.647Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7335124Z logger.go:130: 2021-06-11T17:22:52.659Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7336101Z 26257
2021-06-11T17:22:52.7337169Z logger.go:130: 2021-06-11T17:22:52.674Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7338681Z logger.go:130: 2021-06-11T17:22:52.674Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7340269Z logger.go:130: 2021-06-11T17:22:52.675Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7341916Z logger.go:130: 2021-06-11T17:22:52.686Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:22:52.7343609Z logger.go:130: 2021-06-11T17:22:52.686Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:22:52.7345188Z logger.go:130: 2021-06-11T17:22:52.710Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7346723Z logger.go:130: 2021-06-11T17:22:52.710Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7348253Z logger.go:130: 2021-06-11T17:22:52.710Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7349813Z logger.go:130: 2021-06-11T17:22:52.710Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7351425Z logger.go:130: 2021-06-11T17:22:52.710Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7353139Z logger.go:130: 2021-06-11T17:22:52.710Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7354818Z logger.go:130: 2021-06-11T17:22:52.710Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7356742Z logger.go:130: 2021-06-11T17:22:52.710Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:52.7358560Z logger.go:130: 2021-06-11T17:22:52.710Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:52.7360202Z logger.go:130: 2021-06-11T17:22:52.710Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3723596Z logger.go:130: 2021-06-11T17:22:52.730Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3725839Z logger.go:130: 2021-06-11T17:22:52.730Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3728122Z logger.go:130: 2021-06-11T17:22:52.756Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3729262Z 26257
2021-06-11T17:22:53.3730466Z logger.go:130: 2021-06-11T17:22:52.765Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3732197Z logger.go:130: 2021-06-11T17:22:52.765Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3734053Z logger.go:130: 2021-06-11T17:22:52.765Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3736889Z logger.go:130: 2021-06-11T17:22:52.777Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:22:53.3738576Z logger.go:130: 2021-06-11T17:22:52.777Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:22:53.3740305Z logger.go:130: 2021-06-11T17:22:52.787Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3741729Z logger.go:130: 2021-06-11T17:22:52.787Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3743162Z logger.go:130: 2021-06-11T17:22:52.787Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3744703Z logger.go:130: 2021-06-11T17:22:52.787Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3746209Z logger.go:130: 2021-06-11T17:22:52.787Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3747802Z logger.go:130: 2021-06-11T17:22:52.787Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3749723Z logger.go:130: 2021-06-11T17:22:52.788Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3751517Z logger.go:130: 2021-06-11T17:22:52.788Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:53.3753207Z logger.go:130: 2021-06-11T17:22:52.788Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3754740Z logger.go:130: 2021-06-11T17:22:52.788Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3756206Z logger.go:130: 2021-06-11T17:22:52.807Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3757682Z logger.go:130: 2021-06-11T17:22:52.807Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3759222Z logger.go:130: 2021-06-11T17:22:52.823Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3760058Z 26257
2021-06-11T17:22:53.3760905Z logger.go:130: 2021-06-11T17:22:52.850Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3762121Z logger.go:130: 2021-06-11T17:22:52.850Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3763410Z logger.go:130: 2021-06-11T17:22:52.850Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:53.3764720Z logger.go:130: 2021-06-11T17:22:52.855Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:22:53.3766077Z logger.go:130: 2021-06-11T17:22:52.855Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:22:53.5866973Z [487 / 488] Testing //e2e/decomission:go_default_test; 24s linux-sandbox
2021-06-11T17:22:56.3542286Z === CONT TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:22:56.3543379Z require.go:70: stateful set is not ready
2021-06-11T17:22:56.4550854Z require.go:553: pods-name=crdb-0
2021-06-11T17:22:56.4557785Z require.go:554: pods-status=Pending
2021-06-11T17:22:56.4562097Z require.go:555: pods-condition=[{PodScheduled False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:52 +0000 UTC Unschedulable 0/1 nodes are available: 1 persistentvolumeclaim "datadir-crdb-0" not found.}]
2021-06-11T17:22:56.4563578Z require.go:553: pods-name=crdb-1
2021-06-11T17:22:56.4564363Z require.go:554: pods-status=Pending
2021-06-11T17:22:56.4565309Z require.go:555: pods-condition=[]
2021-06-11T17:22:56.4566073Z require.go:553: pods-name=crdb-2
2021-06-11T17:22:56.4566867Z require.go:554: pods-status=Pending
2021-06-11T17:22:56.4568257Z require.go:555: pods-condition=[]
2021-06-11T17:22:56.4569048Z require.go:553: pods-name=crdb-3
2021-06-11T17:22:56.4569818Z require.go:554: pods-status=Pending
2021-06-11T17:22:56.4570624Z require.go:555: pods-condition=[]
2021-06-11T17:22:56.4571575Z require.go:553: pods-name=crdb-vcheck-27057202-tbq45
2021-06-11T17:22:56.4572523Z require.go:554: pods-status=Running
2021-06-11T17:22:56.4574355Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC }]
2021-06-11T17:22:57.7569939Z === CONT TestDecommissionFunctionality
2021-06-11T17:22:57.7581128Z logger.go:130: 2021-06-11T17:22:57.711Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7583751Z logger.go:130: 2021-06-11T17:22:57.711Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7585704Z logger.go:130: 2021-06-11T17:22:57.711Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7587669Z logger.go:130: 2021-06-11T17:22:57.711Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7589668Z logger.go:130: 2021-06-11T17:22:57.711Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7591709Z logger.go:130: 2021-06-11T17:22:57.711Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7593782Z logger.go:130: 2021-06-11T17:22:57.711Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7596089Z logger.go:130: 2021-06-11T17:22:57.711Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:57.7598249Z logger.go:130: 2021-06-11T17:22:57.711Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7600899Z logger.go:130: 2021-06-11T17:22:57.711Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7605077Z logger.go:130: 2021-06-11T17:22:57.722Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7606954Z logger.go:130: 2021-06-11T17:22:57.722Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7608847Z logger.go:130: 2021-06-11T17:22:57.726Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7609656Z 26257
2021-06-11T17:22:57.7610602Z logger.go:130: 2021-06-11T17:22:57.734Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7612016Z logger.go:130: 2021-06-11T17:22:57.734Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7613715Z logger.go:130: 2021-06-11T17:22:57.734Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7615234Z logger.go:130: 2021-06-11T17:22:57.738Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:22:57.7617319Z logger.go:130: 2021-06-11T17:22:57.738Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:22:57.7618755Z logger.go:130: 2021-06-11T17:22:57.743Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7620192Z logger.go:130: 2021-06-11T17:22:57.743Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7621611Z logger.go:130: 2021-06-11T17:22:57.744Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7623038Z logger.go:130: 2021-06-11T17:22:57.744Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7624776Z logger.go:130: 2021-06-11T17:22:57.744Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7626744Z logger.go:130: 2021-06-11T17:22:57.744Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7628416Z logger.go:130: 2021-06-11T17:22:57.744Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7630333Z logger.go:130: 2021-06-11T17:22:57.744Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:22:57.7632136Z logger.go:130: 2021-06-11T17:22:57.744Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.7633804Z logger.go:130: 2021-06-11T17:22:57.744Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8567029Z logger.go:130: 2021-06-11T17:22:57.763Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8587663Z logger.go:130: 2021-06-11T17:22:57.763Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8589721Z logger.go:130: 2021-06-11T17:22:57.767Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8590597Z 26257
2021-06-11T17:22:57.8591633Z logger.go:130: 2021-06-11T17:22:57.774Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8593457Z logger.go:130: 2021-06-11T17:22:57.775Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8595033Z logger.go:130: 2021-06-11T17:22:57.775Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:22:57.8596693Z logger.go:130: 2021-06-11T17:22:57.779Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:22:57.8598361Z logger.go:130: 2021-06-11T17:22:57.779Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:23:02.7624436Z logger.go:130: 2021-06-11T17:23:02.743Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7626038Z logger.go:130: 2021-06-11T17:23:02.744Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7628002Z logger.go:130: 2021-06-11T17:23:02.744Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7629597Z logger.go:130: 2021-06-11T17:23:02.744Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7631336Z logger.go:130: 2021-06-11T17:23:02.744Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7633038Z logger.go:130: 2021-06-11T17:23:02.744Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7634748Z logger.go:130: 2021-06-11T17:23:02.744Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7636735Z logger.go:130: 2021-06-11T17:23:02.744Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:23:02.7638593Z logger.go:130: 2021-06-11T17:23:02.744Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.7640141Z logger.go:130: 2021-06-11T17:23:02.744Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8624985Z logger.go:130: 2021-06-11T17:23:02.775Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8628209Z logger.go:130: 2021-06-11T17:23:02.775Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8630277Z logger.go:130: 2021-06-11T17:23:02.779Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8631567Z 26257
2021-06-11T17:23:02.8632926Z logger.go:130: 2021-06-11T17:23:02.791Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8634694Z logger.go:130: 2021-06-11T17:23:02.792Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8636486Z logger.go:130: 2021-06-11T17:23:02.792Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8638367Z logger.go:130: 2021-06-11T17:23:02.804Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:23:02.8640947Z logger.go:130: 2021-06-11T17:23:02.804Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:23:02.8642623Z logger.go:130: 2021-06-11T17:23:02.810Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8644298Z logger.go:130: 2021-06-11T17:23:02.811Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8645952Z logger.go:130: 2021-06-11T17:23:02.811Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8649535Z logger.go:130: 2021-06-11T17:23:02.811Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8651090Z logger.go:130: 2021-06-11T17:23:02.811Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8652669Z logger.go:130: 2021-06-11T17:23:02.811Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8654410Z logger.go:130: 2021-06-11T17:23:02.811Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8656202Z logger.go:130: 2021-06-11T17:23:02.811Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:23:02.8657889Z logger.go:130: 2021-06-11T17:23:02.811Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8659787Z logger.go:130: 2021-06-11T17:23:02.811Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8661366Z logger.go:130: 2021-06-11T17:23:02.820Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8662930Z logger.go:130: 2021-06-11T17:23:02.820Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8664600Z logger.go:130: 2021-06-11T17:23:02.825Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8665466Z 26257
2021-06-11T17:23:02.8666492Z logger.go:130: 2021-06-11T17:23:02.832Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8668012Z logger.go:130: 2021-06-11T17:23:02.832Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8669565Z logger.go:130: 2021-06-11T17:23:02.832Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:02.8671195Z logger.go:130: 2021-06-11T17:23:02.840Z INFO Error on action {"CrdbCluster": "crdb-test-vrt8wt/crdb", "Action": "Initialize", "err": "pod is not running"}
2021-06-11T17:23:02.8672838Z logger.go:130: 2021-06-11T17:23:02.840Z WARN requeueing {"CrdbCluster": "crdb-test-vrt8wt/crdb", "reason": "pod is not running", "Action": "Initialize"}
2021-06-11T17:23:06.3672487Z === CONT TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:23:06.3673447Z require.go:70: stateful set is not ready
2021-06-11T17:23:06.3674211Z require.go:553: pods-name=crdb-0
2021-06-11T17:23:06.3674938Z require.go:554: pods-status=Pending
2021-06-11T17:23:06.3677579Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:03 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC }]
2021-06-11T17:23:06.3679511Z require.go:553: pods-name=crdb-1
2021-06-11T17:23:06.3680283Z require.go:554: pods-status=Running
2021-06-11T17:23:06.3682737Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:06.3684640Z require.go:553: pods-name=crdb-2
2021-06-11T17:23:06.3685409Z require.go:554: pods-status=Running
2021-06-11T17:23:06.3688309Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:02 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC }]
2021-06-11T17:23:06.3690269Z require.go:553: pods-name=crdb-3
2021-06-11T17:23:06.3691064Z require.go:554: pods-status=Pending
2021-06-11T17:23:06.3693489Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:01 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:06.3695715Z require.go:553: pods-name=crdb-vcheck-27057202-tbq45
2021-06-11T17:23:06.3696665Z require.go:554: pods-status=Running
2021-06-11T17:23:06.3698458Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC }]
2021-06-11T17:23:07.8691678Z === CONT TestDecommissionFunctionality
2021-06-11T17:23:07.8693545Z logger.go:130: 2021-06-11T17:23:07.811Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8695050Z logger.go:130: 2021-06-11T17:23:07.811Z INFO Running action with index: 2 and name: RequestCert {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8696613Z logger.go:130: 2021-06-11T17:23:07.811Z WARN generating CA {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8698078Z logger.go:130: 2021-06-11T17:23:07.811Z WARN not updating ca key as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8699594Z logger.go:130: 2021-06-11T17:23:07.811Z WARN generating node certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8701157Z logger.go:130: 2021-06-11T17:23:07.811Z WARN not updating node certificate as it exists {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8702744Z logger.go:130: 2021-06-11T17:23:07.811Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8704539Z logger.go:130: 2021-06-11T17:23:07.811Z WARN getExpirationDate from cert {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb", "Not before:": "2021-06-10T17:22:52Z", "Not after:": "2026-06-15T17:22:52Z"}
2021-06-11T17:23:07.8706208Z logger.go:130: 2021-06-11T17:23:07.811Z WARN generating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8707872Z logger.go:130: 2021-06-11T17:23:07.811Z WARN not updating client certificate {"action": "generate_cert", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8709339Z logger.go:130: 2021-06-11T17:23:07.826Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8710831Z logger.go:130: 2021-06-11T17:23:07.826Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8712583Z logger.go:130: 2021-06-11T17:23:07.831Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8713453Z 26257
2021-06-11T17:23:07.8714474Z logger.go:130: 2021-06-11T17:23:07.846Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8715986Z logger.go:130: 2021-06-11T17:23:07.846Z INFO Running action with index: 6 and name: Initialize {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8717753Z logger.go:130: 2021-06-11T17:23:07.846Z WARN initializing CockroachDB {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8719276Z logger.go:130: 2021-06-11T17:23:07.850Z WARN Pod is ready {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:07.8720871Z logger.go:130: 2021-06-11T17:23:07.850Z WARN Executing init in pod crdb-0 with phase Running {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1709290Z logger.go:130: 2021-06-11T17:23:08.153Z WARN Executed init in pod {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1717127Z logger.go:130: 2021-06-11T17:23:08.153Z WARN completed intializing database {"action": "initialize", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1718959Z logger.go:130: 2021-06-11T17:23:08.153Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1720615Z logger.go:130: 2021-06-11T17:23:08.153Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1722169Z logger.go:130: 2021-06-11T17:23:08.153Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1723582Z logger.go:130: 2021-06-11T17:23:08.165Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1724945Z logger.go:130: 2021-06-11T17:23:08.165Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1726388Z logger.go:130: 2021-06-11T17:23:08.165Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1728030Z logger.go:130: 2021-06-11T17:23:08.165Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1729860Z logger.go:130: 2021-06-11T17:23:08.165Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 4}
2021-06-11T17:23:08.1731603Z logger.go:130: 2021-06-11T17:23:08.165Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1733363Z logger.go:130: 2021-06-11T17:23:08.165Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1735113Z logger.go:130: 2021-06-11T17:23:08.165Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1736635Z logger.go:130: 2021-06-11T17:23:08.165Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1738120Z logger.go:130: 2021-06-11T17:23:08.165Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1739548Z logger.go:130: 2021-06-11T17:23:08.165Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.1741020Z logger.go:130: 2021-06-11T17:23:08.165Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2714660Z logger.go:130: 2021-06-11T17:23:08.177Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2715645Z 26257
2021-06-11T17:23:08.2717262Z logger.go:130: 2021-06-11T17:23:08.198Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2719460Z logger.go:130: 2021-06-11T17:23:08.198Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2721395Z logger.go:130: 2021-06-11T17:23:08.198Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2723421Z logger.go:130: 2021-06-11T17:23:08.198Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:08.2725086Z logger.go:130: 2021-06-11T17:23:08.205Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6850294Z logger.go:130: 2021-06-11T17:23:15.619Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6851953Z logger.go:130: 2021-06-11T17:23:15.619Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6853628Z logger.go:130: 2021-06-11T17:23:15.619Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6855739Z logger.go:130: 2021-06-11T17:23:15.619Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 4}
2021-06-11T17:23:15.6857697Z logger.go:130: 2021-06-11T17:23:15.619Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6859449Z logger.go:130: 2021-06-11T17:23:15.619Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6861196Z logger.go:130: 2021-06-11T17:23:15.619Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6862726Z logger.go:130: 2021-06-11T17:23:15.619Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6864202Z logger.go:130: 2021-06-11T17:23:15.619Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6865626Z logger.go:130: 2021-06-11T17:23:15.619Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6867105Z logger.go:130: 2021-06-11T17:23:15.619Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6868620Z logger.go:130: 2021-06-11T17:23:15.628Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6869441Z 26257
2021-06-11T17:23:15.6870419Z logger.go:130: 2021-06-11T17:23:15.636Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6874098Z logger.go:130: 2021-06-11T17:23:15.636Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6875780Z logger.go:130: 2021-06-11T17:23:15.636Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6888679Z logger.go:130: 2021-06-11T17:23:15.636Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:15.6890598Z logger.go:130: 2021-06-11T17:23:15.643Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:16.3822344Z === CONT TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:23:16.3824199Z require.go:70: stateful set is not ready
2021-06-11T17:23:16.3825487Z require.go:553: pods-name=crdb-0
2021-06-11T17:23:16.3826507Z require.go:554: pods-status=Running
2021-06-11T17:23:16.3828429Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:03 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC }]
2021-06-11T17:23:16.3830100Z require.go:553: pods-name=crdb-1
2021-06-11T17:23:16.3831143Z require.go:554: pods-status=Running
2021-06-11T17:23:16.3833733Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:16.3835850Z require.go:553: pods-name=crdb-2
2021-06-11T17:23:16.3836762Z require.go:554: pods-status=Running
2021-06-11T17:23:16.3839292Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:02 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC }]
2021-06-11T17:23:16.3841658Z require.go:553: pods-name=crdb-3
2021-06-11T17:23:16.3842739Z require.go:554: pods-status=Running
2021-06-11T17:23:16.3845073Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:01 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:16.3847089Z require.go:553: pods-name=crdb-vcheck-27057202-tbq45
2021-06-11T17:23:16.3848338Z require.go:554: pods-status=Running
2021-06-11T17:23:16.3850169Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC }]
2021-06-11T17:23:18.8465846Z [487 / 488] Testing //e2e/decomission:go_default_test; 50s linux-sandbox
2021-06-11T17:23:26.3953256Z require.go:70: stateful set is not ready
2021-06-11T17:23:26.3955928Z require.go:553: pods-name=crdb-0
2021-06-11T17:23:26.3957286Z require.go:554: pods-status=Running
2021-06-11T17:23:26.3960060Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:03 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC }]
2021-06-11T17:23:26.3962132Z require.go:553: pods-name=crdb-1
2021-06-11T17:23:26.3963263Z require.go:554: pods-status=Running
2021-06-11T17:23:26.3966826Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:26.3970066Z require.go:553: pods-name=crdb-2
2021-06-11T17:23:26.3971242Z require.go:554: pods-status=Running
2021-06-11T17:23:26.3975029Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:02 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC }]
2021-06-11T17:23:26.3977811Z require.go:553: pods-name=crdb-3
2021-06-11T17:23:26.3979096Z require.go:554: pods-status=Running
2021-06-11T17:23:26.3982647Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:01 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:26.3985672Z require.go:553: pods-name=crdb-vcheck-27057202-tbq45
2021-06-11T17:23:26.3987023Z require.go:554: pods-status=Running
2021-06-11T17:23:26.3989629Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC }]
2021-06-11T17:23:34.8122507Z === CONT TestDecommissionFunctionality
2021-06-11T17:23:34.8266752Z logger.go:130: 2021-06-11T17:23:34.767Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8268449Z logger.go:130: 2021-06-11T17:23:34.767Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8270094Z logger.go:130: 2021-06-11T17:23:34.767Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8272087Z logger.go:130: 2021-06-11T17:23:34.767Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 4}
2021-06-11T17:23:34.8273969Z logger.go:130: 2021-06-11T17:23:34.767Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8275864Z logger.go:130: 2021-06-11T17:23:34.767Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8277626Z logger.go:130: 2021-06-11T17:23:34.767Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8279148Z logger.go:130: 2021-06-11T17:23:34.767Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8280826Z logger.go:130: 2021-06-11T17:23:34.767Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8282274Z logger.go:130: 2021-06-11T17:23:34.767Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8283751Z logger.go:130: 2021-06-11T17:23:34.767Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8285275Z logger.go:130: 2021-06-11T17:23:34.773Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8286083Z 26257
2021-06-11T17:23:34.8287230Z logger.go:130: 2021-06-11T17:23:34.787Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8289430Z logger.go:130: 2021-06-11T17:23:34.787Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8294695Z logger.go:130: 2021-06-11T17:23:34.787Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8296890Z logger.go:130: 2021-06-11T17:23:34.787Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:34.8298872Z logger.go:130: 2021-06-11T17:23:34.795Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:37.3804848Z === CONT TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db
2021-06-11T17:23:37.3805921Z require.go:70: stateful set is not ready
2021-06-11T17:23:37.3806671Z require.go:553: pods-name=crdb-0
2021-06-11T17:23:37.3807753Z require.go:554: pods-status=Running
2021-06-11T17:23:37.3809291Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:03 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:15 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC }]
2021-06-11T17:23:37.3810403Z require.go:553: pods-name=crdb-1
2021-06-11T17:23:37.3811054Z require.go:554: pods-status=Running
2021-06-11T17:23:37.3813037Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:00 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:37.3814604Z require.go:553: pods-name=crdb-2
2021-06-11T17:23:37.3815227Z require.go:554: pods-status=Running
2021-06-11T17:23:37.3817500Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:02 +0000 UTC } {Ready False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC ContainersNotReady containers with unready status: [db]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:58 +0000 UTC }]
2021-06-11T17:23:37.3819284Z require.go:553: pods-name=crdb-3
2021-06-11T17:23:37.3819997Z require.go:554: pods-status=Running
2021-06-11T17:23:37.3821579Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:01 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:34 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:23:34 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:59 +0000 UTC }]
2021-06-11T17:23:37.3822841Z require.go:553: pods-name=crdb-vcheck-27057202-tbq45
2021-06-11T17:23:37.3823590Z require.go:554: pods-status=Running
2021-06-11T17:23:37.3825054Z require.go:555: pods-condition=[{Initialized True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC } {Ready True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:47 +0000 UTC } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2021-06-11 17:22:36 +0000 UTC }]
2021-06-11T17:23:38.8170146Z === CONT TestDecommissionFunctionality
2021-06-11T17:23:38.8172585Z logger.go:130: 2021-06-11T17:23:38.732Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8174520Z logger.go:130: 2021-06-11T17:23:38.732Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8176294Z logger.go:130: 2021-06-11T17:23:38.732Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8178595Z logger.go:130: 2021-06-11T17:23:38.732Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 4}
2021-06-11T17:23:38.8180608Z logger.go:130: 2021-06-11T17:23:38.732Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8182725Z logger.go:130: 2021-06-11T17:23:38.732Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8184728Z logger.go:130: 2021-06-11T17:23:38.732Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8186472Z logger.go:130: 2021-06-11T17:23:38.732Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8188161Z logger.go:130: 2021-06-11T17:23:38.733Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8189820Z logger.go:130: 2021-06-11T17:23:38.733Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8191503Z logger.go:130: 2021-06-11T17:23:38.733Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8193246Z logger.go:130: 2021-06-11T17:23:38.743Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8198705Z 26257
2021-06-11T17:23:38.8199940Z logger.go:130: 2021-06-11T17:23:38.751Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8201404Z logger.go:130: 2021-06-11T17:23:38.751Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8202972Z logger.go:130: 2021-06-11T17:23:38.751Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8204485Z logger.go:130: 2021-06-11T17:23:38.751Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:38.8205903Z logger.go:130: 2021-06-11T17:23:38.759Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8194615Z logger.go:130: 2021-06-11T17:23:39.721Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8196240Z logger.go:130: 2021-06-11T17:23:39.721Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8197784Z logger.go:130: 2021-06-11T17:23:39.721Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8199656Z logger.go:130: 2021-06-11T17:23:39.721Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 4}
2021-06-11T17:23:39.8201409Z logger.go:130: 2021-06-11T17:23:39.721Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8203152Z logger.go:130: 2021-06-11T17:23:39.721Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8204911Z logger.go:130: 2021-06-11T17:23:39.721Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8206695Z logger.go:130: 2021-06-11T17:23:39.721Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8208449Z logger.go:130: 2021-06-11T17:23:39.721Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8210188Z logger.go:130: 2021-06-11T17:23:39.721Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8211800Z logger.go:130: 2021-06-11T17:23:39.721Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8213557Z logger.go:130: 2021-06-11T17:23:39.729Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8214430Z 26257
2021-06-11T17:23:39.8215454Z logger.go:130: 2021-06-11T17:23:39.751Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8217058Z logger.go:130: 2021-06-11T17:23:39.752Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8218746Z logger.go:130: 2021-06-11T17:23:39.752Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8220256Z logger.go:130: 2021-06-11T17:23:39.752Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:39.8221658Z logger.go:130: 2021-06-11T17:23:39.758Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:43.2652094Z [487 / 488] Testing //e2e/decomission:go_default_test; 74s linux-sandbox
2021-06-11T17:23:46.4241875Z === RUN TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:23:46.4243483Z === CONT TestDecommissionFunctionality
2021-06-11T17:23:46.4245547Z logger.go:130: 2021-06-11T17:23:46.362Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:46.4247429Z logger.go:130: 2021-06-11T17:23:46.362Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:46.4249374Z logger.go:130: 2021-06-11T17:23:46.362Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:46.4251516Z logger.go:130: 2021-06-11T17:23:46.362Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 4, "expected": 3}
2021-06-11T17:23:46.4253886Z logger.go:130: 2021-06-11T17:23:46.363Z WARN operator is NOT inside of kubernetes, connnecting to pod ordinal zero for db connection {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:46.4255914Z logger.go:130: 2021-06-11T17:23:46.399Z WARN opened db connection {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:23:46.5244201Z logger.go:130: 2021-06-11T17:23:46.456Z INFO established statefulset watch {"action": "decommission", "name": "crdb", "namespace": "crdb-test-vrt8wt"}
2021-06-11T17:23:46.5246512Z logger.go:130: 2021-06-11T17:23:46.462Z WARN scaling down stateful set {"action": "decommission", "have": 4, "want": 3}
2021-06-11T17:23:46.7249108Z logger.go:130: 2021-06-11T17:23:46.637Z INFO draining node {"action": "decommission", "NodeID": 3}
2021-06-11T17:23:47.0254283Z logger.go:130: 2021-06-11T17:23:46.995Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "26", "isDecommissioning": "true"}
2021-06-11T17:23:47.2259226Z logger.go:130: 2021-06-11T17:23:47.155Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "26", "isDecommissioning": "true"}
2021-06-11T17:23:47.7268893Z logger.go:130: 2021-06-11T17:23:47.672Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "26", "isDecommissioning": "true"}
2021-06-11T17:23:48.4275888Z logger.go:130: 2021-06-11T17:23:48.396Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "26", "isDecommissioning": "true"}
2021-06-11T17:23:49.5321727Z logger.go:130: 2021-06-11T17:23:49.524Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "25", "isDecommissioning": "true"}
2021-06-11T17:23:51.5314887Z logger.go:130: 2021-06-11T17:23:51.481Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "23", "isDecommissioning": "true"}
2021-06-11T17:23:55.1353692Z logger.go:130: 2021-06-11T17:23:55.092Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "18", "isDecommissioning": "true"}
2021-06-11T17:23:58.3401440Z logger.go:130: 2021-06-11T17:23:58.317Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "16", "isDecommissioning": "true"}
2021-06-11T17:24:03.0447195Z logger.go:130: 2021-06-11T17:24:03.036Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "9", "isDecommissioning": "true"}
2021-06-11T17:24:06.4486463Z === CONT TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:24:06.4487563Z require.go:301: statefulset replicas do not match
2021-06-11T17:24:13.9617165Z === CONT TestDecommissionFunctionality
2021-06-11T17:24:13.9619555Z logger.go:130: 2021-06-11T17:24:13.943Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "1", "isDecommissioning": "true"}
2021-06-11T17:24:15.0097395Z [487 / 488] Testing //e2e/decomission:go_default_test; 106s linux-sandbox
2021-06-11T17:24:16.4658623Z === CONT TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:24:16.4659906Z require.go:301: statefulset replicas do not match
2021-06-11T17:24:23.1753871Z === CONT TestDecommissionFunctionality
2021-06-11T17:24:23.1756731Z logger.go:130: 2021-06-11T17:24:23.151Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "1", "isDecommissioning": "true"}
2021-06-11T17:24:26.3777966Z === CONT TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:24:26.3779006Z require.go:301: statefulset replicas do not match
2021-06-11T17:24:35.6435009Z [487 / 488] Testing //e2e/decomission:go_default_test; 127s linux-sandbox
2021-06-11T17:24:36.4894514Z require.go:301: statefulset replicas do not match
2021-06-11T17:24:46.8959079Z require.go:301: statefulset replicas do not match
2021-06-11T17:24:49.6058050Z === CONT TestDecommissionFunctionality
2021-06-11T17:24:49.6060246Z logger.go:130: 2021-06-11T17:24:49.572Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "0", "isDecommissioning": "true"}
2021-06-11T17:24:56.4114058Z === CONT TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:24:56.4114965Z require.go:296: statefulset is not ready
2021-06-11T17:25:04.4234293Z === CONT TestDecommissionFunctionality
2021-06-11T17:25:04.4236197Z logger.go:130: 2021-06-11T17:25:04.396Z INFO established statefulset watch {"action": "decommission", "name": "crdb", "namespace": "crdb-test-vrt8wt"}
2021-06-11T17:25:04.4237616Z logger.go:130: 2021-06-11T17:25:04.399Z WARN deleting PVC {"action": "decommission", "name": "datadir-crdb-3"}
2021-06-11T17:25:04.4239035Z logger.go:130: 2021-06-11T17:25:04.403Z WARN decommission completed {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "cond": null}
2021-06-11T17:25:04.4240460Z logger.go:130: 2021-06-11T17:25:04.411Z INFO request was interrupted {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4241782Z logger.go:130: 2021-06-11T17:25:04.411Z INFO reconciling CockroachDB cluster {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4243213Z logger.go:130: 2021-06-11T17:25:04.411Z INFO Running action with index: 0 and name: Decommission {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4244920Z logger.go:130: 2021-06-11T17:25:04.411Z WARN check decommission oportunities {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4246748Z logger.go:130: 2021-06-11T17:25:04.411Z INFO replicas decommisioning {"action": "decommission", "CrdbCluster": "crdb-test-vrt8wt/crdb", "status.CurrentReplicas": 3, "expected": 3}
2021-06-11T17:25:04.4248660Z logger.go:130: 2021-06-11T17:25:04.411Z INFO Running action with index: 3 and name: PartialUpdate {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4250526Z logger.go:130: 2021-06-11T17:25:04.411Z WARN checking update opportunities, using a partitioned update {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4252256Z logger.go:130: 2021-06-11T17:25:04.411Z INFO no version changes needed {"action": "partitionedUpdate", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4253763Z logger.go:130: 2021-06-11T17:25:04.411Z INFO Running action with index: 4 and name: ResizePVC {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4271752Z logger.go:130: 2021-06-11T17:25:04.412Z INFO Skipping PVC resize as sizes match {"action": "resize_pvc", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4273332Z logger.go:130: 2021-06-11T17:25:04.412Z INFO Running action with index: 5 and name: Deploy {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.4274834Z logger.go:130: 2021-06-11T17:25:04.412Z WARN reconciling resources on deploy action {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5237170Z logger.go:130: 2021-06-11T17:25:04.425Z DEBUG found unknown kubernetes distribution {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5238748Z 26257
2021-06-11T17:25:04.5240822Z logger.go:130: 2021-06-11T17:25:04.446Z INFO deployed database {"action": "deploy", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5242505Z logger.go:130: 2021-06-11T17:25:04.446Z INFO Running action with index: 7 and name: ClusterRestart {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5244201Z logger.go:130: 2021-06-11T17:25:04.446Z WARN starting cluster restart action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5245902Z logger.go:130: 2021-06-11T17:25:04.446Z WARN No restart cluster action {"action": "Crdb Cluster Restart", "CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:04.5247591Z logger.go:130: 2021-06-11T17:25:04.452Z INFO reconciliation completed {"CrdbCluster": "crdb-test-vrt8wt/crdb"}
2021-06-11T17:25:06.6268592Z === CONT TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:25:06.6269689Z require.go:348: draining node do to decommission test
2021-06-11T17:25:06.6270318Z require.go:349: id=4
2021-06-11T17:25:06.6270721Z
2021-06-11T17:25:06.6271169Z require.go:350: isLive=true
2021-06-11T17:25:06.6271599Z
2021-06-11T17:25:06.6272047Z require.go:351: replicas=35
2021-06-11T17:25:06.6272688Z require.go:352: isDecommissioning=false
2021-06-11T17:25:06.6273707Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:16.5379795Z require.go:348: draining node do to decommission test
2021-06-11T17:25:16.5380776Z require.go:349: id=4
2021-06-11T17:25:16.5381339Z
2021-06-11T17:25:16.5381931Z require.go:350: isLive=true
2021-06-11T17:25:16.5382618Z
2021-06-11T17:25:16.5383189Z require.go:351: replicas=35
2021-06-11T17:25:16.5383949Z require.go:352: isDecommissioning=false
2021-06-11T17:25:16.5385048Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:23.1004380Z [487 / 488] Testing //e2e/decomission:go_default_test; 174s linux-sandbox
2021-06-11T17:25:26.5485694Z require.go:348: draining node do to decommission test
2021-06-11T17:25:26.5486877Z require.go:349: id=4
2021-06-11T17:25:26.5487920Z
2021-06-11T17:25:26.5488802Z require.go:350: isLive=true
2021-06-11T17:25:26.5489567Z
2021-06-11T17:25:26.5490690Z require.go:351: replicas=35
2021-06-11T17:25:26.5491837Z require.go:352: isDecommissioning=false
2021-06-11T17:25:26.5493575Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:36.5596749Z require.go:348: draining node do to decommission test
2021-06-11T17:25:36.5598244Z require.go:349: id=4
2021-06-11T17:25:36.5598785Z
2021-06-11T17:25:36.5599365Z require.go:350: isLive=true
2021-06-11T17:25:36.5599938Z
2021-06-11T17:25:36.5600628Z require.go:351: replicas=35
2021-06-11T17:25:36.5601410Z require.go:352: isDecommissioning=false
2021-06-11T17:25:36.5602508Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:46.5732836Z require.go:348: draining node do to decommission test
2021-06-11T17:25:46.5733850Z require.go:349: id=4
2021-06-11T17:25:46.5734394Z
2021-06-11T17:25:46.5734969Z require.go:350: isLive=true
2021-06-11T17:25:46.5735814Z
2021-06-11T17:25:46.5736394Z require.go:351: replicas=35
2021-06-11T17:25:46.5737155Z require.go:352: isDecommissioning=false
2021-06-11T17:25:46.5738263Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:53.9473785Z [487 / 488] Testing //e2e/decomission:go_default_test; 205s linux-sandbox
2021-06-11T17:25:56.5846038Z require.go:348: draining node do to decommission test
2021-06-11T17:25:56.5846964Z require.go:349: id=4
2021-06-11T17:25:56.5847572Z
2021-06-11T17:25:56.5848022Z require.go:350: isLive=true
2021-06-11T17:25:56.5848453Z
2021-06-11T17:25:56.5848979Z require.go:351: replicas=35
2021-06-11T17:25:56.5849622Z require.go:352: isDecommissioning=false
2021-06-11T17:25:56.5850609Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:06.5990679Z require.go:348: draining node do to decommission test
2021-06-11T17:26:06.5992374Z require.go:349: id=4
2021-06-11T17:26:06.5993296Z
2021-06-11T17:26:06.5994427Z require.go:350: isLive=true
2021-06-11T17:26:06.5994965Z
2021-06-11T17:26:06.5995431Z require.go:351: replicas=35
2021-06-11T17:26:06.5996114Z require.go:352: isDecommissioning=false
2021-06-11T17:26:06.5997125Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:16.6083708Z require.go:348: draining node do to decommission test
2021-06-11T17:26:16.6084553Z require.go:349: id=4
2021-06-11T17:26:16.6084937Z
2021-06-11T17:26:16.6085341Z require.go:350: isLive=true
2021-06-11T17:26:16.6085754Z
2021-06-11T17:26:16.6086154Z require.go:351: replicas=35
2021-06-11T17:26:16.6086763Z require.go:352: isDecommissioning=false
2021-06-11T17:26:16.6087840Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:26.6201218Z require.go:348: draining node do to decommission test
2021-06-11T17:26:26.6201967Z require.go:349: id=4
2021-06-11T17:26:26.6202385Z
2021-06-11T17:26:26.6202820Z require.go:350: isLive=true
2021-06-11T17:26:26.6203263Z
2021-06-11T17:26:26.6203692Z require.go:351: replicas=35
2021-06-11T17:26:26.6204340Z require.go:352: isDecommissioning=false
2021-06-11T17:26:26.6205335Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:36.6315770Z require.go:348: draining node do to decommission test
2021-06-11T17:26:36.6316445Z require.go:349: id=4
2021-06-11T17:26:36.6317186Z
2021-06-11T17:26:36.6317721Z require.go:350: isLive=true
2021-06-11T17:26:36.6318261Z
2021-06-11T17:26:36.6318803Z require.go:351: replicas=35
2021-06-11T17:26:36.6319525Z require.go:352: isDecommissioning=false
2021-06-11T17:26:36.6320749Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:46.5424150Z require.go:348: draining node do to decommission test
2021-06-11T17:26:46.5424852Z require.go:349: id=4
2021-06-11T17:26:46.5425245Z
2021-06-11T17:26:46.5425660Z require.go:350: isLive=true
2021-06-11T17:26:46.5426057Z
2021-06-11T17:26:46.5426468Z require.go:351: replicas=35
2021-06-11T17:26:46.5427166Z require.go:352: isDecommissioning=false
2021-06-11T17:26:46.5428078Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:26:56.5538046Z require.go:348: draining node do to decommission test
2021-06-11T17:26:56.5539830Z require.go:349: id=4
2021-06-11T17:26:56.5540678Z
2021-06-11T17:26:56.5541484Z require.go:350: isLive=true
2021-06-11T17:26:56.5542259Z
2021-06-11T17:26:56.5543031Z require.go:351: replicas=35
2021-06-11T17:26:56.5544221Z require.go:352: isDecommissioning=false
2021-06-11T17:26:56.5545790Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:04.8959792Z [487 / 488] Testing //e2e/decomission:go_default_test; 276s linux-sandbox
2021-06-11T17:27:06.5632888Z require.go:348: draining node do to decommission test
2021-06-11T17:27:06.5633639Z require.go:349: id=4
2021-06-11T17:27:06.5634030Z
2021-06-11T17:27:06.5634463Z require.go:350: isLive=true
2021-06-11T17:27:06.5635062Z
2021-06-11T17:27:06.5635752Z require.go:351: replicas=35
2021-06-11T17:27:06.5636407Z require.go:352: isDecommissioning=false
2021-06-11T17:27:06.5637368Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:16.5745414Z require.go:348: draining node do to decommission test
2021-06-11T17:27:16.5746935Z require.go:349: id=4
2021-06-11T17:27:16.5748049Z
2021-06-11T17:27:16.5748678Z require.go:350: isLive=true
2021-06-11T17:27:16.5749215Z
2021-06-11T17:27:16.5749783Z require.go:351: replicas=35
2021-06-11T17:27:16.5750585Z require.go:352: isDecommissioning=false
2021-06-11T17:27:16.5751737Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:26.5867802Z require.go:348: draining node do to decommission test
2021-06-11T17:27:26.5868493Z require.go:349: id=4
2021-06-11T17:27:26.5868885Z
2021-06-11T17:27:26.5869410Z require.go:350: isLive=true
2021-06-11T17:27:26.5869843Z
2021-06-11T17:27:26.5870267Z require.go:351: replicas=35
2021-06-11T17:27:26.5871180Z require.go:352: isDecommissioning=false
2021-06-11T17:27:26.5872149Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:36.5995707Z require.go:348: draining node do to decommission test
2021-06-11T17:27:36.5996376Z require.go:349: id=4
2021-06-11T17:27:36.5996795Z
2021-06-11T17:27:36.5997224Z require.go:350: isLive=true
2021-06-11T17:27:36.5997775Z
2021-06-11T17:27:36.5998212Z require.go:351: replicas=35
2021-06-11T17:27:36.5998957Z require.go:352: isDecommissioning=false
2021-06-11T17:27:36.5999943Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:46.6100971Z require.go:348: draining node do to decommission test
2021-06-11T17:27:46.6102064Z require.go:349: id=4
2021-06-11T17:27:46.6103084Z
2021-06-11T17:27:46.6103690Z require.go:350: isLive=true
2021-06-11T17:27:46.6104132Z
2021-06-11T17:27:46.6104660Z require.go:351: replicas=35
2021-06-11T17:27:46.6105322Z require.go:352: isDecommissioning=false
2021-06-11T17:27:46.6106289Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:27:51.0122863Z [487 / 488] Testing //e2e/decomission:go_default_test; 322s linux-sandbox
2021-06-11T17:27:56.6220570Z require.go:348: draining node do to decommission test
2021-06-11T17:27:56.6221315Z require.go:349: id=4
2021-06-11T17:27:56.6221721Z
2021-06-11T17:27:56.6222459Z require.go:350: isLive=true
2021-06-11T17:27:56.6222899Z
2021-06-11T17:27:56.6223352Z require.go:351: replicas=35
2021-06-11T17:27:56.6224008Z require.go:352: isDecommissioning=false
2021-06-11T17:27:56.6224978Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:06.6335330Z require.go:348: draining node do to decommission test
2021-06-11T17:28:06.6336117Z require.go:349: id=4
2021-06-11T17:28:06.6336521Z
2021-06-11T17:28:06.6336977Z require.go:350: isLive=true
2021-06-11T17:28:06.6337425Z
2021-06-11T17:28:06.6337860Z require.go:351: replicas=35
2021-06-11T17:28:06.6338511Z require.go:352: isDecommissioning=false
2021-06-11T17:28:06.6339480Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:16.6455771Z require.go:348: draining node do to decommission test
2021-06-11T17:28:16.6456534Z require.go:349: id=4
2021-06-11T17:28:16.6456941Z
2021-06-11T17:28:16.6457412Z require.go:350: isLive=true
2021-06-11T17:28:16.6457839Z
2021-06-11T17:28:16.6458283Z require.go:351: replicas=35
2021-06-11T17:28:16.6458938Z require.go:352: isDecommissioning=false
2021-06-11T17:28:16.6459902Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:22.6523376Z W0611 17:28:22.645984 24 warnings.go:70] policy/v1beta1 PodDisruptionBudget is deprecated in v1.21+, unavailable in v1.25+; use policy/v1 PodDisruptionBudget
2021-06-11T17:28:26.5573133Z require.go:348: draining node do to decommission test
2021-06-11T17:28:26.5573770Z require.go:349: id=4
2021-06-11T17:28:26.5574139Z
2021-06-11T17:28:26.5574673Z require.go:350: isLive=true
2021-06-11T17:28:26.5575074Z
2021-06-11T17:28:26.5575489Z require.go:351: replicas=35
2021-06-11T17:28:26.5576075Z require.go:352: isDecommissioning=false
2021-06-11T17:28:26.5577109Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:36.5679049Z require.go:348: draining node do to decommission test
2021-06-11T17:28:36.5679645Z require.go:349: id=4
2021-06-11T17:28:36.5679982Z
2021-06-11T17:28:36.5680329Z require.go:350: isLive=true
2021-06-11T17:28:36.5680694Z
2021-06-11T17:28:36.5681067Z require.go:351: replicas=35
2021-06-11T17:28:36.5681592Z require.go:352: isDecommissioning=false
2021-06-11T17:28:36.5682370Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:46.5804511Z require.go:348: draining node do to decommission test
2021-06-11T17:28:46.5805520Z require.go:349: id=4
2021-06-11T17:28:46.5806230Z
2021-06-11T17:28:46.5806896Z require.go:350: isLive=true
2021-06-11T17:28:46.5807950Z
2021-06-11T17:28:46.5808615Z require.go:351: replicas=35
2021-06-11T17:28:46.5809608Z require.go:352: isDecommissioning=false
2021-06-11T17:28:46.5811159Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:28:56.5911294Z require.go:348: draining node do to decommission test
2021-06-11T17:28:56.5912075Z require.go:349: id=4
2021-06-11T17:28:56.5912531Z
2021-06-11T17:28:56.5913038Z require.go:350: isLive=true
2021-06-11T17:28:56.5913583Z
2021-06-11T17:28:56.5914095Z require.go:351: replicas=35
2021-06-11T17:28:56.5914821Z require.go:352: isDecommissioning=false
2021-06-11T17:28:56.5915934Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:06.6036372Z require.go:348: draining node do to decommission test
2021-06-11T17:29:06.6037089Z require.go:349: id=4
2021-06-11T17:29:06.6037466Z
2021-06-11T17:29:06.6037889Z require.go:350: isLive=true
2021-06-11T17:29:06.6038297Z
2021-06-11T17:29:06.6038717Z require.go:351: replicas=35
2021-06-11T17:29:06.6039309Z require.go:352: isDecommissioning=false
2021-06-11T17:29:06.6040493Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:16.6154343Z require.go:348: draining node do to decommission test
2021-06-11T17:29:16.6155534Z require.go:349: id=4
2021-06-11T17:29:16.6156248Z
2021-06-11T17:29:16.6157410Z require.go:350: isLive=true
2021-06-11T17:29:16.6158171Z
2021-06-11T17:29:16.6159084Z require.go:351: replicas=35
2021-06-11T17:29:16.6160222Z require.go:352: isDecommissioning=false
2021-06-11T17:29:16.6161955Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:26.6251764Z require.go:348: draining node do to decommission test
2021-06-11T17:29:26.6252433Z require.go:349: id=4
2021-06-11T17:29:26.6252884Z
2021-06-11T17:29:26.6253319Z require.go:350: isLive=true
2021-06-11T17:29:26.6253763Z
2021-06-11T17:29:26.6254193Z require.go:351: replicas=35
2021-06-11T17:29:26.6254868Z require.go:352: isDecommissioning=false
2021-06-11T17:29:26.6255837Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:36.6375717Z require.go:348: draining node do to decommission test
2021-06-11T17:29:36.6376332Z require.go:349: id=4
2021-06-11T17:29:36.6376720Z
2021-06-11T17:29:36.6377148Z require.go:350: isLive=true
2021-06-11T17:29:36.6377559Z
2021-06-11T17:29:36.6377957Z require.go:351: replicas=35
2021-06-11T17:29:36.6378560Z require.go:352: isDecommissioning=false
2021-06-11T17:29:36.6379470Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:37.0809956Z [487 / 488] Testing //e2e/decomission:go_default_test; 428s linux-sandbox
2021-06-11T17:29:46.5489930Z require.go:348: draining node do to decommission test
2021-06-11T17:29:46.5490564Z require.go:349: id=4
2021-06-11T17:29:46.5490932Z
2021-06-11T17:29:46.5491344Z require.go:350: isLive=true
2021-06-11T17:29:46.5491764Z
2021-06-11T17:29:46.5492176Z require.go:351: replicas=35
2021-06-11T17:29:46.5492763Z require.go:352: isDecommissioning=false
2021-06-11T17:29:46.5493671Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:29:56.5591544Z require.go:348: draining node do to decommission test
2021-06-11T17:29:56.5592260Z require.go:349: id=4
2021-06-11T17:29:56.5592658Z
2021-06-11T17:29:56.5593101Z require.go:350: isLive=true
2021-06-11T17:29:56.5593527Z
2021-06-11T17:29:56.5593969Z require.go:351: replicas=35
2021-06-11T17:29:56.5594601Z require.go:352: isDecommissioning=false
2021-06-11T17:29:56.5597066Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:06.5703886Z require.go:348: draining node do to decommission test
2021-06-11T17:30:06.5705354Z require.go:349: id=4
2021-06-11T17:30:06.5706102Z
2021-06-11T17:30:06.5706902Z require.go:350: isLive=true
2021-06-11T17:30:06.5707678Z
2021-06-11T17:30:06.5708453Z require.go:351: replicas=35
2021-06-11T17:30:06.5709575Z require.go:352: isDecommissioning=false
2021-06-11T17:30:06.5711314Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:16.5818163Z require.go:348: draining node do to decommission test
2021-06-11T17:30:16.5818903Z require.go:349: id=4
2021-06-11T17:30:16.5819322Z
2021-06-11T17:30:16.5819756Z require.go:350: isLive=true
2021-06-11T17:30:16.5820210Z
2021-06-11T17:30:16.5820642Z require.go:351: replicas=35
2021-06-11T17:30:16.5821402Z require.go:352: isDecommissioning=false
2021-06-11T17:30:16.5822384Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:26.5939206Z require.go:348: draining node do to decommission test
2021-06-11T17:30:26.5939880Z require.go:349: id=4
2021-06-11T17:30:26.5940296Z
2021-06-11T17:30:26.5940989Z require.go:350: isLive=true
2021-06-11T17:30:26.5941446Z
2021-06-11T17:30:26.5941886Z require.go:351: replicas=35
2021-06-11T17:30:26.5942546Z require.go:352: isDecommissioning=false
2021-06-11T17:30:26.5943511Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:36.6053683Z require.go:348: draining node do to decommission test
2021-06-11T17:30:36.6054439Z require.go:349: id=4
2021-06-11T17:30:36.6054837Z
2021-06-11T17:30:36.6055278Z require.go:350: isLive=true
2021-06-11T17:30:36.6055704Z
2021-06-11T17:30:36.6056145Z require.go:351: replicas=35
2021-06-11T17:30:36.6056778Z require.go:352: isDecommissioning=false
2021-06-11T17:30:36.6057871Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:46.0254162Z [487 / 488] Testing //e2e/decomission:go_default_test; 497s linux-sandbox
2021-06-11T17:30:46.6166179Z require.go:348: draining node do to decommission test
2021-06-11T17:30:46.6166887Z require.go:349: id=4
2021-06-11T17:30:46.6167257Z
2021-06-11T17:30:46.6167964Z require.go:350: isLive=true
2021-06-11T17:30:46.6168367Z
2021-06-11T17:30:46.6168783Z require.go:351: replicas=35
2021-06-11T17:30:46.6169390Z require.go:352: isDecommissioning=false
2021-06-11T17:30:46.6170303Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:30:56.6302303Z require.go:348: draining node do to decommission test
2021-06-11T17:30:56.6303414Z require.go:349: id=4
2021-06-11T17:30:56.6304202Z
2021-06-11T17:30:56.6304710Z require.go:350: isLive=true
2021-06-11T17:30:56.6305126Z
2021-06-11T17:30:56.6305583Z require.go:351: replicas=35
2021-06-11T17:30:56.6306176Z require.go:352: isDecommissioning=false
2021-06-11T17:30:56.6307090Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:06.6440285Z require.go:348: draining node do to decommission test
2021-06-11T17:31:06.6441178Z require.go:349: id=4
2021-06-11T17:31:06.6441648Z
2021-06-11T17:31:06.6442185Z require.go:350: isLive=true
2021-06-11T17:31:06.6442700Z
2021-06-11T17:31:06.6443233Z require.go:351: replicas=35
2021-06-11T17:31:06.6444017Z require.go:352: isDecommissioning=false
2021-06-11T17:31:06.6445220Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:16.5542884Z require.go:348: draining node do to decommission test
2021-06-11T17:31:16.5544160Z require.go:349: id=4
2021-06-11T17:31:16.5544916Z
2021-06-11T17:31:16.5545497Z require.go:350: isLive=true
2021-06-11T17:31:16.5545917Z
2021-06-11T17:31:16.5546333Z require.go:351: replicas=35
2021-06-11T17:31:16.5546919Z require.go:352: isDecommissioning=false
2021-06-11T17:31:16.5547977Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:26.5644347Z require.go:348: draining node do to decommission test
2021-06-11T17:31:26.5645027Z require.go:349: id=4
2021-06-11T17:31:26.5645422Z
2021-06-11T17:31:26.5645861Z require.go:350: isLive=true
2021-06-11T17:31:26.5646289Z
2021-06-11T17:31:26.5646757Z require.go:351: replicas=35
2021-06-11T17:31:26.5647648Z require.go:352: isDecommissioning=false
2021-06-11T17:31:26.5649709Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:36.5789792Z require.go:348: draining node do to decommission test
2021-06-11T17:31:36.5790431Z require.go:349: id=4
2021-06-11T17:31:36.5790822Z
2021-06-11T17:31:36.5791224Z require.go:350: isLive=true
2021-06-11T17:31:36.5791638Z
2021-06-11T17:31:36.5792046Z require.go:351: replicas=35
2021-06-11T17:31:36.5792655Z require.go:352: isDecommissioning=false
2021-06-11T17:31:36.5793784Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:46.5905093Z require.go:348: draining node do to decommission test
2021-06-11T17:31:46.5905730Z require.go:349: id=4
2021-06-11T17:31:46.5906106Z
2021-06-11T17:31:46.5906530Z require.go:350: isLive=true
2021-06-11T17:31:46.5907244Z
2021-06-11T17:31:46.5907665Z require.go:351: replicas=35
2021-06-11T17:31:46.5908263Z require.go:352: isDecommissioning=false
2021-06-11T17:31:46.5909175Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:31:56.6015161Z require.go:348: draining node do to decommission test
2021-06-11T17:31:56.6016793Z require.go:349: id=4
2021-06-11T17:31:56.6017167Z
2021-06-11T17:31:56.6017585Z require.go:350: isLive=true
2021-06-11T17:31:56.6018004Z
2021-06-11T17:31:56.6018401Z require.go:351: replicas=35
2021-06-11T17:31:56.6018999Z require.go:352: isDecommissioning=false
2021-06-11T17:31:56.6019918Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:06.6122884Z require.go:348: draining node do to decommission test
2021-06-11T17:32:06.6123565Z require.go:349: id=4
2021-06-11T17:32:06.6123959Z
2021-06-11T17:32:06.6124395Z require.go:350: isLive=true
2021-06-11T17:32:06.6124845Z
2021-06-11T17:32:06.6125278Z require.go:351: replicas=35
2021-06-11T17:32:06.6126007Z require.go:352: isDecommissioning=false
2021-06-11T17:32:06.6126935Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:16.5245405Z require.go:348: draining node do to decommission test
2021-06-11T17:32:16.5246079Z require.go:349: id=4
2021-06-11T17:32:16.5246505Z
2021-06-11T17:32:16.5246944Z require.go:350: isLive=true
2021-06-11T17:32:16.5247602Z
2021-06-11T17:32:16.5248043Z require.go:351: replicas=35
2021-06-11T17:32:16.5248706Z require.go:352: isDecommissioning=false
2021-06-11T17:32:16.5249717Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:26.6364163Z require.go:348: draining node do to decommission test
2021-06-11T17:32:26.6365416Z require.go:349: id=4
2021-06-11T17:32:26.6366144Z
2021-06-11T17:32:26.6366940Z require.go:350: isLive=true
2021-06-11T17:32:26.6368064Z
2021-06-11T17:32:26.6368822Z require.go:351: replicas=35
2021-06-11T17:32:26.6369958Z require.go:352: isDecommissioning=false
2021-06-11T17:32:26.6371664Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:36.5486585Z require.go:348: draining node do to decommission test
2021-06-11T17:32:36.5487247Z require.go:349: id=4
2021-06-11T17:32:36.5487843Z
2021-06-11T17:32:36.5488290Z require.go:350: isLive=true
2021-06-11T17:32:36.5488715Z
2021-06-11T17:32:36.5489266Z require.go:351: replicas=35
2021-06-11T17:32:36.5489920Z require.go:352: isDecommissioning=false
2021-06-11T17:32:36.5490894Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:46.5591310Z require.go:348: draining node do to decommission test
2021-06-11T17:32:46.5591968Z require.go:349: id=4
2021-06-11T17:32:46.5592411Z
2021-06-11T17:32:46.5592839Z require.go:350: isLive=true
2021-06-11T17:32:46.5593279Z
2021-06-11T17:32:46.5593704Z require.go:351: replicas=35
2021-06-11T17:32:46.5594346Z require.go:352: isDecommissioning=false
2021-06-11T17:32:46.5595429Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:32:56.5731537Z require.go:348: draining node do to decommission test
2021-06-11T17:32:56.5733588Z require.go:349: id=4
2021-06-11T17:32:56.5734083Z
2021-06-11T17:32:56.5734655Z require.go:350: isLive=true
2021-06-11T17:32:56.5735169Z
2021-06-11T17:32:56.5735893Z require.go:351: replicas=35
2021-06-11T17:32:56.5736936Z require.go:352: isDecommissioning=false
2021-06-11T17:32:56.5738110Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:06.5837315Z require.go:348: draining node do to decommission test
2021-06-11T17:33:06.5838022Z require.go:349: id=4
2021-06-11T17:33:06.5838651Z
2021-06-11T17:33:06.5839243Z require.go:350: isLive=true
2021-06-11T17:33:06.5839686Z
2021-06-11T17:33:06.5842554Z require.go:351: replicas=35
2021-06-11T17:33:06.5843210Z require.go:352: isDecommissioning=false
2021-06-11T17:33:06.5844175Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:16.5969274Z require.go:348: draining node do to decommission test
2021-06-11T17:33:16.5970019Z require.go:349: id=4
2021-06-11T17:33:16.5970414Z
2021-06-11T17:33:16.5970851Z require.go:350: isLive=true
2021-06-11T17:33:16.5971279Z
2021-06-11T17:33:16.5971757Z require.go:351: replicas=35
2021-06-11T17:33:16.5972389Z require.go:352: isDecommissioning=false
2021-06-11T17:33:16.5973439Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:24.5979861Z [487 / 488] Testing //e2e/decomission:go_default_test; 656s linux-sandbox
2021-06-11T17:33:26.6079815Z require.go:348: draining node do to decommission test
2021-06-11T17:33:26.6081160Z require.go:349: id=4
2021-06-11T17:33:26.6081883Z
2021-06-11T17:33:26.6082746Z require.go:350: isLive=true
2021-06-11T17:33:26.6084317Z
2021-06-11T17:33:26.6084923Z require.go:351: replicas=35
2021-06-11T17:33:26.6085816Z require.go:352: isDecommissioning=false
2021-06-11T17:33:26.6087163Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:36.6193203Z require.go:348: draining node do to decommission test
2021-06-11T17:33:36.6194407Z require.go:349: id=4
2021-06-11T17:33:36.6195506Z
2021-06-11T17:33:36.6196045Z require.go:350: isLive=true
2021-06-11T17:33:36.6196539Z
2021-06-11T17:33:36.6197025Z require.go:351: replicas=35
2021-06-11T17:33:36.6197735Z require.go:352: isDecommissioning=false
2021-06-11T17:33:36.6198667Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:46.6306875Z require.go:348: draining node do to decommission test
2021-06-11T17:33:46.6307659Z require.go:349: id=4
2021-06-11T17:33:46.6308059Z
2021-06-11T17:33:46.6308508Z require.go:350: isLive=true
2021-06-11T17:33:46.6308936Z
2021-06-11T17:33:46.6309385Z require.go:351: replicas=35
2021-06-11T17:33:46.6310036Z require.go:352: isDecommissioning=false
2021-06-11T17:33:46.6311142Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:33:56.5488381Z require.go:348: draining node do to decommission test
2021-06-11T17:33:56.5489066Z require.go:349: id=4
2021-06-11T17:33:56.5489508Z
2021-06-11T17:33:56.5489941Z require.go:350: isLive=true
2021-06-11T17:33:56.5490389Z
2021-06-11T17:33:56.5490819Z require.go:351: replicas=35
2021-06-11T17:33:56.5491466Z require.go:352: isDecommissioning=false
2021-06-11T17:33:56.5492426Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:06.5538105Z require.go:348: draining node do to decommission test
2021-06-11T17:34:06.5538817Z require.go:349: id=4
2021-06-11T17:34:06.5539239Z
2021-06-11T17:34:06.5539740Z require.go:350: isLive=true
2021-06-11T17:34:06.5540188Z
2021-06-11T17:34:06.5540621Z require.go:351: replicas=35
2021-06-11T17:34:06.5541277Z require.go:352: isDecommissioning=false
2021-06-11T17:34:06.5542260Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:16.5650167Z require.go:348: draining node do to decommission test
2021-06-11T17:34:16.5651353Z require.go:349: id=4
2021-06-11T17:34:16.5651885Z
2021-06-11T17:34:16.5652461Z require.go:350: isLive=true
2021-06-11T17:34:16.5653020Z
2021-06-11T17:34:16.5653589Z require.go:351: replicas=35
2021-06-11T17:34:16.5654413Z require.go:352: isDecommissioning=false
2021-06-11T17:34:16.5655818Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:26.5770406Z require.go:348: draining node do to decommission test
2021-06-11T17:34:26.5771091Z require.go:349: id=4
2021-06-11T17:34:26.5771550Z
2021-06-11T17:34:26.5771996Z require.go:350: isLive=true
2021-06-11T17:34:26.5772419Z
2021-06-11T17:34:26.5772861Z require.go:351: replicas=35
2021-06-11T17:34:26.5773492Z require.go:352: isDecommissioning=false
2021-06-11T17:34:26.5774468Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:36.5889664Z require.go:348: draining node do to decommission test
2021-06-11T17:34:36.5890350Z require.go:349: id=4
2021-06-11T17:34:36.5890746Z
2021-06-11T17:34:36.5891238Z require.go:350: isLive=true
2021-06-11T17:34:36.5891791Z
2021-06-11T17:34:36.5892236Z require.go:351: replicas=35
2021-06-11T17:34:36.5892948Z require.go:352: isDecommissioning=false
2021-06-11T17:34:36.5893953Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:46.6008184Z require.go:348: draining node do to decommission test
2021-06-11T17:34:46.6008852Z require.go:349: id=4
2021-06-11T17:34:46.6009263Z
2021-06-11T17:34:46.6009691Z require.go:350: isLive=true
2021-06-11T17:34:46.6010130Z
2021-06-11T17:34:46.6010556Z require.go:351: replicas=35
2021-06-11T17:34:46.6011204Z require.go:352: isDecommissioning=false
2021-06-11T17:34:46.6012166Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:34:56.6123106Z require.go:348: draining node do to decommission test
2021-06-11T17:34:56.6123961Z require.go:349: id=4
2021-06-11T17:34:56.6124508Z
2021-06-11T17:34:56.6124953Z require.go:350: isLive=true
2021-06-11T17:34:56.6125379Z
2021-06-11T17:34:56.6125822Z require.go:351: replicas=35
2021-06-11T17:34:56.6126472Z require.go:352: isDecommissioning=false
2021-06-11T17:34:56.6128028Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:06.6226852Z require.go:348: draining node do to decommission test
2021-06-11T17:35:06.6227662Z require.go:349: id=4
2021-06-11T17:35:06.6228168Z
2021-06-11T17:35:06.6228696Z require.go:350: isLive=true
2021-06-11T17:35:06.6229236Z
2021-06-11T17:35:06.6229762Z require.go:351: replicas=35
2021-06-11T17:35:06.6230559Z require.go:352: isDecommissioning=false
2021-06-11T17:35:06.6231759Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:07.6697832Z [487 / 488] Testing //e2e/decomission:go_default_test; 759s linux-sandbox
2021-06-11T17:35:16.5349764Z require.go:348: draining node do to decommission test
2021-06-11T17:35:16.5350383Z require.go:349: id=4
2021-06-11T17:35:16.5350863Z
2021-06-11T17:35:16.5351283Z require.go:350: isLive=true
2021-06-11T17:35:16.5351689Z
2021-06-11T17:35:16.5352086Z require.go:351: replicas=35
2021-06-11T17:35:16.5352686Z require.go:352: isDecommissioning=false
2021-06-11T17:35:16.5353575Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:26.5464340Z require.go:348: draining node do to decommission test
2021-06-11T17:35:26.5465015Z require.go:349: id=4
2021-06-11T17:35:26.5465409Z
2021-06-11T17:35:26.5465852Z require.go:350: isLive=true
2021-06-11T17:35:26.5466280Z
2021-06-11T17:35:26.5466715Z require.go:351: replicas=35
2021-06-11T17:35:26.5467736Z require.go:352: isDecommissioning=false
2021-06-11T17:35:26.5468660Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:36.5607507Z require.go:348: draining node do to decommission test
2021-06-11T17:35:36.5608751Z require.go:349: id=4
2021-06-11T17:35:36.5609352Z
2021-06-11T17:35:36.5610300Z require.go:350: isLive=true
2021-06-11T17:35:36.5610926Z
2021-06-11T17:35:36.5611569Z require.go:351: replicas=35
2021-06-11T17:35:36.5612407Z require.go:352: isDecommissioning=false
2021-06-11T17:35:36.5613558Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:36.7611310Z require.go:348: draining node do to decommission test
2021-06-11T17:35:36.7612512Z require.go:349: id=4
2021-06-11T17:35:36.7613154Z
2021-06-11T17:35:36.7613776Z require.go:350: isLive=true
2021-06-11T17:35:36.7614406Z
2021-06-11T17:35:36.7615026Z require.go:351: replicas=35
2021-06-11T17:35:36.7615997Z require.go:352: isDecommissioning=false
2021-06-11T17:35:36.7617078Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:35:36.7618002Z require.go:312:
2021-06-11T17:35:36.7618650Z Error Trace: require.go:312
2021-06-11T17:35:36.7619340Z decomission_test.go:93
2021-06-11T17:35:36.7620091Z Error: Received unexpected error:
2021-06-11T17:35:36.7620866Z timed out waiting for the condition
2021-06-11T17:35:36.7622491Z Test: TestDecommissionFunctionality/decommission_a_node
2021-06-11T17:35:36.8616406Z --- FAIL: TestDecommissionFunctionality (781.15s)
2021-06-11T17:35:36.8617878Z --- PASS: TestDecommissionFunctionality/creates_a_4-node_secure_cluster_and_tests_db (70.01s)
2021-06-11T17:35:36.8619363Z --- FAIL: TestDecommissionFunctionality/decommission_a_node (710.37s)
2021-06-11T17:35:36.8620187Z FAIL
2021-06-11T17:35:38.1805825Z FAIL: //e2e/decomission:go_default_test (see /home/runner/.cache/bazel/_bazel_runner/f7e8029c3d6a40b2a20f2d3d4affc796/execroot/com_github_coachroachdb_cockroach_operator/bazel-out/k8-fastbuild/testlogs/e2e/decomission/go_default_test/test.log)
2021-06-11T17:35:38.2817349Z INFO: Elapsed time: 820.768s, Critical Path: 796.73s
2021-06-11T17:35:38.2819302Z INFO: 144 processes: 3 internal, 141 linux-sandbox.
2021-06-11T17:35:38.2820320Z INFO: Build completed, 1 test FAILED, 144 total actions
2021-06-11T17:35:38.2888489Z //e2e/decomission:go_default_test FAILED in 789.4s
2021-06-11T17:35:38.2908828Z /home/runner/.cache/bazel/_bazel_runner/f7e8029c3d6a40b2a20f2d3d4affc796/execroot/com_github_coachroachdb_cockroach_operator/bazel-out/k8-fastbuild/testlogs/e2e/decomission/go_default_test/test.log
2021-06-11T17:35:38.2911181Z
2021-06-11T17:35:38.2911791Z Executed 1 out of 1 test: 1 fails locally.
2021-06-11T17:35:38.2970005Z INFO: Build completed, 1 test FAILED, 144 total actions
2021-06-11T17:35:38.3163767Z make[1]: *** [Makefile:84: test/e2e/testrunner-kind-decomission] Error 3
2021-06-11T17:35:38.3165199Z make[1]: Leaving directory '/home/runner/work/cockroach-operator/cockroach-operator'
2021-06-11T17:35:38.3213308Z F0611 17:35:38.321125 7388 exec.go:78] failed to run exec tester: exit status 2
2021-06-11T17:35:38.3218616Z I0611 17:35:38.321668 5748 down.go:32] Down(): deleting kind cluster...
2021-06-11T17:35:38.5014330Z Deleting cluster "bazel-test" ...
2021-06-11T17:35:39.7269690Z Error: exit status 255
2021-06-11T17:35:39.7312748Z make: *** [Makefile:98: test/e2e/kind-decomission] Error 1
2021-06-11T17:35:39.7325983Z ##[error]Process completed with exit code 2.
2021-06-11T17:35:39.7497786Z Post job cleanup.
2021-06-11T17:35:39.9705588Z [command]/usr/bin/git version
2021-06-11T17:35:39.9754298Z git version 2.31.1
2021-06-11T17:35:39.9803245Z [command]/usr/bin/git config --local --name-only --get-regexp core\.sshCommand
2021-06-11T17:35:39.9845120Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :
2021-06-11T17:35:40.0172704Z [command]/usr/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
2021-06-11T17:35:40.0192541Z http.https://github.com/.extraheader
2021-06-11T17:35:40.0209405Z [command]/usr/bin/git config --local --unset-all http.https://github.com/.extraheader
2021-06-11T17:35:40.0247027Z [command]/usr/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :
2021-06-11T17:35:40.0552228Z Cleaning up orphan processes
2021-06-11T17:35:40.1010389Z Terminate orphan process: pid (1540) (java)
Getting some weird logging that a pvc does not exist
@alinadonisa
2021-06-11T17:28:36.5682370Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
Why are we stuck on this?
Actually, we may have deco'ed the wrong node I think ... uncertain
logger.go:130: 2021-06-11T17:24:49.572Z INFO draining node do to decommission {"action": "decommission", "id": 3, "isLive": "true", "replicas": "0", "isDecommissioning": "true"}
@chrislovecnm decommission timeouts waiting for the replicas to be 0. The value is 35... but watching the code seems we are not decommissioning the last node.
@chrislovecnm we added a bug when using a parallel pod management strategy
// Scale up one node at a time to:
// 1. Mitigate race conditions.
// Some legacy clusters have a parallel pod management strategy.
// (Pod management strategy is immutable)
// This can lead to "unscalable" k8s topologies if many pods are created at once.
// | A | B | C |
// | 0 | | |
// Could result in the following if 4 nodes are added at the same time
// | A | B | C |
// | 0 | 1 | 3 |
// | 4 | 2 | |
// Scaling back to 3 nodes would then result in zone C being removed
// The K8s scheduler, when scaling one at a time, will ensure "correct" distributions
// | A | B | C |
// | 0 | 1 | 2 |
// | 3 | 2 | |
// 2. Minimize the impact on the cluster's performance.
// When adding many nodes to a cluster that is under load, it is possible to max out the available IOPS.
// This results is slower overall performance and slower integration of the new nodes in the cluster
// and may even look like adding new nodes has resulted in worse performance for a few hours.
// 3. Keep us a bit sane.
// When nodes are added in order they'll gain node ids equal to their pod index + 1.
// If all pods are created in parallel cockroachdb-3 may end up being node n1.
//
@chrisseto can verify this, but I am fairly certain that this is an issue with schedule and zones and not an issue with the decommission code. Sorta. There is a second problem with zone outage, you can lose quorum because your zones become unbalanced, if you have a zone outage.
@alinadonisa and I talked and we think we have an issue with the test, where we are testing the incorrect crdb instance id, but decommissioned the correct pod.
It seems like the wrong pod is being decommissioned?
2021-06-11T17:25:06.6272047Z require.go:351: replicas=35
2021-06-11T17:25:06.6272688Z require.go:352: isDecommissioning=false
2021-06-11T17:25:06.6273707Z require.go:307: makeDrainStatusChecker failed due to error unexpected node status
2021-06-11T17:25:16.5379795Z require.go:348: draining node do to decommission test
2021-06-11T17:25:16.5380776Z require.go:349: id=4
This doesn't seem related to the zone scheduling issue (which might not be an issue any more thanks to the PVC pruning). I think what's happened is that the change from ordered to parallel pod management has broken an unsafe assumption that a pod with ordinal X (ie cockroachdb-X) has the id X. When pod management is set to ordered, this is true until a node is decommissioned. When pod management is set to parallel there is no correlation between ordinal and node ID.
Specifically, this line here seems to be the issue. I'd recommend reusing the existing decommission functionality, I'm not sure why it was reimplemented just for a test?
@chrisseto I already fixed the test... We figured out that the correlation between id was lost when using the Pod Parallel Management Strategy. I've seen your comments on decommission code and I wanted to make sure that by changing the id order of the pods we are not affecting anything else.