Skip to content

Instantly share code, notes, and snippets.

@ffilippopoulos

ffilippopoulos/trident-csi-reformat-logs

Created January 26, 2021 16:06
Show Gist options
  • Save ffilippopoulos/40747b8982d174b99b88099d9a6770f4 to your computer and use it in GitHub Desktop.
Save ffilippopoulos/40747b8982d174b99b88099d9a6770f4 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
trident-csi-reformat-logs
time="2021-01-26T11:21:31Z" level=debug msg="GRPC request: volume_id:\"pvc-db68511a-0d70-4845-a0c8-5221122674a9\" publish_context:<key:\"filesystemType\" value:\"ext4\" > publish_context:<key:\"iscsiIgroup\" value:\"dev_kube_trident\" > publish_context:<key:\"iscsiInitiatorSecret\" value:\"\" > publish_context:<key:\"iscsiInterface\" value:\"\" > publish_context:<key:\"iscsiLunNumber\" value:\"65\" > publish_context:<key:\"iscsiLunSerial\" value:\"81D8U+PWVEBG\" > publish_context:<key:\"iscsiTargetIqn\" value:\"iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9\" > publish_context:<key:\"iscsiTargetPortalCount\" value:\"2\" > publish_context:<key:\"iscsiTargetSecret\" value:\"\" > publish_context:<key:\"iscsiTargetUsername\" value:\"\" > publish_context:<key:\"iscsiUsername\" value:\"\" > publish_context:<key:\"mountOptions\" value:\"\" > publish_context:<key:\"p1\" value:\"10.20.50.4\" > publish_context:<key:\"p2\" value:\"10.20.50.5\" > publish_context:<key:\"protocol\" value:\"block\" > publish_context:<key:\"sharedTarget\" value:\"true\" > publish_context:<key:\"useCHAP\" value:\"false\" > staging_target_path:\"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-db68511a-0d70-4845-a0c8-5221122674a9/globalmount\" volume_capability:<mount:<fs_type:\"ext4\" > access_mode:<mode:SINGLE_NODE_WRITER > > volume_context:<key:\"backendUUID\" value:\"1ab1fedc-94cc-4dc3-a650-f0734ee611c7\" > volume_context:<key:\"internalName\" value:\"trident_pvc_db68511a_0d70_4845_a0c8_5221122674a9\" > volume_context:<key:\"name\" value:\"pvc-db68511a-0d70-4845-a0c8-5221122674a9\" > volume_context:<key:\"protocol\" value:\"block\" > volume_context:<key:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1606832900884-8081-csi.trident.netapp.io\" > " requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Attempting to acquire shared lock (NodeStageVolume-pvc-db68511a-0d70-4845-a0c8-5221122674a9)." lock=csi_node_server requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Acquired shared lock (NodeStageVolume-pvc-db68511a-0d70-4845-a0c8-5221122674a9)." lock=csi_node_server requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> NodeStageVolume" Method=NodeStageVolume Type=CSI_Node requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.AttachISCSIVolume" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Attaching iSCSI volume." fstype=ext4 iscsiInterface=default lunID=65 mountpoint= requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI targetIQN="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" targetPortals="[10.20.50.4 10.20.50.5]" volume=trident_pvc_db68511a_0d70_4845_a0c8_5221122674a9
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.ISCSISupported" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.execCommand." args="[-V]" command=iscsiadm requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.execCommand." command=iscsiadm error="<nil>" output="iscsiadm version 2.1.2" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.ISCSISupported" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.portalsIpsToLogin" portalsIps="[10.20.50.4 10.20.50.5]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI targetIQN="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.getISCSISessionInfo" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.execCommand." args="[-m session]" command=iscsiadm requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.execCommand." command=iscsiadm error="<nil>" output="tcp: [3] 10.20.50.4:3260,1030 iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9 (non-flash)\ntcp: [4] 10.20.50.5:3260,1031 iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9 (non-flash)" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Adding iSCSI session info." Portal="10.20.50.4:3260,1030" PortalIP=10.20.50.4 SID=3 TargetName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Adding iSCSI session info." Portal="10.20.50.5:3260,1031" PortalIP=10.20.50.5 SID=4 TargetName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.getISCSISessionInfo" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.portalsIpsToLogin" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.EnsureISCSISessions" portalsIps="[]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI targetIQN="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.EnsureISCSISessions" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="LUN serial check skipped" lun=65 path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="LUN serial check skipped" lun=65 path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="LUN serial check skipped" lun=65 path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="LUN serial check skipped" lun=65 path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.waitForDeviceScanIfNeeded" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:31Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:31Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg="Built iSCSI host/session map." hostSessionMap="map[6:3 7:4]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:31Z" level=debug msg=">>>> osutils.iSCSIScanTargetLUN" hosts="[6 7]" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:32Z" level=debug msg="Invoked single-LUN scan." requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI scanCmd="0 0 65" scanFile=/sys/class/scsi_host/host6/scan
time="2021-01-26T11:21:35Z" level=debug msg="Invoked single-LUN scan." requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI scanCmd="0 0 65" scanFile=/sys/class/scsi_host/host7/scan
time="2021-01-26T11:21:35Z" level=debug msg="<<<< osutils.iSCSIScanTargetLUN" hosts="[6 7]" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:35Z" level=debug msg="Scanning paths: [/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65 /sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:35Z" level=debug msg="All devices not yet present, waiting." increment=1.051593319s requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:36Z" level=debug msg="All devices not yet present, waiting." increment=1.396932958s requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:37Z" level=debug msg="All devices not yet present, waiting." increment=1.969276672s requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC call: /csi.v1.Node/NodeGetCapabilities" requestID=7bf53daf-311d-4106-894b-7eadc93348a2 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC request: " requestID=7bf53daf-311d-4106-894b-7eadc93348a2 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg=">>>> NodeGetCapabilities" Method=NodeGetCapabilities Type=CSI_Node requestID=7bf53daf-311d-4106-894b-7eadc93348a2 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="<<<< NodeGetCapabilities" Method=NodeGetCapabilities Type=CSI_Node requestID=7bf53daf-311d-4106-894b-7eadc93348a2 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > capabilities:<rpc:<type:EXPAND_VOLUME > > capabilities:<rpc:<type:GET_VOLUME_STATS > > " requestID=7bf53daf-311d-4106-894b-7eadc93348a2 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC call: /csi.v1.Node/NodeGetVolumeStats" requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC request: volume_id:\"pvc-d5714dcd-2095-44cc-ac45-8f4a976a52be\" volume_path:\"/var/lib/kubelet/pods/2c772e03-b440-4855-bb4f-0cdba98a8f09/volumes/kubernetes.io~csi/pvc-d5714dcd-2095-44cc-ac45-8f4a976a52be/mount\" " requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg=">>>> osutils_linux.GetFilesystemStats" requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="Filesystem size information" avail=2388261 blocks=2563909 bsize=4096 free=2523429 path="/var/lib/kubelet/pods/2c772e03-b440-4855-bb4f-0cdba98a8f09/volumes/kubernetes.io~csi/pvc-d5714dcd-2095-44cc-ac45-8f4a976a52be/mount" requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI size=10501771264
time="2021-01-26T11:21:38Z" level=debug msg="<<<< osutils_linux.GetFilesystemStats" requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI
time="2021-01-26T11:21:38Z" level=debug msg="GRPC response: usage:<available:9782317056 total:10501771264 used:719454208 unit:BYTES > usage:<available:655342 total:655360 used:18 unit:INODES > " requestID=4eb05655-8cd3-4e82-92db-c5e8acb226c9 requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Paths found: []" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.waitForDeviceScanIfNeeded" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="LUN serial check passed" lun=65 path="/sys/class/scsi_host/host6/device/session3/iscsi_session/session3/device/target6:0:0/6:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI serial=81D8U+PWVEBG target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:39Z" level=debug msg="Get LUN Serial" path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="LUN serial check passed" lun=65 path="/sys/class/scsi_host/host7/device/session4/iscsi_session/session4/device/target7:0:0/7:0:0:65" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI serial=81D8U+PWVEBG target="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9"
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.waitForMultipathDeviceForLUN" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.waitForMultipathDeviceForDevices" devices="[sdd sde]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.multipathdIsRunning" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.execCommand." args="[multipathd]" command=pgrep requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.execCommand." command=pgrep error="<nil>" output=848 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="multipathd is running" pid=848 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.multipathdIsRunning" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.findMultipathDeviceForDevice" device=sdd requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.findMultipathDeviceForDevice" device=sdd requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Multipath device found." multipathDevice=dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.waitForMultipathDeviceForDevices" devices="[sdd sde]" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.waitForMultipathDeviceForLUN" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.getDeviceInfoForLUN" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 needFSType=true requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=6 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=3
time="2021-01-26T11:21:39Z" level=debug msg="Found iSCSI host/session." hostNumber=7 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI sessionNumber=4
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.GetISCSIHostSessionMapForTarget" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.findMultipathDeviceForDevice" device=sdd requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg="<<<< osutils.findMultipathDeviceForDevice" device=sdd requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.ensureDeviceReadable" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:39Z" level=debug msg=">>>> osutils.execCommandWithTimeout." args="[if=/dev/dm-1 bs=4096 count=1 status=none]" command=dd requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI timeoutSeconds=5s
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.execCommandWithTimeout." command=dd error="<nil>" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.ensureDeviceReadable" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.getFSType" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.waitForDevice" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="Device found." device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.waitForDevice" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.execCommandWithTimeout." args="[/dev/dm-1]" command=blkid requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI timeoutSeconds=5s
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.execCommandWithTimeout." command=blkid error="<nil>" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.getFSType" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="Found SCSI device." LUN=65 deviceNames="[sdd sde]" fsType= hostSessionMap="map[6:3 7:4]" multipathDevice=dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.getDeviceInfoForLUN" iSCSINodeName="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" lunID=65 needFSType=true requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="Found device." devices="[sdd sde]" fsType= iqn="iqn.1992-08.com.netapp:sn.0205ffce026911ebb4d9d039ea1a7953:vs.9" multipathDevice=dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI scsiLun=65
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.waitForDevice" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="Device found." device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="<<<< osutils.waitForDevice" device=/dev/dm-1 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg="Formatting LUN." fstype=ext4 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI volume=trident_pvc_db68511a_0d70_4845_a0c8_5221122674a9
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.formatVolume" device=/dev/dm-1 fsType=ext4 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:40Z" level=debug msg=">>>> osutils.execCommand." args="[-F /dev/dm-1]" command=mkfs.ext4 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=debug msg="<<<< osutils.execCommand." command=mkfs.ext4 error="<nil>" output="mke2fs 1.45.5 (07-Jan-2020)\nDiscarding device blocks: 4096/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b 528384/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b 1576960/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b 3149824/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b10489856/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b12062720/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b13635584/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b15208448/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b16781312/26214400\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b \b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\b\bdone \nCreating filesystem with 26214400 4k blocks and 6553600 inodes\nFilesystem UUID: 346e0291-5523-4a1e-8c85-9cd2611f3e01\nSuperblock backups stored on blocks: \n\t32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208, \n\t4096000, 7962624, 11239424, 20480000, 23887872\n\nAllocating group tables: 0/800\b\b\b\b\b\b\b \b\b\b\b\b\b\bdone \nWriting inode tables: 0/800\b\b\b\b\b\b\b \b\b\b\b\b\b\bdone \nCreating journal (131072 blocks): done\nWriting superblocks and filesystem accounting information: 0/800\b\b\b\b\b\b\b \b\b\b\b\b\b\bdone\n" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=info msg="Device formatted." device=/dev/dm-1 fsType=ext4 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=debug msg="<<<< osutils.formatVolume" device=/dev/dm-1 fsType=ext4 requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=debug msg="<<<< osutils.AttachISCSIVolume" requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=debug msg="<<<< NodeStageVolume" Method=NodeStageVolume Type=CSI_Node requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
time="2021-01-26T11:21:48Z" level=debug msg="Released shared lock (NodeStageVolume-pvc-db68511a-0d70-4845-a0c8-5221122674a9)." lock=csi_node_server requestID=1ceb4302-9be7-4af2-a463-81200d165d4e requestSource=CSI
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment