Scheduled jobs

[AGirin]

Hi,

It looks like jobs are not running on my system:

[411]$ /var/www/411/bin/cron.php && /var/www/411/bin/worker.php [+] Scheduler: 1474926082 [+] Maintenance [+] Search Health [+] Rollups [+] Searches [+] Reports [+] Summary [+] Autoclose [+] Cleanup [+] Worker [+] Worker: 1474926093 [+] Job count: 64 PHP Fatal error: Uncaught PDOException: SQLSTATE[HY000]: General error: 1 near "LIMIT": syntax error in /var/www/411/phplib/DB.php:78 Stack trace:

0 /var/www/411/phplib/DB.php(78): PDO->prepare('UPDATE jobs S...')

1 /var/www/411/phplib/Job.php(167): FOO\DB::query('UPDATE jobs S...', Array, 0)

2 /var/www/411/phplib/Worker.php(77): FOO\JobFinder::getAndLock('1', 1474926093)

3 /var/www/411/bin/worker.php(34): FOO\Worker->processSite(Object(FOO\Site), 1474926093)

4 {main}

thrown in /var/www/411/phplib/DB.php on line 78 err [411_Worker] Worker error site:[1] ret:[65280]

And I see this in the web UI:

Any ideas on why this is happening?

Thanks!

Andrew

[kiwiz]

Some quick things to check:

• Are you running the newest version of the code?
• Can you try running bin/migration.php and seeing if that fixes it?

[AGirin]

I ran bin/migration.php - no luck.

And I pull from github this morning so I assume I use the latest code.

[kiwiz]

Can you add Logger::info($query, $params, "TEST"); to DB.php:97 and paste the the log line here?

[AGirin]

Added like this:

    Logger::info($query, $params, "TEST");
    if(!$stmt->execute()) {
        throw new DBException('Query failed: ' . $stmt->errorInfo()[2]);
    }

Where do I find the log line?

[kiwiz]

It should be in PHP's errorlog (possibly /var/log/httpd/error.log).

[AGirin]

Looks like I am getting the same errors as on the console:

[26-Sep-2016 22:25:10 UTC] PHP Fatal error: Uncaught PDOException: SQLSTATE[HY000]: General error: 1 near "LIMIT": syntax error in /var/www/411/phplib/DB.php:78 Stack trace:

0 /var/www/411/phplib/DB.php(78): PDO->prepare('UPDATE jobs S...')

1 /var/www/411/phplib/Job.php(167): FOO\DB::query('UPDATE jobs S...', Array, 0)

2 /var/www/411/phplib/Worker.php(77): FOO\JobFinder::getAndLock('1', 1474928710)

3 /var/www/411/bin/worker.php(34): FOO\Worker->processSite(Object(FOO\Site), 1474928710)

4 {main}

thrown in /var/www/411/phplib/DB.php on line 78 [26-Sep-2016 22:25:10 UTC] err [411_Worker] Worker error site:[1] ret:[65280]

[kiwiz]

Do you see a log line with the string "TEST" in it? It should be right before the error.

[AGirin]

I found that log:

[Tue Sep 27 09:26:44 2016] [error] [client xxx.xxx.xxx.xxx] info [TEST] SELECT value FROM config WHERE site_id = ? AND key = ? 0:[1] 1:[cookie_secret], referer: http://test.test.net/alerts?query=state:(0+1)

I am running sqlite-3.6.20-1.el6_7.2 - could that be an issue?

[AGirin]

Not sure if this is related but I see strange timestamps:

[kiwiz]

The timestamps are just because the jobs haven't run yet (Jan 1, 1970 == 0)

The log line you're looking for should have "UPDATEjobsSETstate= ? somewhere in it.

[AGirin]

I cannot find a way to output this log line. Do I need to do something different? I rebuilt the site many times, tried different options - no luck. Same error all the time. I mentioned this during install:

Please note that, select2-bootstrap3-css#1.4.6 depends on select2#^3.3.2 which resolved to select2#3.5.4 FourOneOne depends on select2#~4.0.0 which resolved to select2#4.0.3 Resort to using select2#^3.3.2 which resolved to select2#3.5.4 Code incompatibilities may occur.

Could that be related to the issue I see?

[AGirin]

Ok, I got this:

earray(4)

{ [0]=> array(6) { ["file"]=> string(26) "/var/www/411/phplib/DB.php" ["line"]=> int(81) ["function"]=> string(7) "prepare" ["class"]=> string(3) "PDO" ["type"]=> string(2) "->" ["args"]=> array(1) { [0]=> string(196) "UPDATE jobs SET state = ?, update_date = ?, tries = tries + 1, completion = 0, last_execution_date = ? WHERE site_id = ? AND archived = 0 AND state = ? AND job_id = ? LIMIT 1" } } [1]=> array(6) { ["file"]=> string(27) "/var/www/411/phplib/Job.php" ["line"]=> int(169) ["function"]=> string(5) "query" ["class"]=> string(6) "FOO\DB" ["type"]=> string(2) "::" ["args"]=> array(3) { [0]=> string(196) "UPDATE jobs SET state = ?, update_date = ?, tries = tries + 1, completion = 0, last_execution_date = ? WHERE site_id = ? AND archived = 0 AND state = ? AND job_id = ? LIMIT 1" [1]=> array(6) { [0]=> int(4) [1]=> int(1475094709) [2]=> int(1475094709) [3]=> int(1) [4]=> int(0) [5]=> string(1) "1" } [2]=> int(0) } } [2]=> array(6) { ["file"]=> string(30) "/var/www/411/phplib/Worker.php" ["line"]=> int(78) ["function"]=> string(10) "getAndLock" ["class"]=> string(13) "FOO\JobFinder" ["type"]=> string(2) "::" ["args"]=> array(2) { [0]=> string(1) "1" [1]=> int(1475094709) } } [3]=> array(6) { ["file"]=> string(27) "/var/www/411/bin/worker.php" ["line"]=> int(35) ["function"]=> string(11) "processSite" ["class"]=> string(10) "FOO\Worker" ["type"]=> string(2) "->" ["args"]=> array(2) { [0]=> object(FOO\Site)#8 (4) { ["obj":protected]=> array(6) { ["site_id"]=> int(1) ["name"]=> string(7) "411" ["host"]=> string(28) "Hostname" ["archived"]=> bool(false) ["create_date"]=> int(1475089719) ["update_date"]=> int(1475089719) } ["new":protected]=> bool(false) ["dirty":protected]=> bool(false) ["initial_update_date":protected]=> int(1475089719) } [1]=> int(1475094709) } } }

[kiwiz]

Maybe it is a sqlite issue. I ran that query locally and it works fine. Could you try updating your copy of sqlite3?

[AGirin]

What version do you run? Mine is sqlite-3.6.20-1.el6_7.2 - I think this is most recent one.

[kiwiz]

I'm running 3.8.2 here.

[AGirin]

Let me try getting this one and see if this fixes the issue.

[AGirin]

Installed sqlite-3.8.8.1; downgraded php from 7.0 to 5.6. Still the same error. Not sure what I am doing wrong.

[AGirin]

Ran this in SQLite3 and got the same error:

sqlite> UPDATE jobs SET state = ?, update_date = ?, tries = tries + 1, completion = 0, last_execution_date = ? WHERE site_id = ? AND archived = 0 AND state = ? AND job_id = ? LIMIT 1; Error: near "LIMIT": syntax error

[kiwiz]

That's a parameterized query, so that makes sense. Can you try this query? UPDATE jobs SET state = 0, update_date = 0, tries = tries + 1, completion = 0, last_execution_date = 0 WHERE site_id = 0 AND archived = 0 AND state = 0 AND job_id = 0 LIMIT 1;

[AGirin]

Same error:

sqlite> UPDATE jobs SET state = 0, update_date = 0, tries = tries + 1, completion = 0, last_execution_date = 0 WHERE site_id = 0 AND archived = 0 AND state = 0 AND job_id = 0 LIMIT 1; Error: near "LIMIT": syntax error sqlite>

[erikmathis]

sqlite> UPDATE jobs SET state = 0, update_date = 0, tries = tries + 1, completion = 0, last_execution_date = 0 WHERE site_id = 0 AND archived = 0 AND state = 0 AND job_id = 0 LIMIT 1; Error: near "LIMIT": syntax error sqlite> UPDATE jobs SET state = 0, update_date = 0, tries = tries + 1, completion = 0, last_execution_date = 0 WHERE site_id = 0 AND archived = 0 AND state = 0 AND job_id = 0; sqlite>

I've never tried, but can you use a limit on an update?

-Erik-

On 09/29/2016 10:41 AM, AGirin wrote:

Same error:

sqlite> UPDATE jobs SET state = 0, update_date = 0, tries = tries + 1, completion = 0, last_execution_date = 0 WHERE site_id = 0 AND archived = 0 AND state = 0 AND job_id = 0 LIMIT 1; Error: near "LIMIT": syntax error sqlite>

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/etsy/411/issues/23#issuecomment-250486442, or mute the thread https://github.com/notifications/unsubscribe-auth/ADVJs7F3uk8eb0FiV3-8hKsREa3D1yG3ks5qu84ugaJpZM4KHB1i.

[AGirin]

I confirm that removing LIMIT does work but I am not sure why the code works for everybody else? I cannot find an issue on my side so far.

[AGirin]

Looks like UPDATE should work with LIMIT: https://www.sqlite.org/lang_update.html

[kiwiz]

I'm at a loss. Running that query on my box definitely works.

[AGirin]

This might answer this: http://sqlite.org/compile.html#enable_update_delete_limit

Basically my SQLite does not have SQLITE_ENABLE_UPDATE_DELETE_LIMIT enabled.

From the page above:

SQLITE_ENABLE_UPDATE_DELETE_LIMIT This option enables an optional ORDER BY and LIMIT clause on UPDATE and DELETE statements.

If this option is defined, then it must also be defined when using the 'lemon' tool to generate a parse.c file. Because of this, this option may only be used when the library is built from source, not from the amalgamation or from the collection of pre-packaged C files provided for non-Unix like platforms on the website.

I am using rpm that I found online (tried different ones with no luck). Where did you get yours? Or did you build it yourself?

[AGirin]

Apparently it is a very complicated process to build sqlite3 with that option enabled. I tried this:

http://stackoverflow.com/questions/1824490/how-do-you-enable-limit-for-delete-in-sqlite

And it worked but... Still LIMIT does not work. I think there at ea bunch of libraires you need to recompile to make this work. Everybody suggest not to use LIMIT with UPDATE statement and use SELECT with LIMIT (UPDATE (SELECT ... LIMIT 1)).

Any suggestion on what I can try changing the query to in order to see if the code works?

[kiwiz]

Is mysql an option? We actually use 411 with that internally, but released the project with sqlite because it's usually easier to set up. db.sql will require a few tweaks and you'll need to make some changes to config.php to point to mysql instead. I can provide more details as necessary.

[AGirin]

Thanks @kiwiz. Could you provide this info? I might be able to work with it.

[kiwiz]

I pushed a db_mysql.sql file with the schema. For config.php you'll need to change the dsn to something like "mysql:host=localhost;dbname=testdb".

[AGirin]

Thanks. I started on a new host and now I am getting this (I am using mysql):

bin/create_site.php Creating new site Site name: 411 Hostname: hostname.test.com PHP Fatal error: Uncaught exception 'PDOException' with message 'SQLSTATE[23000]: Integrity constraint violation: 1048 Column 'site_id' cannot be null' in /var/www/411/phplib/DB.php:97 Stack trace:

0 /var/www/411/phplib/DB.php(97): PDOStatement->execute()

1 /var/www/411/phplib/Model.php(140): FOO\DB::query('INSERT INTO `si...', Array, 0)

2 /var/www/411/phplib/Model.php(116): FOO\Model->create()

3 /var/www/411/bin/create_site.php(14): FOO\Model->store()

4 {main}

thrown in /var/www/411/phplib/DB.php on line 97

[kiwiz]

Should be fixed via 5c259b2d040a23be81f3e5b0869c10da98900f99.

[AGirin]

It is! Thanks! But now this (we are getting there!):

bin/create_user.php Creating new user Username: admin Real name: Admin Password: Test Email: test@test.com Admin (y/n): y PHP Fatal error: Uncaught exception 'PDOException' with message 'SQLSTATE[42S22]: Column not found: 1054 Unknown column 'name' in 'field list'' in /var/www/411/phplib/DB.php:97 Stack trace:

0 /var/www/411/phplib/DB.php(97): PDOStatement->execute()

1 /var/www/411/phplib/Model.php(140): FOO\DB::query('INSERT INTO `us...', Array, 0)

2 /var/www/411/phplib/Model.php(116): FOO\Model->create()

3 /var/www/411/bin/create_user.php(31): FOO\Model->store()

4 {main}

thrown in /var/www/411/phplib/DB.php on line 97

[kiwiz]

Opps, we were missing a few fields in the schema. Pull + apply one more time. 🎱

[AGirin]

Did that and it is fixed. Thanks again! Now I am getting this error when I login to site:

except [NONE] PDOException: "SQLSTATE[42000]: Syntax error or access violation: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ' "unixepoch") as date, action, COUNT(*) as count FROM alert_logs INNER J' at line 1" at [/var/www/411/phplib/DB.php:97] 0:[PDOStatement->execute() called at [/var/www/411/phplib/DB.php:97]] 1:[FOO\DB::query() called at [/var/www/411/phplib/REST/Dashboard.php:59]] 2:[FOO\Dashboard_REST->GET() called at [/var/www/411/phplib/REST.php:107]] 3:[FOO\REST->route() called at [/var/www/411/htdocs/api/dashboard.php:6]], referer: http://test.test.com/

[AGirin]

Also - tried creating new search (ping) and got this:

PDOException: "SQLSTATE[42S02]: Base table or view not found: 1146 Table '411.search_filters' doesn't exist" at [/var/www/411/phplib/DB.php:97] 0:[PDOStatement->execute() called at [/var/www/411/phplib/DB.php:97]] 1:[FOO\DB::query() called at [/var/www/411/phplib/Model.php:494]] 2:[FOO\ModelFinder::getByQuery() called at [/var/www/411/phplib/Element.php:134]] 3:[FOO\ElementFinder::getBySearch() called at [/var/www/411/phplib/Search.php:358]] 4:[FOO\Search->getFilters() called at [/var/www/411/phplib/Job/Search.php:66]] 5:[FOO\Search_Job->_run() called at [/var/www/411/phplib/REST/Searches.php:158]] 6:[FOO\Searches_REST->test() called at [/var/www/411/phplib/REST/Searches.php:58]] 7:[FOO\Searches_REST->POST() called at [/var/www/411/phplib/REST.php:108]] 8:[FOO\REST->route() called at [/var/www/411/htdocs/api/searches.php:6]], referer: http://test.test.com/searches/new?type=ping

[kiwiz]

Hmm, that's an incompatibility between MySQL and SQLite. Can you create a new ticket for just this issue? The rest of 411 should work fine otherwise. (This only affect the dashboard, afaik).

[AGirin]

Sorry - are you referring to the first error?

except [NONE] PDOException: "SQLSTATE[42000]: Syntax error or access violation: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ' "unixepoch") as date, action, COUNT(*) as count FROM alert_logs INNER J' at line 1" at [/var/www/411/phplib/DB.php:97] 0:[PDOStatement->execute() called at [/var/www/411/phplib/DB.php:97]] 1:[FOO\DB::query() called at [/var/www/411/phplib/REST/Dashboard.php:59]] 2:[FOO\Dashboard_REST->GET() called at [/var/www/411/phplib/REST.php:107]] 3:[FOO\REST->route() called at [/var/www/411/htdocs/api/dashboard.php:6]], referer: http://test.test.com/

[kiwiz]

Yup.

[AGirin]

What about the second one?

PDOException: "SQLSTATE[42S02]: Base table or view not found: 1146 Table '411.search_filters' doesn't exist" at [/var/www/411/phplib/DB.php:97] 0:[PDOStatement->execute() called at [/var/www/411/phplib/DB.php:97]] 1:[FOO\DB::query() called at [/var/www/411/phplib/Model.php:494]] 2:[FOO\ModelFinder::getByQuery() called at [/var/www/411/phplib/Element.php:134]] 3:[FOO\ElementFinder::getBySearch() called at [/var/www/411/phplib/Search.php:358]] 4:[FOO\Search->getFilters() called at [/var/www/411/phplib/Job/Search.php:66]] 5:[FOO\Search_Job->_run() called at [/var/www/411/phplib/REST/Searches.php:158]] 6:[FOO\Searches_REST->test() called at [/var/www/411/phplib/REST/Searches.php:58]] 7:[FOO\Searches_REST->POST() called at [/var/www/411/phplib/REST.php:108]] 8:[FOO\REST->route() called at [/var/www/411/htdocs/api/searches.php:6]], referer: http://test.test.com/searches/new?type=ping

[AGirin]

https://github.com/etsy/411/issues/37 --> for the first error.

[kiwiz]

Another schema change. (Sorry, the schema we were using for MySQL was slightly different)

[AGirin]

Almost there I think. New error now: except [NONE] PDOException: "SQLSTATE[42S02]: Base table or view not found: 1146 Table '411.search_logs' doesn't exist" at [/var/www/411/phplib/DB.php:97]

[kiwiz]

Hopefully the last one.

[AGirin]

Ok, this works! I was able to schedule new job but now this:

/var/www/411/bin/cron.php [+] Scheduler: 1475528923 [+] Maintenance PHP Fatal error: Uncaught exception 'PDOException' with message 'SQLSTATE[HY000]: General error' in /var/www/411/phplib/DB.php:118 Stack trace:

0 /var/www/411/phplib/DB.php(118): PDOStatement->fetchAll(2)

1 /var/www/411/phplib/Element.php(146): FOO\DB::query('UPDATE `search_...', Array)

2 /var/www/411/phplib/Scheduler.php(318): FOO\ElementFinder::reap(1475528923)

3 /var/www/411/phplib/Scheduler.php(142): FOO\Scheduler->maintenance(1475528923)

4 /var/www/411/bin/cron.php(45): FOO\Scheduler->processSite(Object(FOO\Site), 1475528923, false)

5 {main}

thrown in /var/www/411/phplib/DB.php on line 118 err [411_Scheduler] Scheduler error site:[1] ret:[65280]

[AGirin]

Sorry - one more (now with Logstash search):

PHP Fatal error: Call to undefined function ESQuery\mb_regex_encoding() in /var/www/411/vendor/kiwiz/esquery/src/Parser.php on line 3796, referer: http://test.test.com/searches/new?type=logstash

[kiwiz]

Do you have mbstring enabled?

[kiwiz]

The DB error is pretty vague. Can you grab the query actually being sent to the db?

[AGirin]

So Logstash was fixed by installing php-mbstring (missed it somehow).

As far as /var/www/411/bin/cron.php - let me try to get the full string for you.

[AGirin]

One more error unfortunately: When I click on Feed under Alerts tab I get:

except [NONE] PDOException: "SQLSTATE[42S02]: Base table or view not found: 1146 Table '411.alert_logs' doesn't exist" at [/var/www/411/phplib/DB.php:97] 0:[PDOStatement->execute() called at [/var/www/411/phplib/DB.php:97]] 1:[FOO\DB::query() called at [/var/www/411/phplib/Model.php:494]] 2:[FOO\ModelFinder::getByQuery() called at [/var/www/411/phplib/REST/Models.php:120]] 3:[FOO\Models_REST->read() called at [/var/www/411/phplib/REST/Models.php:279]] 4:[FOO\Models_REST->GET() called at [/var/www/411/phplib/REST.php:107]] 5:[FOO\REST->route() called at [/var/www/411/htdocs/api/alertlogs.php:6]],

Plus with Logstash now I see this (it supposed to create alert and I think it is failing since there is not table with this name):

[AGirin]

I fixed alert_logs error by rename table alertlogs to alert_logs. Could you fix I it in MySQL script?