search

futurewei-cloud / alcor

Alcor: Cloud native SDN platform powered by Kubernetes and Istio
MIT License
32 stars 33 forks source link

[PM] The user created port for a VM cannot be reused after the created VM is deleted. #513

Closed cj-chung closed 3 years ago

cj-chung commented 3 years ago

Repro Steps

  1. Create a normal port under a subnet
  2. Create a VM via Horizon and select the created port
  3. Delete the VM (the attached port should be released)
  4. Create a new VM via Horizon and search the previous released port.

Issue: The released port in step 3 can be viewed in the port list under the network in Horizon, and it's labelled as "Detached", but the port cannot be found in step 4.

Possible Reason: The "binding:host_id":"fw0009084" is not clean up.

The Port Entity of the released port shows:

{
   "port":{
      "id":"1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b",
      "project_id":"bba04015f47b4719a8edc8006e0abb27",
      "tenant_id":"bba04015f47b4719a8edc8006e0abb27",
      "name":"subnet2-port2",
      "description":"",
      "network_id":"8934df6a-ef1e-4310-8612-2a923e8be6fa",
      "admin_state_up":false,
      "mac_address":"aa:bb:cc:c3:4e:22",
      "veth_name":"",
      "fast_path":false,
      "device_id":"",
      "device_owner":"",
      "status":"",
      "fixed_ips":[
         {
            "subnet_id":"31665ab5-6f44-4074-88fb-8c80ec6a9f78",
            "ip_address":"192.168.2.3"
         }
      ],
      "allowed_address_pairs":[

      ],
      "extra_dhcp_opts":[

      ],
      "security_groups":[
         "57315298-5cec-4b3d-aeed-9e100af1a7cd",
         "833acb7f-2a9e-4d83-8d76-c05fa1381909"
      ],
      "binding:host_id":"fw0009084",
      "binding:profile":{
         "local_link_information":null
      },
      "binding:vif_details":{

      },
      "binding:vif_type":"ovs",
      "binding:vnic_type":"",
      "network_ns":"",
      "dns_name":"",
      "dns_domain":"",
      "dns_assignment":{

      },
      "create_at":"",
      "update_at":"",
      "ip_allocation":"",
      "port_security_enabled":true,
      "qos_network_policy_id":"",
      "qos_policy_id":"",
      "revision_number":0,
      "resource_request":{

      },
      "tags":[

      ],
      "uplink_status_propagation":false,
      "mac_learning_enabled":false
   }
}
cj-chung commented 3 years ago 
root@fw0015526:~# kubectl -n default logs deployment/portmanager --all-containers=true | grep 1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b
Found 5 pods, using pod/portmanager-6f4fc7b874-27xt5
2020-12-09 20:43:04.739 DEBUG [port-manager,,,] 1 --- [io-8080-exec-10] o.a.coyote.http11.Http11InputBuffer      : Received [GET /project/bba04015f47b4719a8edc8006e0abb27/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b?fields=binding%3Aprofile&fields=network_id HTTP/1.1
2020-12-09 20:43:04.739 DEBUG [port-manager,,,] 1 --- [io-8080-exec-10] o.apache.catalina.valves.RemoteIpValve   : Incoming request /project/bba04015f47b4719a8edc8006e0abb27/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b with originalRemoteAddr [172.16.190.65], originalRemoteHost=[172.16.190.65], originalSecure=[false], originalScheme=[http], originalServerName=[portmanager-service.default.svc.cluster.local], originalServerPort=[9006] will be seen as newRemoteAddr=[172.16.194.192], newRemoteHost=[172.16.194.192], newSecure=[false], newScheme=[http], newServerName=[10.213.43.111], newServerPort=[30009]
2020-12-09 20:43:04.739 DEBUG [port-manager,,,] 1 --- [io-8080-exec-10] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /project/bba04015f47b4719a8edc8006e0abb27/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b
2020-12-09 20:43:04.740 DEBUG [port-manager,2370c40075ad4c2b,09638d1de72243fe,true] 1 --- [io-8080-exec-10] o.s.web.servlet.DispatcherServlet        : GET "/project/bba04015f47b4719a8edc8006e0abb27/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b?fields=binding%3Aprofile&fields=network_id", parameters={masked}
2020-12-09 20:43:04.746  INFO [port-manager,2370c40075ad4c2b,09638d1de72243fe,true] 1 --- [io-8080-exec-10] c.f.a.p.service.PortServiceImpl          : Get port success, projectId: bba04015f47b4719a8edc8006e0abb27, portId: 1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b
2020-12-09 20:43:04.772 DEBUG [port-manager,,,] 1 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer      : Received [PUT /project/d6e737d6243d4618b29702ba410a5af4/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b HTTP/1.1
2020-12-09 20:43:04.773 DEBUG [port-manager,,,] 1 --- [nio-8080-exec-1] o.apache.catalina.valves.RemoteIpValve   : Incoming request /project/d6e737d6243d4618b29702ba410a5af4/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b with originalRemoteAddr [172.16.190.65], originalRemoteHost=[172.16.190.65], originalSecure=[false], originalScheme=[http], originalServerName=[portmanager-service.default.svc.cluster.local], originalServerPort=[9006] will be seen as newRemoteAddr=[172.16.194.192], newRemoteHost=[172.16.194.192], newSecure=[false], newScheme=[http], newServerName=[10.213.43.111], newServerPort=[30009]
2020-12-09 20:43:04.773 DEBUG [port-manager,,,] 1 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase    : Security checking request PUT /project/d6e737d6243d4618b29702ba410a5af4/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b
2020-12-09 20:43:04.773 DEBUG [port-manager,27c345db50870429,6cbbad70da6bb42a,true] 1 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : PUT "/project/d6e737d6243d4618b29702ba410a5af4/ports/1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b", parameters={}
2020-12-09 20:43:04.880 DEBUG [port-manager,27c345db50870429,6cbbad70da6bb42a,true] 1 --- [nio-8080-exec-1] c.f.a.p.service.PortServiceImpl          : Update port enter, projectId: d6e737d6243d4618b29702ba410a5af4, portId: 1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b, PortWebJson: PortWebJson(portEntity=PortEntity(vpcId=null, adminStateUp=false, macAddress=null, vethName=null, fastPath=false, deviceId=, deviceOwner=, status=null, fixedIps=null, allowedAddressPairs=null, extraDhcpOpts=null, securityGroups=null, bindingHostId=null, bindingProfile=com.futurewei.alcor.web.entity.port.BindingProfile@55526d65, bindingVifDetails=null, bindingVifType=null, bindingVnicType=null, networkNamespace=null, dnsName=null, dnsDomain=null, dnsAssignment=null, createAt=null, updateAt=null, ipAllocation=null, portSecurityEnabled=true, qosNetworkPolicyId=null, qosPolicyId=null, revisionNumber=0, resourceRequest=null, tags=null, uplinkStatusPropagation=false, macLearningEnabled=false))
2020-12-09 20:43:04.995  INFO [port-manager,27c345db50870429,6cbbad70da6bb42a,true] 1 --- [nio-8080-exec-1] c.f.a.p.processor.DataPlaneProcessor     : Network configuration: NetworkConfiguration{rsType=null, opType=null, portEntities=[InternalPortEntity(routes=[RouteEntity(destination=192.168.2.0/24, target=Local, priority=0, associatedType=VPC, associatedTableId=1bbc51cf-b89c-4623-a80e-26ff2905ecca)], bindingHostIP=10.213.43.109, internalNeighborInfo1=null, subnetEntities=null, vpcEntities=null)], vpcs=[VpcEntity(cidr=, routeEntities=[RouteEntity(destination=null, target=Local, priority=0, associatedType=VPC, associatedTableId=881de7b6-eb71-40d6-810b-798d8225c23c)], router=Router(neutronRouteTable=null, neutronSubnetRouteTables=null, vpcRouteTables=null, vpcDefaultRouteTableId=null, owner=null, routerExtraAttributeId=null, gatewayPorts=null, tenantId=null, adminStateUp=false, status=null, created_at=null, updated_at=null), adminStateUp=true, dnsDomain=, mtu=1450, portSecurityEnabled=true, networkType=vxlan, physicalNetwork=, segmentationId=9375744, routerExternal=false, segments=[], shared=false, vlanTransparent=false, isDefault=false, availabilityZoneHints=[], availabilityZones=[Nova], qosPolicyId=[], revisionNumber=1, status=ACTIVE, tags=[], created_at=2020-12-09 18:21:19, updated_at=2020-12-09 18:21:19, ipv4AddressScope=, ipv6AddressScope=, l2Adjacency=, subnets=[556bc513-5f4c-4455-924b-db78848c2a20, 31665ab5-6f44-4074-88fb-8c80ec6a9f78])], subnets=[InternalSubnetEntity(tunnelId=9375744), InternalSubnetEntity(tunnelId=9375744)], securityGroups=[CustomerResource{projectId='bba04015f47b4719a8edc8006e0abb27', id='57315298-5cec-4b3d-aeed-9e100af1a7cd', name='default', description=''}, CustomerResource{projectId='bba04015f47b4719a8edc8006e0abb27', id='833acb7f-2a9e-4d83-8d76-c05fa1381909', name='default', description=''}], neighborInfos=[NeighborInfo(hostIp=10.213.43.104, hostId=fw0009083, portId=2d94ea4d-5d1c-4458-8428-c91accdd8179, portMac=aa:bb:cc:57:ca:06, portIp=192.168.1.3, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=556bc513-5f4c-4455-924b-db78848c2a20), NeighborInfo(hostIp=10.213.43.184, hostId=fw0016585, portId=323bf2b1-e837-47dc-a68a-5775c9d2b83b, portMac=aa:bb:cc:a7:5a:02, portIp=192.168.1.2, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=556bc513-5f4c-4455-924b-db78848c2a20), NeighborInfo(hostIp=10.213.43.109, hostId=fw0009084, portId=1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b, portMac=aa:bb:cc:c3:4e:22, portIp=192.168.2.3, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=31665ab5-6f44-4074-88fb-8c80ec6a9f78), NeighborInfo(hostIp=10.213.43.105, hostId=fw0009089, portId=651511a8-1575-4b82-92e0-fd0b5bdc5fa2, portMac=aa:bb:cc:4f:94:d1, portIp=192.168.2.2, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=31665ab5-6f44-4074-88fb-8c80ec6a9f78)], neighborTable=[com.futurewei.alcor.web.entity.dataplane.NeighborEntry@6ecf5855, com.futurewei.alcor.web.entity.dataplane.NeighborEntry@381770a2, com.futurewei.alcor.web.entity.dataplane.NeighborEntry@50255c82], routerTable=[com.futurewei.alcor.web.entity.route.InternalRouterInfo@42796692]}
2020-12-09 20:43:05.137 DEBUG [port-manager,,,] 1 --- [dPoolExecutor-7] o.s.web.client.RestTemplate              : Writing [NetworkConfiguration{rsType=null, opType=null, portEntities=[InternalPortEntity(routes=[RouteEntity(destination=192.168.2.0/24, target=Local, priority=0, associatedType=VPC, associatedTableId=1bbc51cf-b89c-4623-a80e-26ff2905ecca)], bindingHostIP=10.213.43.109, internalNeighborInfo1=null, subnetEntities=null, vpcEntities=null)], vpcs=[VpcEntity(cidr=, routeEntities=[RouteEntity(destination=null, target=Local, priority=0, associatedType=VPC, associatedTableId=881de7b6-eb71-40d6-810b-798d8225c23c)], router=Router(neutronRouteTable=null, neutronSubnetRouteTables=null, vpcRouteTables=null, vpcDefaultRouteTableId=null, owner=null, routerExtraAttributeId=null, gatewayPorts=null, tenantId=null, adminStateUp=false, status=null, created_at=null, updated_at=null), adminStateUp=true, dnsDomain=, mtu=1450, portSecurityEnabled=true, networkType=vxlan, physicalNetwork=, segmentationId=9375744, routerExternal=false, segments=[], shared=false, vlanTransparent=false, isDefault=false, availabilityZoneHints=[], availabilityZones=[Nova], qosPolicyId=[], revisionNumber=1, status=ACTIVE, tags=[], created_at=2020-12-09 18:21:19, updated_at=2020-12-09 18:21:19, ipv4AddressScope=, ipv6AddressScope=, l2Adjacency=, subnets=[556bc513-5f4c-4455-924b-db78848c2a20, 31665ab5-6f44-4074-88fb-8c80ec6a9f78])], subnets=[InternalSubnetEntity(tunnelId=9375744), InternalSubnetEntity(tunnelId=9375744)], securityGroups=[CustomerResource{projectId='bba04015f47b4719a8edc8006e0abb27', id='57315298-5cec-4b3d-aeed-9e100af1a7cd', name='default', description=''}, CustomerResource{projectId='bba04015f47b4719a8edc8006e0abb27', id='833acb7f-2a9e-4d83-8d76-c05fa1381909', name='default', description=''}], neighborInfos=[NeighborInfo(hostIp=10.213.43.104, hostId=fw0009083, portId=2d94ea4d-5d1c-4458-8428-c91accdd8179, portMac=aa:bb:cc:57:ca:06, portIp=192.168.1.3, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=556bc513-5f4c-4455-924b-db78848c2a20), NeighborInfo(hostIp=10.213.43.184, hostId=fw0016585, portId=323bf2b1-e837-47dc-a68a-5775c9d2b83b, portMac=aa:bb:cc:a7:5a:02, portIp=192.168.1.2, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=556bc513-5f4c-4455-924b-db78848c2a20), NeighborInfo(hostIp=10.213.43.109, hostId=fw0009084, portId=1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b, portMac=aa:bb:cc:c3:4e:22, portIp=192.168.2.3, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=31665ab5-6f44-4074-88fb-8c80ec6a9f78), NeighborInfo(hostIp=10.213.43.105, hostId=fw0009089, portId=651511a8-1575-4b82-92e0-fd0b5bdc5fa2, portMac=aa:bb:cc:4f:94:d1, portIp=192.168.2.2, vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, subnetId=31665ab5-6f44-4074-88fb-8c80ec6a9f78)], neighborTable=[com.futurewei.alcor.web.entity.dataplane.NeighborEntry@6ecf5855, com.futurewei.alcor.web.entity.dataplane.NeighborEntry@381770a2, com.futurewei.alcor.web.entity.dataplane.NeighborEntry@50255c82], routerTable=[com.futurewei.alcor.web.entity.route.InternalRouterInfo@42796692]}] with org.springframework.http.converter.json.MappingJackson2HttpMessageConverter
2020-12-09 20:43:06.984  INFO [port-manager,27c345db50870429,6cbbad70da6bb42a,true] 1 --- [nio-8080-exec-1] c.f.a.p.service.PortServiceImpl          : Update port success, projectId: d6e737d6243d4618b29702ba410a5af4, portId: 1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b, PortWebJson: PortWebJson(portEntity=PortEntity(vpcId=8934df6a-ef1e-4310-8612-2a923e8be6fa, adminStateUp=false, macAddress=aa:bb:cc:c3:4e:22, vethName=null, fastPath=false, deviceId=, deviceOwner=, status=null, fixedIps=[FixedIp{subnetId='31665ab5-6f44-4074-88fb-8c80ec6a9f78', ipAddress='192.168.2.3'}], allowedAddressPairs=null, extraDhcpOpts=null, securityGroups=[57315298-5cec-4b3d-aeed-9e100af1a7cd, 833acb7f-2a9e-4d83-8d76-c05fa1381909], bindingHostId=fw0009084, bindingProfile=com.futurewei.alcor.web.entity.port.BindingProfile@55526d65, bindingVifDetails=null, bindingVifType=ovs, bindingVnicType=null, networkNamespace=null, dnsName=null, dnsDomain=null, dnsAssignment=null, createAt=null, updateAt=null, ipAllocation=null, portSecurityEnabled=true, qosNetworkPolicyId=null, qosPolicyId=null, revisionNumber=0, resourceRequest=null, tags=null, uplinkStatusPropagation=false, macLearningEnabled=false))
cj-chung commented 3 years ago

nova-compute's log:

Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.187 150885 INFO nova.compute.manager [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] [instance: d0617b69-9d54-4fa3-8a1b-6258d11b9910] Terminating instance
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.188 150885 DEBUG nova.compute.manager [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] [instance: d0617b69-9d54-4fa3-8a1b-6258d11b9910] Start destroying the instance on the hypervisor. _shutdown_instance /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/compute/manager.py:2845
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.617 150885 DEBUG nova.objects.instance [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Lazy-loading 'resources' on Instance uuid d0617b69-9d54-4fa3-8a1b-6258d11b9910 obj_load_attr /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/objects/instance.py:1090
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.629 150885 DEBUG nova.virt.libvirt.vif [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] vif_type=ovs instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=False,config_drive='',created_at=2020-12-09T18:35:19Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description=None,display_name='VM4',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(3),hidden=False,host='fw0009084',hostname='vm4',id=628062,image_ref='56c1318f-0880-4d4a-aa86-071c8e526f40',info_cache=InstanceInfoCache,instance_type_id=3,kernel_id='',key_data=None,key_name=None,keypairs=<?>,launch_index=0,launched_at=2020-12-09T19:07:36Z,launched_on='fw0009084',locked=False,locked_by=None,memory_mb=512,metadata={},migration_context=<?>,new_flavor=None,node='fw0009084',numa_topology=None,old_flavor=None,os_type=None,pci_devices=<?>,pci_requests=<?>,power_state=1,progress=0,project_id='bba04015f47b4719a8edc8006e0abb27',ramdisk_id='',reservation_id='r-47kt0mms',resources=None,root_device_name='/dev/vda',root_gb=1,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='member,admin,reader',image_base_image_ref='56c1318f-0880-4d4a-aa86-071c8e526f40',image_container_format='bare',image_disk_format='qcow2',image_min_disk='1',image_min_ram='0',image_owner_specified.openstack.md5='f8ab98ff5e73ebab884d80c9dc9c7290',image_owner_specified.openstack.object='images/cirros-healthcheck',image_owner_specified.openstack.sha256='e137062a4dfbb4c225971b67781bc52183d14517170e16a3841d16f962ae7470',owner_project_name='admin1',owner_user_name='admin1'},tags=<?>,task_state='deleting',terminated_at=None,trusted_certs=<?>,updated_at=2020-12-09T18:35:27Z,user_data=None,user_id='366deb5d5fe44ac7834b14de65f179cd',uuid=d0617b69-9d54-4fa3-8a1b-6258d11b9910,vcpu_model=<?>,vcpus=1,vm_mode=None,vm_state='active') vif={"id": "1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b", "address": "aa:bb:cc:c3:4e:22", "network": {"id": "8934df6a-ef1e-4310-8612-2a923e8be6fa", "bridge": "br-int", "label": "net1", "subnets": [{"cidr": "192.168.2.0/24", "dns": [], "gateway": {"address": "192.168.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.168.2.3", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.168.2.1"}}], "meta": {"injected": false, "tenant_id": "bba04015f47b4719a8edc8006e0abb27", "mtu": 1450, "physical_network": "", "tunneled": true}}, "type": "ovs", "details": {}, "devname": "tap1ec9dbb7-e7", "ovs_interfaceid": "1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "", "profile": {}, "preserve_on_delete": true, "meta": {}} unplug /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/virt/libvirt/vif.py:832
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.630 150885 DEBUG nova.network.os_vif_util [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Converting VIF {"id": "1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b", "address": "aa:bb:cc:c3:4e:22", "network": {"id": "8934df6a-ef1e-4310-8612-2a923e8be6fa", "bridge": "br-int", "label": "net1", "subnets": [{"cidr": "192.168.2.0/24", "dns": [], "gateway": {"address": "192.168.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.168.2.3", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.168.2.1"}}], "meta": {"injected": false, "tenant_id": "bba04015f47b4719a8edc8006e0abb27", "mtu": 1450, "physical_network": "", "tunneled": true}}, "type": "ovs", "details": {}, "devname": "tap1ec9dbb7-e7", "ovs_interfaceid": "1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "", "profile": {}, "preserve_on_delete": true, "meta": {}} nova_to_osvif_vif /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/network/os_vif_util.py:516
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.631 150885 DEBUG nova.network.os_vif_util [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Converted object VIFOpenVSwitch(active=True,address=aa:bb:cc:c3:4e:22,bridge_name='br-int',has_traffic_filtering=False,id=1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b,network=Network(8934df6a-ef1e-4310-8612-2a923e8be6fa),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap1ec9dbb7-e7') nova_to_osvif_vif /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/network/os_vif_util.py:553
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.631 150885 DEBUG os_vif [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Unplugging vif VIFOpenVSwitch(active=True,address=aa:bb:cc:c3:4e:22,bridge_name='br-int',has_traffic_filtering=False,id=1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b,network=Network(8934df6a-ef1e-4310-8612-2a923e8be6fa),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap1ec9dbb7-e7') unplug /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/os_vif/__init__.py:109
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.658 150885 INFO os_vif [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Successfully unplugged vif VIFOpenVSwitch(active=True,address=aa:bb:cc:c3:4e:22,bridge_name='br-int',has_traffic_filtering=False,id=1ec9dbb7-e7e4-42c0-a5b7-11d36bc3720b,network=Network(8934df6a-ef1e-4310-8612-2a923e8be6fa),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap1ec9dbb7-e7')
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.659 150885 INFO nova.virt.libvirt.driver [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] [instance: d0617b69-9d54-4fa3-8a1b-6258d11b9910] Deleting instance files /var/lib/nova/instances/d0617b69-9d54-4fa3-8a1b-6258d11b9910_del
Dec 09 13:20:32 fw0009084 nova-compute[150885]: 2020-12-09 13:20:32.660 150885 INFO nova.virt.libvirt.driver [req-2ed19e28-ddfb-4d13-9959-24909b86ae67 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] [instance: d0617b69-9d54-4fa3-8a1b-6258d11b9910] Deletion of /var/lib/nova/instances/d0617b69-9d54-4fa3-8a1b-6258d11b9910_del complete
cj-chung commented 3 years ago

@chenpiaoping, @xieus This is the logs from compute node when I delete a VM:

Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.425 124056 DEBUG neutronclient.v2_0.client [-] ******* ClientRequest: GET /v2.0/ports?device_id=672067ce-464b-4da4-86c8-7ecc3218c072 None do_request /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/neutronclient/v2_0/client.py:281**
Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.706 124056 DEBUG nova.network.base_api [-] [instance: 672067ce-464b-4da4-86c8-7ecc3218c072] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/nova/network/base_api.py:47
Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.722 124056 INFO nova.compute.manager [-] [instance: 672067ce-464b-4da4-86c8-7ecc3218c072] Took 0.30 seconds to deallocate network for instance.
Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.967 124056 INFO nova.scheduler.client.report [req-9f4a29f5-a4a3-4f3c-9207-129243dbfd6c 366deb5d5fe44ac7834b14de65f179cd bba04015f47b4719a8edc8006e0abb27 - default default] Deleted allocation for instance 672067ce-464b-4da4-86c8-7ecc3218c072

Here is the port delete part:

Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.516 124056 DEBUG neutronclient.v2_0.client [-] ***** ClientRequest: GET /v2.0/ports/b6bdb348-2a62-4d7c-aa98-19d6001be8ae?fields=binding%3Aprofile&fields=network_id None do_request /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/neutronclient/v2_0/client.py:281
Dec 10 14:39:05 fw0009084 nova-compute[124056]: 2020-12-10 14:39:05.545 124056 DEBUG neutronclient.v2_0.client [-] ***** ClientRequest: PUT /v2.0/ports/b6bdb348-2a62-4d7c-aa98-19d6001be8ae {"port": {"device_id": "", "device_owner": "", "binding:host_id": null, "binding:profile": {}}} do_request /openstack/venvs/nova-20.1.1/lib/python3.6/site-packages/neutronclient/v2_0/client.py:281
Dec 10 14:39:05 fw0009084 AlcorControlAgent[131534]: [update_port_state_workitem:237] Port Operation: CREATE: port_id: b6bdb348-2a62-4d7c-aa98-19d6001be8ae, vpc_id:8934df6a-ef1e-4310-8612-2a923e8be6fa, network_type:0, virtual_ip_address:192.168.2.4, virtual_mac_address:aa:bb:cc:f0:f9:64, generated_port_name: tapb6bdb348-2a, port_cidr: 192.168.2.4/24, tunnel_id: 9375744
Dec 10 14:39:05 fw0009084 AlcorControlAgent[131534]: [add_goal_state_operation_status:253] gsOperationReply - resource_id: b6bdb348-2a62-4d7c-aa98-19d6001be8ae

@chenpiaoping Here is the url and body from neutronclient to PM:

PUT /v2.0/ports/b6bdb348-2a62-4d7c-aa98-19d6001be8ae {"port": {"device_id": "", "device_owner": "", "binding:host_id": null, "binding:profile": {}}}

I think this is the similar problem to default gateway disable feature in SM. Java will just ignore a field with null value. That's why PM didn't update binding:host_id.

Also, after port update operation with PUT, you can see that ACA's log indicates Port Operation: CREATE. I think there is something wrong in PM when sending down port update goalstate.

chenpiaoping commented 3 years ago

I think this is the similar problem to default gateway disable feature in SM. Java will just ignore a field with null value. That's why PM didn't update binding:host_id.

Yes, you are right, PM believes that if you want to clear a field, the value of it should be "" instead of null. but why the value of device_id is "", and the value of binding:host_id is null?

Also, after port update operation with PUT, you can see that ACA's log indicates Port Operation: CREATE. I think there is something wrong in PM when sending down port update goalstate.

Is it a PUT request or an POST request in PM's log?

cj-chung commented 3 years ago

I think this is the similar problem to default gateway disable feature in SM. Java will just ignore a field with null value. That's why PM didn't update binding:host_id.

Yes, you are right, PM believes that if you want to clear a field, the value of it should be "" instead of null. but why the value of device_id is "", and the value of binding:host_id is null?

This request is created by nova's neutronclient, we cannot modify it.

Also, after port update operation with PUT, you can see that ACA's log indicates Port Operation: CREATE. I think there is something wrong in PM when sending down port update goalstate.

Is it a PUT request or an POST request in PM's log?

It's a PUT request.

xieus commented 3 years ago

I think this is the similar problem to default gateway disable feature in SM. Java will just ignore a field with null value. That's why PM didn't update binding:host_id.

Yes, you are right, PM believes that if you want to clear a field, the value of it should be "" instead of null. but why the value of device_id is "", and the value of binding:host_id is null?

This request is created by nova's neutronclient, we cannot modify it.

The problem we are trying to resolve is this: (1) Nova Neutron client may pass "binding:host_id"=null (explicit) or not pass at all. These are considered two different scenarios and python-based Neutron server can easily differentiate two scenarios. (2) Java-based server at this point can't tell the difference as the deserialization translates to the same Java object. (3) Some random suggestion: can we set the default value of the "binding:host_id" field as empty string "", or something like "NULL". In this case, the deserialization of two different scenarios generate two different objects, one is null, the other is "" or "NULL". @chenpiaoping @cj-chung What do you think of?

cj-chung commented 3 years ago

@xieus and @chenpiaoping How about these solutions:

  1. https://stackoverflow.com/questions/38071243/jackson-serializer-cover-string-null-to-empty-string-and-keep-object-null-is
  2. https://stackoverflow.com/questions/5782284/how-to-serialize-in-jackson-json-null-string-to-empty-string
chenpiaoping commented 3 years ago

This PR has solved this problem: https://github.com/futurewei-cloud/alcor/pull/515 @cj-chung please help to test again whether port can be reused after the virtual machine is deleted.