I am running Nginx + PHP-FPM + MongoDB using Docker containers.
Here is my docker-compose.yml
version: '3.2'
name: app
services:
nginx:
container_name: app-nginx
build:
context: ./nginx
dockerfile: Dockerfile
ports:
- 80:80
- 443:443
volumes:
- ../src:/var/www/html:ro
depends_on:
- php-fpm
php-fpm:
container_name: app-php-fpm
build:
context: .
dockerfile: Dockerfile
volumes:
- ../src:/var/www/html
links:
- "mysql:mysqldb"
- "mongo:mongodb"
environment:
YII_ENV: 'prod'
YII_DEBUG: '0'
depends_on:
- mysql
- mongo
mysql:
container_name: app-mysql
image: mysql:8.0
volumes:
- mysqldb:/var/lib/mysql
environment:
MYSQL_ROOT_PASSWORD: ${MYSQL_ROOT_PASSWORD}
MYSQL_DATABASE: ${MYSQL_DATABASE}
MYSQL_USER: ${MYSQL_USER}
MYSQL_PASSWORD: ${MYSQL_PASSWORD}
mongo:
container_name: app-mongo
image: mongo:7.0
volumes:
- mongodb:/data/db
environment:
MONGO_INITDB_ROOT_USERNAME: ${MONGO_INITDB_ROOT_USERNAME}
MONGO_INITDB_ROOT_PASSWORD: ${MONGO_INITDB_ROOT_PASSWORD}
volumes:
mysqldb:
name: app-mysql-db
driver: local
mongodb:
name: app-mongo-db
driver: local
networks:
default:
name: app-network
The PHP-FPM Dockerfile:
FROM php:8.3-fpm-alpine
# Use the default production configuration
RUN mv "$PHP_INI_DIR/php.ini-production" "$PHP_INI_DIR/php.ini"
# Install required utilities
RUN apk update
&& apk add --no-cache icu icu-data-full libzip libpng libjpeg-turbo libwebp freetype
# Install deps, compile php extensions, install extensions, and purge the temp libraries
RUN apk add --no-cache --virtual build-essentials
${PHPIZE_DEPS} curl-dev openssl-dev icu-dev libzip-dev libpng-dev libwebp-dev libjpeg-turbo-dev freetype-dev
&& pecl install mongodb
&& docker-php-ext-enable mongodb
&& docker-php-ext-install zip
&& docker-php-ext-install pdo_mysql
&& docker-php-ext-configure intl
&& docker-php-ext-install intl
&& docker-php-ext-configure gd --enable-gd --with-freetype --with-jpeg --with-webp
&& docker-php-ext-install gd
&& apk del build-essentials
&& rm -rf /usr/src/php*
&& rm -rf /tmp/pear
# Install PHP composer
RUN php -r "copy('https://getcomposer.org/installer', 'composer-setup.php');"
&& php -r "if (hash_file('sha384', 'composer-setup.php') === 'e21205b207c3ff031906575712edab6f13eb0b361f2085f1f1237b7126d785e826a450292b6cfd1d64d92e6563bbde02') { echo 'Installer verified'; } else { echo 'Installer corrupt'; unlink('composer-setup.php'); exit(80); } echo PHP_EOL;"
&& php composer-setup.php --install-dir=/usr/local/bin --filename=composer
&& php -r "unlink('composer-setup.php');"
The PHP container runs application on Yii2 framework. There is nothing fancy in the connection setup:
'statsDb' => [
'class' => 'yiimongodbConnection',
'dsn' => 'mongodb://'.$credentials['components']['statsDb']['username'].':'.$credentials['components']['statsDb']['password'].'@mongodb:27017/appstats',
'options' => [
'socketTimeoutMS' => 300000, # 5 minutes
'maxIdleTimeMS' => 300000, # 5 minutes
],
],
The problem is – approx every minute I get the following errors in MongoDB container logs:
app-mongo | {"t":{"$date":"2024-01-08T20:15:11.460+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn25","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:37498","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":60175101,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:15:17.066+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn23","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:54348","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":63439603,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:16:02.141+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn24","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:57018","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":64052295,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:16:11.650+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn25","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:37498","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":60190144,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:16:17.070+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn23","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:54348","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":60003787,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:17:08.237+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn24","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:57018","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":66096005,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:17:13.099+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn25","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:37498","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":61448810,"summary":{}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:17:18.822+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn23","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:54348","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Overridden by new authentication session","result":337,"metrics":{"conversation_duration":{"micros":61752258,"summary":{}}},"extraInfo":{}}}
The client IP 172.24.0.4 is PHP-FPM container IP. The strange thing is that connection to the MongoDB works fine, the application is able to read/write data to the Database all the time.
I could not find any resource explaining this particular error: "AuthenticationAbandoned: Overridden by new authentication session"
I tried to set maxIdleTimeMS to 5 minutes to the connection options, but it didn’t change the interval of the errors.
I tried also to make a constant page views to see if the connections remains if web has steady traffic (no idle connections to database).
Also I checked the single connection lifecycle from Mongo logs:
app-mongo | {"t":{"$date":"2024-01-08T20:27:55.406+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"172.24.0.4:52552","uuid":{"uuid":{"$uuid":"1f900032-c828-46db-953d-8589d632f586"}},"connectionId":40,"connectionCount":10}}
app-mongo | {"t":{"$date":"2024-01-08T20:27:55.407+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn40","msg":"client metadata","attr":{"remote":"172.24.0.4:52552","client":"conn40","doc":{"driver":{"name":"mongoc / ext-mongodb:PHP ","version":"1.25.2 / 1.17.2 "},"os":{"type":"Linux","name":"Alpine Linux","version":"3.19.0","architecture":"x86_64"},"platform":"PHP 8.3.1 cfg=0x03d21620c9 posix=200809 stdc=201710 CC=GCC 13.2.1 20231014 CFLAGS="" LDFLAGS="""}}}
app-mongo | {"t":{"$date":"2024-01-08T20:27:55.407+00:00"},"s":"I", "c":"ACCESS", "id":6788604, "ctx":"conn40","msg":"Auth metrics report","attr":{"metric":"acquireUser","micros":0}}
app-mongo | {"t":{"$date":"2024-01-08T20:27:55.439+00:00"},"s":"I", "c":"ACCESS", "id":5286306, "ctx":"conn40","msg":"Successfully authenticated","attr":{"client":"172.24.0.4:52552","isSpeculative":true,"isClusterMember":false,"mechanism":"SCRAM-SHA-256","user":"appuser","db":"appstats","result":0,"metrics":{"conversation_duration":{"micros":32602,"summary":{"0":{"step":1,"step_total":2,"duration_micros":48},"1":{"step":2,"step_total":2,"duration_micros":17}}}},"extraInfo":{}}}
app-mongo | {"t":{"$date":"2024-01-08T20:27:55.440+00:00"},"s":"I", "c":"NETWORK", "id":6788700, "ctx":"conn40","msg":"Received first command on ingress connection since session start or auth handshake","attr":{"elapsedMillis":0}}
app-mongo | {"t":{"$date":"2024-01-08T20:29:09.051+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn40","msg":"Connection ended","attr":{"remote":"172.24.0.4:52552","uuid":{"uuid":{"$uuid":"1f900032-c828-46db-953d-8589d632f586"}},"connectionId":40,"connectionCount":10}}
app-mongo | {"t":{"$date":"2024-01-08T20:29:09.052+00:00"},"s":"I", "c":"ACCESS", "id":5286307, "ctx":"conn40","msg":"Failed to authenticate","attr":{"client":"172.24.0.4:52552","isSpeculative":false,"isClusterMember":false,"mechanism":"","user":"","db":"","error":"AuthenticationAbandoned: Authentication session abandoned, client has likely disconnected","result":337,"metrics":{"conversation_duration":{"micros":13119620,"summary":{}}},"extraInfo":{}}}