Skip to content

exceptions in log on daemon stop and service redeploy/reconfig (probably with same root cause) #1121

@barakda

Description

@barakda
  1. Exception after stopping nvmeof daemon
Feb 24 14:48:57 cephnvme-vm14 systemd[1]: Stopping Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601...
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:57] INFO server.py:44 (7): GatewayServer: SIGTERM received signum=15
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:57] ERROR server.py:153 (7): GatewayServer exception occurred:
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: {traceback}
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: Traceback (most recent call last):
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:   File "/src/control/__main__.py", line 33, in <module>
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:     gateway.keep_alive()
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:   File "/src/control/server.py", line 817, in keep_alive
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:     time.sleep(spdk_ping_interval_in_seconds)
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:   File "/src/control/server.py", line 45, in sigterm_handler
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]:     raise SystemExit(0)
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: SystemExit: 0
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:57] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 24 args ['/usr/bin/ceph-nvmeof-monitor-client', '--gateway-name', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '--gateway-address', '10.242.64.37:5500', '--gateway-pool', 'mypool', '--gateway-group', 'mygroup1', '--monitor-group-address', '10.242.64.37:5499', '-c', '/etc/ceph/ceph.conf', '-n', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '-k', '/etc/ceph/keyring'] ...
Feb 24 14:48:57 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:57] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 79 args ['/usr/local/bin/nvmf_tgt', '-u', '-r', '/var/tmp/spdk.sock', '--wait-for-rpc', '-m', '0xF'] ...
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO server.py:192 (7): Stopping the server...
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO server.py:718 (7): Terminating discovery service...
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO state.py:682 (87): Cleanup OMAP on exit (discovery-cephnvme-vm14)
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO server.py:725 (7): Discovery service terminated
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO state.py:682 (7): Cleanup OMAP on exit (gateway-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj)
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO server.py:204 (7): Exiting the gateway process.
Feb 24 14:48:59 cephnvme-vm14 bash[3227405]: [24-Feb-2025 12:48:59] INFO utils.py:507 (7): Will compress log file /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log to /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log.gz
Feb 24 14:48:59 cephnvme-vm14 bash[3303335]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601-nvmeof-mypool-mygroup1-cephnvme-vm14-qxhwtj
Feb 24 14:48:59 cephnvme-vm14 systemd[1]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601@nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj.service: Deactivated successfully.
Feb 24 14:48:59 cephnvme-vm14 systemd[1]: Stopped Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601.
  1. exception after redeploing nvmeof service
Feb 24 15:07:49 cephnvme-vm14 systemd[1]: Stopping Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601...
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:50] INFO server.py:44 (7): GatewayServer: SIGTERM received signum=15
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:50] ERROR server.py:153 (7): GatewayServer exception occurred:
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: {traceback}
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: Traceback (most recent call last):
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/control/__main__.py", line 33, in <module>
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     gateway.keep_alive()
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/control/server.py", line 813, in keep_alive
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     timedout = self.server.wait_for_termination(timeout=1)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/__pypackages__/3.9/lib/grpc/_server.py", line 1118, in wait_for_termination
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     return _common.wait(self._state.termination_event.wait,
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/__pypackages__/3.9/lib/grpc/_common.py", line 157, in wait
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     _wait_once(wait_fn, remaining, spin_cb)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/__pypackages__/3.9/lib/grpc/_common.py", line 112, in _wait_once
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     wait_fn(timeout=timeout)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/usr/lib64/python3.9/threading.py", line 581, in wait
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     signaled = self._cond.wait(timeout)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/usr/lib64/python3.9/threading.py", line 316, in wait
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     gotit = waiter.acquire(True, timeout)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:   File "/src/control/server.py", line 45, in sigterm_handler
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]:     raise SystemExit(0)
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: SystemExit: 0
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:50] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 24 args ['/usr/bin/ceph-nvmeof-monitor-client', '--gateway-name', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '--gateway-address', '10.242.64.37:5500', '--gateway-pool', 'mypool', '--gateway-group', 'mygroup1', '--monitor-group-address', '10.242.64.37:5499', '-c', '/etc/ceph/ceph.conf', '-n', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '-k', '/etc/ceph/keyring'] ...
Feb 24 15:07:50 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:50] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 70 args ['/usr/local/bin/nvmf_tgt', '-u', '-r', '/var/tmp/spdk.sock', '--wait-for-rpc', '-m', '0xF'] ...
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO server.py:192 (7): Stopping the server...
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO server.py:718 (7): Terminating discovery service...
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO state.py:682 (75): Cleanup OMAP on exit (discovery-cephnvme-vm14)
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO server.py:725 (7): Discovery service terminated
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO state.py:682 (7): Cleanup OMAP on exit (gateway-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj)
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO server.py:204 (7): Exiting the gateway process.
Feb 24 15:07:51 cephnvme-vm14 bash[3311922]: [24-Feb-2025 13:07:51] INFO utils.py:507 (7): Will compress log file /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log to /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log.gz
Feb 24 15:07:51 cephnvme-vm14 bash[3379504]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601-nvmeof-mypool-mygroup1-cephnvme-vm14-qxhwtj
Feb 24 15:07:51 cephnvme-vm14 systemd[1]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601@nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj.service: Deactivated successfully.
Feb 24 15:07:51 cephnvme-vm14 systemd[1]: Stopped Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601.
  1. exception after reconfig nvmeof service
Feb 24 15:10:16 cephnvme-vm14 systemd[1]: Stopping Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601...
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:16] INFO server.py:44 (7): GatewayServer: SIGTERM received signum=15
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:16] ERROR server.py:153 (7): GatewayServer exception occurred:
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: {traceback}
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: Traceback (most recent call last):
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:   File "/src/control/__main__.py", line 33, in <module>
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:     gateway.keep_alive()
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:   File "/src/control/server.py", line 817, in keep_alive
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:     time.sleep(spdk_ping_interval_in_seconds)
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:   File "/src/control/server.py", line 45, in sigterm_handler
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]:     raise SystemExit(0)
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: SystemExit: 0
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:16] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 24 args ['/usr/bin/ceph-nvmeof-monitor-client', '--gateway-name', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '--gateway-address', '10.242.64.37:5500', '--gateway-pool', 'mypool', '--gateway-group', 'mygroup1', '--monitor-group-address', '10.242.64.37:5499', '-c', '/etc/ceph/ceph.conf', '-n', 'client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj', '-k', '/etc/ceph/keyring'] ...
Feb 24 15:10:16 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:16] INFO server.py:663 (7): Terminating sub process of (client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj) pid 3505 args ['/usr/local/bin/nvmf_tgt', '-u', '-r', '/var/tmp/spdk.sock', '--wait-for-rpc', '-m', '0xF'] ...
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO server.py:192 (7): Stopping the server...
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO server.py:718 (7): Terminating discovery service...
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO state.py:682 (3510): Cleanup OMAP on exit (discovery-cephnvme-vm14)
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO server.py:725 (7): Discovery service terminated
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO state.py:682 (7): Cleanup OMAP on exit (gateway-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj)
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO server.py:204 (7): Exiting the gateway process.
Feb 24 15:10:18 cephnvme-vm14 bash[3379662]: [24-Feb-2025 13:10:18] INFO utils.py:507 (7): Will compress log file /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log to /var/log/ceph/nvmeof-client.nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj/nvmeof-log.gz
Feb 24 15:10:18 cephnvme-vm14 bash[3392283]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601-nvmeof-mypool-mygroup1-cephnvme-vm14-qxhwtj
Feb 24 15:10:18 cephnvme-vm14 systemd[1]: ceph-16c5192e-f2a8-11ef-be49-0200229b9601@nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj.service: Deactivated successfully.
Feb 24 15:10:18 cephnvme-vm14 systemd[1]: Stopped Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601.
Feb 24 15:10:18 cephnvme-vm14 systemd[1]: Started Ceph nvmeof.mypool.mygroup1.cephnvme-vm14.qxhwtj for 16c5192e-f2a8-11ef-be49-0200229b9601.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    Status

    🆕 New

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions