Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Jira Tracker] TrueNAS API reports error 500 when sensor on TrueNAS side is not working #12

Open
tomaae opened this issue Apr 12, 2022 · 20 comments
Labels
bug Something isn't working testing Solution is being tested

Comments

@tomaae
Copy link
Owner

tomaae commented Apr 12, 2022

ok, I will only use another branch based on author's advice.

strange I have 2 TrueNAS Scale servers on different Proxmox servers. 1 is reporting correctly in HA and one I'm still getting a 500.

2022-04-11 11:24:07 DEBUG (SyncWorker_5) [custom_components.truenas.truenas_api] TrueNAS 192.168.1.101 query: system/info, get, {}
2022-04-11 11:24:07 DEBUG (SyncWorker_5) [custom_components.truenas.truenas_api] TrueNAS 192.168.1.101 query response: {'version': 'TrueNAS-SCALE-22.02.0.1', 'buildtime': {'$date': 1647930354000}, 'hostname': 'PCC-NAS2.localhost', 'physmem': 12552777728, 'model': 'AMD Phenom(tm) 9550 Quad-Core Processor', 'cores': 4, 'physical_cores': 4, 'loadavg': [0.04, 0.1, 0.04], 'uptime': '2:44:00.515940', 'uptime_seconds': 9840.515940204, 'system_serial': 'Not Specified', 'system_product': 'Standard PC (i440FX + PIIX, 1996)', 'system_product_version': 'pc-i440fx-6.1', 'license': None, 'boottime': {'$date': 1649680807088}, 'datetime': {'$date': 1649690647604}, 'birthday': None, 'timezone': 'America/Toronto', 'system_manufacturer': 'QEMU', 'ecc_memory': True}
2022-04-11 11:24:07 DEBUG (SyncWorker_5) [custom_components.truenas.apiparser] Processing source [{'version': 'TrueNAS-SCALE-22.02.0.1', 'buildtime': {'$date': 1647930354000}, 'hostname': 'PCC-NAS2.localhost', 'physmem': 12552777728, 'model': 'AMD Phenom(tm) 9550 Quad-Core Processor', 'cores': 4, 'physical_cores': 4, 'loadavg': [0.04, 0.1, 0.04], 'uptime': '2:44:00.515940', 'uptime_seconds': 9840.515940204, 'system_serial': '**REDACTED**', 'system_product': 'Standard PC (i440FX + PIIX, 1996)', 'system_product_version': 'pc-i440fx-6.1', 'license': None, 'boottime': {'$date': 1649680807088}, 'datetime': {'$date': 1649690647604}, 'birthday': None, 'timezone': 'America/Toronto', 'system_manufacturer': 'QEMU', 'ecc_memory': True}]
2022-04-11 11:24:07 DEBUG (SyncWorker_5) [custom_components.truenas.apiparser] Processing entry {'version': 'TrueNAS-SCALE-22.02.0.1', 'buildtime': {'$date': 1647930354000}, 'hostname': 'PCC-NAS2.localhost', 'physmem': 12552777728, 'model': 'AMD Phenom(tm) 9550 Quad-Core Processor', 'cores': 4, 'physical_cores': 4, 'loadavg': [0.04, 0.1, 0.04], 'uptime': '2:44:00.515940', 'uptime_seconds': 9840.515940204, 'system_serial': '**REDACTED**', 'system_product': 'Standard PC (i440FX + PIIX, 1996)', 'system_product_version': 'pc-i440fx-6.1', 'license': None, 'boottime': {'$date': 1649680807088}, 'datetime': {'$date': 1649690647604}, 'birthday': None, 'timezone': 'America/Toronto', 'system_manufacturer': 'QEMU', 'ecc_memory': True}
2022-04-11 11:24:08 DEBUG (SyncWorker_6) [custom_components.truenas.truenas_api] TrueNAS 192.168.1.101 query: reporting/get_data, post, {'graphs': [{'name': 'load'}, {'name': 'cpu'}, {'name': 'arcsize'}, {'name': 'arcratio'}], 'reporting_query': {'start': 'now-90s', 'end': 'now-30s', 'aggregate': True}}
2022-04-11 11:24:08 WARNING (SyncWorker_6) [custom_components.truenas.truenas_api] TrueNAS 192.168.1.101 unable to fetch data (500)

Originally posted by @pcampan in #9 (comment)

@tomaae tomaae added bug Something isn't working more info needed Need more information labels Apr 12, 2022
@tomaae
Copy link
Owner Author

tomaae commented Apr 12, 2022

error 500 is not documented at all, so confirming on truenas forums

@tomaae
Copy link
Owner Author

tomaae commented Apr 12, 2022

Confirmed this looks like a bug by ixsystems. Jira ticked opened NAS-115761

@andreclemente
Copy link
Contributor

I'm also having this issue, here's my logbook:
June 20, 2022
NAS Uptime became unavailable
3:47:00 PM - 1 minute ago

NAS Uptime changed to June 20, 2022 at 3:11 PM
3:47:00 PM - 1 minute ago

NAS Uptime became unavailable
3:46:00 PM - 2 minutes ago

NAS Uptime changed to June 20, 2022 at 3:11 PM
3:46:00 PM - 2 minutes ago

NAS Uptime became unavailable
3:51:00 PM - 3 minutes ago

I'm running TrueNAS Core v13 (same issue with v12) in a QEMU VM.

Any clue?

@tomaae
Copy link
Owner Author

tomaae commented Jun 21, 2022

I'm also having this issue, here's my logbook: June 20, 2022 NAS Uptime became unavailable 3:47:00 PM - 1 minute ago

NAS Uptime changed to June 20, 2022 at 3:11 PM 3:47:00 PM - 1 minute ago

NAS Uptime became unavailable 3:46:00 PM - 2 minutes ago

NAS Uptime changed to June 20, 2022 at 3:11 PM 3:46:00 PM - 2 minutes ago

NAS Uptime became unavailable 3:51:00 PM - 3 minutes ago

I'm running TrueNAS Core v13 (same issue with v12) in a QEMU VM.

Any clue?

Open a separate issue for it, you will also need to provide debugs capturing the issue.

@andreclemente
Copy link
Contributor

I think the problem is exactly the same:

2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.truenas_api] TrueNAS truenas.local query: system/info, get, {}
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.truenas_api] TrueNAS truenas.local query response: {'version': 'TrueNAS-13.0-RELEASE', 'buildtime': {'$date': 1652121872000}, 'hostname': 'truenas.local', 'physmem': 12832964608, 'model': 'Intel Xeon Processor (Cooperlake)', 'cores': 6, 'loadavg': [0.24365234375, 0.26513671875, 0.24658203125], 'uptime': '9:02:30.667797', 'uptime_seconds': 32550.667796614, 'system_serial': 'Not Specified', 'system_product': 'Standard PC (Q35 + ICH9, 2009)', 'system_product_version': 'pc-q35-6.0', 'license': None, 'boottime': {'$date': 1655764990000}, 'datetime': {'$date': 1655797541102}, 'birthday': {'$date': 1632178179458}, 'timezone': 'Europe/Lisbon', 'system_manufacturer': 'QEMU', 'ecc_memory': True}
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.apiparser] Processing source [{'version': 'TrueNAS-13.0-RELEASE', 'buildtime': {'$date': 1652121872000}, 'hostname': 'truenas.local', 'physmem': 12832964608, 'model': 'Intel Xeon Processor (Cooperlake)', 'cores': 6, 'loadavg': [0.24365234375, 0.26513671875, 0.24658203125], 'uptime': '9:02:30.667797', 'uptime_seconds': 32550.667796614, 'system_serial': '**REDACTED**', 'system_product': 'Standard PC (Q35 + ICH9, 2009)', 'system_product_version': 'pc-q35-6.0', 'license': None, 'boottime': {'$date': 1655764990000}, 'datetime': {'$date': 1655797541102}, 'birthday': {'$date': 1632178179458}, 'timezone': 'Europe/Lisbon', 'system_manufacturer': 'QEMU', 'ecc_memory': True}]
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.apiparser] Processing entry {'version': 'TrueNAS-13.0-RELEASE', 'buildtime': {'$date': 1652121872000}, 'hostname': 'truenas.local', 'physmem': 12832964608, 'model': 'Intel Xeon Processor (Cooperlake)', 'cores': 6, 'loadavg': [0.24365234375, 0.26513671875, 0.24658203125], 'uptime': '9:02:30.667797', 'uptime_seconds': 32550.667796614, 'system_serial': '**REDACTED**', 'system_product': 'Standard PC (Q35 + ICH9, 2009)', 'system_product_version': 'pc-q35-6.0', 'license': None, 'boottime': {'$date': 1655764990000}, 'datetime': {'$date': 1655797541102}, 'birthday': {'$date': 1632178179458}, 'timezone': 'Europe/Lisbon', 'system_manufacturer': 'QEMU', 'ecc_memory': True}
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.truenas_api] TrueNAS truenas.local query: interface, get, {}
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.truenas_api] TrueNAS truenas.local query response: [{'id': 're0', 'name': 're0', 'fake': False, 'type': 'PHYSICAL', 'state': {'name': 're0', 'orig_name': 're0', 'description': None, 'mtu': 1500, 'cloned': False, 'flags': ['DRV_RUNNING', 'UP', 'BROADCAST', 'PROMISC', 'SIMPLEX', 'MULTICAST', 'CANTCONFIG', 'PPROMISC', 'MONITOR', 'STATICARP', 'DYING', 'RENAMING'], 'nd6_flags': ['IFDISABLED', 'PERFORMNUD'], 'capabilities': ['VLAN_MTU', 'VLAN_HWTAGGING', 'VLAN_HWCSUM', 'LINKSTATE'], 'link_state': 'LINK_STATE_UP', 'media_type': 'Ethernet', 'media_subtype': 'autoselect', 'active_media_type': 'Ethernet', 'active_media_subtype': '100baseTX', 'supported_media': ['autoselect', '10baseT/UTP', '100baseTX'], 'media_options': [], 'aliases': [{'type': 'LINK'}, {'type': 'INET', 'netmask': 24, 'broadcast': '10.0.10.255'}], 'carp_config': []}, 'aliases': [], 'ipv4_dhcp': True, 'ipv6_auto': False, 'description': '', 'options': '', 'mtu': None, 'disable_offload_capabilities': True}]
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.apiparser] Processing source [{'id': 're0', 'name': 're0', 'fake': False, 'type': 'PHYSICAL', 'state': {'name': 're0', 'orig_name': 're0', 'description': None, 'mtu': 1500, 'cloned': False, 'flags': ['DRV_RUNNING', 'UP', 'BROADCAST', 'PROMISC', 'SIMPLEX', 'MULTICAST', 'CANTCONFIG', 'PPROMISC', 'MONITOR', 'STATICARP', 'DYING', 'RENAMING'], 'nd6_flags': ['IFDISABLED', 'PERFORMNUD'], 'capabilities': ['VLAN_MTU', 'VLAN_HWTAGGING', 'VLAN_HWCSUM', 'LINKSTATE'], 'link_state': 'LINK_STATE_UP', 'media_type': 'Ethernet', 'media_subtype': 'autoselect', 'active_media_type': 'Ethernet', 'active_media_subtype': '100baseTX', 'supported_media': ['autoselect', '10baseT/UTP', '100baseTX'], 'media_options': [], 'aliases': [{'type': 'LINK'}, {'type': 'INET', 'netmask': 24, 'broadcast': '10.0.10.255'}], 'carp_config': []}, 'aliases': [], 'ipv4_dhcp': True, 'ipv6_auto': False, 'description': '', 'options': '', 'mtu': None, 'disable_offload_capabilities': True}]
2022-06-21 08:45:41 DEBUG (SyncWorker_1) [custom_components.truenas.apiparser] Processing entry {'id': 're0', 'name': 're0', 'fake': False, 'type': 'PHYSICAL', 'state': {'name': 're0', 'orig_name': 're0', 'description': None, 'mtu': 1500, 'cloned': False, 'flags': ['DRV_RUNNING', 'UP', 'BROADCAST', 'PROMISC', 'SIMPLEX', 'MULTICAST', 'CANTCONFIG', 'PPROMISC', 'MONITOR', 'STATICARP', 'DYING', 'RENAMING'], 'nd6_flags': ['IFDISABLED', 'PERFORMNUD'], 'capabilities': ['VLAN_MTU', 'VLAN_HWTAGGING', 'VLAN_HWCSUM', 'LINKSTATE'], 'link_state': 'LINK_STATE_UP', 'media_type': 'Ethernet', 'media_subtype': 'autoselect', 'active_media_type': 'Ethernet', 'active_media_subtype': '100baseTX', 'supported_media': ['autoselect', '10baseT/UTP', '100baseTX'], 'media_options': [], 'aliases': [{'type': 'LINK'}, {'type': 'INET', 'netmask': 24, 'broadcast': '10.0.10.255'}], 'carp_config': []}, 'aliases': [], 'ipv4_dhcp': True, 'ipv6_auto': False, 'description': '', 'options': '', 'mtu': None, 'disable_offload_capabilities': True}
2022-06-21 08:45:41 DEBUG (SyncWorker_4) [custom_components.truenas.truenas_api] TrueNAS truenas.local query: reporting/get_data, post, {'graphs': [{'name': 'load'}, {'name': 'cpu'}, {'name': 'arcsize'}, {'name': 'arcratio'}, {'name': 'interface', 'identifier': 're0'}], 'reporting_query': {'start': 'now-90s', 'end': 'now-30s', 'aggregate': True}}

2022-06-21 08:45:41 WARNING (SyncWorker_4) [custom_components.truenas.truenas_api] TrueNAS truenas.local unable to fetch data (500)

2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_uptime
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cpu_temperature
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_load_shortterm
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_load_midterm
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_load_longterm
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cpu_usage
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cache_size-arc_value
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cache_size-L2_value
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cache_ratio-arc_value
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-system_cache_ratio-L2_value
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-traffic_rx-re0
2022-06-21 08:45:41 DEBUG (MainThread) [custom_components.truenas.model] Updating entity NAS-traffic_tx-re0

@tomaae
Copy link
Owner Author

tomaae commented Jun 21, 2022

Technically, yes. It is related to TrueNAS bug. But it has nothing to do with tracking it.
Your issue seems to be related to #28

@lbandi2
Copy link

lbandi2 commented Jun 22, 2022

I have the same issue with 1.1 and 1.1.1 so I've rolled back to 1.0.2.

I don't know if it is related or not, but when I click on "Visit device" it opens up the wrong URL because I have it set to HTTPS and it just opens HTTP.

image

@tomaae
Copy link
Owner Author

tomaae commented Jun 23, 2022

I have the same issue with 1.1 and 1.1.1 so I've rolled back to 1.0.2.

I don't know if it is related or not, but when I click on "Visit device" it opens up the wrong URL because I have it set to HTTPS and it just opens HTTP.

image

Open a new issue, you will need to provide debugs as well.

@Final-Hawk
Copy link

Final-Hawk commented Jul 11, 2022

I was having this issue and I found the cause on my system.
It was the setting "Report CPU usage in percent"

You can find this under: Reporting -> Settings icon (top right) -> deselect "Report CPU usage in percent" and save.

Hopefully this works for you!

Edit: Seems like what I thought fixed it, doesn't work. I did have this issue, but then it started working again after a reboot. Strange.

@andreclemente
Copy link
Contributor

System -> Reporting -> Report CPU usage in percent -> false
Didn't work for me :/

@andreclemente
Copy link
Contributor

andreclemente commented Jul 11, 2022

I explored a bit more and I was finally able to fix it!

$ service collectd stop
$ service rrdcached stop
$ rm -rf /var/db/collectd/rrd/*
$ cd /var/db/collectd/rrd/
$ mkdir localhost
$ ln -s localhost truenas.local
$ ln -s localhost [FQDN]
$ service rrdcached start
$ service collectd start Edit: Maybe $ service collectd onestart

Also ran $ rm -rf /var/db/collectd/rrd/* but I'm not sure if this helped or not.

Credits: https://www.truenas.com/community/threads/rrdcached-could-not-read-rrd-file.74785/post-534842

@lbandi2
Copy link

lbandi2 commented Jul 11, 2022

Tried the Report CPU usage in percent -> false option, but didn't do anything.

I also tried the fix you mentioned but didn't work for me either. I get to the final point where I have to start collectd and it says:

root@truenas:/var/db/collectd/rrd # service collectd start
Cannot 'start' collectd. Set collectd_enable to YES in /etc/rc.conf or use 'onestart' instead of 'start'.
root@truenas:/var/db/collectd/rrd # service collectd onestart
collectd already running? (pid=85758).
root@truenas:/var/db/collectd/rrd # service collectd status
Cannot 'status' collectd. Set collectd_enable to YES in /etc/rc.conf or use 'onestatus' instead of 'status'.

@andreclemente
Copy link
Contributor

What about $ service collectd onestart ?

@lbandi2
Copy link

lbandi2 commented Jul 11, 2022

I ran it on the third line, the fourth line is the output.

@andreclemente
Copy link
Contributor

And did you reboot it? And maybe reconfigure the integration...

@lbandi2
Copy link

lbandi2 commented Jul 11, 2022

Yep, both TrueNAS and HA and tried reconfiguring the integration.

The funny thing is that 1.02 runs fine.

@andreclemente
Copy link
Contributor

The integration never worked for me before. Only today after those commands. Sorry I can't help you :/

@lbandi2
Copy link

lbandi2 commented Jul 11, 2022

Don't worry, you get an A for effort heh.

Repository owner locked as off-topic and limited conversation to collaborators Jul 11, 2022
@tomaae
Copy link
Owner Author

tomaae commented Jul 11, 2022

I will be locking conversation here as it is being used to unrelated discussions. This issue is only a placeholder for TrueNAS API bug.
Just open a ticket for your specific issue and we can have a look.

@tomaae tomaae added the planned To be implemented in future release label Aug 13, 2022
@tomaae tomaae unpinned this issue Aug 15, 2022
@tomaae
Copy link
Owner Author

tomaae commented Aug 17, 2022

Should not reoccur anymore due to workaround

@tomaae tomaae added testing Solution is being tested and removed planned To be implemented in future release labels Aug 17, 2022
@tomaae tomaae changed the title [Bug] TrueNAS API reports error 500 when sensor on TrueNAS side is not working [Jira Tracker] TrueNAS API reports error 500 when sensor on TrueNAS side is not working Nov 3, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working testing Solution is being tested
Projects
None yet
Development

No branches or pull requests

4 participants