Is FlexVolume working? - Githubissues

guhuajun commented 5 years ago

Greetings,

I got an issue when using FelxVolume with Windows Server 2019 built-in iSCSI target and file sharing. (Any requirement for iSCSI target? Help needed.)

What happened: Running dir c:\d failed with DirIOError

What you expected to happen: Running dir c:\d should return without error.

How to reproduce it (as minimally and precisely as possible): kubectl apply [iscsi|smb].yaml (using mcr.microsoft.com/powershell:6.2.0-nanoserver-1809 instead)

Anything else we need to know?:

Environment:

Kubernetes version (use kubectl version): v1.14.1
Cloud provider or hardware configuration: VirtualBox
OS (e.g: cat /etc/os-release): CentOS 7.4.1708 + Windows Server 2019 Standard
Kernel (e.g. uname -a): Linux: 3.10.0-693.el7.x86_64; Windows: 10.0.17763.475
Install tools: kubeadm, microsoft/sdn flannel related scripts
Network plugin and version (if this is a network-related bug): Flannel
Others:

Screenshots

KnicKnic commented 5 years ago

The plugins log to the 'Application' event channel on the appropriate worker node. Get-EventLog -LogName Application -Source Kube* -Newest 50

You can get a more detailed trace of the components by enabling debug logs may contain your passwords when you do this edit C:\usr\libexec\kubernetes\kubelet-plugins\volume\exec\microsoft.com~iscsi.cmd\flexvolume.ps1 and C:\usr\libexec\kubernetes\kubelet-plugins\volume\exec\microsoft.com~smb.cmd\flexvolume.ps1 and change $debug_mode = $false to $debug_mode = $true

Also what would be useful is to dump the pod & pv config to yaml or json and include it.

KnicKnic commented 5 years ago

@guhuajun I am able to reproduce access denied for iSCSI. The issue is that the user in the container is not an Adminstrator and therefore does not have access to create files on the root of the iSCSI volume. I will work on a fix. To verify if it is this issue, please try to run with an administrative user and see if that works. You can create a new image with the following docker file

FROM mcr.microsoft.com/powershell:6.2.0-nanoserver-1809
USER containeradministrator

guhuajun commented 5 years ago

@KnicKnic Thank you. Let me verify it.

And here are the log entries in Application log.

"TimeGenerated","Message" "5/15/2019 4:43:06 PM","log: " "5/15/2019 4:43:06 PM","log: {""status"": ""Success""}" "5/15/2019 4:43:06 PM","log: C:\var\lib\kubelet\pods\25373de4-740a-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:43:06 PM","log: deleting folder c:\var\lib\kubelet\pods\25373de4-740a-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:43:06 PM","log: mklink c:\var\lib\kubelet\pods\25373de4-740a-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume \192.168.0.44\k8sdata" "5/15/2019 4:43:06 PM","log: A specified logon session does not exist. It may already have been terminated. " "5/15/2019 4:43:05 PM","log: smbGlobal" "5/15/2019 4:43:05 PM","log: \192.168.0.44\k8sdata" "5/15/2019 4:43:05 PM","log: Make dir c:\var\lib\kubelet\pods\25373de4-740a-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume..\" "5/15/2019 4:43:05 PM","log: mount" "5/15/2019 4:35:49 PM","log: " "5/15/2019 4:35:49 PM","log: {""status"": ""Success""}" "5/15/2019 4:35:49 PM","log: removing symlink for path c:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:35:49 PM","log: unmount c:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:35:49 PM","log: unmount" "5/15/2019 4:31:52 PM","log: " "5/15/2019 4:31:52 PM","log: {""status"": ""Success""}" "5/15/2019 4:31:52 PM","log: C:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:31:52 PM","log: deleting folder c:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:31:52 PM","log: mklink c:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume \192.168.0.44\k8sdata" "5/15/2019 4:31:52 PM","log: A specified logon session does not exist. It may already have been terminated. " "5/15/2019 4:31:51 PM","log: smbGlobal" "5/15/2019 4:31:51 PM","log: \192.168.0.44\k8sdata" "5/15/2019 4:31:50 PM","log: Make dir c:\var\lib\kubelet\pods\71bdccf1-7408-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume..\" "5/15/2019 4:31:50 PM","log: mount" "5/15/2019 4:30:05 PM","log: " "5/15/2019 4:30:05 PM","log: {""status"": ""Success""}" "5/15/2019 4:30:05 PM","log: removing symlink for path c:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:30:05 PM","log: unmount c:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:30:05 PM","log: unmount" "5/15/2019 4:28:08 PM","log: " "5/15/2019 4:28:08 PM","log: {""status"": ""Success""}" "5/15/2019 4:28:08 PM","log: C:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:28:08 PM","log: deleting folder c:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume" "5/15/2019 4:28:08 PM","log: mklink c:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume \192.168.0.44\k8sdata" "5/15/2019 4:28:08 PM","log: A specified logon session does not exist. It may already have been terminated. " "5/15/2019 4:28:06 PM","log: smbGlobal" "5/15/2019 4:28:06 PM","log: \192.168.0.44\k8sdata" "5/15/2019 4:28:06 PM","log: Make dir c:\var\lib\kubelet\pods\e0f72c14-7407-11e9-9b61-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume..\" "5/15/2019 4:28:06 PM","log: mount" "5/15/2019 4:20:51 PM","log: " "5/15/2019 4:20:51 PM","log: {""status"": ""Success""}" "5/15/2019 4:20:51 PM","log: Changin state of disk number 1 to offline True" "5/15/2019 4:20:50 PM","log: Changin state of disk number 1 to readonly True" "5/15/2019 4:20:47 PM","log: unmount c:\var\lib\kubelet\pods\8c3ae711-73fe-11e9-9b61-0800275d95f3\volumes\microsoft.com~iscsi.cmd\iscsi-volume" "5/15/2019 4:20:47 PM","log: unmount c:\var\lib\kubelet\pods\8c3ae711-73fe-11e9-9b61-0800275d95f3\volumes\microsoft.com~iscsi.cmd\iscsi-volume" "5/15/2019 4:20:47 PM","log: unmount" "5/15/2019 3:27:37 PM","log: " "5/15/2019 3:27:37 PM","log: {""status"": ""Success""}" "5/15/2019 3:27:37 PM","log: C:\var\lib\kubelet\pods\8c3ae711-73fe-11e9-9b61-0800275d95f3\volumes\microsoft.com~iscsi.cmd\iscsi-volume"

guhuajun commented 5 years ago

After adding USER containeradministrator, iSCSI is working. However SMB still fails with Access Denied error. Any special configuration for SMB?

iSCSI

[root@k8s114001 ~]# kubectl exec -it iscsi-deployment-869588fd49-t7ml4 pwsh
PowerShell 6.2.0
Copyright (c) Microsoft Corporation. All rights reserved.

https://aka.ms/pscore6-docs
Type 'help' to get help.

PS C:> cd d
PS C:\d> Get-Process | Export-Csv -Path .\process.csv -NoTypeInformation
PS C:\d> (Get-Content -Path .\process.csv)[-1]
"wininit","3","98","2203372113920","4292608","1064960","7712",,,,"0.09375",,,,,"Process",,,"13",,"False","5/16/2019 4:07:01 PM",,"7820",".",,,,"7712","7712","1064960","1064960","39

96","39896","1462272","1462272","4378624","4378624","2203374735360","56512512",,,"1064960","1064960","wininit",,"3",,"System.Diagnostics.ProcessThreadCollection","98","220337211392 PS C:\d> exit
[root@k8s114001 ~]# kubectl describe pod iscsi-deployment-869588fd49-t7ml4
Name: iscsi-deployment-869588fd49-t7ml4
Namespace: default
Priority: 0
PriorityClassName:
Node: k8s114004/192.168.0.44
Start Time: Thu, 16 May 2019 16:06:50 +0800
Labels: app=iscsi-app
pod-template-hash=869588fd49
Annotations:
Status: Running
IP: 10.244.3.25
Controlled By: ReplicaSet/iscsi-deployment-869588fd49
Containers:
iscsi-app:
Container ID: docker://b849711aba82e1b9ec29b89136bf1931c7f092fd61db1256270cc2e5b33fb4a0
Image: greggu/flexvolume:0.1
Image ID: docker://sha256:db29e99bd12b628b479ee707ec1db8ebf7239400a295799c081965e364a129d2
Port:
Host Port:
Command:
pwsh.exe
-c
ping
127.0.0.1
-t
State: Running
Started: Thu, 16 May 2019 16:07:02 +0800
Ready: True
Restart Count: 0
Limits:
cpu: 200m
memory: 500Mi
Requests:
cpu: 200m
memory: 500Mi
Environment:
Mounts:
/d from iscsi-volume (rw)
/var/run/secrets/kubernetes.io/serviceaccount from default-token-gx4hx (ro)
Conditions:
Type Status
Initialized True
Ready True
ContainersReady True
PodScheduled True
Volumes:
iscsi-volume:
Type: FlexVolume (a generic volume resource that is provisioned/attached using an exec based plugin)
Driver: microsoft.com/iscsi.cmd
FSType: ntfs
SecretRef: &LocalObjectReference{Name:iscsi-secret,}
ReadOnly: false
Options: map[authType:ONEWAYCHAP chapAuthDiscovery:false chapAuthSession:true iqn:iqn.1991-05.com.microsoft:k8s114004-k8s114004-target lun:0 portals:192.168.0.44 targetPorta :192.168.0.44]
default-token-gx4hx:
Type: Secret (a volume populated by a Secret)
SecretName: default-token-gx4hx
Optional: false
QoS Class: Guaranteed
Node-Selectors: beta.kubernetes.io/os=windows
Tolerations: node.kubernetes.io/not-ready:NoExecute for 300s
node.kubernetes.io/unreachable:NoExecute for 300s
Events:
Type Reason Age From Message

Normal Scheduled 11m default-scheduler Successfully assigned default/iscsi-deployment-869588fd49-t7ml4 to k8s114004
Normal Pulled 11m kubelet, k8s114004 Container image "greggu/flexvolume:0.1" already present on machine
Normal Created 11m kubelet, k8s114004 Created container iscsi-app
Normal Started 11m kubelet, k8s114004 Started container iscsi-app

SMB

PS C:\Users\Administrator\Downloads\flexvolume> Get-EventLog -LogName Application -Source KubeSMB* -Newest 50 | Select-Object TimeGenerated, Message

TimeGenerated Message

5/16/2019 4:40:18 PM log: 5/16/2019 4:40:18 PM log: {"status": "Success"} 5/16/2019 4:40:18 PM log: C:\var\lib\kubelet\pods\39c9dcaf-77b6-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/16/2019 4:40:18 PM log: deleting folder c:\var\lib\kubelet\pods\39c9dcaf-77b6-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/16/2019 4:40:18 PM log: mklink c:\var\lib\kubelet\pods\39c9dcaf-77b6-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume \192.168.0.44\k8sdata 5/16/2019 4:40:18 PM log: A specified logon session does not exist. It may already have been terminated. 5/16/2019 4:40:17 PM log: smbGlobal 5/16/2019 4:40:17 PM log: \192.168.0.44\k8sdata 5/16/2019 4:40:17 PM log: Make dir c:\var\lib\kubelet\pods\39c9dcaf-77b6-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume..\ 5/16/2019 4:40:17 PM log: mount 5/16/2019 4:39:58 PM log: 5/16/2019 4:39:58 PM log: {"status": "Success"} 5/16/2019 4:39:57 PM log: removing symlink for path c:\var\lib\kubelet\pods\5992a4e8-77b5-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/16/2019 4:39:57 PM log: unmount c:\var\lib\kubelet\pods\5992a4e8-77b5-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/16/2019 4:39:57 PM log: unmount

KnicKnic commented 5 years ago

@guhuajun Can you share your spec which you use to mount the smb share. Everything but the secret / password.

Also can you ensure 2 things.

You are not using a DFS share path for the SMB path.
That the username is of specification domainname\username or computername\username it is vital that it is of format something\username.

Lastly there is a bugfix for server 2019 that is not in the payload you are using for remounting SMB shares.

Please update the plugin directory with the contents from https://github.com/microsoft/K8s-Storage-Plugins/tree/master/flexvolume/windows/plugins/microsoft.com~smb.cmd the default path is C:\usr\libexec\kubernetes\kubelet-plugins\volume\exec

guhuajun commented 5 years ago

@KnicKnic

I am not using DFS.

Yes, you are correct. The username is the key for this issue. After playing Linux for years, '/' becomes correct in my mind. (I am a Windows Server administrator before. Missing these pure windows days...) After the username is converted by base64, it's a little bit harder to find I have used '/' in the username. It should be '\'. Here is the correct log entries.

5/17/2019 9:34:19 AM log: 5/17/2019 9:34:19 AM log: {"status": "Success"} 5/17/2019 9:34:19 AM log: C:\var\lib\kubelet\pods\e13cfd08-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/17/2019 9:34:19 AM log: deleting folder c:\var\lib\kubelet\pods\e13cfd08-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/17/2019 9:34:19 AM log: mklink c:\var\lib\kubelet\pods\e13cfd08-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume \192.168.0.44\k8sdata 5/17/2019 9:34:19 AM log: MSFT_SmbGlobalMapping (LocalPath = "", RemotePath = "\192.168.0.44\k8sdata") 5/17/2019 9:34:17 AM log: smbGlobal 5/17/2019 9:34:17 AM log: \192.168.0.44\k8sdata 5/17/2019 9:34:17 AM log: Make dir c:\var\lib\kubelet\pods\e13cfd08-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume..\ 5/17/2019 9:34:17 AM log: mount 5/17/2019 9:34:13 AM log: 5/17/2019 9:34:13 AM log: {"status": "Success"} 5/17/2019 9:34:13 AM log: removing symlink for path c:\var\lib\kubelet\pods\14b505ba-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/17/2019 9:34:13 AM log: unmount c:\var\lib\kubelet\pods\14b505ba-7843-11e9-83de-0800275d95f3\volumes\microsoft.com~smb.cmd\smb-volume 5/17/2019 9:34:13 AM log: unmount

Here is my spec for SMB. Using deployment instead of pod and set replicas to 2, it works as excepted!

apiVersion: extensions/v1beta1
kind: Deployment
metadata:
  name:  smb-deployment
  labels:
    name:  smb-app
spec:
  replicas: 2
  selector:
    matchLabels:
      app: smb-app
  strategy:
    rollingUpdate:
      maxSurge: 1
      maxUnavailable: 1
    type: RollingUpdate
  template:
    metadata:
      labels:
        app:  smb-app
    spec:
      containers:
      - name: smb
        image: greggu/flexvolume:0.1 # mcr.microsoft.com/powershell:6.2.0-nanoserver-1809
        command: ["pwsh.exe", "-c", "ping", "127.0.0.1", "-t"]
        volumeMounts:
        - name: smb-volume
          mountPath: /d
        resources:
          requests:
            cpu: 200m
            memory: 500Mi
          limits:
            cpu: 200m
            memory: 500Mi
      volumes:
      - name: smb-volume
        flexVolume:
          driver: "microsoft.com/smb.cmd"
          secretRef:
            name: "smb-secret"
          options:
            # source can be in any of the following formats 
            # \\servername\share\path  (\'s will need to be escaped)
            # smb://servername/share/path
            # //servername/share/path
            source: "\\\\192.168.0.44\\k8sdata"

KnicKnic commented 5 years ago

@guhuajun fyi a release was created that should take care of your iSCSI issue.

https://github.com/microsoft/K8s-Storage-Plugins/releases/tag/V0.0.3

guhuajun commented 5 years ago

@guhuajun fyi a release was created that should take care of your iSCSI issue.

https://github.com/microsoft/K8s-Storage-Plugins/releases/tag/V0.0.3

Thank you! I will verify this release soon!

microsoft / K8s-Storage-Plugins

Is FlexVolume working? #9