Alluxio / alluxio

Alluxio, data orchestration for analytics and machine learning in the cloud
https://www.alluxio.io
Apache License 2.0
6.81k stars 2.93k forks source link

v2.8.0 kubernetes.io~csi/alluxio-airflow-pv/mount file exists #15613

Closed takersk closed 2 years ago

takersk commented 2 years ago

Alluxio Version: v2.8.0 (v2.7.1 same error)

Describe the bug Intermittent error when creating pods

[2022-05-25 21:31:13,119] {kubernetes_pod.py:366} INFO - creating pod with labels {'dag_id': 'etl_processing_dag', 'task_id': 'etl_gift_stats_also_buy_product', 'execution_date': '2022-05-24T2100000000-020f21c22', 'try_number': '6'} and launcher <airflow.providers.cncf.kubernetes.utils.pod_launcher.PodLauncher object at 0x7f31157e9cf8>
[2022-05-25 21:31:13,157] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Pending
[2022-05-25 21:31:13,157] {pod_launcher.py:128} WARNING - Pod not yet started: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347
[2022-05-25 21:31:14,166] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Pending
[2022-05-25 21:31:14,166] {pod_launcher.py:128} WARNING - Pod not yet started: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347
[2022-05-25 21:31:15,174] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Pending
[2022-05-25 21:31:15,174] {pod_launcher.py:128} WARNING - Pod not yet started: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347
[2022-05-25 21:31:16,183] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Pending
[2022-05-25 21:31:16,183] {pod_launcher.py:128} WARNING - Pod not yet started: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347
[2022-05-25 21:31:17,194] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Pending
[2022-05-25 21:31:17,194] {pod_launcher.py:128} WARNING - Pod not yet started: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347
[2022-05-25 21:31:18,202] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Failed
[2022-05-25 21:31:18,202] {pod_launcher.py:308} ERROR - Event with job id etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 Failed
[2022-05-25 21:31:18,223] {pod_launcher.py:193} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-05-25 21:31:18,224] {pod_launcher.py:149} INFO - failed to try resolving symlinks in path "/var/log/pods/airflow_etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347_cf0d1c24-a325-433b-b371-464e63181b95/base/0.log": lstat /var/log/pods/airflow_etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347_cf0d1c24-a325-433b-b371-464e63181b95/base/0.log: no such file or directory
[2022-05-25 21:31:19,240] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Failed
[2022-05-25 21:31:19,240] {pod_launcher.py:308} ERROR - Event with job id etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 Failed
[2022-05-25 21:31:19,247] {pod_launcher.py:198} INFO - Event: etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 had an event of type Failed
[2022-05-25 21:31:19,247] {pod_launcher.py:308} ERROR - Event with job id etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347 Failed
'state': {'running': None,
                                              'terminated': {'container_id': 'docker://671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43',
                                                             'exit_code': 128,
                                                             'finished_at': datetime.datetime(2022, 5, 25, 21, 31, 16, tzinfo=tzlocal()),
                                                             'message': 'error '
                                                                        'while '
                                                                        'creating '
                                                                        'mount '
                                                                        'source '
                                                                        'path '
                                                                        "'/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': "
                                                                        'mkdir '
                                                                        '/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: '
                                                                        'file '
                                                                        'exists',
                                                             'reason': 'ContainerCannotRun',
                                                             'signal': None,
                                                             'started_at': datetime.datetime(2022, 5, 25, 21, 31, 16, tzinfo=tzlocal())},
                                              'waiting': None}}],

To Reproduce see above

Expected behavior mount success

Urgency Describe the impact and urgency of the bug.

Are you planning to fix it No.

Additional context ...

ssz1997 commented 2 years ago

@takersk Saw your comment at https://github.com/Alluxio/alluxio/issues/15235#issuecomment-1138044215. To confirm, were you using a non-root Alluxio path for mounting? Did you try use the Alluxio root path?

takersk commented 2 years ago

@ssz1997 thank you for confirmation. I am using Alluxio root path .

...

'persistent_volume_claim': {'claim_name': 'alluxio-airflow-pvc', 'read_only': None},

...

'state': {'running': None, 'terminated': {'container_id': 'docker://671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43', 'exit_code': 128, 'finished_at': datetime.datetime(2022, 5, 25, 21, 31, 16, tzinfo=tzlocal()), 'message': 'error ' 'while ' 'creating ' 'mount ' 'source ' 'path ' "'/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': " 'mkdir ' '/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: ' 'file ' 'exists', 'reason': 'ContainerCannotRun', 'signal': None, 'started_at': datetime.datetime(2022, 5, 25, 21, 31, 16, tzinfo=tzlocal())}, 'waiting': None}}],


* kubelet logs

root@dkosv3-cdp-ml-prod-worker-8:/var/log# cat kubelet.ERROR | grep cf0d1c24-a325-433b-b371-464e63181b95 E0526 06:31:17.236673 4536 remote_runtime.go:222] StartContainer "671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43" from runtime service failed: rpc error: code = Unknown desc = failed to start container "671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists E0526 06:31:17.236746 4536 kuberuntime_manager.go:809] container start failed: RunContainerError: failed to start container "671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists E0526 06:31:17.236792 4536 pod_workers.go:191] Error syncing pod cf0d1c24-a325-433b-b371-464e63181b95 ("etl-gift-stats-also-buy-product.19ad0eec871c41a39f3336791c166347_airflow(cf0d1c24-a325-433b-b371-464e63181b95)"), skipping: failed to "StartContainer" for "base" with RunContainerError: "failed to start container \"671240747c7f34a0718dc7b097dafa4f58fdfae6de7af1306626cb1b01e4fc43\": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/cf0d1c24-a325-433b-b371-464e63181b95/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists"

ssz1997 commented 2 years ago

@takersk I'll look into this. In the mean time, can you try change the accessMode in your pv and pvc to ReadWriteOnce and try again? Thanks!

takersk commented 2 years ago

@ssz1997 I changed accessMode to ReadWriteOnce but, Unfortunately I am getting the same error.

ssz1997 commented 2 years ago

@takersk Can you help check:

  1. What version of Kubernetes are you using?
  2. In csi-nodeserver container in csi nodeplugin pod, can you upload the log in /opt/alluxio/fuse.log and /opt/alluxio/fuse.out? Thanks!
takersk commented 2 years ago

@ssz1997 hi!! I'll answer your question~~ thanks!!

  1. What version of Kubernetes are you using? k8s version : v1.17.12

  2. In csi-nodeserver container in csi nodeplugin pod, can you upload the log in /opt/alluxio/fuse.log and /opt/alluxio/fuse.out?


* /opt/alluxio/fuse.out

Exception in thread "Thread-3" alluxio.jnifuse.FuseException: Unable to umount FS with exit code 1 at alluxio.jnifuse.AbstractFuseFileSystem.umountInternal(AbstractFuseFileSystem.java:172) at alluxio.jnifuse.AbstractFuseFileSystem.umount(AbstractFuseFileSystem.java:125) at alluxio.fuse.AlluxioJniFuseFileSystem.umount(AlluxioJniFuseFileSystem.java:1041) at alluxio.jnifuse.AbstractFuseFileSystem.lambda$mount$0(AbstractFuseFileSystem.java:91) at java.lang.Thread.run(Thread.java:748) INFO ../../src/main/native/libjnifuse/jnifuse_helper.cc:33 Start initializing JNIFuse INFO ../../src/main/native/libjnifuse/jnifuse_helper.cc:88 JNIFuse initialized

ssz1997 commented 2 years ago

@takersk Thanks. Unfortunately the info-level log doesn't provide enough information. Can you add the property alluxio.fuse.debug.enabled: true, restart the Alluxio cluster, reproduce this issue, then send the fuse.log and fuse.out over? We can then get the debug-level logs for further investigation.

takersk commented 2 years ago

@ssz1997 I'll switch to debug and share it again next week.

ssz1997 commented 2 years ago

@takersk Another thing you can try is to use the alluxio/alluxio:2.9.0-SNAPSHOT image, and set mountInPod in your storageclass/pv to true. The fuse processes will be isolated into respective pods in this mode, and may solve the issue.

takersk commented 2 years ago

@ssz1997 There are many things to consider when upgrading the version, so I will share the fuse-logs first.

** pods logs

 'state': {'running': None,
                                              'terminated': {'container_id': 'docker://5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2',
                                                             'exit_code': 128,
                                                             'finished_at': datetime.datetime(2022, 6, 6, 21, 1, tzinfo=tzlocal()),
                                                             'message': 'error '
                                                                        'while '
                                                                        'creating '
                                                                        'mount '
                                                                        'source '
                                                                        'path '
                                                                        "'/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': "
                                                                        'mkdir '
                                                                        '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: '
                                                                        'file '
                                                                        'exists',
                                                             'reason': 'ContainerCannotRun',
                                                             'signal': None,
                                                             'started_at': datetime.datetime(2022, 6, 6, 21, 1, tzinfo=tzlocal())},
                                              'waiting': None}}],

** fuse.log (debug)

2022-06-03 21:00:30,083 INFO  AlluxioFuse - Alluxio version: 2.8.0-bcb29e5a8e5bab1f4559b38c161e090a51c3fa8f
2022-06-03 21:00:30,466 INFO  NativeLibraryLoader - Loaded lib by jar from path /tmp/libjnifuse4450524986429375457.so.
2022-06-03 21:00:30,466 INFO  NativeLibraryLoader - Loaded libjnifuse with libfuse version 2.
2022-06-03 21:00:30,563 INFO  MetricsSystem - Starting sinks with config: {}.
2022-06-03 21:00:30,574 INFO  MetricsHeartbeatContext - Created metrics heartbeat with ID app-68316877811854769. This ID will be used for identifying info from the client. It can be set manually through the alluxio.user.app.id property
2022-06-03 21:00:30,761 INFO  NettyUtils - EPOLL_MODE is available
2022-06-03 21:00:31,314 INFO  TieredIdentityFactory - Initialized tiered identity TieredIdentity(node=10.92.174.163, rack=null)
2022-06-03 21:00:31,573 INFO  Reflections - Reflections took 175 ms to scan 1 urls, producing 58 keys and 199 values 
2022-06-03 21:00:31,615 INFO  AlluxioFuse - Mounting AlluxioJniFuseFileSystem: mount point="/var/lib/kubelet/pods/6e209397-0425-4357-89b1-60345d19389e/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount", OPTIONS="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-03 21:00:31,615 INFO  AbstractFuseFileSystem - Mounting /var/lib/kubelet/pods/6e209397-0425-4357-89b1-60345d19389e/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: blocking=true, debug=true, fuseOpts="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-03 21:00:34,600 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/)
2022-06-03 21:00:34,801 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/) in 200 ms
2022-06-03 21:00:40,188 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage)
2022-06-03 21:00:40,201 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage) in 12 ms
2022-06-03 21:00:40,201 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai)
2022-06-03 21:00:40,214 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai) in 13 ms
2022-06-03 21:00:40,215 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz)
2022-06-03 21:00:40,223 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz) in 8 ms
2022-06-03 21:00:40,223 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages)
2022-06-03 21:00:40,234 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages) in 11 ms
2022-06-03 21:00:40,234 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03)
2022-06-03 21:00:40,244 DEBUG AlluxioJniFuseFileSystem - Failed to getattr /stage/kcai/giftbiz/messages/2022-06-03: path does not exist or is invalid
2022-06-03 21:00:40,247 DEBUG AlluxioJniFuseFileSystem - Exit (-2): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03) in 13 ms
2022-06-03 21:00:40,249 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Mkdir(path=/stage/kcai/giftbiz/messages/2022-06-03,mode=755,)
2022-06-03 21:00:40,290 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Mkdir(path=/stage/kcai/giftbiz/messages/2022-06-03,mode=755,) in 41 ms
2022-06-03 21:00:40,290 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03)
2022-06-03 21:00:40,294 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03) in 4 ms
2022-06-03 21:00:40,295 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet)
2022-06-03 21:00:40,298 DEBUG AlluxioJniFuseFileSystem - Failed to getattr /stage/kcai/giftbiz/messages/2022-06-03/raw.parquet: path does not exist or is invalid
2022-06-03 21:00:40,299 DEBUG AlluxioJniFuseFileSystem - Exit (-2): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet) in 4 ms
2022-06-03 21:00:40,422 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet)
2022-06-03 21:00:40,427 DEBUG AlluxioJniFuseFileSystem - Failed to getattr /stage/kcai/giftbiz/messages/2022-06-03/raw.parquet: path does not exist or is invalid
2022-06-03 21:00:40,427 DEBUG AlluxioJniFuseFileSystem - Exit (-2): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet) in 5 ms
2022-06-03 21:00:40,428 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet)
2022-06-03 21:00:40,432 DEBUG AlluxioJniFuseFileSystem - Failed to getattr /stage/kcai/giftbiz/messages/2022-06-03/raw.parquet: path does not exist or is invalid
2022-06-03 21:00:40,432 DEBUG AlluxioJniFuseFileSystem - Exit (-2): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet) in 4 ms
2022-06-03 21:00:40,435 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Create(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet,mode=100644)
2022-06-03 21:00:40,469 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Create(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet,mode=100644) in 34 ms
2022-06-03 21:00:40,469 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-03/raw.parquet)

...

2022-06-05 21:01:06,588 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=2678784)
2022-06-05 21:01:06,588 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=2678784) in 0 ms
2022-06-05 21:01:06,588 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=103087,offset=2809856)
2022-06-05 21:01:06,588 DEBUG AlluxioJniFuseFileSystem - Exit (103087): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=103087,offset=2809856) in 0 ms
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=581,offset=2912943)
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Exit (581): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=581,offset=2912943) in 0 ms
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2828,offset=2913524)
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Exit (2828): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2828,offset=2913524) in 0 ms
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=2916352)
2022-06-05 21:01:06,592 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=2916352) in 0 ms
2022-06-05 21:01:06,593 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3047424)
2022-06-05 21:01:06,593 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3047424) in 0 ms
2022-06-05 21:01:06,594 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=91021,offset=3178496)
2022-06-05 21:01:06,594 DEBUG AlluxioJniFuseFileSystem - Exit (91021): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=91021,offset=3178496) in 0 ms
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=323,offset=3269517)
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Exit (323): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=323,offset=3269517) in 0 ms
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2864,offset=3269840)
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Exit (2864): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2864,offset=3269840) in 0 ms
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3272704)
2022-06-05 21:01:06,598 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3272704) in 0 ms
2022-06-05 21:01:06,599 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3403776)
2022-06-05 21:01:06,599 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3403776) in 0 ms
2022-06-05 21:01:06,599 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=114494,offset=3534848)
2022-06-05 21:01:06,599 DEBUG AlluxioJniFuseFileSystem - Exit (114494): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=114494,offset=3534848) in 0 ms
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=194,offset=3649342)
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Exit (194): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=194,offset=3649342) in 0 ms
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=62,offset=3649536)
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Exit (62): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=62,offset=3649536) in 0 ms
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=4034,offset=3649598)
2022-06-05 21:01:06,602 DEBUG AlluxioJniFuseFileSystem - Exit (4034): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=4034,offset=3649598) in 0 ms
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3653632)
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3653632) in 0 ms
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3784704)
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3784704) in 0 ms
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=9830,offset=3915776)
2022-06-05 21:01:06,603 DEBUG AlluxioJniFuseFileSystem - Exit (9830): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=9830,offset=3915776) in 0 ms
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=518,offset=3925606)
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Exit (518): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=518,offset=3925606) in 0 ms
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1940,offset=3926124)
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Exit (1940): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1940,offset=3926124) in 0 ms
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3928064)
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=3928064) in 0 ms
2022-06-05 21:01:06,607 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=4059136)
2022-06-05 21:01:06,608 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=4059136) in 1 ms
2022-06-05 21:01:06,608 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=68087,offset=4190208)
2022-06-05 21:01:06,609 DEBUG AlluxioJniFuseFileSystem - Exit (68087): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=68087,offset=4190208) in 1 ms
2022-06-05 21:01:06,611 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=345,offset=4258295)
2022-06-05 21:01:06,611 DEBUG AlluxioJniFuseFileSystem - Exit (345): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=345,offset=4258295) in 0 ms
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1200,offset=4258640)
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Exit (1200): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1200,offset=4258640) in 0 ms
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=4259840)
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Exit (131072): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=131072,offset=4259840) in 0 ms
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=116694,offset=4390912)
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Exit (116694): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=116694,offset=4390912) in 0 ms
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2090,offset=4507606)
2022-06-05 21:01:06,612 DEBUG AlluxioJniFuseFileSystem - Exit (2090): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=2090,offset=4507606) in 0 ms
2022-06-05 21:01:06,613 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1536,offset=4509696)
2022-06-05 21:01:06,613 DEBUG AlluxioJniFuseFileSystem - Exit (1536): Fuse.Write(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1,size=1536,offset=4509696) in 0 ms
2022-06-05 21:01:06,613 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Flush(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1)
2022-06-05 21:01:06,613 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Flush(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1) in 0 ms
2022-06-05 21:01:06,613 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Release(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1)
2022-06-05 21:01:06,675 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Release(path=/stage/kcai/giftbiz/messages/2022-06-05/transform.parquet,fd=1) in 62 ms
2022-06-05 21:01:07,464 INFO  AbstractFuseFileSystem - Unmounting Fuse through shutdown hook
2022-06-05 21:01:07,464 INFO  AbstractFuseFileSystem - Umounting /var/lib/kubelet/pods/4deada83-9292-405e-b000-49591649cd10/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
2022-06-05 21:01:07,466 ERROR AbstractFuseFileSystem - Failed to umount /var/lib/kubelet/pods/4deada83-9292-405e-b000-49591649cd10/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
alluxio.jnifuse.FuseException: Unable to umount FS with exit code 1
    at alluxio.jnifuse.AbstractFuseFileSystem.umountInternal(AbstractFuseFileSystem.java:172)
    at alluxio.jnifuse.AbstractFuseFileSystem.umount(AbstractFuseFileSystem.java:125)
    at alluxio.fuse.AlluxioJniFuseFileSystem.umount(AlluxioJniFuseFileSystem.java:1041)
    at alluxio.jnifuse.AbstractFuseFileSystem.lambda$mount$0(AbstractFuseFileSystem.java:91)
    at java.lang.Thread.run(Thread.java:748)
2022-06-05 21:25:44,893 INFO  AlluxioFuse - Alluxio version: 2.8.0-bcb29e5a8e5bab1f4559b38c161e090a51c3fa8f
2022-06-05 21:25:45,253 INFO  NativeLibraryLoader - Loaded lib by jar from path /tmp/libjnifuse2210574007035359877.so.
2022-06-05 21:25:45,253 INFO  NativeLibraryLoader - Loaded libjnifuse with libfuse version 2.
2022-06-05 21:25:45,334 INFO  MetricsSystem - Starting sinks with config: {}.
2022-06-05 21:25:45,343 INFO  MetricsHeartbeatContext - Created metrics heartbeat with ID app-1700457275457099311. This ID will be used for identifying info from the client. It can be set manually through the alluxio.user.app.id property
2022-06-05 21:25:45,512 INFO  NettyUtils - EPOLL_MODE is available
2022-06-05 21:25:46,023 INFO  TieredIdentityFactory - Initialized tiered identity TieredIdentity(node=10.92.174.163, rack=null)
2022-06-05 21:25:46,319 INFO  Reflections - Reflections took 193 ms to scan 1 urls, producing 58 keys and 199 values 
2022-06-05 21:25:46,360 INFO  AlluxioFuse - Mounting AlluxioJniFuseFileSystem: mount point="/var/lib/kubelet/pods/3ede028d-66be-4a64-929e-c67a70b6a22a/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount", OPTIONS="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-05 21:25:46,360 INFO  AbstractFuseFileSystem - Mounting /var/lib/kubelet/pods/3ede028d-66be-4a64-929e-c67a70b6a22a/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: blocking=true, debug=true, fuseOpts="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-05 21:25:47,909 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/)
2022-06-05 21:25:48,069 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/) in 160 ms
2022-06-05 21:25:48,305 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage)
2022-06-05 21:25:48,314 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage) in 9 ms
2022-06-05 21:25:48,314 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai)
2022-06-05 21:25:48,323 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai) in 9 ms
2022-06-05 21:25:48,323 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz)
2022-06-05 21:25:48,329 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz) in 6 ms
2022-06-05 21:25:48,329 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages)
2022-06-05 21:25:48,337 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages) in 8 ms
2022-06-05 21:25:48,340 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Readdir(path=/stage/kcai/giftbiz/messages)
2022-06-05 21:25:48,363 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Readdir(path=/stage/kcai/giftbiz/messages) in 22 ms
2022-06-05 21:25:48,364 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05)
2022-06-05 21:25:48,390 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05) in 26 ms
2022-06-05 21:25:48,390 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Readdir(path=/stage/kcai/giftbiz/messages/2022-05-05)
2022-06-05 21:25:48,403 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Readdir(path=/stage/kcai/giftbiz/messages/2022-05-05) in 13 ms
2022-06-05 21:25:48,403 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/transform.parquet)
2022-06-05 21:25:48,407 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/transform.parquet) in 4 ms
2022-06-05 21:25:48,408 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/transform.parquet)
2022-06-05 21:25:48,431 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/transform.parquet) in 23 ms
2022-06-05 21:25:48,431 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/raw.parquet)
2022-06-05 21:25:48,436 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/raw.parquet) in 5 ms
2022-06-05 21:25:48,436 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/raw.parquet)
2022-06-05 21:25:48,446 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/raw.parquet) in 10 ms
2022-06-05 21:25:48,447 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/group_inference.parquet)
2022-06-05 21:25:48,451 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/group_inference.parquet) in 4 ms
2022-06-05 21:25:48,451 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/group_inference.parquet)
2022-06-05 21:25:48,465 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/group_inference.parquet) in 14 ms
2022-06-05 21:25:48,466 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/inference.parquet)
2022-06-05 21:25:48,470 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-05-05/inference.parquet) in 4 ms
2022-06-05 21:25:48,470 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/inference.parquet)
2022-06-05 21:25:48,481 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Unlink(path=/stage/kcai/giftbiz/messages/2022-05-05/inference.parquet) in 11 ms
2022-06-05 21:25:48,481 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Rmdir(path=/stage/kcai/giftbiz/messages/2022-05-05)
2022-06-05 21:25:48,499 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Rmdir(path=/stage/kcai/giftbiz/messages/2022-05-05) in 18 ms
2022-06-05 21:25:49,499 INFO  AbstractFuseFileSystem - Unmounting Fuse through shutdown hook
2022-06-05 21:25:49,499 INFO  AbstractFuseFileSystem - Umounting /var/lib/kubelet/pods/3ede028d-66be-4a64-929e-c67a70b6a22a/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
2022-06-05 21:25:49,502 ERROR AbstractFuseFileSystem - Failed to umount /var/lib/kubelet/pods/3ede028d-66be-4a64-929e-c67a70b6a22a/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
alluxio.jnifuse.FuseException: Unable to umount FS with exit code 1
    at alluxio.jnifuse.AbstractFuseFileSystem.umountInternal(AbstractFuseFileSystem.java:172)
    at alluxio.jnifuse.AbstractFuseFileSystem.umount(AbstractFuseFileSystem.java:125)
    at alluxio.fuse.AlluxioJniFuseFileSystem.umount(AlluxioJniFuseFileSystem.java:1041)
    at alluxio.jnifuse.AbstractFuseFileSystem.lambda$mount$0(AbstractFuseFileSystem.java:91)
    at java.lang.Thread.run(Thread.java:748)
2022-06-06 21:00:57,850 INFO  AlluxioFuse - Alluxio version: 2.8.0-bcb29e5a8e5bab1f4559b38c161e090a51c3fa8f
2022-06-06 21:00:58,204 INFO  NativeLibraryLoader - Loaded lib by jar from path /tmp/libjnifuse2717559219175875493.so.
2022-06-06 21:00:58,204 INFO  NativeLibraryLoader - Loaded libjnifuse with libfuse version 2.
2022-06-06 21:00:58,283 INFO  MetricsSystem - Starting sinks with config: {}.
2022-06-06 21:00:58,291 INFO  MetricsHeartbeatContext - Created metrics heartbeat with ID app-1987941659293887464. This ID will be used for identifying info from the client. It can be set manually through the alluxio.user.app.id property
2022-06-06 21:00:58,457 INFO  NettyUtils - EPOLL_MODE is available
2022-06-06 21:00:58,975 INFO  TieredIdentityFactory - Initialized tiered identity TieredIdentity(node=10.92.174.163, rack=null)
2022-06-06 21:00:59,264 INFO  Reflections - Reflections took 191 ms to scan 1 urls, producing 58 keys and 199 values 
2022-06-06 21:00:59,304 INFO  AlluxioFuse - Mounting AlluxioJniFuseFileSystem: mount point="/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount", OPTIONS="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-06 21:00:59,305 INFO  AbstractFuseFileSystem - Mounting /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: blocking=true, debug=true, fuseOpts="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-06 21:01:01,879 INFO  AbstractFuseFileSystem - Unmounting Fuse through shutdown hook
2022-06-06 21:01:01,880 INFO  AbstractFuseFileSystem - Umounting /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
2022-06-06 21:01:01,882 ERROR AbstractFuseFileSystem - Failed to umount /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount
alluxio.jnifuse.FuseException: Unable to umount FS with exit code 1
    at alluxio.jnifuse.AbstractFuseFileSystem.umountInternal(AbstractFuseFileSystem.java:172)
    at alluxio.jnifuse.AbstractFuseFileSystem.umount(AbstractFuseFileSystem.java:125)
    at alluxio.fuse.AlluxioJniFuseFileSystem.umount(AlluxioJniFuseFileSystem.java:1041)
    at alluxio.jnifuse.AbstractFuseFileSystem.lambda$mount$0(AbstractFuseFileSystem.java:91)
    at java.lang.Thread.run(Thread.java:748)
2022-06-06 21:02:15,546 INFO  AlluxioFuse - Alluxio version: 2.8.0-bcb29e5a8e5bab1f4559b38c161e090a51c3fa8f
2022-06-06 21:02:15,902 INFO  NativeLibraryLoader - Loaded lib by jar from path /tmp/libjnifuse1844611896834546330.so.
2022-06-06 21:02:15,902 INFO  NativeLibraryLoader - Loaded libjnifuse with libfuse version 2.
2022-06-06 21:02:15,981 INFO  MetricsSystem - Starting sinks with config: {}.
2022-06-06 21:02:15,989 INFO  MetricsHeartbeatContext - Created metrics heartbeat with ID app-7192947363258653197. This ID will be used for identifying info from the client. It can be set manually through the alluxio.user.app.id property
2022-06-06 21:02:16,156 INFO  NettyUtils - EPOLL_MODE is available
2022-06-06 21:02:16,663 INFO  TieredIdentityFactory - Initialized tiered identity TieredIdentity(node=10.92.174.163, rack=null)
2022-06-06 21:02:16,951 INFO  Reflections - Reflections took 188 ms to scan 1 urls, producing 58 keys and 199 values 
2022-06-06 21:02:16,992 INFO  AlluxioFuse - Mounting AlluxioJniFuseFileSystem: mount point="/var/lib/kubelet/pods/bedf0a80-fddd-4296-8afd-9608af7ad108/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount", OPTIONS="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-06 21:02:16,992 INFO  AbstractFuseFileSystem - Mounting /var/lib/kubelet/pods/bedf0a80-fddd-4296-8afd-9608af7ad108/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: blocking=true, debug=true, fuseOpts="[-obig_writes, -oallow_other, -oentry_timeout=36000, -oattr_timeout=36000, -omax_readahead=0, -omax_write=131072]"
2022-06-06 21:02:18,560 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/)
2022-06-06 21:02:18,724 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/) in 164 ms
2022-06-06 21:02:20,159 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage)
2022-06-06 21:02:20,167 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage) in 8 ms
2022-06-06 21:02:20,167 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai)
2022-06-06 21:02:20,177 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai) in 9 ms
2022-06-06 21:02:20,177 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz)
2022-06-06 21:02:20,182 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz) in 5 ms
2022-06-06 21:02:20,183 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages)
2022-06-06 21:02:20,194 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages) in 11 ms
2022-06-06 21:02:20,194 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-06)
2022-06-06 21:02:20,200 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-06) in 6 ms
2022-06-06 21:02:20,201 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet)
2022-06-06 21:02:20,216 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Getattr(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet) in 15 ms
2022-06-06 21:02:20,225 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Open(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,flags=0x8000(READ_ONLY))
2022-06-06 21:02:20,242 DEBUG AlluxioJniFuseFileSystem - Exit (0): Fuse.Open(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,flags=0x8000(READ_ONLY)) in 17 ms
2022-06-06 21:02:20,265 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3854336)
2022-06-06 21:02:20,351 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3854336) in 86 ms
2022-06-06 21:02:20,351 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3858432)
2022-06-06 21:02:20,351 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3858432) in 0 ms
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3862528)
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3862528) in 0 ms
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3866624)
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3866624) in 0 ms
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3870720)
2022-06-06 21:02:20,352 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3870720) in 0 ms
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3874816)
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3874816) in 0 ms
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3878912)
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3878912) in 0 ms
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3883008)
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3883008) in 0 ms
2022-06-06 21:02:20,353 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3887104)
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3887104) in 0 ms
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3891200)
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3891200) in 0 ms
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3895296)
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3895296) in 0 ms
2022-06-06 21:02:20,354 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3899392)
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3899392) in 0 ms
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3903488)
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3903488) in 0 ms
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3907584)
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3907584) in 0 ms
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3911680)
2022-06-06 21:02:20,355 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3911680) in 0 ms
2022-06-06 21:02:20,356 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3915776)
2022-06-06 21:02:20,356 DEBUG AlluxioJniFuseFileSystem - Exit (4096): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3915776) in 0 ms
2022-06-06 21:02:20,356 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3919872)
2022-06-06 21:02:20,366 DEBUG AlluxioJniFuseFileSystem - Exit (3252): Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=3919872) in 10 ms
2022-06-06 21:02:20,368 DEBUG AlluxioJniFuseFileSystem - Enter: Fuse.Read(path=/stage/kcai/giftbiz/messages/2022-06-06/raw.parquet,fd=0,size=4096,offset=0)

... END

** fuse.out (debug)

Exception in thread "Thread-3" alluxio.jnifuse.FuseException: Unable to umount FS with exit code 1
    at alluxio.jnifuse.AbstractFuseFileSystem.umountInternal(AbstractFuseFileSystem.java:172)
    at alluxio.jnifuse.AbstractFuseFileSystem.umount(AbstractFuseFileSystem.java:125)
    at alluxio.fuse.AlluxioJniFuseFileSystem.umount(AlluxioJniFuseFileSystem.java:1041)
    at alluxio.jnifuse.AbstractFuseFileSystem.lambda$mount$0(AbstractFuseFileSystem.java:91)
    at java.lang.Thread.run(Thread.java:748)
INFO ../../src/main/native/libjnifuse/jnifuse_helper.cc:33 Start initializing JNIFuse
INFO ../../src/main/native/libjnifuse/jnifuse_helper.cc:88 JNIFuse initialized
ssz1997 commented 2 years ago

@takersk Thanks. Can you also share the log of the nodeserver on the sama machine?

takersk commented 2 years ago

@ssz1997 Can I share the sama machine kubelet log?

$ cat kubelet.ERROR | grep 34fa28d2-2a44-4e01-b37a-85fa6f56730f

E0607 06:01:00.666435  538690 remote_runtime.go:222] StartContainer "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2" from runtime service failed: rpc error: code = Unknown desc = failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666500  538690 kuberuntime_manager.go:809] container start failed: RunContainerError: failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666540  538690 pod_workers.go:191] Error syncing pod 34fa28d2-2a44-4e01-b37a-85fa6f56730f ("etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"), skipping: failed to "StartContainer" for "base" with RunContainerError: "failed to start container \"5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2\": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists"

$ kubelet.INFO | grep 34fa28d2-2a44-4e01-b37a-85fa6f56730f

I0607 06:00:57.220360  538690 kubelet.go:1909] SyncLoop (ADD, "api"): "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"
I0607 06:00:57.391702  538690 reconciler.go:209] operationExecutor.VerifyControllerAttachedVolume started for volume "alluxio-airflow-pv" (UniqueName: "kubernetes.io/csi/alluxio^alluxio") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:57.391735  538690 reconciler.go:209] operationExecutor.VerifyControllerAttachedVolume started for volume "airflow-worker-token-bkx8f" (UniqueName: "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:57.491925  538690 reconciler.go:254] operationExecutor.MountVolume started for volume "alluxio-airflow-pv" (UniqueName: "kubernetes.io/csi/alluxio^alluxio") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:57.491962  538690 reconciler.go:254] operationExecutor.MountVolume started for volume "airflow-worker-token-bkx8f" (UniqueName: "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:57.493422  538690 operation_generator.go:587] MountVolume.MountDevice succeeded for volume "alluxio-airflow-pv" (UniqueName: "kubernetes.io/csi/alluxio^alluxio") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f") device mount path "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/alluxio-airflow-pv/globalmount"
I0607 06:00:57.502202  538690 operation_generator.go:634] MountVolume.SetUp succeeded for volume "airflow-worker-token-bkx8f" (UniqueName: "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:59.621511  538690 operation_generator.go:634] MountVolume.SetUp succeeded for volume "alluxio-airflow-pv" (UniqueName: "kubernetes.io/csi/alluxio^alluxio") pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:00:59.646046  538690 kuberuntime_manager.go:430] No sandbox for pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)" can be found. Need to start a new one
I0607 06:00:59.850369  538690 kubelet.go:1954] SyncLoop (PLEG): "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)", event: &pleg.PodLifecycleEvent{ID:"34fa28d2-2a44-4e01-b37a-85fa6f56730f", Type:"ContainerDied", Data:"c1ca73aab945f45118741f4b730be64d2ad5e05778e92b988181d544d0fb612e"}
E0607 06:01:00.666435  538690 remote_runtime.go:222] StartContainer "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2" from runtime service failed: rpc error: code = Unknown desc = failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666500  538690 kuberuntime_manager.go:809] container start failed: RunContainerError: failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666540  538690 pod_workers.go:191] Error syncing pod 34fa28d2-2a44-4e01-b37a-85fa6f56730f ("etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"), skipping: failed to "StartContainer" for "base" with RunContainerError: "failed to start container \"5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2\": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists"
I0607 06:01:00.864475  538690 kubelet.go:1954] SyncLoop (PLEG): "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)", event: &pleg.PodLifecycleEvent{ID:"34fa28d2-2a44-4e01-b37a-85fa6f56730f", Type:"ContainerStarted", Data:"c1ca73aab945f45118741f4b730be64d2ad5e05778e92b988181d544d0fb612e"}
I0607 06:01:00.998028  538690 reconciler.go:183] operationExecutor.UnmountVolume started for volume "data-volume" (UniqueName: "kubernetes.io/csi/alluxio^alluxio") pod "34fa28d2-2a44-4e01-b37a-85fa6f56730f" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:01:00.998072  538690 reconciler.go:183] operationExecutor.UnmountVolume started for volume "airflow-worker-token-bkx8f" (UniqueName: "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f") pod "34fa28d2-2a44-4e01-b37a-85fa6f56730f" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f")
I0607 06:01:01.000088  538690 operation_generator.go:713] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f" (OuterVolumeSpecName: "airflow-worker-token-bkx8f") pod "34fa28d2-2a44-4e01-b37a-85fa6f56730f" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f"). InnerVolumeSpecName "airflow-worker-token-bkx8f". PluginName "kubernetes.io/secret", VolumeGidValue ""
I0607 06:01:01.098401  538690 reconciler.go:303] Volume detached for volume "airflow-worker-token-bkx8f" (UniqueName: "kubernetes.io/secret/34fa28d2-2a44-4e01-b37a-85fa6f56730f-airflow-worker-token-bkx8f") on node "dkosv3-cdp-ml-stage-worker-t694" DevicePath ""
I0607 06:01:01.116446  538690 operation_generator.go:713] UnmountVolume.TearDown succeeded for volume "kubernetes.io/csi/alluxio^alluxio" (OuterVolumeSpecName: "data-volume") pod "34fa28d2-2a44-4e01-b37a-85fa6f56730f" (UID: "34fa28d2-2a44-4e01-b37a-85fa6f56730f"). InnerVolumeSpecName "alluxio-airflow-pv". PluginName "kubernetes.io/csi", VolumeGidValue ""
I0607 06:01:01.316095  538690 kubelet.go:1925] SyncLoop (DELETE, "api"): "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"
I0607 06:01:01.321218  538690 kubelet.go:1919] SyncLoop (REMOVE, "api"): "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"
I0607 06:01:01.321245  538690 kubelet.go:2118] Failed to delete pod "etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)", err: pod not found
W0607 06:01:01.741685  538690 kubelet_getters.go:297] Path "/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes" does not exist
I0607 06:01:01.874931  538690 status_manager.go:542] Status for pod "34fa28d2-2a44-4e01-b37a-85fa6f56730f" is up-to-date; skipping

$ cat kubelet.WARNING | grep 34fa28d2-2a44-4e01-b37a-85fa6f56730f

E0607 06:01:00.666435  538690 remote_runtime.go:222] StartContainer "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2" from runtime service failed: rpc error: code = Unknown desc = failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666500  538690 kuberuntime_manager.go:809] container start failed: RunContainerError: failed to start container "5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists
E0607 06:01:00.666540  538690 pod_workers.go:191] Error syncing pod 34fa28d2-2a44-4e01-b37a-85fa6f56730f ("etl-giftbiz-message-transform-dfa1a881daf04279a65dfd2c937e960b_airflow(34fa28d2-2a44-4e01-b37a-85fa6f56730f)"), skipping: failed to "StartContainer" for "base" with RunContainerError: "failed to start container \"5965c53d01d673adf44ea791d4483ab63344d0dda549e3f9a41874fce6a29cd2\": Error response from daemon: error while creating mount source path '/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount': mkdir /var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes/kubernetes.io~csi/alluxio-airflow-pv/mount: file exists"
W0607 06:01:01.741685  538690 kubelet_getters.go:297] Path "/var/lib/kubelet/pods/34fa28d2-2a44-4e01-b37a-85fa6f56730f/volumes" does not exist
takersk commented 2 years ago

hi!! Are you still in the process of resolving the issue?

ssz1997 commented 2 years ago

@takersk Seems like this is not a deterministic failure right? This pr https://github.com/Alluxio/alluxio/pull/15788 may fix it. You can try it out.

takersk commented 2 years ago

@ssz1997 thank you I'll test it when the tag version goes up.

takersk commented 2 years ago

@ssz1997 I applied the code patch, and after a few days of monitoring, I will share the results.

takersk commented 2 years ago

@ssz1997 hi!! No issues have occurred since apply on 08.03. please close the issue

스크린샷 2022-08-08 오전 11 19 18
ssz1997 commented 2 years ago

@tak Glad to hear it's resolved. Thanks for reporting!