Random "Authentication failed" since upgrade to pecl-mongodb 1.3.0

[bodenh...@gmail.com]

Hi,

since my upgrade from 1.2.9 to 1.3.0, my application "crashed" random with the fatal error message:

Fatal error: Uncaught MongoDB\Driver\Exception\AuthenticationException: Authentication failed. in /var/www/xyz.xyz/htdocs/includes/vendor/mongodb/mongodb/src/Operation/Update.php:158

Stack trace:

#0 /var/www/xyz.xyz/htdocs/includes/vendor/mongodb/mongodb/src/Operation/Update.php(158): MongoDB\Driver\Server->executeBulkWrite('databasename.runtime_...', Object(MongoDB\Driver\BulkWrite), Object(MongoDB\Driver\WriteConcern))

#1 /var/www/xyz.xyz/htdocs/includes/vendor/mongodb/mongodb/src/Operation/UpdateMany.php(92): MongoDB\Operation\Update->execute(Object(MongoDB\Driver\Server))

#2 /var/www/xyz.xyz/htdocs/includes/vendor/mongodb/mongodb/src/Collection.php(817): MongoDB\Operation\UpdateMany->execute(Object(MongoDB\Driver\Server))

#3 /var/www/xyz.xyz/htdocs/includes/mongo.class.inc.php(66): MongoDB\Collection->updateMany(Array, Array, Array)

#4 /var/www/xyz.xyz/admin/admscripts/cron.update.runtime.hostname.php(18): myMongo->mongoUpdtMulti(Array, Array)

#5 {main}

  thrown in /var/www/xyz.xyz/htdocs/includes/vendor/mongodb/mongodb/src/Operation/Update.php on line 158

It doesn´t matter if cli or php-fpm script.

In my mongodb.log i see:

2017-10-13T06:55:02.755Z I ACCESS   [conn80091] SCRAM-SHA-1 authentication failed for databaseuser on databasename from client 127.0.0.1:51242 ; AuthenticationFailed: SCRAM-SHA-1 authentication failed, storedKey mismatch

But not every time, sometimes it runs without any errors. Thats confused me a little.

Thanks and best regards,

N.

[Jeremy Mikola]

Can you share how you're connecting via the PHP driver? Specifically, I'd like to see how authentication options are being passed to the MongoDB\Driver\Manager or MongoDB\Client constructor. Please redact the credentials, but note any characteristics of the strings that may be relevant (e.g. special characters that appear). Also, please share what version of MongoDB is in use in case that is relevant (e.g. SERVER-20365 before 3.4.0).

As you mentioned the authentication error appears sporadically, can you confirm whether the script is always interacting with the authenticated connection on each request? I ask because the connections are initialized lazily at the time the first command, query, or write is executed (not at the time the manager/client object is constructed).

--
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.
 
For other MongoDB technical support options, see: https://docs.mongodb.com/manual/support/
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user+unsubscribe@googlegroups.com.
To post to this group, send email to mongod...@googlegroups.com.
Visit this group at https://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CA%2B5YK2HtkPFExXjS4HO5nJW9pxVGgL2t1Z0t45-wBpvTD_%3D5rw%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.

[bodenh...@gmail.com]

Hi,

2017-10-16 19:38 GMT+02:00 'Jeremy Mikola' via mongodb-user <mongod...@googlegroups.com>:

Can you share how you're connecting via the PHP driver? Specifically, I'd like to see how authentication options are being passed to the MongoDB\Driver\Manager or MongoDB\Client constructor. Please redact the credentials, but note any characteristics of the strings that may be relevant (e.g. special characters that appear). Also, please share what version of MongoDB is in use in case that is relevant (e.g. SERVER-20365 before 3.4.0).

Sure:

MongoDB is v3.4.9 on Ubuntu 14.04.

###

$sslContext = stream_context_create(array("ssl" => array("verify_peer" => false, "verify_peer_name" => false, "allow_self_signed" => true)));

                        $this->client = new MongoDB\Client(

                                'mongodb://db1:27017,db2:27017,db3:27017/',

                                [

                                        'username'               => $this->conOpts['username'],

                                        'password'               => $this->conOpts['password'],

                                        'ssl'                    => true,

                                        'replicaSet'             => $this->conOpts['replicaSet'],

                                        'authSource'             => $this->conOpts['db'],

                                ],

                                [

                                        'context' => $sslContext,

                                        'typeMap' => ['root' => 'array', 'document' => 'array', 'array' => 'array']

                                ]

                        );

                }

###

 

As you mentioned the authentication error appears sporadically, can you confirm whether the script is always interacting with the authenticated connection on each request? I ask because the connections are initialized lazily at the time the first command, query, or write is executed (not at the time the manager/client object is constructed).

Yes, on every run from the script(s) (cli/fpm) are included the connection class.

I also tried the new 1.3.1 driver, unfortunaly with the same problem.

Thank you and best regards,

Norbert

 

To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CACypnJWfUxON2dUvB2mP8PkfCqurYNU14nRGY6PbivmB9fEqQw%40mail.gmail.com.

[Jeremy Mikola]

Thanks for the details. I've opened PHPC-1022 to track this as a bug. We'll still need to investigate this further, but it may be related to some SCRAM-SHA-1 caching that was introduced in our libmongoc dependency, which was updated from 1.5.5 in PHP driver 1.2.x to 1.8.0 in PHP driver 1.3.0. I've cross-referenced the issue and suspected upstream change in the JIRA issue linked above.

Please follow that issue for updates, and note that it may take some time for us to properly diagnose this.

In the meantime, any more details you can provide about the nature of the CLI environment would be helpful. I'm singling out the CLI environment over FPM as I assume that the CLI script would be running in a fresh process each time, and not reusing a persisted libmongoc client (see: connection handling) where SCRAM-SHA-1 could be cached from a previous execution/request.

Answers to the following would be helpful:

• How often is the CLI script executed (e.g. nightly cron job)?
• On average, for how long does it execute (e.g. a few seconds, minutes at a time)?
• When the exception occurs, is it always at the beginning of the script's execution, or does it sometimes happen in the middle of its duration?
• Can you make any correlation between the server that fails authentication and the replica set configuration? For instance, is the first server listed in the connection string seed list (e.g. "db1:27017") the one to fail, or perhaps the first server listed in the isMaster.hosts array field from the isMaster command response? This might tell us if the driver tends to fail on the second server it attempts to connect to, after presumably caching values from the first connection made.
  
• Do you observe any notable events with the cluster while the script is running and this error appears (e.g. primary fails over, dropped connections at any point, adding a new node to the cluster)?

My last comment in the issue above speculates that a cached value for SCRAM-SHA-1 may be getting invalid over the course of the CLI script's execution.

To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CA%2B5YK2E6z-NUVUDByn-GAo7HrGKXNvM-y8JdAbbJ--Ar35sR3Q%40mail.gmail.com.