Comments (18)
gman0
commented on August 26, 2024
1
It should've exited after the error you were getting (I'm guessing this is related to #133 ?) . We could add a timeout for such cases when we encounter a run-away process like this one.
from ceph-csi.
Madhu-1
commented on August 26, 2024
@rootfs ^^
from ceph-csi.
gman0
commented on August 26, 2024
What exactly is this log of?
from ceph-csi.
Madhu-1
commented on August 26, 2024
this is the log of ps -ef |grep ceph-fuse from plugin container. due to the hang state mutliple ceph-fuse for same PVC
from ceph-csi.
Madhu-1
commented on August 26, 2024
yes, it's better to add a timeout to avoid this situation.
from ceph-csi.
Madhu-1
commented on August 26, 2024
but this is not related to #133, this I have tested with the latest plugin image from quay.io/cephcsi/cephfsplugin:v1.0.0
i was facing #133 because of my own plugin image
from ceph-csi.
Madhu-1
commented on August 26, 2024
this is the error message am getting on provisioner pod
I0122 18:04:00.906176 1 controller.go:121] GRPC call: /csi.v1.Controller/CreateVolume
I0122 18:04:00.906201 1 controller.go:122] GRPC request: name:"pvc-279b619c-1e6d-11e9-8331-52540035463f" capacity_range:<required_bytes:5368709120 > volume_capabilities:<mount:<fs_type:"ext4" > access_mode:<mode:MULTI_NODE_MULTI_WRITER > > parameters:<key:"csiNodeStageSecretName" value:"csi-cephfs-secret" > parameters:<key:"csiNodeStageSecretNamespace" value:"default" > parameters:<key:"csiProvisionerSecretName" value:"csi-cephfs-secret" > parameters:<key:"csiProvisionerSecretNamespace" value:"default" > parameters:<key:"monitors" value:"rook-ceph-mon-b.rook-ceph.svc.cluster.local:6790" > parameters:<key:"pool" value:"cephfs_data" > parameters:<key:"provisionVolume" value:"true" > secrets:<key:"adminID" value:"admin" > secrets:<key:"adminKey" value:"AQBZg0VcRUNIGxAACmSPMmTI89vdAESBIoiqhQ==" >
I0122 18:04:10.906527 1 controller.go:124] GRPC response:
I0122 18:04:10.906662 1 controller.go:125] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded
W0122 18:04:10.906754 1 controller.go:490] CreateVolume timeout: 10s has expired, operation will be retried
I0122 18:04:15.906969 1 controller.go:121] GRPC call: /csi.v1.Controller/CreateVolume
from ceph-csi.
gman0
commented on August 26, 2024
Would you happen to have cephfsplugin's logs as well?
from ceph-csi.
Madhu-1
commented on August 26, 2024
no specific error log in plugin pod
I0122 18:59:43.187855 1 util.go:41] cephfs: EXEC ceph-fuse [/var/lib/kubelet/plugins_registry/csi-cephfsplugin/controller/volumes/root-csi-cephfs-pvc-a4920ecb-1e77-11e9-8331-52540035463f -c /etc/ceph/ceph.share.csi-cephfs-pvc-a4920ecb-1e77-11e9-8331-52540035463f.conf -n client.admin --keyring /etc/ceph/ceph.share.csi-cephfs-pvc-a4920ecb-1e77-11e9-8331-52540035463f.client.admin.keyring -r / -o nonempty]
I0122 18:59:55.628890 1 utils.go:97] GRPC call: /csi.v1.Controller/CreateVolume
I0122 18:59:55.629010 1 utils.go:98] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ca34cee1-1e77-11e9-8331-52540035463f","parameters":{"csiNodeStageSecretName":"csi-cephfs-secret","csiNodeStageSecretNamespace":"default","csiProvisionerSecretName":"csi-cephfs-secret","csiProvisionerSecretNamespace":"default","monitors":"rook-ceph-mon-b.rook-ceph.svc.cluster.local:6790","pool":"cephfs_data","provisionVolume":"true"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":5}}]}
I0122 18:59:55.654971 1 util.go:41] cephfs: EXEC ceph-fuse [/var/lib/kubelet/plugins_registry/csi-cephfsplugin/controller/volumes/root-csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f -c /etc/ceph/ceph.share.csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f.conf -n client.admin --keyring /etc/ceph/ceph.share.csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f.client.admin.keyring -r / -o nonempty]
but we i manually ran
kube exec -it csi-cephfsplugin-v7kr2 -c csi-cephfsplugin /bin/bash
[root@kube3 /]# ceph-fuse /var/lib/kubelet/plugins_registry/csi-cephfsplugin/controller/volumes/root-csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f -c /etc/ceph/ceph.share.csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f.conf -n client.admin --keyring /etc/ceph/ceph.share.csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f.client.admin.keyring -r / -o nonempty
2019-01-22 19:01:26.966050 7f80ffb2d0c0 -1 asok(0x5625363a21c0) AdminSocketConfigObs::init: failed: AdminSocket::bind_and_listen: failed to bind the UNIX domain socket to '/var/run/ceph/ceph.share.csi-cephfs-pvc-ca34cee1-1e77-11e9-8331-52540035463f-client.admin.asok': (17) File exists
2019-01-22 19:01:26.981027 7f80ffb2d0c0 -1 init, newargv = 0x5625363a1c00 newargc=11
ceph-fuse[350]: starting ceph client
then it got hang
from ceph-csi.
gman0
commented on August 26, 2024
Ok well, what I wanted to see in the logs is whether any of theCreateVolume calls got through, or if it just hangs on mount all together right from the start - if that's the case, I'd look somewhere else for the cause of this problem. Either way, the plugin has to synchronize with the exec and must block until the process finishes.
from ceph-csi.
rootfs
commented on August 26, 2024
@Madhu-1 still have the problem?
from ceph-csi.
Madhu-1
commented on August 26, 2024
@rootfs yes still I have this error.
from ceph-csi.
gman0
commented on August 26, 2024
@Madhu-1 you're deploying ceph using rook, right? I finally got around to try it and I haven't run into the problem you're describing :/ I've used all default values, the only thing I've changed was to deploy only 1 monitor instead of 3.
from ceph-csi.
gman0
commented on August 26, 2024
I did a bit testing with csi-cephfs + rook and requested 10 PVCs at once. Once the provisioning completed (10 bound PVCs):
one sleeping ceph-fuse process
root@csi-cephfsplugin-provisioner-0:/# ps aux
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.1 0.6 129512 24184 ? Ssl 21:23 0:00 /cephfsplugin --nodeid=kmaster1 --endpoint=unix://var/lib/kubelet/plugins/csi-cephfsplugin/csi-provisioner.sock --v=5 --drivername=csi
root 5042 0.0 0.4 426164 17120 ? Sl 21:31 0:00 ceph-fuse /var/lib/kubelet/plugins/csi-cephfsplugin/controller/volumes/root-csi-cephfs-pvc-d4504bdd-3943-11e9-a432-52540013b951 -m 10.
root 5472 0.5 0.0 18252 3380 pts/1 Ss 21:32 0:00 bash
root 5481 0.0 0.0 34420 2916 pts/1 R+ 21:32 0:00 ps aux
an abort in ceph-fuse reported in /var/log/ceph/ceph-client.admin.log
2019-02-25 21:25:57.567 7f314af45c00 0 ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable), process ceph-fuse, pid 335
2019-02-25 21:25:57.567 7f314af45c00 0 pidfile_write: ignore empty --pid-file
2019-02-25 21:25:57.571 7f314af45c00 -1 init, newargv = 0x19ddb20 newargc=9
2019-02-25 21:25:57.571 7f314af45c00 -1 auth: unable to find a keyring on /etc/ceph/ceph.client.admin.keyring,/etc/ceph/ceph.keyring,/etc/ceph/keyring,/etc/ceph/keyring.bin,: (2) No such file or directory
2019-02-25 21:25:58.151 7f3133b7e700 -1 client.39324 failed to remount (to trim kernel dentries): return code = 1
2019-02-25 21:25:58.151 7f3133b7e700 -1 client.39324 failed to remount for kernel dentry trimming; quitting!
2019-02-25 21:25:58.151 7f3133b7e700 -1 *** Caught signal (Aborted) **
in thread 7f3133b7e700 thread_name:tester
ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: ceph-fuse() [0x4f34b0]
2: (()+0x11390) [0x7f31418d0390]
3: (gsignal()+0x38) [0x7f314101d428]
4: (abort()+0x16a) [0x7f314101f02a]
5: (Client::_do_remount()+0x398) [0x4b1cb8]
6: (Client::test_dentry_handling(bool)+0x1f0) [0x4b1ef0]
7: ceph-fuse() [0x440e2d]
8: (()+0x76ba) [0x7f31418c66ba]
9: (clone()+0x6d) [0x7f31410ef41d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- begin dump of recent events ---
-177> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perfcounters_dump hook 0x19e0110
-176> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command 1 hook 0x19e0110
-175> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perf dump hook 0x19e0110
-174> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perfcounters_schema hook 0x19e0110
-173> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perf histogram dump hook 0x19e0110
-172> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command 2 hook 0x19e0110
-171> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perf schema hook 0x19e0110
-170> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perf histogram schema hook 0x19e0110
-169> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command perf reset hook 0x19e0110
-168> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config show hook 0x19e0110
-167> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config help hook 0x19e0110
-166> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config set hook 0x19e0110
-165> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config unset hook 0x19e0110
-164> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config get hook 0x19e0110
-163> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config diff hook 0x19e0110
-162> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command config diff get hook 0x19e0110
-161> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command log flush hook 0x19e0110
-160> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command log dump hook 0x19e0110
-159> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command log reopen hook 0x19e0110
-158> 2019-02-25 21:25:57.551 7f314af45c00 5 asok(0x1a08240) register_command dump_mempools hook 0x1a5a068
-157> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient: get_monmap_and_config
-156> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient: build_initial_monmap
-155> 2019-02-25 21:25:57.559 7f313c38f700 2 Event(0x1a08e00 nevent=5000 time_id=1).set_owner idx=2 owner=139849440491264
-154> 2019-02-25 21:25:57.559 7f313cb90700 2 Event(0x1a08500 nevent=5000 time_id=1).set_owner idx=1 owner=139849448883968
-153> 2019-02-25 21:25:57.559 7f313d391700 2 Event(0x1a08bc0 nevent=5000 time_id=1).set_owner idx=0 owner=139849457276672
-152> 2019-02-25 21:25:57.559 7f314af45c00 1 Processor -- start
-151> 2019-02-25 21:25:57.559 7f314af45c00 1 -- - start start
-150> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient: init
-149> 2019-02-25 21:25:57.559 7f314af45c00 5 adding auth protocol: cephx
-148> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient: auth_supported 2 method cephx
-147> 2019-02-25 21:25:57.559 7f314af45c00 -1 auth: unable to find a keyring on /etc/ceph/ceph.client.admin.keyring,/etc/ceph/ceph.keyring,/etc/ceph/keyring,/etc/ceph/keyring.bin,: (2) No such file or directory
-146> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient: _reopen_session rank -1
-145> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient(hunting): picked mon.noname-c con 0x1c50700 addr 10.101.181.49:6789/0
-144> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient(hunting): picked mon.noname-b con 0x1c50e00 addr 10.100.212.130:6789/0
-143> 2019-02-25 21:25:57.559 7f314af45c00 1 -- - --> 10.100.212.130:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x1bbe780 con 0
-142> 2019-02-25 21:25:57.559 7f314af45c00 1 -- - --> 10.101.181.49:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x1bbea00 con 0
-141> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient(hunting): _renew_subs
-140> 2019-02-25 21:25:57.559 7f314af45c00 10 monclient(hunting): authenticate will time out at 2019-02-25 21:30:57.565753
-139> 2019-02-25 21:25:57.559 7f313c38f700 1 -- 10.244.0.254:0/693432054 learned_addr learned my addr 10.244.0.254:0/693432054
-138> 2019-02-25 21:25:57.563 7f313c38f700 2 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-137> 2019-02-25 21:25:57.563 7f313cb90700 2 -- 10.244.0.254:0/693432054 >> 10.101.181.49:6789/0 conn(0x1c50700 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-136> 2019-02-25 21:25:57.563 7f313c38f700 5 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2261 cs=1 l=1). rx mon.0 seq 1 0x1a09680 mon_map magic: 0 v1
-135> 2019-02-25 21:25:57.563 7f313c38f700 5 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2261 cs=1 l=1). rx mon.0 seq 2 0x1bbe780 auth_reply(proto 2 0 (0) Success) v1
-134> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 <== mon.0 10.100.212.130:6789/0 1 ==== mon_map magic: 0 v1 ==== 361+0+0 (3007813193 0 0) 0x1a09680 con 0x1c50e00
-133> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-132> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient(hunting): got monmap 3, mon.noname-b is now rank -1
-131> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient(hunting): dump:
epoch 3
fsid d150cf0b-c27d-45ff-947b-b71a07bedd69
last_changed 2019-02-21 14:17:21.414482
created 2019-02-21 14:16:14.518883
0: 10.100.212.130:6789/0 mon.b
1: 10.101.181.49:6789/0 mon.c
2: 10.103.49.162:6789/0 mon.a
-130> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 <== mon.0 10.100.212.130:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (2010286927 0 0) 0x1bbe780 con 0x1c50e00
-129> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient(hunting): my global_id is 39321
-128> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 --> 10.100.212.130:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x1bbef00 con 0
-127> 2019-02-25 21:25:57.563 7f313c38f700 5 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2261 cs=1 l=1). rx mon.0 seq 3 0x1bbef00 auth_reply(proto 2 0 (0) Success) v1
-126> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 <== mon.0 10.100.212.130:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (4205552282 0 0) 0x1bbef00 con 0x1c50e00
-125> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 >> 10.101.181.49:6789/0 conn(0x1c50700 :-1 s=STATE_OPEN pgs=2341 cs=1 l=1).mark_down
-124> 2019-02-25 21:25:57.563 7f313bb8e700 2 -- 10.244.0.254:0/693432054 >> 10.101.181.49:6789/0 conn(0x1c50700 :-1 s=STATE_OPEN pgs=2341 cs=1 l=1)._stop
-123> 2019-02-25 21:25:57.563 7f313bb8e700 1 monclient: found mon.b
-122> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient: _send_mon_message to mon.b at 10.100.212.130:6789/0
-121> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 --> 10.100.212.130:6789/0 -- mon_subscribe({config=0+,monmap=0+}) v3 -- 0x1a08fc0 con 0
-120> 2019-02-25 21:25:57.563 7f314af45c00 5 monclient: authenticate success, global_id 39321
-119> 2019-02-25 21:25:57.563 7f313c38f700 5 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2261 cs=1 l=1). rx mon.0 seq 4 0x1a08fc0 config(0 keys) v1
-118> 2019-02-25 21:25:57.563 7f313c38f700 5 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2261 cs=1 l=1). rx mon.0 seq 5 0x1a098c0 mon_map magic: 0 v1
-117> 2019-02-25 21:25:57.563 7f313bb8e700 1 -- 10.244.0.254:0/693432054 <== mon.0 10.100.212.130:6789/0 4 ==== config(0 keys) v1 ==== 4+0+0 (0 0 0) 0x1a08fc0 con 0x1c50e00
-116> 2019-02-25 21:25:57.563 7f313bb8e700 10 monclient: handle_config config(0 keys) v1
-115> 2019-02-25 21:25:57.563 7f313a38b700 4 set_mon_vals no callback set
-114> 2019-02-25 21:25:57.563 7f314af45c00 10 monclient: get_monmap_and_config success
-113> 2019-02-25 21:25:57.563 7f314af45c00 10 monclient: shutdown
-112> 2019-02-25 21:25:57.563 7f314af45c00 1 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN pgs=2261 cs=1 l=1).mark_down
-111> 2019-02-25 21:25:57.563 7f314af45c00 2 -- 10.244.0.254:0/693432054 >> 10.100.212.130:6789/0 conn(0x1c50e00 :-1 s=STATE_OPEN pgs=2261 cs=1 l=1)._stop
-110> 2019-02-25 21:25:57.563 7f314af45c00 1 -- 10.244.0.254:0/693432054 shutdown_connections
-109> 2019-02-25 21:25:57.563 7f314af45c00 5 -- 10.244.0.254:0/693432054 shutdown_connections mark down 10.100.212.130:6789/0 0x1c50e00
-108> 2019-02-25 21:25:57.563 7f314af45c00 5 -- 10.244.0.254:0/693432054 shutdown_connections mark down 10.101.181.49:6789/0 0x1c50700
-107> 2019-02-25 21:25:57.563 7f314af45c00 5 -- 10.244.0.254:0/693432054 shutdown_connections delete 0x1c50700
-106> 2019-02-25 21:25:57.563 7f314af45c00 5 -- 10.244.0.254:0/693432054 shutdown_connections delete 0x1c50e00
-105> 2019-02-25 21:25:57.563 7f314af45c00 1 -- 10.244.0.254:0/693432054 shutdown_connections
-104> 2019-02-25 21:25:57.563 7f314af45c00 1 -- 10.244.0.254:0/693432054 wait complete.
-103> 2019-02-25 21:25:57.563 7f314af45c00 1 -- 10.244.0.254:0/693432054 >> 10.244.0.254:0/693432054 conn(0x1c50000 :-1 s=STATE_NONE pgs=0 cs=0 l=0).mark_down
-102> 2019-02-25 21:25:57.563 7f314af45c00 2 -- 10.244.0.254:0/693432054 >> 10.244.0.254:0/693432054 conn(0x1c50000 :-1 s=STATE_NONE pgs=0 cs=0 l=0)._stop
-101> 2019-02-25 21:25:57.567 7f314af45c00 0 ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable), process ceph-fuse, pid 335
-100> 2019-02-25 21:25:57.567 7f314af45c00 0 pidfile_write: ignore empty --pid-file
-99> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) init /var/run/ceph/ceph-client.admin.335.27926528.asok
-98> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) bind_and_listen /var/run/ceph/ceph-client.admin.335.27926528.asok
-97> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) register_command 0 hook 0x19d5300
-96> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) register_command version hook 0x19d5300
-95> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) register_command git_version hook 0x19d5300
-94> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) register_command help hook 0x19e04b0
-93> 2019-02-25 21:25:57.567 7f314af45c00 5 asok(0x1a08240) register_command get_command_descriptions hook 0x19e04a0
-92> 2019-02-25 21:25:57.567 7f314af45c00 10 monclient: build_initial_monmap
-91> 2019-02-25 21:25:57.571 7f313ab8c700 2 Event(0x1a08500 nevent=5000 time_id=1).set_owner idx=2 owner=139849415313152
-90> 2019-02-25 21:25:57.571 7f313cb90700 5 asok(0x1a08240) entry start
-89> 2019-02-25 21:25:57.571 7f313b38d700 2 Event(0x1a094c0 nevent=5000 time_id=1).set_owner idx=1 owner=139849423705856
-88> 2019-02-25 21:25:57.571 7f313bb8e700 2 Event(0x1a08e00 nevent=5000 time_id=1).set_owner idx=0 owner=139849432098560
-87> 2019-02-25 21:25:57.571 7f314af45c00 -1 init, newargv = 0x19ddb20 newargc=9
-86> 2019-02-25 21:25:57.571 7f314af45c00 1 -- - start start
-85> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command objecter_requests hook 0x19e0200
-84> 2019-02-25 21:25:57.571 7f314af45c00 1 Processor -- start
-83> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient: init
-82> 2019-02-25 21:25:57.571 7f314af45c00 5 adding auth protocol: cephx
-81> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient: auth_supported 2 method cephx
-80> 2019-02-25 21:25:57.571 7f314af45c00 -1 auth: unable to find a keyring on /etc/ceph/ceph.client.admin.keyring,/etc/ceph/ceph.keyring,/etc/ceph/keyring,/etc/ceph/keyring.bin,: (2) No such file or directory
-79> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient: _renew_subs
-78> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient: _reopen_session rank -1
-77> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient(hunting): picked mon.noname-c con 0x1bbee00 addr 10.101.181.49:6789/0
-76> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient(hunting): picked mon.noname-b con 0x1bbf500 addr 10.100.212.130:6789/0
-75> 2019-02-25 21:25:57.571 7f314af45c00 1 -- - --> 10.100.212.130:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x1bc6780 con 0
-74> 2019-02-25 21:25:57.571 7f314af45c00 1 -- - --> 10.101.181.49:6789/0 -- auth(proto 0 30 bytes epoch 0) v1 -- 0x1bc6a00 con 0
-73> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient(hunting): _renew_subs
-72> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command mds_requests hook 0x1c5e020
-71> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command mds_sessions hook 0x1c5e020
-70> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command dump_cache hook 0x1c5e020
-69> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command kick_stale_sessions hook 0x1c5e020
-68> 2019-02-25 21:25:57.571 7f314af45c00 5 asok(0x1a08240) register_command status hook 0x1c5e020
-67> 2019-02-25 21:25:57.571 7f314af45c00 10 monclient(hunting): authenticate will time out at 2019-02-25 21:30:57.577092
-66> 2019-02-25 21:25:57.571 7f313ab8c700 1 -- 10.244.0.254:0/630923031 learned_addr learned my addr 10.244.0.254:0/630923031
-65> 2019-02-25 21:25:57.571 7f313ab8c700 2 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-64> 2019-02-25 21:25:57.571 7f313b38d700 2 -- 10.244.0.254:0/630923031 >> 10.101.181.49:6789/0 conn(0x1bbee00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0
-63> 2019-02-25 21:25:57.571 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 1 0x1a08fc0 mon_map magic: 0 v1
-62> 2019-02-25 21:25:57.571 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 2 0x1bc6780 auth_reply(proto 2 0 (0) Success) v1
-61> 2019-02-25 21:25:57.571 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 1 ==== mon_map magic: 0 v1 ==== 361+0+0 (3007813193 0 0) 0x1a08fc0 con 0x1bbf500
-60> 2019-02-25 21:25:57.571 7f3137b86700 10 monclient(hunting): handle_monmap mon_map magic: 0 v1
-59> 2019-02-25 21:25:57.571 7f3137b86700 10 monclient(hunting): got monmap 3, mon.noname-b is now rank -1
-58> 2019-02-25 21:25:57.571 7f3137b86700 10 monclient(hunting): dump:
epoch 3
fsid d150cf0b-c27d-45ff-947b-b71a07bedd69
last_changed 2019-02-21 14:17:21.414482
created 2019-02-21 14:16:14.518883
0: 10.100.212.130:6789/0 mon.b
1: 10.101.181.49:6789/0 mon.c
2: 10.103.49.162:6789/0 mon.a
-57> 2019-02-25 21:25:57.571 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (874550470 0 0) 0x1bc6780 con 0x1bbf500
-56> 2019-02-25 21:25:57.571 7f3137b86700 10 monclient(hunting): my global_id is 39324
-55> 2019-02-25 21:25:57.571 7f3137b86700 1 -- 10.244.0.254:0/630923031 --> 10.100.212.130:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x1bc7680 con 0
-54> 2019-02-25 21:25:57.575 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 3 0x1bc7680 auth_reply(proto 2 0 (0) Success) v1
-53> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 206+0+0 (852682542 0 0) 0x1bc7680 con 0x1bbf500
-52> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 --> 10.100.212.130:6789/0 -- auth(proto 2 165 bytes epoch 0) v1 -- 0x1bc6780 con 0
-51> 2019-02-25 21:25:57.575 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 4 0x1bc6780 auth_reply(proto 2 0 (0) Success) v1
-50> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 409+0+0 (2937225315 0 0) 0x1bc6780 con 0x1bbf500
-49> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 >> 10.101.181.49:6789/0 conn(0x1bbee00 :-1 s=STATE_OPEN pgs=2342 cs=1 l=1).mark_down
-48> 2019-02-25 21:25:57.575 7f3137b86700 2 -- 10.244.0.254:0/630923031 >> 10.101.181.49:6789/0 conn(0x1bbee00 :-1 s=STATE_OPEN pgs=2342 cs=1 l=1)._stop
-47> 2019-02-25 21:25:57.575 7f3137b86700 1 monclient: found mon.b
-46> 2019-02-25 21:25:57.575 7f3137b86700 10 monclient: _send_mon_message to mon.b at 10.100.212.130:6789/0
-45> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 --> 10.100.212.130:6789/0 -- mon_subscribe({osdmap=0}) v3 -- 0x1a09b00 con 0
-44> 2019-02-25 21:25:57.575 7f314af45c00 5 monclient: authenticate success, global_id 39324
-43> 2019-02-25 21:25:57.575 7f314af45c00 10 monclient: _renew_subs
-42> 2019-02-25 21:25:57.575 7f314af45c00 10 monclient: _send_mon_message to mon.b at 10.100.212.130:6789/0
-41> 2019-02-25 21:25:57.575 7f314af45c00 1 -- 10.244.0.254:0/630923031 --> 10.100.212.130:6789/0 -- mon_subscribe({config=0+,mdsmap=0+,monmap=4+}) v3 -- 0x1a09200 con 0
-40> 2019-02-25 21:25:57.575 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 5 0x1a5b340 osd_map(277..277 src has 1..277) v4
-39> 2019-02-25 21:25:57.575 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 6 0x1a09200 config(0 keys) v1
-38> 2019-02-25 21:25:57.575 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 7 0x1bc7900 mdsmap(e 147) v1
-37> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 5 ==== osd_map(277..277 src has 1..277) v4 ==== 1850+0+0 (339032216 0 0) 0x1a5b340 con 0x1bbf500
-36> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 6 ==== config(0 keys) v1 ==== 4+0+0 (0 0 0) 0x1a09200 con 0x1bbf500
-35> 2019-02-25 21:25:57.575 7f3137b86700 10 monclient: handle_config config(0 keys) v1
-34> 2019-02-25 21:25:57.575 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 7 ==== mdsmap(e 147) v1 ==== 763+0+0 (542677415 0 0) 0x1bc7900 con 0x1bbf500
-33> 2019-02-25 21:25:57.575 7f3137b86700 1 client.39324 handle_mds_map epoch 147
-32> 2019-02-25 21:25:57.575 7f314af45c00 1 -- 10.244.0.254:0/630923031 --> 10.244.0.227:6800/1551071473 -- client_session(request_open) v3 -- 0x1a09680 con 0
-31> 2019-02-25 21:25:57.575 7f3136383700 4 set_mon_vals no callback set
-30> 2019-02-25 21:25:57.579 7f313b38d700 2 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=0)._process_connection got newly_acked_seq 0 vs out_seq 0
-29> 2019-02-25 21:25:58.111 7f313b38d700 5 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=324 cs=1 l=0). rx mds.0 seq 1 0x1a09680 client_session(open) v3
-28> 2019-02-25 21:25:58.111 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mds.0 10.244.0.227:6800/1551071473 1 ==== client_session(open) v3 ==== 44+0+0 (2569400099 0 0) 0x1a09680 con 0x1bbfc00
-27> 2019-02-25 21:25:58.111 7f3137b86700 1 -- 10.244.0.254:0/630923031 --> 10.244.0.227:6800/1551071473 -- client_session(request_renewcaps seq 1) v3 -- 0x1a08fc0 con 0
-26> 2019-02-25 21:25:58.111 7f314af45c00 1 -- 10.244.0.254:0/630923031 --> 10.244.0.227:6800/1551071473 -- client_request(unknown.0:1 getattr pAsLsXsFs #0x1 2019-02-25 21:25:57.581360 caller_uid=0, caller_gid=0{}) v4 -- 0x1c84000 con 0
-25> 2019-02-25 21:25:58.119 7f313b38d700 5 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=324 cs=1 l=0). rx mds.0 seq 2 0x1a09d40 client_session(renewcaps seq 1) v1
-24> 2019-02-25 21:25:58.119 7f313b38d700 5 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=324 cs=1 l=0). rx mds.0 seq 3 0x1a04f00 client_reply(???:1 = 0 (0) Success) v1
-23> 2019-02-25 21:25:58.119 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mds.0 10.244.0.227:6800/1551071473 2 ==== client_session(renewcaps seq 1) v1 ==== 28+0+0 (2614397064 0 0) 0x1a09d40 con 0x1bbfc00
-22> 2019-02-25 21:25:58.119 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mds.0 10.244.0.227:6800/1551071473 3 ==== client_reply(???:1 = 0 (0) Success) v1 ==== 370+0+0 (3923587992 0 0) 0x1a04f00 con 0x1bbfc00
-21> 2019-02-25 21:25:58.139 7f313337d700 3 client.39324 ll_lookup 0x1.head csi-volumes
-20> 2019-02-25 21:25:58.139 7f313337d700 3 client.39324 may_lookup 0x1baeb00 = 0
-19> 2019-02-25 21:25:58.139 7f313337d700 1 -- 10.244.0.254:0/630923031 --> 10.244.0.227:6800/1551071473 -- client_request(unknown.0:2 lookup #0x1/csi-volumes 2019-02-25 21:25:58.143367 caller_uid=0, caller_gid=0{}) v4 -- 0x1c84340 con 0
-18> 2019-02-25 21:25:58.139 7f3133b7e700 1 client.39324 using remount_cb
-17> 2019-02-25 21:25:58.139 7f313b38d700 5 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=324 cs=1 l=0). rx mds.0 seq 4 0x1a04f00 client_reply(???:2 = 0 (0) Success) v1
-16> 2019-02-25 21:25:58.139 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mds.0 10.244.0.227:6800/1551071473 4 ==== client_reply(???:2 = 0 (0) Success) v1 ==== 698+0+0 (3002970968 0 0) 0x1a04f00 con 0x1bbfc00
-15> 2019-02-25 21:25:58.139 7f313337d700 3 client.39324 ll_lookup 0x1.head csi-volumes -> 0 (1000000009c)
-14> 2019-02-25 21:25:58.139 7f3132b7c700 3 client.39324 ll_lookup 0x1000000009c.head csi-cephfs-pvc-d532bc6d-3943-11e9-a432-52540013b951
-13> 2019-02-25 21:25:58.139 7f3132b7c700 3 client.39324 may_lookup 0x1baf080 = 0
-12> 2019-02-25 21:25:58.139 7f3132b7c700 1 -- 10.244.0.254:0/630923031 --> 10.244.0.227:6800/1551071473 -- client_request(unknown.0:3 lookup #0x1000000009c/csi-cephfs-pvc-d532bc6d-3943-11e9-a432-52540013b951 2019-02-25 21:25:58.146382 caller_uid=0, caller_gid=0{}) v4 -- 0x1c84680 con 0
-11> 2019-02-25 21:25:58.143 7f313b38d700 5 -- 10.244.0.254:0/630923031 >> 10.244.0.227:6800/1551071473 conn(0x1bbfc00 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=324 cs=1 l=0). rx mds.0 seq 5 0x1a05200 client_reply(???:3 = 0 (0) Success) v1
-10> 2019-02-25 21:25:58.143 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mds.0 10.244.0.227:6800/1551071473 5 ==== client_reply(???:3 = 0 (0) Success) v1 ==== 840+0+0 (1975105633 0 0) 0x1a05200 con 0x1bbfc00
-9> 2019-02-25 21:25:58.143 7f3132b7c700 3 client.39324 ll_lookup 0x1000000009c.head csi-cephfs-pvc-d532bc6d-3943-11e9-a432-52540013b951 -> 0 (100000000df)
-8> 2019-02-25 21:25:58.143 7f313337d700 3 client.39324 ll_getattr 0x100000000df.head = 0
-7> 2019-02-25 21:25:58.147 7f313337d700 3 client.39324 ll_getattr 0x1.head = 0
-6> 2019-02-25 21:25:58.147 7f3132b7c700 10 monclient: _send_mon_message to mon.b at 10.100.212.130:6789/0
-5> 2019-02-25 21:25:58.147 7f3132b7c700 1 -- 10.244.0.254:0/630923031 --> 10.100.212.130:6789/0 -- statfs(1 pool 2 v0) v2 -- 0x1a09680 con 0
-4> 2019-02-25 21:25:58.151 7f313ab8c700 5 -- 10.244.0.254:0/630923031 >> 10.100.212.130:6789/0 conn(0x1bbf500 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=2262 cs=1 l=1). rx mon.0 seq 8 0x1a09680 statfs_reply(1) v1
-3> 2019-02-25 21:25:58.151 7f3137b86700 1 -- 10.244.0.254:0/630923031 <== mon.0 10.100.212.130:6789/0 8 ==== statfs_reply(1) v1 ==== 56+0+0 (1297293781 0 0) 0x1a09680 con 0x1bbf500
-2> 2019-02-25 21:25:58.151 7f3133b7e700 -1 client.39324 failed to remount (to trim kernel dentries): return code = 1
-1> 2019-02-25 21:25:58.151 7f3133b7e700 -1 client.39324 failed to remount for kernel dentry trimming; quitting!
0> 2019-02-25 21:25:58.151 7f3133b7e700 -1 *** Caught signal (Aborted) **
in thread 7f3133b7e700 thread_name:tester
ceph version 13.2.4 (b10be4d44915a4d78a8e06aa31919e74927b142e) mimic (stable)
1: ceph-fuse() [0x4f34b0]
2: (()+0x11390) [0x7f31418d0390]
3: (gsignal()+0x38) [0x7f314101d428]
4: (abort()+0x16a) [0x7f314101f02a]
5: (Client::_do_remount()+0x398) [0x4b1cb8]
6: (Client::test_dentry_handling(bool)+0x1f0) [0x4b1ef0]
7: ceph-fuse() [0x440e2d]
8: (()+0x76ba) [0x7f31418c66ba]
9: (clone()+0x6d) [0x7f31410ef41d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 rbd_mirror
0/ 5 rbd_replay
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
1/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 1 reserver
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 rgw_sync
1/10 civetweb
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
0/ 0 refs
1/ 5 xio
1/ 5 compressor
1/ 5 bluestore
1/ 5 bluefs
1/ 3 bdev
1/ 5 kstore
4/ 5 rocksdb
4/ 5 leveldb
4/ 5 memdb
1/ 5 kinetic
1/ 5 fuse
1/ 5 mgr
1/ 5 mgrc
1/ 5 dpdk
1/ 5 eventtrace
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-client.admin.log
--- end dump of recent events ---
the same thing happens with Luminous. @rootfs sounds familiar?
from ceph-csi.
nenadalm
commented on August 26, 2024
Hi. I am getting similar error in provisioner pod as mentioned here: #140 (comment)
# kubectl -n ceph-csi-cephfs logs ceph-csi-cephfs-provisioner-7d69d9b59-jbq6w -c csi-provisioner
I1129 08:48:40.819096 1 connection.go:180] GRPC call: /csi.v1.Controller/CreateVolume
I1129 08:48:40.841089 1 connection.go:181] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-0683ae3d-2ea9-4b13-9f16-2d22554c0c83","parameters":{"clusterID":"cluster-id","fsName":"/data/volumes"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":5}}]}
I1129 08:48:44.756515 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:48:49.821292 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:48:54.828842 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:48:59.841438 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:04.848608 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:09.856141 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:14.861549 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:19.870195 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:24.877145 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:29.884279 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:34.889051 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:39.895173 1 leaderelection.go:258] successfully renewed lease ceph-csi-cephfs/cephfs-csi-ceph-com
I1129 08:49:40.792890 1 connection.go:183] GRPC response: {}
I1129 08:49:40.793524 1 connection.go:184] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded
I1129 08:49:40.793564 1 controller.go:979] Final error received, removing PVC 0683ae3d-2ea9-4b13-9f16-2d22554c0c83 from claims in progress
W1129 08:49:40.793574 1 controller.go:886] Retrying syncing claim "0683ae3d-2ea9-4b13-9f16-2d22554c0c83", failure 71
E1129 08:49:40.793603 1 controller.go:908] error syncing claim "0683ae3d-2ea9-4b13-9f16-2d22554c0c83": failed to provision volume with StorageClass "csi-cephfs": rpc error: code = DeadlineExceeded desc = context deadline exceeded
I1129 08:49:40.794394 1 event.go:209] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"csi-cephfs-pvc", UID:"0683ae3d-2ea9-4b13-9f16-2d22554c0c83", APIVersion:"v1", ResourceVersion:"633499", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "csi-cephfs": rpc error: code = DeadlineExceeded desc = context deadline exceeded
plugin logs:
# kubectl -n ceph-csi-cephfs logs ceph-csi-cephfs-nodeplugin-crsf9 -c csi-cephfsplugin
1128 14:05:24.788792 1 cephcsi.go:104] Driver version: v1.2.2 and Git version: f8c854dc7d6ffff02cb2eed6002534dc0473f111
I1128 14:05:25.219271 1 cachepersister.go:45] cache-perister: using kubernetes configmap as metadata cache persister
I1128 14:05:26.916027 1 cephcsi.go:131] Initial PID limit is set to -1
I1128 14:05:26.916237 1 cephcsi.go:140] Reconfigured PID limit to -1 (max)
I1128 14:05:26.916251 1 cephcsi.go:159] Starting driver type: cephfs with name: cephfs.csi.ceph.com
I1128 14:05:27.880505 1 volumemounter.go:159] loaded mounter: kernel
I1128 14:05:30.443067 1 volumemounter.go:167] loaded mounter: fuse
I1128 14:05:30.701643 1 mountcache.go:59] mount-cache: name: cephfs.csi.ceph.com, version: v1.2.2, mountCacheDir: /mount-cache-dir
I1128 14:05:30.796966 1 mountcache.go:99] mount-cache: successfully remounted 0 volumes
I1128 14:05:30.882214 1 server.go:118] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi.sock", Net:"unix"}
I1128 14:05:34.729741 1 utils.go:119] ID: 1 GRPC call: /csi.v1.Identity/GetPluginInfo
I1128 14:05:34.729784 1 utils.go:120] ID: 1 GRPC request: {}
I1128 14:05:34.821613 1 identityserver-default.go:37] ID: 1 Using default GetPluginInfo
I1128 14:05:34.821766 1 utils.go:125] ID: 1 GRPC response: {"name":"cephfs.csi.ceph.com","vendor_version":"v1.2.2"}
I1128 14:05:54.956852 1 utils.go:119] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I1128 14:05:54.956871 1 utils.go:120] ID: 2 GRPC request: {}
I1128 14:05:54.970611 1 identityserver-default.go:37] ID: 2 Using default GetPluginInfo
I1128 14:05:54.970666 1 utils.go:125] ID: 2 GRPC response: {"name":"cephfs.csi.ceph.com","vendor_version":"v1.2.2"}
I1128 14:06:30.254161 1 utils.go:119] ID: 3 GRPC call: /csi.v1.Node/NodeGetInfo
I1128 14:06:30.254202 1 utils.go:120] ID: 3 GRPC request: {}
I1128 14:06:30.349098 1 nodeserver-default.go:58] ID: 3 Using default NodeGetInfo
I1128 14:06:30.349597 1 utils.go:125] ID: 3 GRPC response: {"node_id":"k8s-node"}
then the plugin log just repeats the lines below:
I1128 14:06:32.191992 1 utils.go:119] ID: 4 GRPC call: /csi.v1.Identity/Probe
I1128 14:06:32.192019 1 utils.go:120] ID: 4 GRPC request: {}
I1128 14:06:32.263914 1 utils.go:125] ID: 4 GRPC response: {}
I installed the driver using chart: https://github.com/ceph/ceph-csi/tree/master/charts/ceph-csi-cephfs#install-chart
from ceph-csi.
humblec
commented on August 26, 2024
@Madhu-1 iic, with the improvements in latest versions , may be we are out of this issue. Definitely go ceph could improve.. but I think this kind of lockups were improved on our way to 3.1.1. I am closing this issue for now and please feel free to reopen if you think this is still an issue.
from ceph-csi.
Madhu-1
commented on August 26, 2024
@humblec as its related to mounting how go-ceph can improve it? or am I missing something else?
from ceph-csi.
humblec
commented on August 26, 2024
@humblec as its related to mounting how go-ceph can improve it? or am I missing something else?
@Madhu-1 as in isolation steps, the suspecion here is that, the load on the server could have caused the behaviour too. In short, with go ceph and other connection improvements, we are reducing the load which eventually help on subsequent operations coming in.
Are you able to reproduce this issue ? or want to analyse this further ? if yes, we can keep this open. Also last update here in this issue is around an year back, so may be there is no point in keeping it open.
from ceph-csi.
Related Issues (20)
- Can we share VolumeLocks for NodeServer/ControllerServer? HOT 3
- Not able to start CI job because of no nodes HOT 1
- RBD-Images are not shown in the Dashbord: Failed to execute RBD [errno 19] error generating diff from snapshot None HOT 2
- Concurrency issue when pvc is mounted to multiple pods HOT 23
- CentOS Stream 8 is EOL HOT 4
- Add support for ModifyVolume HOT 5
- allow podSecurityContexts to be set in `nodeplugin` and `provisioner` of chart `ceph-csi-cephfs` HOT 2
- Add http health endpoint for ceph-csi-cephfs and ceph-csi-rbd HOT 4
- cephfs-csi Pod has always been in containercreating HOT 3
- CephFS keyring requires nonsensicaly enormous and insecure privileges to work HOT 6
- Update modprobe in csi-rbdplugin to support zstd compressed rbd and nbd kernel module HOT 7
- Unable to create CephFS subvolume dynamically (`no available topology found`) HOT 2
- cephFS: Remove the 400 snapshot limitation from the doc HOT 2
- Allow to change mounter option from an existing PV HOT 9
- cephfs csi error,mds mds status Start request repeated too quickly. Failed with result 'signal'. HOT 3
- New csiplugin-configmap.yaml setting to override PVs's volumeAttributes.mounter HOT 2
- 'luksOpen'` encrypted volumes HOT 1
- rbd remap on network failure HOT 8
- Remove podSecurityPolicy from the helm documentation
- Ensure ceph-lock is always released when staging encrypted cephfs volume HOT 4
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from ceph-csi.