openssl encypt/decrypt inconsistently working/failing

Question

I'm seeing some weird behaviour with the openssl_* methods in PHP. 50% of the time, it will fail, throwing Unknown cipher algorithm, and the other 50% of the time, it will correctly encode my data. Here's the relevant snippet from my code:

$iv = openssl_random_pseudo_bytes(16);
$hash = openssl_encrypt($raw, "AES-128-CBC", $hashing_secret, OPENSSL_RAW_DATA, $iv);
// send $iv.$hash

using openssl_get_cipher_methods gives me:

[0] => AES-128-CBC
...
[81] => aes-128-cbc

so I know that the ciphers are available. Additionally, $ openssl ciphers lists AES-128-CBC as an available cipher at the system level (however, I've been told that PHP's bundled openssl is independent)

I'm running Ubuntu 14.04, php5.5.9-1ubuntu4.14, openssl 1.0.1f 6 Jan 2014 (the version listed in phpinfo is the same). If it's relevant, all this code is running under the Silex framework via nginx/php-fpm.

Update: A bit more info...

I've done some more testing. I wrote a small script that just loops over x times, encoding some data.

set_error_handler(function() use (&$errorCount) {
    $errorCount++;
});

for ($i = 0; $i < $numTests; $i++) {
    $hash = openssl_encrypt($data, "AES-128-CBC", $hashing_secret, OPENSSL_RAW_DATA, $iv);    
}

If I run that (via php test.php) on the same server, it runs consistently - i.e. $errorCount == 0 every time. That leads me to believe it's either: a) silex or b) the fastcgi process that impeding the function - I've added those tags.

Not really sure where to go from here, now, though...

Second Update

I did a little more testing. I stuck the test script behind nginx, running php-fpm. The odd thing here is that either a) it fails 100% of the time or b) it fails 0 times, instead of a little bit of both results. This leads me to believe that it's nginx or php-fpm that's the culprit.

Answer 1

This looks like it might be an OpenSSL mis-locking error. You should ensure that only one OpenSSL object is ever in use at any one time in the same process space.

To verify, run the test script so that it is the only one using OpenSSL. Does it still fail 50% of the time? Or is the failure only happening with multiple concurrent accesses to the script?

If it still happens, it almost has to be a bug in php-fpm -- it is instantiating the function and not clearing its data areas properly until an error occurs. In that case I expect it to fail once every two calls, not "50% on average" but exactly once every even-numbered call. In that case I'd try with a different version of OpenSSL.

To lock openssl, you might try using flock and instantiate a lock file for use by the SSL function (first you check the lock is available, then run the function and unlock). Try this and see whether it works. If it does, you can look into a more efficient way of doing it - for example you might use a MySQL LOCK(), or a semaphore if it is available.

Spelunking

The misbehaving function in 5.5.9 is to be found in ext/openssl/openssl.c and the error being thrown is one of the preliminary checks. No surprises yet:

/* {{{ proto string openssl_encrypt(string data, string method, string password [, long options=0 [, string $iv='']])
   Encrypts given data with given method and key, returns raw or base64 encoded string */
PHP_FUNCTION(openssl_encrypt)
{
    long options = 0;
    char *data, *method, *password, *iv = "";
    int data_len, method_len, password_len, iv_len = 0, max_iv_len;
    const EVP_CIPHER *cipher_type;
    EVP_CIPHER_CTX cipher_ctx;
    int i=0, outlen, keylen;
    unsigned char *outbuf, *key;
    zend_bool free_iv;

    if (zend_parse_parameters(ZEND_NUM_ARGS() TSRMLS_CC, "sss|ls", &data, &data_len, &method, &method_len, &password, &password_len, &options, &iv, &iv_len) == FAILURE) {
        return;
    }
    cipher_type = EVP_get_cipherbyname(method);
    if (!cipher_type) {
        php_error_docref(NULL TSRMLS_CC, E_WARNING, "Unknown cipher algorithm");
        RETURN_FALSE;
    }

So we can assume that EVP_get_cipherbyname(method) is returning a falsehood.

Except that it is a standard SSL function. I found this terse (and very possibly outdated) reply which seems to indicate there's some facepalm juice in the recipe somewhere. But this does not explain why the function should fail once every two.

The function is here on github. It initializes OpenSSL, and it gets the method name via an ancillary function that will return a pointer to non-nulled memory.

I had a farfetched hypothesis that the function was returning something akin to 0 or 81 at random (since both strings are in your cipherlist output, with indexes 0 and 81) and 0 was equaled to NULL, hence failing. It appears it can't work like that, and it should do so also in the CLI. But just to be sure, verify whether it is only that particular cipher that fails (while e.g. AES-256-CBC works).

The other possibility is that it's the OPENSSL_init_crypto(OPENSSL_INIT_ADD_ALL_CIPHERS, NULL) call which is failing. This can happen if this test (on Ubuntu; other platforms behave differently) fails:

int CRYPTO_THREAD_run_once(CRYPTO_ONCE *once, void (*init)(void))
{
    if (pthread_once(once, init) != 0)
        return 0;

    return 1;
}

This again would indicate some shared resource conflict deep inside libcrypto.

As another test, I suggest you do not call the random bytes IV initialization and try with a fixed IV; that's because I've also stumbled across this note, which points to a slightly different resource than I was thinking of, but close enough to have me react:

It appears that openssl_random_pseudo_bytes(), which calls openssl, causes the underlying libcrypto to invoke a callback that was established previously by PostgreSQL library as part of the lock portability callbacks for multi-threading of openssl.

Some information on the topic can be found here http://wiki.openssl.org/index.php/Manual:Threads(3)

If HHVM openssl extension does not establish these same callbacks, it may be causing the wrong callbacks to be called.

The next tests I'm going to perform, time permitting, is to place alerts (in the form of static syslog calls) in the above mentioned failure points, to exactly pinpoint which test is failing... provided I can install the same setup as you have on a VM, and I can reproduce the same weird behaviour.