longhorn: [BUG] Longhorn CSI prints out many error logs during the CSI backup

Describe the bug

Longhorn CSI prints out many error logs during the CSI backup:

logs message

<be>

longhorn-csi-plugin-k4gst longhorn-csi-plugin
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:20:55Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:20:55Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:20:55Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:20:55Z" level=info msg="CreateSnapshot: volume test-vol initiating snapshot snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:20:55Z" level=info msg="CreateSnapshot: volume test-vol initiating backup for snapshot snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="Backup backup-933fd3425ee4420f initiated for volume test-vol for snapshot snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: volume test-vol backup backup-933fd3425ee4420f of snapshot snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272 in progress" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=debug msg="ControllerServer CreateSnapshot rsp: snapshot:<size_bytes:6442450944 snapshot_id:\"bs://test-vol/backup-933fd3425ee4420f\" source_volume_id:\"test-vol\" creation_time:<seconds:1639012855 > > " 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"creation_time\":{\"seconds\":1639012855},\"size_bytes\":6442450944,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:00Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:01Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:02Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:02Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:02Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:02Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:02Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:03Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:03Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:03Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:03Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:03Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:06Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:06Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:06Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:06Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:06Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:11Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:11Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:11Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:11Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:11Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:21Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:21Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:21Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:21Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:21Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:41Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:41Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:41Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:41Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:41Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:52Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:52Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:52Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:52Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:21:52Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:22Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:22Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:22Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:22Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:22Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:52Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:52Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:52Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:52Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:22:52Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:23:52Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:23:52Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:23:52Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:23:52Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:23:52Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:24:52Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:24:52Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:24:52Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:24:52Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:24:52Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:06Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:06Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:06Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:06Z" level=error msg="Failed to parse creation time  for backup backup-933fd3425ee4420f" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:06Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"ready_to_use\":true,\"size_bytes\":2097152,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:52Z" level=info msg="GetPluginInfo: req: {}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:52Z" level=info msg="GetPluginInfo: rsp: {\"name\":\"driver.longhorn.io\",\"vendor_version\":\"dcaa23e0\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:52Z" level=info msg="CreateSnapshot: req: {\"name\":\"snapshot-13ca8602-1fa3-4ae3-8fa3-22a819e5f272\",\"source_volume_id\":\"test-vol\"}" 
[longhorn-csi-plugin-k4gst longhorn-csi-plugin] time="2021-12-09T01:25:52Z" level=info msg="CreateSnapshot: rsp: {\"snapshot\":{\"creation_time\":{\"seconds\":1639012855},\"ready_to_use\":true,\"size_bytes\":6442450944,\"snapshot_id\":\"bs://test-vol/backup-933fd3425ee4420f\",\"source_volume_id\":\"test-vol\"}}"

Also, there are many error logs inside csi-snaphotter:

`csi-snaphotter`: `[csi-snapshotter-5b7fff5647-cpcsz] I1209 01:24:52.195081       1 snapshot_controller.go:291] createSnapshotWrapper: CreateSnapshot for content snapcontent-13ca8602-1fa3-4ae3-8fa3-22a819e5f272 returned error: timestamp: nil Timestamp`

To Reproduce

Steps to reproduce the behavior:

Create a volume, attach to a node, write 500mb of data to the volume
Create CSI snapshot
See error logs inside longhorn-csi-plugin and csi-snapshoter

Expected behavior

No error logs inside longhorn-csi-plugin and csi-snapshoter

Environment

Longhorn version: master Dec 9 2021

Additional context

It was because csi-snapshotter repeatedly asking Longhorn CSI plugin about about the creating CSI snapshot. Longhorn CSI plugin returns the response here with the empty backup.SnapshotCreated. The backup.SnapshotCreated is empty because backup controller only set it once the backup has finished and persisted into the backup target link.

The empty timestamp lead to the many error logs in the csi-snaphotter: [csi-snapshotter-5b7fff5647-cpcsz] I1209 01:24:52.195081 1 snapshot_controller.go:291] createSnapshotWrapper: CreateSnapshot for content snapcontent-13ca8602-1fa3-4ae3-8fa3-22a819e5f272 returned error: timestamp: nil Timestamp

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 21 (12 by maintainers)

Most upvoted comments

I’ve met the same issue in v1.4.1.

dkeven on Apr 19, 2023

Hello, I have the issue on 1.5.1 too.

ghost on Aug 10, 2023

The engine.SnapshotBackup call inside of the longhorn-manager already has access to the snapshot information, and can therefore reply with it withhout requiring modification on the engine side.

https://github.com/longhorn/longhorn-manager/blob/dcaa23e0ca65962a97a947d0dd198bc96fa20066/engineapi/backups.go#L254

joshimoo on Dec 10, 2021

In my case, there’s another variable to consider. I’m using longhorn by way of Harvester. After digging some more, I’ve determined that I can successfully create ‘regular’ snapshots through the Harvester interface but when I try to create a VM backup, the corresponding volumesnapshot fails with the ‘nil Timestamp’ error. Digging around some more, I’ve found that there’s a ‘harvester-snapshot-validation-webhook’ pod which is reporting TLS handshake errors (eg., TLS handshake error from 10.99.0.21:46076: EOF).

Any time I’ve run into TLS errors with Harvester/Longhorn/Rancher, they seem to be at the root of whatever current problem is. I wish there were a definitive map of the myriad communication flows between all of these systems as cert issues seem to be a particularly nasty thorn. Everything else is working okay in this cluster. This snapshot controller seems to be the only thing complaining and VM backup functionality is the only thing impacted.

On Thu, Mar 14, 2024 at 1:20 PM khushboo-rancher @.***> wrote:

I checked high level in a Harvester cluster with Longhorn 1.5.3 (Harvester uses CSI snapshot to create snapshot/backup), didn’t see this issue. I’ll dig into this more.

— Reply to this email directly, view it on GitHub https://github.com/longhorn/longhorn/issues/3392#issuecomment-1998062970, or unsubscribe https://github.com/notifications/unsubscribe-auth/AIYCOIL2RNZNK6PFRNV7UVLYYHS5HAVCNFSM5JYCFNWKU5DIOJSWCZC7NNSXTN2JONZXKZKDN5WW2ZLOOQ5TCOJZHAYDMMRZG4YA . You are receiving this because you commented.Message ID: @.***>

joshuarestivo on Mar 14, 2024

Here’s the bundle longhorn-support-bundle_8d048492-8ba5-4c90-93df-2d1f709585da_2022-08-10T19-25-16Z.zip

hariprasadiit on Aug 10, 2022