Skip to:

  1. Skip to Jira Navigation
  2. Skip to Side Navigation
  3. Skip to Main Content

repeated tracebacks and system messages due to client-server socket timeout

Description

Not dissimilar to (closed due to no debug file), could be same issue. At first it looks like an issue with disk timeout, but I think it might be more likely to be client-server socket timeout in middleware.

I've had this both during a local zfs send/recv, and also when it didn't seem so busy.

Sample of log messages below.

Debug log to follow once the system isn't so busy doing send/recv that it can generate one.

SAMPLE:

File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 01:24:28 MY-NAS 1 2020-08-01T01:24:28.912951+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 01:29:27 MY-NAS 1 2020-08-01T01:29:27.572448+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 01:34:27 MY-NAS 1 2020-08-01T01:34:27.118619+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 01:54:27 MY-NAS 1 2020-08-01T01:54:27.538840+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 01:59:27 MY-NAS 1 2020-08-01T01:59:27.109865+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 02:14:27 MY-NAS 1 2020-08-01T02:14:27.182634+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 02:29:30 MY-NAS 1 2020-08-01T02:29:30.206703+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 02:39:27 MY-NAS 1 2020-08-01T02:39:27.176557+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 02:44:27 MY-NAS 1 2020-08-01T02:44:27.112646+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 02:49:32 MY-NAS 1 2020-08-01T02:49:32.453178+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:04:29 MY-NAS 1 2020-08-01T03:04:29.118655+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:09:27 MY-NAS 1 2020-08-01T03:09:27.775170+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:14:33 MY-NAS 1 2020-08-01T03:14:33.274547+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:19:27 MY-NAS 1 2020-08-01T03:19:27.378490+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:24:28 MY-NAS 1 2020-08-01T03:24:28.543476+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 03:29:27 MY-NAS 1 2020-08-01T03:29:27.116494+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 03:34:27 MY-NAS 1 2020-08-01T03:34:27.353548+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 03:49:28 MY-NAS 1 2020-08-01T03:49:28.396620+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 04:29:27 MY-NAS 1 2020-08-01T04:29:27.113494+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 04:44:30 MY-NAS 1 2020-08-01T04:44:30.586127+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 284, in _init_
raise ClientException('Failed connection handshake')
middlewared.client.client.ClientException: Failed connection handshake
Aug 1 04:49:27 MY-NAS 1 2020-08-01T04:49:27.201128+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 05:08:44 MY-NAS 1 2020-08-01T05:08:44.765474+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:13:41 MY-NAS 1 2020-08-01T05:13:41.467173+01:00 MY-NAS.earlobe.site login 4274 - - ROOT LOGIN (root) ON ttyv1
Aug 1 05:14:27 MY-NAS 1 2020-08-01T05:14:27.109690+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 05:15:37 MY-NAS 1 2020-08-01T05:15:37.971956+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:15:53 MY-NAS 1 2020-08-01T05:15:53.924213+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:16:10 MY-NAS 1 2020-08-01T05:16:10.624357+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:16:22 MY-NAS 1 2020-08-01T05:16:22.351336+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:16:45 MY-NAS 1 2020-08-01T05:16:45.440896+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:17:17 MY-NAS 1 2020-08-01T05:17:17.037329+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:17:40 MY-NAS 1 2020-08-01T05:17:40.773009+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:17:50 MY-NAS 1 2020-08-01T05:17:50.920019+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:18:01 MY-NAS 1 2020-08-01T05:18:01.908546+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:18:57 MY-NAS 1 2020-08-01T05:18:57.454009+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:19:09 MY-NAS 1 2020-08-01T05:19:09.246733+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:19:20 MY-NAS 1 2020-08-01T05:19:20.172738+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:19:27 MY-NAS 1 2020-08-01T05:19:27.118425+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 05:19:52 MY-NAS 1 2020-08-01T05:19:52.920312+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:20:36 MY-NAS 1 2020-08-01T05:20:36.712831+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:21:00 MY-NAS 1 2020-08-01T05:21:00.665444+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:21:11 MY-NAS 1 2020-08-01T05:21:11.198233+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:21:29 MY-NAS 1 2020-08-01T05:21:29.094186+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:22:04 MY-NAS 1 2020-08-01T05:22:04.290839+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:22:37 MY-NAS 1 2020-08-01T05:22:37.388620+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:23:01 MY-NAS 1 2020-08-01T05:23:01.659423+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:23:24 MY-NAS 1 2020-08-01T05:23:24.818393+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:23:59 MY-NAS 1 2020-08-01T05:23:59.695865+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:24:19 MY-NAS 1 2020-08-01T05:24:19.589141+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:24:27 MY-NAS 1 2020-08-01T05:24:27.109610+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 05:24:44 MY-NAS 1 2020-08-01T05:24:44.811166+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:25:05 MY-NAS 1 2020-08-01T05:25:05.720039+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:25:16 MY-NAS 1 2020-08-01T05:25:16.430408+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:25:51 MY-NAS 1 2020-08-01T05:25:51.969107+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:26:01 MY-NAS 1 2020-08-01T05:26:01.180621+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:26:31 MY-NAS 1 2020-08-01T05:26:31.317882+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:27:09 MY-NAS 1 2020-08-01T05:27:09.447646+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:27:27 MY-NAS 1 2020-08-01T05:27:27.867201+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:27:55 MY-NAS 1 2020-08-01T05:27:55.421973+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:28:06 MY-NAS 1 2020-08-01T05:28:06.403217+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:28:12 MY-NAS 1 2020-08-01T05:28:12.148220+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:28:34 MY-NAS 1 2020-08-01T05:28:34.423931+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:28:57 MY-NAS 1 2020-08-01T05:28:57.277247+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:29:22 MY-NAS 1 2020-08-01T05:29:22.426285+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:29:27 MY-NAS 1 2020-08-01T05:29:27.110182+01:00 MY-NAS.earlobe.site collectd 45932 - - Traceback (most recent call last):
File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 62, in read
with Client() as c:
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 281, in _init_
self._ws.connect()
File "/usr/local/lib/python3.8/site-packages/middlewared/client/client.py", line 124, in connect
rv = super(WSClient, self).connect()
File "/usr/local/lib/python3.8/site-packages/ws4py/client/_init_.py", line 223, in connect
bytes = self.sock.recv(128)
socket.timeout: timed out
Aug 1 05:29:33 MY-NAS 1 2020-08-01T05:29:33.981727+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:29:55 MY-NAS 1 2020-08-01T05:29:55.988329+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:30:13 MY-NAS 1 2020-08-01T05:30:13.918306+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:31:02 MY-NAS 1 2020-08-01T05:31:02.003662+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client
Aug 1 05:31:14 MY-NAS 1 2020-08-01T05:31:14.542079+01:00 MY-NAS.earlobe.site devd 3330 - - notify_clients: send() failed; dropping unresponsive client

Problem/Justification

None

Impact

None

SmartDraw Connector

Katalon Manual Tests (BETA)

Activity

Show:

Stilez 
August 26, 2020 at 1:12 AM
(edited)

See also my comment at

 

Pathological scrub behaviour now collated and issue created: 

Alexander Motin 
August 14, 2020 at 1:44 PM

, it looks like worth reproduction/investigation. I don't remember complains like that.

Stilez 
August 13, 2020 at 11:12 PM
(edited)

It does happen after Beta2. But I think it's a symptom of another issue.

When I set scrub going on both pools, it's forcing the CPU into starvation (top: 0.0% idle, many "z_rd_int_NN"). Keystrokes take 5-10 secs to appear, sessions take 10-20 secs to login. Pause the scrub and it's immediately fine. I haven't seen this behaviour other than during CPU starvation... yet

I'm guessing what happens is, with no other pool activity at all going on, ZFS goes as fast as it can on scrub... but on a deduped pool scrub involves a lot of CPU hashchecks, and the metrics  designed to stop scrub dominating I/O (scan_vdev_limit, scrub_max_active etc) maybe aren't  checking if it's tangentially dominating CPU as a byproduct when hashing at speed, or ensuring some percent of CPU is reserved?  (I've got zio.taskq_batch_pct set at max 80% of CPU, but that doesn't seem to help)

Screenshot of "top" and help request was posted on forums: https://www.ixsystems.com/community/threads/correct-tunable-to-reduce-out-of-control-scrub-cpu-usage-z_rd_int.86796.  Scrub was starving my 4 core E5-1620 v4 (never had an issue on 11.3), so I swapped that to an 8 core E5-1680 v4 and immediately ZFS grabbed all 8 cores of that at 100%  instead.

I've tried all tunables I can find that could bring scrub under control without affecting other operations. Right now I'm at:

and it's still using 100% of an 8 core Xeon v4 for scrub to the point that WebUI, SSH and largely, keystrokes in the console, fail or are greatly delayed.

 

Is the CPU starvation issue worth reporting?

Stilez 
August 3, 2020 at 5:50 PM

OK and thank you

William Gryzbowski 
August 3, 2020 at 5:30 PM

We think this is a duplicate of an issue that happens when middlewared log rotates. Let us know if this happens after BETA2.

Duplicate

Details

Assignee

Reporter

Components

Fix versions

Affects versions

Priority

More fields

Katalon Platform

Created August 1, 2020 at 4:36 AM
Updated July 1, 2022 at 4:56 PM
Resolved August 3, 2020 at 5:30 PM