Bug 1809001

Summary: [Azure] Creating machineset with "publicIP: true" results in panic
Product: OpenShift Container Platform Reporter: sunzhaohua <zhsun>
Component: Cloud ComputeAssignee: Alexander Demicev <ademicev>
Cloud Compute sub component: BareMetal Provider QA Contact: sunzhaohua <zhsun>
Status: CLOSED ERRATA Docs Contact:
Severity: medium    
Priority: medium CC: agarcial, stbenjam
Version: 4.4   
Target Milestone: ---   
Target Release: 4.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1809521 (view as bug list) Environment:
Last Closed: 2020-08-27 22:35:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1809521    

Description sunzhaohua 2020-03-02 08:52:25 UTC 
Description of problem:
IPI in Azure, create a machineset and set "publicIP: true", machine couldn't be created successful, logs output " Observed a panic".

Version-Release number of selected component (if applicable):
4.4.0-0.nightly-2020-03-01-215047

How reproducible:
Always

Steps to Reproduce:
1. Copy a valid machineset, set "publicIP: true"
2. Check machine status and logs


Actual results:
$ oc get machine
NAME                                   PHASE          TYPE              REGION      ZONE   AGE
zhsun2-mmqfd-master-0                  Running        Standard_D8s_v3   centralus   3      6h59m
zhsun2-mmqfd-master-1                  Running        Standard_D8s_v3   centralus   2      6h59m
zhsun2-mmqfd-master-2                  Running        Standard_D8s_v3   centralus   1      6h59m
zhsun2-mmqfd-worker-centralus1-6nwkv   Running        Standard_D2s_v3   centralus   1      6h54m
zhsun2-mmqfd-worker-centralus2-sgxsc   Running        Standard_D2s_v3   centralus   2      23m
zhsun2-mmqfd-worker-centralus4-qwxvs   Provisioning                                        6m35s


I0302 08:23:50.600987       1 controller.go:163] zhsun2-mmqfd-worker-centralus4-qwxvs: reconciling Machine
I0302 08:23:50.621510       1 controller.go:163] zhsun2-mmqfd-worker-centralus4-qwxvs: reconciling Machine
I0302 08:23:50.621536       1 actuator.go:196] Checking if machine zhsun2-mmqfd-worker-centralus4-qwxvs exists
I0302 08:23:50.875346       1 controller.go:419] zhsun2-mmqfd-worker-centralus4-qwxvs: going into phase "Provisioning"
I0302 08:23:50.890211       1 controller.go:307] zhsun2-mmqfd-worker-centralus4-qwxvs: reconciling machine triggers idempotent create
I0302 08:23:50.890228       1 actuator.go:85] Creating machine zhsun2-mmqfd-worker-centralus4-qwxvs
I0302 08:23:50.890777       1 publicips.go:57] creating public ip zhsun2-mmqfd-zhsun2-mmqfd-worker-centralus4-qwxvs
E0302 08:23:50.890859       1 runtime.go:78] Observed a panic: "invalid memory address or nil pointer dereference" (runtime error: invalid memory address or nil pointer dereference)
goroutine 371 [running]:
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime.logPanic(0x14a4ba0, 0x24ae0d0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime/runtime.go:74 +0xa3
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime.HandleCrash(0x0, 0x0, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime/runtime.go:48 +0x82
panic(0x14a4ba0, 0x24ae0d0)
	/opt/rh/go-toolset-1.13/root/usr/lib/go-toolset-1.13-golang/src/runtime/panic.go:679 +0x1b2
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/services/publicips.(*Service).CreateOrUpdate(0xc000873040, 0x1875860, 0xc0000d2068, 0x13e6ee0, 0xc0009f7590, 0x31, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/services/publicips/publicips.go:73 +0x1dd
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).createNetworkInterface(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0xc000be2ea0, 0x28, 0xc000be2ea0, 0x28)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:489 +0x362
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).CreateMachine(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0x0, 0xdf8475800)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:112 +0x111
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).Create(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0x0, 0xc000c9a840)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:90 +0x5d
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Actuator).Create(0xc00051dcb0, 0x1875860, 0xc0000d2070, 0xc000c9a840, 0xc000701a40, 0x1)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/actuator.go:96 +0x313
sigs.k8s.io/cluster-api-provider-azure/vendor/github.com/openshift/machine-api-operator/pkg/controller/machine.(*ReconcileMachine).Reconcile(0xc00024a440, 0xc000600160, 0x15, 0xc0005139e0, 0x24, 0xc000701cd8, 0xc000028090, 0xc00002a128, 0x184a680)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/github.com/openshift/machine-api-operator/pkg/controller/machine/controller.go:308 +0x58b
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc00040ccc0, 0x14f8020, 0xc0005375c0, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:256 +0x162
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc00040ccc0, 0xc00037d700)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:232 +0xcb
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker(0xc00040ccc0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:211 +0x2b
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1(0xc00036a0c0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152 +0x5e
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil(0xc00036a0c0, 0x3b9aca00, 0x0, 0xc00036af01, 0xc0000a8300)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:153 +0xf8
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.Until(0xc00036a0c0, 0x3b9aca00, 0xc0000a8300)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88 +0x4d
created by sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func1
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:193 +0x328
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x12f768d]
goroutine 371 [running]:
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime.HandleCrash(0x0, 0x0, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/runtime/runtime.go:55 +0x105
panic(0x14a4ba0, 0x24ae0d0)
	/opt/rh/go-toolset-1.13/root/usr/lib/go-toolset-1.13-golang/src/runtime/panic.go:679 +0x1b2
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/services/publicips.(*Service).CreateOrUpdate(0xc000873040, 0x1875860, 0xc0000d2068, 0x13e6ee0, 0xc0009f7590, 0x31, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/services/publicips/publicips.go:73 +0x1dd
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).createNetworkInterface(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0xc000be2ea0, 0x28, 0xc000be2ea0, 0x28)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:489 +0x362
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).CreateMachine(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0x0, 0xdf8475800)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:112 +0x111
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Reconciler).Create(0xc000bf0e70, 0x1875860, 0xc0000d2068, 0x0, 0xc000c9a840)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/reconciler.go:90 +0x5d
sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine.(*Actuator).Create(0xc00051dcb0, 0x1875860, 0xc0000d2070, 0xc000c9a840, 0xc000701a40, 0x1)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/pkg/cloud/azure/actuators/machine/actuator.go:96 +0x313
sigs.k8s.io/cluster-api-provider-azure/vendor/github.com/openshift/machine-api-operator/pkg/controller/machine.(*ReconcileMachine).Reconcile(0xc00024a440, 0xc000600160, 0x15, 0xc0005139e0, 0x24, 0xc000701cd8, 0xc000028090, 0xc00002a128, 0x184a680)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/github.com/openshift/machine-api-operator/pkg/controller/machine/controller.go:308 +0x58b
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc00040ccc0, 0x14f8020, 0xc0005375c0, 0x0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:256 +0x162
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc00040ccc0, 0xc00037d700)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:232 +0xcb
sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker(0xc00040ccc0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:211 +0x2b
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1(0xc00036a0c0)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152 +0x5e
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil(0xc00036a0c0, 0x3b9aca00, 0x0, 0xc00036af01, 0xc0000a8300)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:153 +0xf8
sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait.Until(0xc00036a0c0, 0x3b9aca00, 0xc0000a8300)
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88 +0x4d
created by sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func1
	/go/src/sigs.k8s.io/cluster-api-provider-azure/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:193 +0x328


Expected results:
Machine could be created successful and join the cluster.

Additional info:
Comment 4 sunzhaohua 2020-03-12 07:45:48 UTC 
Verified

clusterversion: 4.5.0-0.nightly-2020-03-12-041748

I0312 07:44:31.097849       1 actuator.go:85] Creating machine zhsun9-l4nxj-worker-westus-2-2drk7
I0312 07:44:31.098220       1 publicips.go:57] creating public ip zhsun9-l4nxj-zhsun9-l4nxj-worker-westus-2-2drk7
I0312 07:44:34.924224       1 publicips.go:91] successfully created public ip zhsun9-l4nxj-zhsun9-l4nxj-worker-westus-2-2drk7
I0312 07:44:35.646118       1 networkinterfaces.go:205] successfully created network interface zhsun9-l4nxj-worker-westus-2-2drk7-nic
I0312 07:44:35.691426       1 virtualmachines.go:73] getting nic zhsun9-l4nxj-worker-westus-2-2drk7-nic
I0312 07:44:35.744309       1 virtualmachines.go:82] got nic zhsun9-l4nxj-worker-westus-2-2drk7-nic
I0312 07:44:35.744332       1 virtualmachines.go:84] creating vm zhsun9-l4nxj-worker-westus-2-2drk7 
I0312 07:44:36.889226       1 machine_scope.go:185] zhsun9-l4nxj-worker-westus-2-2drk7: patching machine
E0312 07:44:36.909114       1 actuator.go:79] Machine error: failed to reconcile machine "zhsun9-l4nxj-worker-westus-2-2drk7"s: failed to create vm zhsun9-l4nxj-worker-westus-2-2drk7 : failed to create or get machine: compute.VirtualMachinesCreateOrUpdateFuture: asynchronous operation has not completed
W0312 07:44:36.909230       1 controller.go:309] zhsun9-l4nxj-worker-westus-2-2drk7: failed to create machine: requeue in: 20s
I0312 07:44:36.909244       1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s
I0312 07:44:36.909299       1 controller.go:163] zhsun9-l4nxj-worker-westus-1-wrmvc: reconciling Machine
Comment 7 Luke Meyer 2020-08-27 22:35:19 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:2409'