PHP warnings/notices (due to unsupported CLI context) cause malformed output

[PhasecoreX]

I have followed the instructions to setting up the authentication script from the readme, but I cannot login to my ejabberd server. This appears in the server log at /var/log/ejabberd/ejabberd.log, and is logged roughly 5 times a second:

=ERROR REPORT==== 2014-12-15 21:59:34 ===
C(<0.381.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

=ERROR REPORT==== 2014-12-15 21:59:34 ===
C(<0.382.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

=ERROR REPORT==== 2014-12-15 21:59:34 ===
C(<0.383.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

Interestingly, the login does try to happen:

=INFO REPORT==== 2014-12-15 21:59:46 ===
I(<0.370.0>:ejabberd_listener:281) : (#Port<0.1847>) Accepted connection {{192,168,0,8},52118} -> {{192,168,0,42},5222}

=ERROR REPORT==== 2014-12-15 21:59:46 ===
C(<0.379.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

=ERROR REPORT==== 2014-12-15 22:00:46 ===
E(<0.382.0>:extauth:133) : extauth call '["auth","phasecorex","phasecorex.tk",
                                          "password"]' didn't receive response

=INFO REPORT==== 2014-12-15 22:00:46 ===
I(<0.381.0>:ejabberd_c2s:649) : ({socket_state,tls,{tlssock,#Port<0.1847>,#Port<0.1876>},<0.380.0>}) Failed authentication for phasecorex@phasecorex.tk

=ERROR REPORT==== 2014-12-15 22:00:47 ===
C(<0.383.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

=ERROR REPORT==== 2014-12-15 22:00:47 ===
C(<0.384.0>:extauth:146) : extauth script has exitted abruptly with reason 'normal'

I've been looking at the code for a day now and cannot figure out what is wrong. Ejabberd owns the ejabberd-auth-php folder, and all paths have been set in both configs (ejabberd-auth-php and ejabberd) as absolute paths. I created a logs folder, however ejabberd-auth-php does not create any logs itself, which I feel would help me out a lot. Any help would be greatly appreciated!

[cburschka]

If the PHP script doesn't create any logs even though the log paths and permissions are set correctly, then maybe the script runs into a fatal error before it can run and log anything. This would explain the repeated exit (the script is supposed to run indefinitely, so ejabberd keeps trying to restart it).

There could be any number of reasons for this - eg. if the CMS has a plugin that doesn't work properly when the CMS bootstraps in a CLI environment instead of a web request.

1. Could you try running the test script? ./tests/test.php <valid-user> <valid-pass> This will run the script and test both valid and invalid logins, and show the results.
2. What CMS are you authenticating against? Drupal, SMF, phpBB?

[PhasecoreX]

Yes, there was a plugin interfering. I am using SMF2, and the plugin causing problems was httpBL:

PHP Warning:  Missing argument 1 for httpBL_look_for_empty_ip(), called in /var/www/forum/Sources/httpBL_Subs.php on line 680 and defined in /var/www/forum/Sources/httpBL_Subs.php on line 517
PHP Notice:  Undefined variable: ip in /var/www/forum/Sources/httpBL_Subs.php on line 519
PHP Warning:  xcache_unset(): XCache var cache was not initialized properly. Check php log for actual reason in /var/www/forum/Sources/Load.php on line 2655
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #1: isuser with valid username
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #2: isuser with bad username
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #3: auth with valid password
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #4: auth with bad username
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #5: auth with bad password
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #6: attempt to set password (fail)
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #7: attempt to create account (fail)
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #8: attempt to delete account (fail)
PHP Warning:  unpack(): Type n: not enough input, need 2, have 0 in /opt/ejabberd-auth-php/tests/unit_test.php on line 33
FAIL #9: attempt to login and delete account (fail)
9 tests, 0 passed, 9 failed

(Pretty sure XCache is just caused by SMF2 itself, not actually causing problems). Turns out that httpBL (a popular spammer detection mod) tries to look up IP addresses of everyone connecting to the site. When accessed directly from SSI.php, it never gets an IP address to lookup, and thus stops the script completely.

I looked into the SSI.php script and what httpBL adds to it, and I was able to essentially disable the check completely by setting a global variable in ejabberd-auth-php/plugins/smf2/smf2.module. It all now works correctly!

function smf2_bootstrap($config) {
  $smf_root_path = $config['root_path'];
  if (file_exists($smf_root_path . 'SSI.php')) {
    include_once $smf_root_path . 'SSI.php';
  }
  else {
    file_put_contents('php://stderr', "SMF not found at <{$smf_root_path}>.\n");
    exit;
  }
}

Add two lines in if statement to get:

function smf2_bootstrap($config) {
  $smf_root_path = $config['root_path'];
  if (file_exists($smf_root_path . 'SSI.php')) {
    global $httpBL_warning;
    $httpBL_warning = True;
    include_once $smf_root_path . 'SSI.php';
  }
  else {
    file_put_contents('php://stderr', "SMF not found at <{$smf_root_path}>.\n");
    exit;
  }
}

If $httpBL_warning is set, it skips the entire httpBL if statement in SSI.php that does IP checks. Not sure on your protocol for submitting code to your repo, but you can just add those two lines if you'd like, unless you want me to do something about it.

[cburschka]

Thanks for finding this!

Fortunately the problem doesn't cause the script to crash; it just spits PHP warnings into the output and messes up the IO (I assume that ejabberd itself then terminates and restarts the script, since the test script didn't do this). I don't think it's feasible to code around each specific plugin that does this, but there's a better solution - I could turn on output buffering and disable error reporting to ensure that such notices and errors get suppressed.

[cburschka]

(Oops, I missed the part where httpBL actually terminates the script if it breaks. We might have to circumvent that specifically after all. :) )

[PhasecoreX]

Yeah, httpBL will redirect the user and call the exit() function if the IP lookup fails (either if they are a spammer, or has no IP address):

// Before we do anything else with this user we check projecthoneypot to see if it's a spammer. MOD httpBL
// But do it only if we are not coming from the file warning.php
global $boardurl, $httpBL_warning;
if ($modSettings['httpBL_enable'] && !isset($httpBL_warning))
{
    require_once($sourcedir . '/httpBL_Subs.php');
    $response = httpBL_dnslookup($user_info['ip'], $modSettings['httpBL_honeyPot_key']);
    if ($response)
    {
        $_SESSION['response'] = $response;
        header('Location: '. $boardurl .'/warning.php');
        exit();
    }
}

Thus, setting $httpBL_warning (globally from smf2.module) will skip all of this. I completely agree though that it's not cool to code for specific plugin compatibility and to instead find a general case. In this case however, I can't seem to find an alternative, unless there is a way to pass the users IP address to SSI.php (globally set $user_info['ip']?). But even then, we might still have the problem of a terminating script, since it originally terminated far more times than connections were made (first post).

Fortunately though, there aren't that many spam prevention mods listed on SMF's mod site.

[cburschka]

(Additionally, it might be worth requesting a fix to the plugin itself. The only time $_SERVER['REMOTE_ADDR'] and therefore $user_info['ip'] should be empty is in a CLI context, which is unavailable to spammers by definition.

Since SSI.php exists for this purpose, I don't think what we're trying to do in SMF is unsupported or too extraordinary...

If they can't fix this on the SMF side, then we can probably circumvent this and other problems like it by setting $_SERVER['REMOTE_ADDR'] to 127.0.0.1 but that's a bit of a hack. Though not as much of a hack as setting $httpBL_warning, which basically pretends we're already on the warning page. :P )

[cburschka]

The bug is here:

    if ($values['ip'] == '')
    {
        // Still empty? Stop the visitor. Sorry, no blanks IPs allowed
        // TO DO: Find more methods or more possibilities why sometimes $ip is blank
        $values['errorNumber'] = 150;
        $values['ID'] = httpBL_logme($values, true);
        //httpBL_session_put_data($httpBL_session, $values, $cache_seconds);
        return $values;
    }

[PhasecoreX]

Right, I don't like the $httpBL_warning method at all haha. It was just a quick fix at the time. I've gone on and tested another mod that also uses http:BL/ProjectHoneyPot, and it works perfectly with ejabberd-auth-php (The mod is called Bad Behavior, which was updated January 30, 2014, as opposed to httpBL being updated June 18, 2011...).

I went to the httpBL support forum and saw you posted there about this issue (I was going to reference it for you, until I realized it was you). Based on their last plugin update, I have no clue if this will ever be fixed on their end officially, but at least we know what to tell others who are in my position. But I'm thinking now that yes, this is something that should be fixed in the plugin, and not here.

[PhasecoreX]

Alright so I spoke too soon on that last one. Bad Behavior does not work, it has a similar problem where it needs a bunch of information ($_SERVER['SERVER_PROTOCOL'], $_SERVER['REMOTE_ADDR'], and $_SERVER['REQUEST_METHOD'] as far as I could tell). Unlike httpBL, there was no if statement that would allow me to prevent the script from running. Even setting $_SERVER['REMOTE_ADDR'] to 127.0.0.1 doesn't help.

Thus, I have just created an if($_SERVER['HTTP_HOST']) statement around that include in SSI.php, reverted all your code back to what it was, and everything works as expected. Again, nothing on this end to fix, as these plugins should be checking for this HTTP_HOST variable anyway. Just thought I'd let you know though.

[cburschka]

Thanks for clearing this up! I guess that with this particular method of access being so uncommon, very few plugin developers check for it.