azure-vnet.json.lock left with corresponding azure-vnet.exe missing

[zhiweiv]

Is this an ISSUE or FEATURE REQUEST? (choose one):
ISSUE

---

Which release version?:
1.0.18

---

Which component (CNI/IPAM/CNM/CNS):
CNI

---

Which Operating System (Linux/Windows):
Windows
10.0.17763.194 (WinBuild.160101.0800)

---

Which Orchestrator and version (e.g. Kubernetes, Docker)
k8s 1.14.1

---

What happened:
Sometimes I found azure-vnet.json.lock left which blocked all following cni requets, it's owner azure-vnet.exe didn't exist.

C:\k>type azure-vnet.json.lock
10776
C:\k>tasklist | findstr "azure"
azure-vnet.exe                5508 Services                   0      8,568 K
azure-vnet.exe               27892 Services                   0      8,484 K
azure-vnet.exe                7744 Services                   0      8,296 K
azure-vnet.exe                6952 Services                   0      8,380 K

---

What you expected to happen:
azure-vnet.exe should delete the lock file when it exits in any condition.

---

How to reproduce it (as minimally and precisely as possible):
Unable to find the reproduce steps, it happens randomly.

[ashvindeodhar]

Can you please share the cni log?

[zhiweiv]

I forgot to upload the log, unable to find it now. This issue occurred 3~4 times in the past 6 months, not sure if it was caused by same issue in #358.

Close this temporarily, will open again once I can reproduce again.

[zhiweiv]

Reproduced again, there is a fix in #445, we will try new azure cni plugin soon.

[zhiweiv]

Pid in orphan lock file is 19592, I can find these logs about 19592, seems different with before.
@ashvindeodhar, not sure if you are interested in this log.
cni.zip

2020/03/10 19:41:37 [19592] [cni-net] ADD command completed with result:Interfaces:[{Name:eth0 Mac: Sandbox:}], IP:[{Version:4 Interface: Address:{IP:10.20.1.86 Mask:ffff0000} Gateway:10.20.0.1}], Routes:[{Dst:{IP:0.0.0.0 Mask:00000000} GW:10.20.0.1}], DNS:{Nameservers:[192.168.200.10 168.63.129.16] Domain: Search:[] Options:[]} err:.
2020/03/10 19:41:37 [19592] [cni-net] Plugin stopped.
2020/03/10 19:41:37 [19592] [cni] Failed to unlock store: remove azure-vnet.json.lock: The process cannot access the file because it is being used by another process..
2020/03/10 19:41:37 [19592] Failed to uninitialize key-value store of network plugin, err:remove azure-vnet.json.lock: The process cannot access the file because it is being used by another process..
2020/03/10 19:41:37 [19592] Sending report succeeded
2020/03/10 19:41:37 [19592] [cni] Failed to unlock store: remove azure-vnet.json.lock: The process cannot access the file because it is being used by another process..
2020/03/10 19:41:37 [19592] Failed to uninitialize key-value store of network plugin, err:remove azure-vnet.json.lock: The process cannot access the file because it is being used by another process..
2020/03/10 19:41:37 [26416] Formatted Boot time: 2020-02-06 08:45:59

[ashvindeodhar]

@zhiweiv thanks for sharing the log snippet. Are you still seeing this issue with the latest CNI release?

[zhiweiv]

AKS is rolling update with azure cni 1.0.30 for Windows, I will try that once it is available.