[CLOSED]API problems/errors

[SkippyDo]

Debian Buster (fresh install)
ZM 1.34.11 (fresh install) w/APIs enabled for all/every user

Testing (per instructions in the document noted below):

https://<my server>/zm/api/host/getVersion.json

From Firefox on my Linux laptop (also on my Android phone using Chrome or Firefox) gives me:

{"success":false,"data":{"name":"Not Authenticated","message":"Not Authenticated","url":"\/zm\/api\/host\/getVersion.json","exception":{"class":"UnauthorizedException","code":401,"message":"Not Authenticated"}}}

And running https://<my server>/zm/api/events.json produces:

{"name":"An Internal Error Has Occurred.","message":"An Internal Error Has Occurred.","url":"\/zm\/api\/events.json"}

I first detected API problems with ZMninja. Stepped through the document https://zmninja.readthedocs.io/en/lates ... g-api.html. Authentication IS succeeding, in which case I'm assuming the token mechanism is functioning properly.

[SkippyDo]

Still having issues.

mysql log:

2020-05-16 6:05:47 12362 [Warning] Aborted connection 12362 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)

Increased cake debugging level and now see this output:

Request URL: /zm/api/monitors/index/Type%20!=:WebSite.json?token=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNTg5NjgzODE5LCJleHAiOjE1ODk2OTEwMTksInVzZXIiOiJtYXJrIiwidHlwZSI6ImFjY2VzcyJ9.pV99piHbVXPy64SvdK7NwCOd6F5l7kT2TXU8JS6A-k0
Stack Trace:
#0 /usr/share/zoneminder/www/api/lib/Cake/Model/Datasource/DboSource.php(271): Mysql->connect()
#1 /usr/share/zoneminder/www/api/lib/Cake/Model/ConnectionManager.php(105): DboSource->__construct(Array)
#2 /usr/share/zoneminder/www/api/lib/Cake/Model/Model.php(3646): ConnectionManager::getDataSource('default')
#3 /usr/share/zoneminder/www/api/lib/Cake/Model/Model.php(1162): Model->setDataSource('default')
#4 /usr/share/zoneminder/www/api/lib/Cake/Model/Model.php(3673): Model->setSource('Monitors')
#5 /usr/share/zoneminder/www/api/lib/Cake/Model/Model.php(1394): Model->getDataSource()
#6 /usr/share/zoneminder/www/api/app/Plugin/CakePHP-Enum-Behavior/Model/Behavior/EnumBehavior.php(34): Model->schema()
#7 /usr/share/zoneminder/www/api/lib/Cake/Model/BehaviorCollection.php(145): EnumBehavior->setup(Object(Monitor), Array)
#8 /usr/share/zoneminder/www/api/lib/Cake/Model/BehaviorCollection.php(66): BehaviorCollection->load('CakePHP-Enum-Be...', Array)
#9 /usr/share/zoneminder/www/api/lib/Cake/Model/Model.php(781): BehaviorCollection->init('Monitor', Array)
#10 [internal function]: Model->__construct(NULL)
#11 /usr/share/zoneminder/www/api/lib/Cake/Utility/ClassRegistry.php(169): ReflectionClass->newInstance(Array)
#12 /usr/share/zoneminder/www/api/lib/Cake/Controller/Controller.php(741): ClassRegistry::init('Monitor')
#13 /usr/share/zoneminder/www/api/lib/Cake/Controller/Controller.php(368): Controller->loadModel('Monitor')
#14 /usr/share/zoneminder/www/api/lib/Cake/Controller/Controller.php(406): Controller->__isset('Monitor')
#15 /usr/share/zoneminder/www/api/app/Plugin/Crud/Controller/Component/CrudComponent.php(812): Controller->__get('Monitor')
#16 /usr/share/zoneminder/www/api/app/Plugin/Crud/Controller/Component/CrudComponent.php(614): CrudComponent->_setModelProperties()
#17 /usr/share/zoneminder/www/api/app/Plugin/Crud/Controller/Component/CrudComponent.php(751): CrudComponent->getSubject()
#18 /usr/share/zoneminder/www/api/app/Plugin/Crud/Controller/Component/CrudComponent.php(728): CrudComponent->_loadListener('RelatedModels')
#19 /usr/share/zoneminder/www/api/app/Plugin/Crud/Controller/Component/CrudComponent.php(169): CrudComponent->_loadListeners()
#20 /usr/share/zoneminder/www/api/lib/Cake/Utility/ObjectCollection.php(128): CrudComponent->initialize(Object(MonitorsController))
#21 /usr/share/zoneminder/www/api/lib/Cake/Event/CakeEventManager.php(243): ObjectCollection->trigger('initialize')
#22 /usr/share/zoneminder/www/api/lib/Cake/Controller/Controller.php(677): CakeEventManager->dispatch(Object(CakeEvent))
#23 /usr/share/zoneminder/www/api/lib/Cake/Routing/Dispatcher.php(189): Controller->startupProcess()
#24 /usr/share/zoneminder/www/api/lib/Cake/Routing/Dispatcher.php(167): Dispatcher->_invoke(Object(MonitorsController), Object(CakeRequest))
#25 /usr/share/zoneminder/www/api/app/webroot/index.php(107): Dispatcher->dispatch(Object(CakeRequest), Object(CakeResponse))
#26 {main}

Any ideas on where to look further?

[asker]

It seems to me you have a resource issue with mysql

Code: Select all

2020-05-16 6:05:47 12362 [Warning] Aborted connection 12362 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)

I think this needs to be resolved first. Doing some quick googling, it seems this occurs when the system is running out of ram or too many sql connections. Maybe someone who knows exactly how to address this can chime in.

[SkippyDo]

Yeah, that's one take on what the error could be about. I've got zero resource issues that I've been able to determine. The ONLY thing that seems to raise a red flag is the number of active_connections that phpinfo reported: 18446744073709551614 This is on a system install that's less than a week old. From what I've read on this variable it's an accumulator, doesn't actually mean you have that many connections "active." Actual connections were shown to be more of what I'd figure to be normal (something like 12 or so from what I remember).

Don't know whether there's a connection issue on the server itself. It's not clear to me what user credentials are being used for all the various actions. I'm thinking that it's just zmuser that's used; I've verified that all proper permissions/grants are there in the database; if these were wrong I'm also thinking that that would show itself to be an issue in console originated logins as well.

This one is really frustrating me. Everything seems to be running great: I even think that my long-running wifi interface dropping issue is gone/licked (when it's your only avenue for managing the server [headless] it sucks when it drops out); this was the biggest reason to just up and upgrade everything. And was really looking forward to getting event notification SW running (I'd got a brief taste of it over a year ago on an unstable install of Sid and ZM 1.32- had to revert back to Stretch and ZM 1.30.4). It and ZMninja really make ZM a great setup.

Will also add that:

I'm running UFW on this server. I'm pretty much of a novice and there could be something here causing grief.

I am unsure whether my SLL certs (created via/from Let's Encrypt) are installed and working properly as far as ZM and Apache require. I have strict SSL enabled on ZMninja and it seems to authenticate properly. And the cert tests post-install all ran clean.

[SkippyDo]

As this seems to be a DB connection issue I'm tending to focus on that. Here's a couple more bits of relevant information on mysqld (as reported by phpinfo):

Version: mysqlnd 5.0.12-dev - 20150407
core SSL: supported
extended SSL: supported
Loaded plugins: mysqlnd,debug_trace,auth_plugin_mysql_native_password,auth_plugin_mysql_clear_password,auth_plugin_sha256_password
API Extensions : mysqli,pdo_mysql

Further research on the active_connections variable output noted in my above post is that this is what is reported as "-1." A bug from the sounds of it: though the reports of it being a bug were from many years ago (seems questionable that it could survive as a bug for years).

[SkippyDo]

Continuing to dig into this..

At this point it seems most likely that it's an SSL cert issue or a socket one. The former affecting the later?

mysql.sock is properly configured, so that's not likely it. Which seems to leave SSL cert as the issue.

I'd previously used a self-signed cert w/o issue. Current cert is newly created from/by Let's Encrypt. The post-install checks showed all was good there. And this, then, would point to a configuration issue with ZM and associated components.

A similar case: https://github.com/MISP/MISP/issues/3270 . This person's solution:

It was all about the certificate, key and server ca pem files. I had to move them to /var/www/MISP directory and give www-data read access to them. Then the Mysql.php could provide them to the PDO connection object. Worked.

Pretty sure that I don't need to be moving certs around.

ZM SSL configs (/etc/zm/conf.d/custom.conf) has:

ZM_DB_SSL_CLIENT_CERT=/etc/letsencrypt/live/<my server's FQDN>/chain.pem
ZM_DB_SSL_CLIENT_KEY=/etc/letsencrypt/live/<my server's FQDN>/privkey.pem

Apache SSL configs (/etc/apache2/sites-enabled/000-default-le-ssl.conf) has:

ServerName <my server's FQDN>
SSLCertificateFile /etc/letsencrypt/live/<my server's FQDN>fullchain.pem
SSLCertificateKeyFile /etc/letsencrypt/live/<my server's FQDN>/privkey.pem
Include /etc/letsencrypt/options-ssl-apache.conf

Looking at these shows that I have a discrepancy with the cert File. Before I go messing with these I'd like to know if this is even the right tree to be barking up? It's not clear to me which one is supposed to be used.

I'm assuming that my "/etc/zm/conf.d/custom.conf" file is in fact being read.

Hoping that it's really just something this "simple." I've tweaked various mysql settings that could be responsible, to no avail. And I've rummaged around in a ton of files looking for signs of where this problem could exist; also to no avail (other than this cert issue).

[SkippyDo]

OK, I messed with the certs to no avail.

ZMninja desktop (on a client) logs make it appear as though it's a cache problem (highlighted below)?

May 19, 2020 03:26:59 AM INFO Login data not changed, not saving
May 19, 2020 03:26:54 AM DEBUG Does login need to hear the wizard? false
May 19, 2020 03:26:54 AM DEBUG skipping image refresh, packery is still loading
May 19, 2020 03:26:54 AM DEBUG Setting up cycle interval of:10000
May 19, 2020 03:26:54 AM DEBUG bandwidth: highbw montage refresh set to: 2
May 19, 2020 03:26:54 AM DEBUG cache_or_http error:[object Object]
May 19, 2020 03:26:54 AM DEBUG Multiport=0
May 19, 2020 03:26:54 AM INFO sending stored ZM_MIN_STREAMING_PORT 0
May 19, 2020 03:26:54 AM DEBUG Montage beforeEnter: copying monitors to montage monitors
May 19, 2020 03:26:54 AM DEBUG Montage beforeEnter: got 0 monitors
May 19, 2020 03:26:54 AM DEBUG Setting streamQuery timer to 10000
May 19, 2020 03:26:54 AM ERROR Monitor load failed {"data":{"code":500,"name":"Database connection &quot;Mysql&quot; is missing, or could not be created:\n SQLSTATE[HY000] [2006] MySQL server has gone away","message":"SQLSTATE[HY000] [2006] MySQL server has gone away","url":"/zm/api/monitors/index/Type%20!=:WebSite.json?token=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNTg5ODc4MTA4LCJleHAiOjE1ODk4ODUzMDgsInVzZXIiOiJtYXJrIiwidHlwZSI6ImFjY2VzcyJ9.gdwxjYfqpxdfs2teEP4643llwMq9YfU0Z5l3nroaiH0"},"status":500,"config":{"method":"GET","transformRequest":[null],"transformResponse":[null],"url":"https://<my server's FQDN>/zm/api/monitors/index/Type !=:WebSite.json?&token=<removed>
May 19, 2020 03:26:54 AM INFO CACHE: error with http get [object Object]
May 19, 2020 03:26:52 AM DEBUG CACHE: NOT found for:cached_monitors reverting to HTTP
May 19, 2020 03:26:52 AM DEBUG cache_or_http error:[object Object]
May 19, 2020 03:26:52 AM DEBUG returning promise
May 19, 2020 03:26:52 AM DEBUG Monitor URL to fetch is:https://<my server's FQDN>/zm/api/monitors/index/Type !=:WebSite.json?&token=<removed>

[asker]

No, all zmNinja is saying is that it did not find a cache for monitors.json. It did not find a cache because monitors.json failed when doing an http.get
So the problem is the same - your monitors.json API is not working.

Your errors above it seem to indicate it is still a MYSQL problem (MySQL gone away, 500 error)

[SkippyDo]

Would running ZMninja desktop directly on the server likely give me more insight? I'd have done this already if not for the fact that the server is headless: it's kind of remote; I'd have to lug a monitor, keyboard and mouse to test).

Seems that I'm the only person to have this problem that isn't resolvable by any of the known fixes. I'd really like to resolve this so I can get on with my life...

[asker]

I doubt it. This is not a zmNinja issue at all, so moving it around won't really help (is my guess).
The issue is related to the API invoking DB queries and failing for what seems to be larger queries.

Let's forget zmNinja for a bit. You are facing this problem even when doing a monitor.json API call from your browser, is that right? If so, that is what needs to be fixed. What happens if you replace monitors.json with events.json from the browser (that is https://server/zm/api/events.json) ? Same issue? If so, then its very likely some sort of MySQL issue. If events works, but monitors doesn't, then I wonder if its some form of UTF-8 encoding issue for monitor names.

I don't know enough of ZM DB backend to give more details on that, but that is probably where the focus should be.

[SkippyDo]

Same connect issue with events.json.

What I meant when I said I was wanting to try ZMninja direclty ON the server was more for convenience than anything to do with ZMninja-specific processing/operation: I don't trust the mechanisms with browser access (authenticating by logging in on one window and hitting an API call in another window). The essence of testing directly on the server is to rule in/out any hostname, firewall or permission issues: all would factor into connectivity.

I'll have more time to apply to this in a couple of days. I appreciate your support in this.

[SkippyDo]

Tried running zmNinja desktop on my server but it wouldn't run (sandbox issues), so am currently trying to troubleshoot through web browsers only (Firefox).

On ZM I enabled OPT_USE_LEGACY_API_AUTH and am able to, via web browser, get getVersion.json to return proper values. With anything that attempts to fetch data from the database (such as monitors.json) I get:

2020-05-25 11:05:07 Error: [MissingConnectionException] Database connection "Mysql" is missing, or could not be created.
Exception Attributes: array (
'class' => 'Mysql',
'message' => 'SQLSTATE[HY000] [2006] MySQL server has gone away',
'enabled' => true,
)

I have even tried disabling ENABLE_CSRF_MAGIC, but no difference.

From a web browser, which I'm logged in to the console, running zm/api/monitors.json causes mysql to increase Aborted_connects (by one for each attempt to query).

Here's output of 'mysqladmin staus' (to show that mysqld isn't dropping out):

Uptime: 746949 Threads: 25 Questions: 1471063 Slow queries: 0 Opens: 181 Flush tables: 1 Open tables: 175 Queries per second avg: 1.969

[SkippyDo]

Does the fact that I can run things out of "host" (getVersion.json; getload.json etc.) mean that the API facility is working, that it is purely only the database connection that is failing?

BUT... isn't authentication requiring database access?

I have tried everything, even statically setting variables in database.php, but nothing seems to influence/affect this problem. I've tried up-ing database timeouts and buffer sizes. This is a default installation. Same hardware that I was successfully running 1.30.4 on (and also, for a brief moment in time, 1.32).

The ONLY thing that I can think of is that when I installed mysql I had not set up my custom mounts yet. I moved everything to the larger disk and it's now mounted on /var/lib/mysql. No change in path names at all. As everything else seems to work just fine I can only believe that this is having no bearing on the API connection. I mention it only because this is the only deviation from a by-the-book install.

[asker]

Several APIs don't do database seeks. I think getVersion/getLoad are some of them.

I see one of two issues:
a) Your MYSQL is not configured correctly with the cakePHP layer (less likely)
b) Your MYSQL is running out of resources whenever a heavy request is sent to it (more likely)

Question: Are you able to use operations like timeline/Montage Review on ZM Console? If so, I don't think its purely a DB load issue and may be related to some connection between CakePHP and the DB. I found this on SO https://stackoverflow.com/questions/400 ... in-cakephp - but first check if you are easily able to use montage review. I know that is really DB heavy.

Some other thoughts:

a) Lines 67-78 of /usr/share/zoneminder/www/api/app/Config/database.php should look like this. Is that the case in yours?

Code: Select all

  public $default = array(
                'datasource' => 'Database/Mysql',
                'persistent' => false,
                'login' => ZM_DB_USER,
                'password' => ZM_DB_PASS,
                'database' => ZM_DB_NAME,
                'ssl_ca' => ZM_DB_SSL_CA_CERT,
                'ssl_key' => ZM_DB_SSL_CLIENT_KEY,
                'ssl_cert' => ZM_DB_SSL_CLIENT_CERT,
                'prefix' => '',
                'encoding' => 'utf8',
        );

b) Make sure your ZM_DB_USER, ZM_DB_PASS etc are correctly configured in /etc/zm/zm.conf (or correctly overriden inside conf.d)

[SkippyDo]

Doesn't the database have to be queried in order to authenticate? Different mechanism than API calls?

I can bring up the montage review screen but I see static images of each camera view with "no data" messages overlain. If I pick a time frame, say 8hrs, nothing comes up (there are events shown in the history bar). In the logs I'm getting:

Code: Select all

05/27/20 08:23:11.010080 web_php[2549].ERR [deleted] [No data to read from socket] at /usr/share/zoneminder/www/includes/functions.php line 2177
05/27/20 08:23:21.382106 web_php[22776].ERR [deleted] [Timed out waiting for msg /var/run/zm/zms-323929s.sock] at /usr/share/zoneminder/www/ajax/stream.php line 93
05/27/20 08:23:24.239642 web_php[19175].ERR [deleted] [Socket /var/run/zm/zms-323929s.sock does not exist.  This file is created by zms, and since it does not exist, either zms did not run, or zms exited early.  Please check your zms logs and ensure that CGI is enabled in apache and check that the PATH_ZMS is set correctly.  Make sure that ZM is actually recording.  If you are trying to view a live stream and the capture process (zmc) is not running then zms will exit. Please go to http://zoneminder.readthedocs.io/en/latest/faq.html#why-can-t-i-see-streamed-images-when-i-can-see-stills-in-the-zone-window-etc for more information.] at /usr/share/zoneminder/www/includes/functions.php line 2177

I'd noticed a while back that I was getting frequent screen redraws when viewing monitors. I did a quick search on this but didn't really come up with anything: figured I'd come back to this after solving the API DB access issues.

I increased max_allowed_packet to something like 64mb (default 16mb?). No change. I'd figure that the default installation of all the bits would work for simple operations (I've only got 4 cameras; since install I have racked up 234 events and am consuming 2.27GB [7%] of disk- all suggests a minimally loaded system; /dev/shm, however is running 34%- I have the cameras' capture set to 2304x1296 32bit color, which is the default for these cameras; I reset to 1280x720 and shm dropped to 19%, but no change in behavior).

While I'd like to figure out what's going on I'm thinking that it's going to, once again, come down to doing a complete re-install. My concern, other than having to do a bunch of re-configuring, is whether I'd also have to, in addition to ZM, remove apache and php. This hardware was easily running 1.30.4; difference with 1.34.15 is that I'm now running H264 passthrough (not jpegs). I have not, however, set up zones, which I'd figure would cut down on some of the processing overhead (modetect): was waiting to iron out the API (and other?) issues before committing to this.