HW-2.6, can't start mongod

Although I have started the KMIP server, as far as I can see, with no problem;
while working on HW-2.6, this is how I (try to) launch mongod and hit some issues.

It would great if somebody could give some good advice to get out of that.

mongod --dbpath /home/vagrant/M310-HW-2.6/db --logpath /home/vagrant/M310-HW-2.6/db/mongodb.log --port 31260 --enableEncryption --kmipServerName infrastructure.m310.mongodb.university --kmipServerCAFile /home/vagrant/shared/certs/ca.pem --kmipClientCertificateFile /home/vagrant/shared/certs/client.pem

But it is not working and this is what I get in the log file.

vagrant@database:~$ 
vagrant@database:~$ cat M310-HW-2.6/db/mongodb.log
2020-12-04T04:49:40.775+0000 I CONTROL  [initandlisten] MongoDB starting : pid=11107 port=31260 dbpath=/home/vagrant/M310-HW-2.6/db 64-bit host=database
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] db version v3.2.22
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] git version: 105acca0d443f9a47c1a5bd608fd7133840a58dd
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] modules: enterprise 
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] build environment:
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten]     distmod: ubuntu1404
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-12-04T04:49:40.776+0000 I CONTROL  [initandlisten] options: { net: { port: 31260 }, security: { enableEncryption: true, kmip: { clientCertificateFile: "/home/vagrant/shared/certs/client.pem", serverCAFile: "/home/vagrant/shared/certs/ca.pem", serverName: "infrastructure.m310.mongodb.university" } }, storage: { dbPath: "/home/vagrant/M310-HW-2.6/db" }, systemLog: { destination: "file", path: "/home/vagrant/M310-HW-2.6/db/mongodb.log" } }
2020-12-04T04:49:40.795+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),extensions=[local=(entry=mongo_addWiredTigerEncryptors)],encryption=(name=AES256-CBC,keyid=".system"),
2020-12-04T04:49:40.806+0000 E STORAGE  [initandlisten] Unable to retrieve key .system, error: Failed to open connection to KMIP server infrastructure.m310.mongodb.university.
2020-12-04T04:49:40.808+0000 I -        [initandlisten] Fatal Assertion 28561
2020-12-04T04:49:40.808+0000 I -        [initandlisten] 

***aborting after fassert() failure


vagrant@database:~$

It says cannot open connection to KMIP server
Is your kmip up and running?
Are database and infrastructure able to communicate each other
Try ping,telnet as given in below link
Sometimes IP/hostname resolution issues cause the connection failures

Please go through this link

HW 2.6: server certificate does not match the host name

Yes as I wrote.

I have started the KMIP server, as far as I can see, with no problem

I tried a ping, it was perfectly working.

does telnet infrastructure 5696 from database work?

Please show contents of
pykmip_server.py

Yes it does.

vagrant@database:~$ telnet infrastructure 5696
Trying 192.168.31.200...
Connected to infrastructure.m310.mongodb.university.
Escape character is '^]'.
^]

telnet> help
Commands may be abbreviated.  Commands are:

close   	close current connection
logout  	forcibly logout remote user and close the connection
display 	display operating parameters
mode    	try to enter line or character mode ('mode ?' for more)
open    	connect to a site
quit    	exit telnet
send    	transmit special characters ('send ?' for more)
set     	set operating parameters ('set ?' for more)
unset   	unset operating parameters ('unset ?' for more)
status  	print status information
toggle  	toggle operating parameters ('toggle ?' for more)
slc     	set treatment of special characters

z       	suspend telnet
environ 	change environment variables ('environ ?' for more)
telnet>

The file pykmip_server.py is as I downloaded it.

[vagrant@infrastructure shared]$ pwd
/home/vagrant/shared
[vagrant@infrastructure shared]$ cat pykmip_server.py
#!/usr/bin/python

# this file is a thin wrapper around the PyKMIP server
# which is required for some encrypted storage engine tests

import logging

from kmip.services.kmip_server import KMIPServer

def main():

    logger = logging.getLogger(__name__)

    server = KMIPServer(
        host="192.168.31.200",
        port=5696,
        keyfile="/home/vagrant/shared/certs/server.pem",
        certfile="/home/vagrant/shared/certs/server.pem",
        cert_reqs="CERT_REQUIRED",
        ssl_version="PROTOCOL_TLSv1",
        ca_certs="/home/vagrant/shared/certs/ca.pem",
        do_handshake_on_connect=True,
        suppress_ragged_eofs=True)

    logger.info("Starting KMIP server")

    try:
        server.serve()
    except Exception as e:
        logger.info('Exception received while serving: {0}'.format(e))
    finally:
        server.close()

    logger.info("Stopping KMIP server")


if __name__ == '__main__':
    main()

[vagrant@infrastructure shared]$ 
[vagrant@infrastructure shared]$

Here is a report of what I do an what is happening.
Please let me know if you see any kind of mistake.

On the infrastructure VM.

[vagrant@infrastructure shared]$ 
[vagrant@infrastructure shared]$ python pykmip_server.py
2020-12-04 14:14:31,707 - __main__ - INFO - Starting KMIP server


[vagrant@infrastructure ~]$ 
[vagrant@infrastructure ~]$ ps -aef | grep pykmip_server
vagrant   3135  3108  0 14:14 pts/0    00:00:00 python pykmip_server.py
vagrant   3172  3141  0 14:18 pts/1    00:00:00 grep --color=auto pykmip_server
[vagrant@infrastructure ~]$ 

On the database VM.

vagrant@database:~$ 
vagrant@database:~$ mongod --dbpath /home/vagrant/M310-HW-2.6/db --logpath /home/vagrant/M310-HW-2.6/db/mongodb.log --port 31260 --enableEncryption --kmipServerName infrastructure.m310.mongodb.university --kmipServerCAFile /home/vagrant/shared/certs/ca.pem --kmipClientCertificateFile /home/vagrant/shared/certs/client.pem
vagrant@database:~$ 
vagrant@database:~$ 
vagrant@database:~$ ps -aef | grep mongod
vagrant   7945  7895  0 14:24 pts/0    00:00:00 grep --color=auto mongod
vagrant@database:~$ 

One can see that mongod didn't fire up.

And this is what I get in the log file.

vagrant@database:~$ 
vagrant@database:~$ 
vagrant@database:~$ cat M310-HW-2.6/db/mongodb.log
2020-12-04T14:23:35.226+0000 I CONTROL  [initandlisten] MongoDB starting : pid=7942 port=31260 dbpath=/home/vagrant/M310-HW-2.6/db 64-bit host=database
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] db version v3.2.22
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] git version: 105acca0d443f9a47c1a5bd608fd7133840a58dd
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] modules: enterprise 
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] build environment:
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten]     distmod: ubuntu1404
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-12-04T14:23:35.227+0000 I CONTROL  [initandlisten] options: { net: { port: 31260 }, security: { enableEncryption: true, kmip: { clientCertificateFile: "/home/vagrant/shared/certs/client.pem", serverCAFile: "/home/vagrant/shared/certs/ca.pem", serverName: "infrastructure.m310.mongodb.university" } }, storage: { dbPath: "/home/vagrant/M310-HW-2.6/db" }, systemLog: { destination: "file", path: "/home/vagrant/M310-HW-2.6/db/mongodb.log" } }
2020-12-04T14:23:35.247+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),extensions=[local=(entry=mongo_addWiredTigerEncryptors)],encryption=(name=AES256-CBC,keyid=".system"),
2020-12-04T14:23:35.257+0000 E STORAGE  [initandlisten] Unable to retrieve key .system, error: Failed to open connection to KMIP server infrastructure.m310.mongodb.university.
2020-12-04T14:23:35.258+0000 I -        [initandlisten] Fatal Assertion 28561
2020-12-04T14:23:35.258+0000 I -        [initandlisten] 

***aborting after fassert() failure


vagrant@database:~$ 
vagrant@database:~$

Steps you performed looks fine

Are the certificates avail in the given path?
Double check
ls -lrt /home/vagrant/shared/certs/ca.pem
ls -lrt /home/vagrant/shared/certs/client.pem
Are they latest downloaded from this lab?
Move if any old files exist
Make sure infrastructure session is active where you started KMIP

In addition, is there any error message in the infrastructure terminal where kmip server is started?

I started again this morning, tackling HW-2.6; here is a report.

This is the state right after starting the KMIP server:

[vagrant@infrastructure shared]$ python pykmip_server.py 
2020-12-05 01:51:46,582 - __main__ - INFO - Starting KMIP server

Then on the database VM.

vagrant@database:~$ mongod --dbpath /home/vagrant/M310-HW-2.6/db --logpath /home/vagrant/M310-HW-2.6/db/mongodb.log --port 31260 --enableEncryption --kmipServerName infrastructure.m310.mongodb.university --kmipServerCAFile /home/vagrant/shared/certs/ca.pem --kmipClientCertificateFile /home/vagrant/shared/certs/client.pem

and then:

vagrant@database:~$ ps -aef | grep mongod
vagrant   7836  7805  2 02:00 pts/0    00:00:04 mongod --dbpath /home/vagrant/M310-HW-2.6/db --logpath /home/vagrant/M310-HW-2.6/db/mongodb.log --port 31260 --enableEncryption --kmipServerName infrastructure.m310.mongodb.university --kmipServerCAFile /home/vagrant/shared/certs/ca.pem --kmipClientCertificateFile /home/vagrant/shared/certs/client.pem
vagrant   7949  7932  0 02:03 pts/2    00:00:00 grep --color=auto mongod
vagrant@database:~$ 

So it looks like this time the mongod is started.

But going back to the infrastructure VM. This is the state:

[vagrant@infrastructure shared]$ python pykmip_server.py 
2020-12-05 01:51:46,582 - __main__ - INFO - Starting KMIP server
2020-12-05 02:00:49,032 - kmip.services.kmip_server - ERROR - KMIPServer <class 'ssl.SSLEOFError'> EOF occurred in violation of protocol (_ssl.c:1826)

And finally, this is the contents of the log file on the database VM:

vagrant@database:~$ 
vagrant@database:~$ cat M310-HW-2.6/db/mongodb.log 
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] MongoDB starting : pid=7836 port=31260 dbpath=/home/vagrant/M310-HW-2.6/db 64-bit host=database
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] db version v3.2.22
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] git version: 105acca0d443f9a47c1a5bd608fd7133840a58dd
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] modules: enterprise 
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten] build environment:
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten]     distmod: ubuntu1404
2020-12-05T02:00:48.934+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-12-05T02:00:48.935+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-12-05T02:00:48.935+0000 I CONTROL  [initandlisten] options: { net: { port: 31260 }, security: { enableEncryption: true, kmip: { clientCertificateFile: "/home/vagrant/shared/certs/client.pem", serverCAFile: "/home/vagrant/shared/certs/ca.pem", serverName: "infrastructure.m310.mongodb.university" } }, storage: { dbPath: "/home/vagrant/M310-HW-2.6/db" }, systemLog: { destination: "file", path: "/home/vagrant/M310-HW-2.6/db/mongodb.log" } }
2020-12-05T02:00:48.956+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),extensions=[local=(entry=mongo_addWiredTigerEncryptors)],encryption=(name=AES256-CBC,keyid=".system"),
2020-12-05T02:00:48.995+0000 I STORAGE  [initandlisten] Created KMIP key with id: 1
2020-12-05T02:00:49.039+0000 I STORAGE  [initandlisten] Encryption key manager initialized using KMIP key with id: 1.
2020-12-05T02:00:49.050+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/home/vagrant/M310-HW-2.6/db/diagnostic.data'
2020-12-05T02:00:49.050+0000 I NETWORK  [initandlisten] waiting for connections on port 31260
2020-12-05T02:00:49.050+0000 I NETWORK  [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
vagrant@database:~$ 

Just in case this might be of some use:

[vagrant@infrastructure ~]$ ls -l shared/certs/
total 12
-rw-r--r--. 1 vagrant vagrant 1314 Dec  4 04:28 ca.pem
-rw-r--r--. 1 vagrant vagrant 3104 Dec  4 04:28 client.pem
-rw-r--r--. 1 vagrant vagrant 3108 Dec  4 04:28 server.pem
[vagrant@infrastructure ~]$ 
[vagrant@infrastructure ~]$ md5sum shared/certs/*
158d4af4a90a2c8308516369c62f49b2  shared/certs/ca.pem
4021dcadca697dadaf28018d36d06a61  shared/certs/client.pem
c935a710ecafd2a0c598da914ac46997  shared/certs/server.pem
[vagrant@infrastructure ~]$ 

and :

vagrant@database:~$ ls -l shared/certs/
total 12
-rw-r--r-- 1 vagrant vagrant 1314 Dec  5 01:37 ca.pem
-rw-r--r-- 1 vagrant vagrant 3104 Dec  4 04:52 client.pem
-rw-r--r-- 1 vagrant vagrant 3108 Dec  5 01:37 server.pem
vagrant@database:~$ 
vagrant@database:~$ md5sum shared/certs/*
158d4af4a90a2c8308516369c62f49b2  shared/certs/ca.pem
4021dcadca697dadaf28018d36d06a61  shared/certs/client.pem
c935a710ecafd2a0c598da914ac46997  shared/certs/server.pem
vagrant@database:~$

Seems those are normal messages when you run mongod without --fork
Try to login to mongo

Please check this link

HW 2.6 EOF occurred in violation of protocol (_ssl.c:1822)

OK, I see. (mine is 1826 not 1822)

I does not look like a “NICE START”, but I guess this is the way it is.

Thanks anyway for the help.