New error Line 8019

I am getting this repeated error

Apr 28, 2021 at 3:05:24 PM
uniFiAP Error in Line 8019 has error=No JSON object could be decoded
uniFiAP checkAndPrepDict JSON len:56; mca-dump | sed -e 's/^ *//' xxxThisIsTheEndTokenxxx2...
... ed -e 's/^ *//' xxxThisIsTheEndTokenxxx2
uniFiAP .... in receiving DICTs for APdict-192.168.1.9; for details check unifi logfile at: /Library/Application Support/Perceptive Automation/Indigo 7.5/Logs/com.karlwachs.uniFiAP/plugin.log


Log File info
28 15:02:39 getMessages: relaunching dictLoop.exp / APdict / 192.168.1.8: timeSinceLastRestart 175 > forcedRestart:999999999 [sec] ; without message:136.7[sec], limitforRestart:135.0[sec], restartCount:0, len(msg):54; lastMSG:mca-dump | sed -e 's/^ *//' xxxThisIsTheEndTokenxxx3<<
2021-04-28 15:03:19.791 ERROR Plugin.checkAndPrepDict in Line 8019 has error=No JSON object could be decoded
28 15:03:19 checkAndPrepDict JSON len:56; mca-dump | sed -e 's/^ *//' xxxThisIsTheEndTokenxxx2...
... ed -e 's/^ *//' xxxThisIsTheEndTokenxxx2
28 15:03:19 .... in receiving DICTs for APdict-192.168.1.9; for details check unifi logfile at: /Library/Application Support/Perceptive Automation/Indigo 7.5/Logs/com.karlwachs.uniFiAP/plugin.log
28 15:03:19 .... ping test: ok
28 15:03:19 .... ssh test: ok
28 15:03:19 .... uid/passwd:>(u'myuzsername', u'mypassword)<
28 15:03:19 getMessages: consume data needed 10.7[secs] for data form APdict-192.168.1.9-1; len(MSG):56 lastMSG:mca-dump | sed -e 's/^ *//'
xxxThisIsTheEndTokenxxx2

Thanks Karl..

Try: Restart the UniFi device(s)


Sent from my iPhone using Tapatalk

And before you do that can you check
UniFi app go to the wifi ap and check stats
The graph with CPU and memory. Could you post that?


Sent from my iPhone using Tapatalk

Similar error for me too:

Code: Select all

   uniFiAP Error                   in Line 7850 has error=No JSON object could be decoded
   uniFiAP                         checkAndPrepDict JSON len:85; mca-dump | sed -e 's/^ *//' UbiquitiAPLiving-BZ.v4.3.28# xxxThisIsTheEndTokenxxx1...
...  ing-BZ.v4.3.28# xxxThisIsTheEndTokenxxx1
   uniFiAP                         .... in receiving DICTs for APdict-192.168.1.117;  for details check unifi logfile  at: /Library/Application Support/Perceptive Automation/Indigo 7.5/Preferences/Plugins/com.karlwachs.uniFiAP/plugin.log


AP shows fine on Unifi app:

IMG_2393.png (434.89 KiB) Viewed 4518 times

IMG_2394.jpg (221.91 KiB) Viewed 4518 times

Then restart the wifiap


Sent from my iPhone using Tapatalk

Any idea what's going on? Restarting the AP doesn't really solve the problem, just makes is dissapear until the next time it shows up.

Looks like the mca-dump commands returns nothing. Error code is 0 too.

Code: Select all

UbiquitiAPLiving-BZ.v4.3.28# mca-dump
UbiquitiAPLiving-BZ.v4.3.28# echo $?
0


OK mca-dump actually calls "mca-ctrl -t dump" and this one is ending in error:

Code: Select all

UbiquitiAPLiving-BZ.v4.3.28# mca-ctrl -t dump
UbiquitiAPLiving-BZ.v4.3.28# echo $?
255


I have posted a thread on the Ubiquiti forums: https://community.ui.com/questions/mca-ctrl-t-dump-returns-nothing/7b95ebd2-0489-452f-ad97-867ae5886124

I post back here if I get anything useful.

I have one ap that does that once every 2 weeks. It is an ap that sometimes has no clients. The 3 other APs do not show that behavior.

This started about 6 months ago.

Karl.


Sent from my iPhone using Tapatalk

I don't think the issue is about the clients since mine has clients.

What kind of AP is it?
I have 2 ac pro, 4 years old, and 2 new flex-hd ap
Only one of the acpro shows that symptom. But as it only happens once or twice a month I have ignored it so far


Sent from my iPhone using Tapatalk

AC Pro, probably about the same age as yours. I got it working without a reboot, this is what I did (although I am not sure which of them did the trick I suspect it's the last one):

Killed the mcad deamon process (there is mca-monitor process so the mcad will be auto-restarted)
rm -fr /tmp/.speedtest.socket
rm -fr /tmp/.mcad

Then a couple of minutes later it started to work again. Looking at the logs (see below) it seems that by deleting /tmp/.mcad file I might have cause it to give up and restart something. Next time it happens can you test if deleting alone /tmp/.mcad does the trick?

Code: Select all

Fri Apr 30 14:10:15 2021 user.err : mca-ctrl[23522]: mca-proto.service(): too many retries for temporary file creation
Fri Apr 30 14:10:15 2021 user.info : mca-ctrl[23522]: mca-proto.service_json(): failed to contact mcad
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:15 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:16 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:17 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.err : mca-monitor[23255]: mca-proto.service(): too many retries for temporary file creation
Fri Apr 30 14:10:18 2021 user.info : mca-monitor[23255]: mca-monitor.do_monitor(): mcad.checkin is 276 ago (max=200)
Fri Apr 30 14:10:18 2021 user.notice syswrapper: kill-mcad. reason: mcad not responding
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/mcad' (pid 23253, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/reset-handler' (pid 23254, uid 0, pending 0, crashes 0) exited after 11 seconds with status 0. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/mca-monitor' (pid 23255, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/mesh-monitor -i vwire2' (pid 23256, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/mesh-monitor -i vwire5' (pid 23257, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/element-adopt-monitor -i ath0' (pid 23258, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 daemon.notice procd: Process '/usr/bin/element-adopt-monitor -i ath3' (pid 23259, uid 0, pending 0, crashes 0) exited after 11 seconds with status 15. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:18 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload_default_url(): mgmt_cfg.default_url gets http://unifi:8080/inform
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload_config(): default url = http://unifi:8080/inform
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload_config(): set inform_url http://192.168.1.122:8080/inform
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload_config(): authkey=xxxxxxx
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload(): [MCAD] Self-Run Beaconing enabled !
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.reporter_reload(): [MCAD] Discovery Response disbled !
Fri Apr 30 14:10:19 2021 user.info : mcad[23675]: ace_reporter.set_default_localtime(): time is ready
Fri Apr 30 14:10:19 2021 user.notice syswrapper: [state is locked] waiting for lock
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/mcad' (pid 23675, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/reset-handler' (pid 23676, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/mca-monitor' (pid 23677, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/mesh-monitor -i vwire2' (pid 23678, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/mesh-monitor -i vwire5' (pid 23679, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/element-adopt-monitor -i ath0' (pid 23680, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).
Fri Apr 30 14:10:19 2021 daemon.notice procd: Process '/usr/bin/element-adopt-monitor -i ath3' (pid 23681, uid 0, pending 0, crashes 0) exited after 1 seconds with status 9. Scheduling for restart (no alert sent).


Nice. Will look into it.
.. but difficult to test as it happens not very often.


Sent from my iPhone using Tapatalk

I will keep an eye on mine too. It happens fairly regularly for all my 3 APs (all AC Pros from about the same age) and I get an alert because I have a script that checks for Last Update Date Time on all my devices to make sure I know if some devices are not being updated anymore.

You can see the ".reporter_reload(): [MCAD]" events so clearly it's restarting the reporter which is a lot better than a full device restart. If this works maybe you can add the work around to the plugin to simply delete the lock file when mca-dump returns no output although it will be cleaner to run "mca-ctrl -t dump" and check for the error code. Once I get the error again I will test to see if I can give you a 1 liner command to run instead of "mca-dump | sed -e 's/^ *//'".