公開日: 2024/8/23
Out of Service 時の挙動
mysql との接続断が起きた場合、Out of Serviceとなります。その際の挙動について紹介します。
mysql
mysqlとの接続が切れてしまった場合、以下のような挙動になります。
API のレスポンス
エラーコード503が返却されます。
% curl -i -g "${ENV}"/classes -H "X-Xaas-Auth-Token: "${TOKEN}""
HTTP/2 503
server: Qmonus/v23.2LTS-patch20240708
content-type: application/problem+json
date: Fri, 23 Aug 2024 04:45:34 GMT
content-length: 26
via: 1.1 google
alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000
{"cause":"OUT OF SERVICE"}%
出力されるログの例
10秒ごとに接続を試みるログが出力されます。
Out of Service 、および In Service Status のバナーが表示されます。
切断ログ
[I 240822 07:51:59 boot:115] {"status":404,"method":"POST","url":"/logon","remote":"10.98.33.164","elapsed":"1.73ms"}
[I 240822 07:51:59 boot:115] {"status":404,"method":"POST","url":"/logon","remote":"10.98.33.164","elapsed":"0.98ms"}
[I 240822 07:51:59 boot:115] {"status":404,"method":"POST","url":"/logon","remote":"10.98.33.164","elapsed":"1.22ms"}
[I 240822 07:53:47 boot:115] {"status":404,"method":"POST","url":"/logon","remote":"10.98.33.164","elapsed":"1.64ms"}
[E 240822 07:53:47 context_manager:146] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 527, in _connect
self._reader, self._writer = await \
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 408, in wait_for
return await fut
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 88, in _open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
TimeoutError: [Errno 110] Connection timed out
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/root/axis-stable/axis/boot/context_manager.py", line 144, in __aenter__
self.conn = await self.engine.acquire()
File "/usr/local/lib/python3.10/site-packages/aiomysql/sa/engine.py", line 156, in _acquire
raw = await self._pool.acquire()
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 142, in _acquire
await self._fill_free_pool(True)
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 182, in _fill_free_pool
conn = await connect(echo=self._echo, loop=self._loop,
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 75, in _connect
await conn._connect()
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 558, in _connect
raise OperationalError(2003,
pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on 'mysql'")
[W 240822 07:53:47 context:971] [9] Shutdown db engine...
[E 240822 07:53:47 context_manager:146] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 527, in _connect
self._reader, self._writer = await \
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 408, in wait_for
return await fut
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 88, in _open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
ConnectionRefusedError: [Errno 111] Connection refused
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/root/axis-stable/axis/boot/context_manager.py", line 144, in __aenter__
self.conn = await self.engine.acquire()
File "/usr/local/lib/python3.10/site-packages/aiomysql/sa/engine.py", line 156, in _acquire
raw = await self._pool.acquire()
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 142, in _acquire
await self._fill_free_pool(True)
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 182, in _fill_free_pool
conn = await connect(echo=self._echo, loop=self._loop,
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 75, in _connect
await conn._connect()
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 558, in _connect
raise OperationalError(2003,
pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on 'mysql'")
[C 240822 07:53:47 context_manager:174] [9] DB failover waiting TIMEDOUT. Impossible to acquire database connection
[I 240822 07:53:47 daemon:173] DeleteCompletedHealthCheckOperation daemon terminated
[W 240822 07:53:47 context:741] [9] Stop all job and consumer (shutdown=False)...
[W 240822 07:53:47 context:2236] The message notification was discarded because the master node was not detected.
[W 240822 07:53:47 context:977] [9] Released all db connections
[C 240822 07:53:47 context_manager:132] [9] Wait for the completion of failover. unknown (1/12)
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-487192' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/event_handler.py", line 117, in subscribe
await reader(p)
File "/root/axis-stable/axis/lib/event_handler.py", line 107, in reader
msg = await channel.get_message(ignore_subscribe_messages=True)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4174, in get_message
response = await self.parse_response(block=False, timeout=timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4051, in parse_response
if not block and not await conn.can_read(timeout=timeout):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 893, in can_read
return await self._parser.can_read(timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 479, in can_read
raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
aioredis.exceptions.ConnectionError: Connection closed by server.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-487194' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/event_handler.py", line 117, in subscribe
await reader(p)
File "/root/axis-stable/axis/lib/event_handler.py", line 107, in reader
msg = await channel.get_message(ignore_subscribe_messages=True)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4174, in get_message
response = await self.parse_response(block=False, timeout=timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4051, in parse_response
if not block and not await conn.can_read(timeout=timeout):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 893, in can_read
return await self._parser.can_read(timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 479, in can_read
raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
aioredis.exceptions.ConnectionError: Connection closed by server.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-487193' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/event_handler.py", line 117, in subscribe
await reader(p)
File "/root/axis-stable/axis/lib/event_handler.py", line 107, in reader
msg = await channel.get_message(ignore_subscribe_messages=True)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4174, in get_message
response = await self.parse_response(block=False, timeout=timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4051, in parse_response
if not block and not await conn.can_read(timeout=timeout):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 893, in can_read
return await self._parser.can_read(timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 479, in can_read
raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
aioredis.exceptions.ConnectionError: Connection closed by server.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-487191' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/event_handler.py", line 117, in subscribe
await reader(p)
File "/root/axis-stable/axis/lib/event_handler.py", line 107, in reader
msg = await channel.get_message(ignore_subscribe_messages=True)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4174, in get_message
response = await self.parse_response(block=False, timeout=timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4051, in parse_response
if not block and not await conn.can_read(timeout=timeout):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 893, in can_read
return await self._parser.can_read(timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 479, in can_read
raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
aioredis.exceptions.ConnectionError: Connection closed by server.
[C 240822 07:53:47 context:3856]
!=================================================================!
! ╔═╗╦ ╦┌┬┐ ┌─┐┌─┐ ╔═╗┌─┐┬─┐┬ ┬┬┌─┐┌─┐ ┌─┐┌┬┐┌─┐┌┬┐┬ ┬┌─┐ !
! ║ ║║ ║ │ │ │├┤ ╚═╗├┤ ├┬┘└┐┌┘││ ├┤ └─┐ │ ├─┤ │ │ │└─┐ !
! ╚═╝╚═╝ ┴ └─┘└ ╚═╝└─┘┴└─ └┘ ┴└─┘└─┘ └─┘ ┴ ┴ ┴ ┴ └─┘└─┘ !
!=================================================================!
PID: 9
MASTER: None:None
[C 240822 07:53:47 streamer:52] {"timestamp":"2024-08-22T16:53:47.429279+09:00","message":"Out-of-Service status","severity":"critical"}
[W 240822 07:53:47 decorator:559] Unable to process because Redis master is undetected
[I 240822 07:53:47 streamer:52] {"timestamp":"2024-08-22T16:53:47.415497+09:00","message":"Stopped Plugins Watch Daemon","severity":"info"}
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964529' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964532' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964528' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964533' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964527' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964531' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
[E 240822 07:53:47 boot:499] Task exception was never retrieved
future: <Task finished name='Task-964526' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=RedisError('Connection already closed.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 288, in subscribe
await p.unsubscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4023, in execute_command
await self._execute(connection, connection.send_command, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4027, in _execute
return await command(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 885, in send_command
await self.send_packed_command(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 860, in send_packed_command
await asyncio.wait_for(
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 445, in wait_for
return fut.result()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 839, in _send_packed_command
raise RedisError("Connection already closed.")
aioredis.exceptions.RedisError: Connection already closed.
切断中 10秒ごとに出力
[E 240822 08:00:34 context:3551] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 527, in _connect
self._reader, self._writer = await \
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 408, in wait_for
return await fut
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 88, in _open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
ConnectionRefusedError: [Errno 111] Connection refused
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/root/axis-stable/axis/boot/context.py", line 3549, in ins
await self.dbengine()
File "/root/axis-stable/axis/boot/context.py", line 1063, in dbengine
self.__async_db_engine__ = await create_engine(
File "/usr/local/lib/python3.10/site-packages/aiomysql/sa/engine.py", line 74, in _create_engine
pool = await aiomysql.create_pool(minsize=minsize, maxsize=maxsize,
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 29, in _create_pool
await pool._fill_free_pool(False)
File "/usr/local/lib/python3.10/site-packages/aiomysql/pool.py", line 182, in _fill_free_pool
conn = await connect(echo=self._echo, loop=self._loop,
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 75, in _connect
await conn._connect()
File "/usr/local/lib/python3.10/site-packages/aiomysql/connection.py", line 558, in _connect
raise OperationalError(2003,
pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on 'mysql'")
復帰ログ
[W 240822 08:00:44 context:2673] [9] Looking for the master node...
[I 240822 08:00:44 context:1091] [9] Created new database engine
[I 240822 08:00:44 context:3571] Detecting API Gateway Endpoint...
[I 240822 08:00:44 event_handler:99] [9] Recovered internal pubsub channels ['xaas.service.channel', 'xaas.daemon.channel', 'xaas.plugins.channel', 'xaas.sync.channel']
[I 240822 08:00:44 context:3596] Detecting Transaction Endpoint...
[I 240822 08:00:47 context:3009] [9] Sync scenario start...
[I 240822 08:00:47 context:3016] [9] Sync scenario Done
[I 240822 08:00:47 context:592] [9] HealthCheckOperation ATOM class generated
[I 240822 08:00:47 context:592] [9] HealthCheckResource ATOM class generated
[I 240822 08:00:47 context:592] [9] LocalEmployee ATOM class generated
[I 240822 08:00:47 context:592] [9] Local ATOM class generated
[I 240822 08:00:47 context:592] [9] Group1 ATOM class generated
[I 240822 08:00:47 context:592] [9] Group2 ATOM class generated
[I 240822 08:00:47 context:592] [9] TestClass ATOM class generated
[I 240822 08:00:47 context:3041] [9] Sync model start...
[I 240822 08:00:47 context:3110] [9] Sync model Done.
[I 240822 08:00:47 context:3279] [9] Sync gRPC servicers start...
[I 240822 08:00:47 context:3293] [9] Sync gRPC servicers Done.
[I 240822 08:00:47 context:4337] [9] Start job consume...
[C 240822 08:00:47 job:304] Stoppped job consume
[I 240822 08:00:47 context:3679]
#======================================================#
# ╦╔╗╔ ╔═╗┌─┐┬─┐┬ ┬┬┌─┐┌─┐ ┌─┐┌┬┐┌─┐┌┬┐┬ ┬┌─┐ #
# ║║║║ ╚═╗├┤ ├┬┘└┐┌┘││ ├┤ └─┐ │ ├─┤ │ │ │└─┐ #
# ╩╝╚╝ ╚═╝└─┘┴└─ └┘ ┴└─┘└─┘ └─┘ ┴ ┴ ┴ ┴ └─┘└─┘ #
#======================================================#
PID: 9
MASTER NODE: redis:6379
MASTER PROCESS: True
[I 240822 08:00:48 boot:115] {"status":200,"method":"GET","url":"/masterlookup?role=SCENARIO&scope=cluster","remote":"10.98.33.165","elapsed":"5.36ms"}
[I 240822 08:00:48 boot:115] {"status":200,"method":"GET","url":"/scenarios","remote":"10.98.35.243","elapsed":"5.83ms"}
[I 240822 08:00:48 installer:175] Create new sync plugins periodic job
[I 240822 08:00:48 installer:525] Plugin is already installed
redis との接続断
redisとの接続が切れてしまった場合、Out of Serviceとはなりませんが、十全な機能を提供することはできません。挙動は以下のようになります。
API のレスポンス
エラーコード500が返却されます。
% curl -i -g "${TEST_ENV}"/apis -H "X-Xaas-Auth-Token: "${TEST_TOKEN}""
HTTP/2 500
server: Qmonus/v23.2LTS-patch20240708
content-type: application/problem+json
date: Thu, 22 Aug 2024 09:18:10 GMT
content-length: 33
via: 1.1 google
alt-svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000
{"cause":"Internal Server Error"}%
出力されるログの例
コネクションエラー、タイムアウトエラーが高頻度で出力されます。
Out of Service 、および In Service Status のバナーは表示されません。
切断ログ
[E 240822 09:12:35 boot:499] Task exception was never retrieved
future: <Task finished name='Task-10' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/event_handler.py", line 117, in subscribe
await reader(p)
File "/root/axis-stable/axis/lib/event_handler.py", line 107, in reader
msg = await channel.get_message(ignore_subscribe_messages=True)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4174, in get_message
response = await self.parse_response(block=False, timeout=timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4051, in parse_response
if not block and not await conn.can_read(timeout=timeout):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 893, in can_read
return await self._parser.can_read(timeout)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 484, in can_read
return await self.read_from_socket(timeout=timeout, raise_on_timeout=False)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 500, in read_from_socket
raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR) from None
aioredis.exceptions.ConnectionError: Connection closed by server.
[E 240822 09:12:35 boot:499] Task exception was never retrieved
future: <Task finished name='Task-9' coro=<EventHandler.subscribe() done, defined at /root/axis-stable/axis/lib/event_handler.py:102> exception=ConnectionError('Connection closed by server.')>
Traceback (most recent call last):
...
...
...
[E 240822 09:12:35 boot:499] Task exception was never retrieved
future: <Task finished name='Task-4943' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=ConnectionError('Error 111 connecting to redis:6379. 111.')>
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 692, in connect
await self._connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 719, in _connect
reader, writer = await asyncio.open_connection(
File "/usr/local/lib/python3.10/asyncio/streams.py", line 48, in open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
ConnectionRefusedError: [Errno 111] Connection refused
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/root/axis-stable/axis/services/subscribers.py", line 286, in subscribe
await p.subscribe(ch)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4134, in subscribe
ret_val = await self.execute_command("SUBSCRIBE", *new_channels.keys())
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 4015, in execute_command
self.connection = await self.connection_pool.get_connection(
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 1617, in get_connection
await connection.connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 698, in connect
raise ConnectionError(self._error_message(e))
aioredis.exceptions.ConnectionError: Error 111 connecting to redis:6379. 111.
[E 240822 09:12:35 boot:499] Task exception was never retrieved
future: <Task finished name='Task-4942' coro=<Subscribers.subscribe() done, defined at /root/axis-stable/axis/services/subscribers.py:264> exception=ConnectionError('Error 111 connecting to redis:6379. 111.')>
Traceback (most recent call last):
...
...
...
[E 240822 09:12:37 decorator:576] Traceback (most recent call last):
...
...
...
切断中 高頻度で出力
定期的に実行されるそれぞれの処理により、ConnectionError、もしくはTimeoutErrorが出力されます。ConnectionError
[E 240822 09:14:58 decorator:576] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 692, in connect
await self._connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 719, in _connect
reader, writer = await asyncio.open_connection(
File "/usr/local/lib/python3.10/asyncio/streams.py", line 48, in open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
ConnectionRefusedError: [Errno 111] Connection refused
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/decorator.py", line 568, in wrapper
return await func(*args, **kwargs, conn=conn)
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 1617, in get_connection
await connection.connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 698, in connect
raise ConnectionError(self._error_message(e))
aioredis.exceptions.ConnectionError: Error 111 connecting to redis:6379. 111.
[E 240822 09:15:20 decorator:576] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 719, in _connect
reader, writer = await asyncio.open_connection(
File "/usr/local/lib/python3.10/asyncio/streams.py", line 48, in open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2029, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 692, in connect
await self._connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 718, in _connect
async with async_timeout.timeout(self.socket_connect_timeout):
File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
self._do_exit(exc_type)
File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/xxx.py", line xxx, in xxx
xxxxxxxxxxxxxxxxxxx
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 1082, in execute_command
conn = self.connection or await pool.get_connection(command_name, **options)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 1617, in get_connection
await connection.connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 696, in connect
raise TimeoutError("Timeout connecting to server")
aioredis.exceptions.TimeoutError: Timeout connecting to server
復帰ログ
[E 240822 09:19:35 decorator:576] Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 692, in connect
await self._connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 719, in _connect
reader, writer = await asyncio.open_connection(
File "/usr/local/lib/python3.10/asyncio/streams.py", line 48, in open_connection
transport, _ = await loop.create_connection(
File "uvloop/loop.pyx", line 2039, in create_connection
File "uvloop/loop.pyx", line 2016, in uvloop.loop.Loop.create_connection
ConnectionRefusedError: [Errno 111] Connection refused
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/root/axis-stable/axis/lib/decorator.py", line 568, in wrapper
return await func(*args, **kwargs, conn=conn)
File "/root/axis-stable/axis/boot/context.py", line 3956, in hgetall
o = await conn.hgetall(key)
File "/usr/local/lib/python3.10/site-packages/aioredis/client.py", line 1082, in execute_command
conn = self.connection or await pool.get_connection(command_name, **options)
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 1617, in get_connection
await connection.connect()
File "/usr/local/lib/python3.10/site-packages/aioredis/connection.py", line 698, in connect
raise ConnectionError(self._error_message(e))
aioredis.exceptions.ConnectionError: Error 111 connecting to redis:6379. 111.
[I 240822 09:19:36 boot:115] {"status":200,"method":"GET","url":"/services","remote":"10.98.37.45","elapsed":"79.16ms"}
[I 240822 09:19:36 boot:115] {"status":200,"method":"GET","url":"/masterlookup?role=SCENARIO&scope=cluster","remote":"10.98.36.136","elapsed":"2.45ms"}
[I 240822 09:19:36 daemon:107] DeleteCompletedHealthCheckOperation daemon is already active.
[I 240822 09:19:36 boot:115] {"status":200,"method":"GET","url":"/processes","remote":"10.98.37.45","elapsed":"14.01ms"}
[W 240822 09:19:37 context:3540] Detects disconnection of internal sync channels...
[I 240822 09:19:37 event_handler:99] [9] Recovered internal pubsub channels ['xaas.service.channel', 'xaas.daemon.channel', 'xaas.plugins.channel', 'xaas.sync.channel']
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/plugins","remote":"10.98.36.136","elapsed":"4.16ms"}
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/modelschemas","remote":"10.98.36.136","elapsed":"6.13ms"}
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/classes","remote":"10.98.36.136","elapsed":"5.03ms"}
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/modules","remote":"10.98.36.136","elapsed":"5.38ms"}
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/functions","remote":"10.98.36.136","elapsed":"3.41ms"}
[I 240822 09:19:40 boot:115] {"status":200,"method":"GET","url":"/formats","remote":"10.98.36.136","elapsed":"2.36ms"}
[I 240822 09:19:45 boot:115] {"status":200,"method":"GET","url":"/masterlookup?role=SCENARIO&scope=cluster","remote":"10.98.36.136","elapsed":"2.77ms"}
[I 240822 09:19:48 boot:115] {"status":200,"method":"GET","url":"/services","remote":"10.98.37.45","elapsed":"46.85ms"}
[I 240822 09:19:48 boot:115] {"status":200,"method":"GET","url":"/processes","remote":"10.98.37.45","elapsed":"13.56ms"}