Cron.php isn't firing (or Schedulers aren't working)

jbuxer · 6 January 2020 11:13

I’m trying to run the Google Calendar sync scheduler.

I’m on a Windows shared hosting environment. Plesk is the admin portal. I’ve scheduled a task to run a php script and pointed it to cron.php.

When I run the task, the task runs successfully (in Plesk), but has the following message:
“Bad data passed in; Return to Home”

When I look at the schedulers in the Admin page of SuiteCRM, there are no completed jobs.

I’ve stepped through the code and noticed that the failure happens at the following line of code:

cron.php: require_once(‘include/entryPoint.php’);
entryPoint.php: clean_incoming_data();
utils.php: clean_incoming_data() <-- It’s happening somewhere from a call within this formula.

My environment

SuiteCRM Version used: 7.11.70
Browser name and version (e.g. Chrome Version 51.0.2704.63 (64-bit)): Chrome Version 79.0.3945.88
Environment name and version (e.g. MySQL, PHP 7): PHP 7
Operating System and version (e.g Ubuntu 16.04): Windows (shared hosting)

pgr · 6 January 2020 12:38

Thanks for moving this discussion here.

What does the batch file you’re using with the Scheduler look like? Are you calling command-line (CLI) PHP, or making a web request?

The behaviour you’re getting is typical for when a user is not logged in, so the request isn’t allowed. But this shouldn’t be happening for CLI PHP.

jbuxer · 17 January 2020 11:32

Sorry for the delayed reply. I’ll have to figure out how to get notified when there’s a response.

Since the original post, I set “$dieOnBadData = false” in the clean_string function header. The scheduler is now firing, but I’d like to fix the root cause and change it back to true.

Following is what I had in the batch file.

cd C:\Program Files (x86)\Plesk\Additional\PleskPHP70\
php.exe -q -f  D:\InetPub\vhosts\<domain>\crm.<domain>\cron.php

Also, “Schedule Task” in Plesk allows you to just call a php file to run the script. Using the batch file and running the script via calling a file has the same outcome.

Thanks for your help @pgr!

pgr · 17 January 2020 11:43

Exactly which filter is breaking in clean_string?

You should have FATAL messages specifying the filter in your suitecrm.log, coming from here:

github.com

salesagility/SuiteCRM/blob/master/include/utils.php#L2198


        'SQL_COLUMN_LIST' => '#[^A-Z0-9\(\),_\.]#i',
        'PATH_NO_URL' => '#://#i',
        'SAFED_GET' => '#[^A-Z0-9\@\=\&\?\.\/\-_~+]#i', /* range of allowed characters in a GET string */
        'UNIFIED_SEARCH' => '#[\\x00]#', /* cn: bug 3356 & 9236 - MBCS search strings */
        'AUTO_INCREMENT' => '#[^0-9\-,\ ]#i',
        'ALPHANUM' => '#[^A-Z0-9\-]#i',
    );


    if (preg_match($filters[$filter], $str)) {
        if (isset($GLOBALS['log']) && is_object($GLOBALS['log'])) {
            $GLOBALS['log']->fatal("SECURITY[$filter]: bad data passed in; string: {$str}");
        }
        if ($dieOnBadData) {
            die("Bad data passed in; <a href=\"{$sugar_config['site_url']}\">Return to Home</a>");
        }


        return false;
    } else {
        return $str;
    }
}

jbuxer · 17 January 2020 11:49

The two fatal errors I have from today are:

Fri Jan 17 04:57:42 2020 [156784][1][FATAL] IP Address mismatch: SESSION IP: 174.xxx.xxx.x CLIENT IP: 73.xxx.xxx.xxx
Fri Jan 17 03:28:32 2020 [150372][1][FATAL] Caught Exception While Syncing User:1

pgr · 17 January 2020 11:53

You don’t have a message with that sentence I highlighted above? Did you get a bad data passed in today?

Maybe try changing the message in the die:

die("Bad data passed in, string is {$str} and filter is {$filter}; <a href=\"{$sugar_config['site_url']}\">Return to Home</a>");

jbuxer · 17 January 2020 12:01

I’m not getting an error in suitecrm.log, but the task scheduler displays the output from running the task. What I get there is:

Bad data passed in, string is D:\InetPub\vhosts<domain>\crm.\cron.php and filter is SAFED_GET; Return to Home

pgr · 17 January 2020 12:04

Ok, now we’re getting somewhere, check this regexp

github.com

salesagility/SuiteCRM/blob/master/include/utils.php#L2190


{
    global $sugar_config;


    $filters = array(
        'STANDARD' => '#[^A-Z0-9\-_\.\@]#i',
        'STANDARDSPACE' => '#[^A-Z0-9\-_\.\@\ ]#i',
        'FILE' => '#[^A-Z0-9\-_\.]#i',
        'NUMBER' => '#[^0-9\-]#i',
        'SQL_COLUMN_LIST' => '#[^A-Z0-9\(\),_\.]#i',
        'PATH_NO_URL' => '#://#i',
        'SAFED_GET' => '#[^A-Z0-9\@\=\&\?\.\/\-_~+]#i', /* range of allowed characters in a GET string */
        'UNIFIED_SEARCH' => '#[\\x00]#', /* cn: bug 3356 & 9236 - MBCS search strings */
        'AUTO_INCREMENT' => '#[^0-9\-,\ ]#i',
        'ALPHANUM' => '#[^A-Z0-9\-]#i',
    );


    if (preg_match($filters[$filter], $str)) {
        if (isset($GLOBALS['log']) && is_object($GLOBALS['log'])) {
            $GLOBALS['log']->fatal("SECURITY[$filter]: bad data passed in; string: {$str}");
        }
        if ($dieOnBadData) {

something in your data is triggering that, maybe the dot .?

EDIT: I think the lack of the message in suitecrm.log is a bug, please see if you can figure that one out, also. Maybe try moving the logging command outside the condition

jbuxer · 17 January 2020 12:50

Ok, I had to remove the following for the string to pass:

A-Z, ., #, and #i

In terms of the log entry, I moved that line of code to just before the die call. It now posts the error and stack trace in the output when I run the script, but still doesn’t post the error to suitecrm.log.

pgr · 17 January 2020 15:11

This is strange, maybe it doesn’t finish flushing the log because it dies immediately after. Oh well

jbuxer · 18 January 2020 07:26

Yeah, it’s strange. A debugging project for another time

Thanks for your help!