TrueNAS 12 (ESXi VM) crashed

testcb00 · Apr 22, 2023

Today when I wake up, I find that the services in my Jail are in Down state.

I try to access the server UI but it failed to show the login page (keeping say "Connecting to NAS", like in booting stage).

Luckily, I can reboot the server via Console.
After the reboot, I try to find the problem. It seems that the TrueNAS is broken after upsmon / upssched event.

I have tested the UPS service function (physically / dummy), TrueNAS works flawlessly in blackout simulation.
Though the event in this case seems to be Electrical Noise (5 seconds), there should be a timer trigger just after the ONBATT notification.
From the log, the timer daemon is delayed around 10-16 seconds.

However, the error is called after 18 mins of upsmon event.
The error ConnectionRefusedError: [Errno 61] Connection refused keep looping after it exists.
It seems that the middlewared is the problem.

I would like to know the reason and the solution of the problem.


Apr 22 21:08:05 truenas 1 2023-04-22T21:08:05.807482+00:00 truenas.local upsmon 1120 - - UPS be850g2@192.168.99.4:3493 on battery
Apr 22 21:08:05 truenas 1 2023-04-22T21:08:05.846560+00:00 truenas.local upssched 34268 - - Executing command: NOTIFY-ONBATT
Apr 22 21:08:10 truenas 1 2023-04-22T21:08:10.817258+00:00 truenas.local upsmon 1120 - - UPS be850g2@192.168.99.4:3493 on line power
Apr 22 21:08:10 truenas 1 2023-04-22T21:08:10.820591+00:00 truenas.local upssched 34275 - - Executing command: NOTIFY-ONLINE
Apr 22 21:08:21 truenas 1 2023-04-22T21:08:21.685798+00:00 truenas.local upssched 34282 - - Timer daemon started
Apr 22 21:08:21 truenas 1 2023-04-22T21:08:21.939250+00:00 truenas.local upssched 34282 - - New timer: SHUTDOWN (15 seconds)
Apr 22 21:08:36 truenas 1 2023-04-22T21:08:36.154355+00:00 truenas.local upssched 34282 - - Event: SHUTDOWN 
Apr 22 21:08:57 truenas 1 2023-04-22T21:08:57.945519+00:00 truenas.local upssched 34282 - - Timer queue empty, exiting
Apr 22 21:13:38 truenas 1 2023-04-22T21:13:38.838853+00:00 truenas.local upsmon 1120 - - UPS be850g2@192.168.99.4:3493 on battery
Apr 22 21:13:38 truenas 1 2023-04-22T21:13:38.841917+00:00 truenas.local upssched 34399 - - Executing command: NOTIFY-ONBATT
Apr 22 21:13:43 truenas 1 2023-04-22T21:13:43.850552+00:00 truenas.local upsmon 1120 - - UPS be850g2@192.168.99.4:3493 on line power
Apr 22 21:13:43 truenas 1 2023-04-22T21:13:43.853612+00:00 truenas.local upssched 34405 - - Executing command: NOTIFY-ONLINE
Apr 22 21:13:49 truenas 1 2023-04-22T21:13:49.547100+00:00 truenas.local upssched 34410 - - Timer daemon started
Apr 22 21:13:49 truenas 1 2023-04-22T21:13:49.812502+00:00 truenas.local upssched 34410 - - New timer: SHUTDOWN (15 seconds)
Apr 22 21:14:04 truenas 1 2023-04-22T21:14:04.049438+00:00 truenas.local upssched 34410 - - Event: SHUTDOWN 
Apr 22 21:14:24 truenas 1 2023-04-22T21:14:24.849800+00:00 truenas.local upssched 34410 - - Timer queue empty, exiting
Apr 22 21:32:17 truenas 1 2023-04-22T21:32:17.187302+00:00 truenas.local collectd 21091 - - rrdcached plugin: Failed to reconnect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:32:17 truenas 1 2023-04-22T21:32:17.187387+00:00 truenas.local collectd 21091 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:32:17 truenas 1 2023-04-22T21:32:17.187472+00:00 truenas.local collectd 21091 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:32:17 truenas 1 2023-04-22T21:32:17.187519+00:00 truenas.local collectd 21091 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:32:17 truenas 1 2023-04-22T21:32:17.187553+00:00 truenas.local collectd 21091 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.250178+00:00 truenas.local collectd 34842 - - plugin_load: plugin "syslog" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.250722+00:00 truenas.local collectd 34842 - - plugin_load: plugin "threshold" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.250866+00:00 truenas.local collectd 34842 - - plugin_load: plugin "zfs_arc" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.250997+00:00 truenas.local collectd 34842 - - plugin_load: plugin "nfsstat" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.251443+00:00 truenas.local collectd 34842 - - plugin_load: plugin "write_graphite" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.251594+00:00 truenas.local collectd 34842 - - plugin_load: plugin "cputemp" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.251749+00:00 truenas.local collectd 34842 - - plugin_load: plugin "ctl" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.252175+00:00 truenas.local collectd 34842 - - plugin_load: plugin "geom_stat" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.252460+00:00 truenas.local collectd 34842 - - plugin_load: plugin "nut" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.256663+00:00 truenas.local collectd 34842 - - plugin_load: plugin "python" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.257100+00:00 truenas.local collectd 34842 - - plugin_load: plugin "zfs_arc_v2" successfully loaded.
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.257135+00:00 truenas.local collectd 34842 - - plugin = nut, key = UPS, value = be850g2@192.168.99.4:3493
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.257146+00:00 truenas.local collectd 34842 - - nut plugin: nut_add_ups (name = be850g2@192.168.99.4:3493);
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.257166+00:00 truenas.local collectd 34842 - - plugin = syslog, key = LogLevel, value = err
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.533870+00:00 truenas.local collectd 34842 - - Traceback (most recent call last):
  File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 43, in init
    with Client() as c:
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 283, in __init__
    self._ws.connect()
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 124, in connect
    rv = super(WSClient, self).connect()
  File "/usr/local/lib/python3.9/site-packages/ws4py/client/__init__.py", line 216, in connect
    self.sock.connect(self.bind_addr)
ConnectionRefusedError: [Errno 61] Connection refused
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.535648+00:00 truenas.local collectd 34842 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.536104+00:00 truenas.local collectd 34842 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.536245+00:00 truenas.local collectd 34842 - - rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: Connection refused (status=61)
Apr 22 21:34:16 truenas 1 2023-04-22T21:34:16.537084+00:00 truenas.local collectd 34842 - - Traceback (most recent call last):
  File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 43, in init
    with Client() as c:
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 283, in __init__
    self._ws.connect()
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 124, in connect
    rv = super(WSClient, self).connect()
  File "/usr/local/lib/python3.9/site-packages/ws4py/client/__init__.py", line 216, in connect
    self.sock.connect(self.bind_addr)
ConnectionRefusedError: [Errno 61] Connection refused
Apr 22 21:39:16 truenas 1 2023-04-22T21:39:16.564846+00:00 truenas.local collectd 34842 - - Traceback (most recent call last):
  File "/usr/local/lib/collectd_pyplugins/disktemp.py", line 43, in init
    with Client() as c:
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 283, in __init__
    self._ws.connect()
  File "/usr/local/lib/python3.9/site-packages/middlewared/client/client.py", line 124, in connect
    rv = super(WSClient, self).connect()
  File "/usr/local/lib/python3.9/site-packages/ws4py/client/__init__.py", line 216, in connect
    self.sock.connect(self.bind_addr)
ConnectionRefusedError: [Errno 61] Connection refused

Important Announcement for the TrueNAS Community.

TrueNAS 12 (ESXi VM) crashed

testcb00

Dabbler

Similar threads