search

fkie-cad / FACT_docker

Dockerfile for building the FACT container
GNU General Public License v3.0
23 stars 9 forks source link

Container fails to start due to mongodb error #17

Closed frakman1 closed 2 years ago

frakman1 commented 3 years ago

I had a previously working FACT docker container. I tried re-installing the "dtb finder" plugin today by going to /opt/FACT_core/src folder and running ./install.py -B I then restarted the FACT container but got this error:

2021-11-30 13:39:53][init_database][INFO]: Trying to start Mongo Server and initializing users...
[2021-11-30 13:39:53][MongoMgr][INFO]: Starting local mongo database
[2021-11-30 13:39:53][MongoMgr][INFO]: Starting DB: mongod --config /opt/FACT_core/src/config/mongod.conf --fork --logpath /tmp/fact_mongo.log
[2021-11-30 13:39:55][MongoMgr][INFO]: Creating users for MongoDB authentication
[2021-11-30 13:39:55][MongoMgr][ERROR]: The DB seems to be running with authentication. Try terminating the MongoDB process.
[2021-11-30 13:39:55][MongoMgr][ERROR]: Could not create users:
User "fact_admin@admin" already exists, full error: {'ok': 0.0, 'errmsg': 'User "fact_admin@admin" already exists', 'code': 11000, 'codeName': 'DuplicateKey'}
[2021-11-30 13:39:55][MongoMgr][INFO]: Stopping local mongo database
[2021-11-30 13:39:55][start_all_installed_fact_components][INFO]: starting db
[2021-11-30 13:39:56][MongoMgr][INFO]: Starting local mongo database
[2021-11-30 13:39:56][MongoMgr][INFO]: Starting DB: mongod --auth --config /opt/FACT_core/src/config/mongod.conf --fork --logpath /tmp/fact_mongo.log
Traceback (most recent call last):
  File "/opt/FACT_core/src/../start_fact_db", line 44, in <module>
    FactDb().main()
  File "/opt/FACT_core/src/../start_fact_db", line 36, in __init__
    super().__init__()
  File "/opt/FACT_core/src/fact_base.py", line 31, in __init__
    self.work_load_stat = WorkLoadStatistic(config=self.config, component=self.COMPONENT)
  File "/opt/FACT_core/src/statistic/work_load.py", line 21, in __init__
    self.db = StatisticDbUpdater(config=self.config)
  File "/opt/FACT_core/src/storage/db_interface_statistic.py", line 15, in __init__
    super().__init__(config=config)
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 25, in __init__
    self._authenticate()
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 40, in _authenticate
    self.client.admin.authenticate(user, pw, mechanism='SCRAM-SHA-1')
  File "/usr/local/lib/python3.8/dist-packages/pymongo/collection.py", line 2579, in __call__
    raise TypeError("'Collection' object is not callable. If you "
TypeError: 'Collection' object is not callable. If you meant to call the 'authenticate' method on a 'Database' object it is failing because no such method exists.
[2021-11-30 13:39:57][start_all_installed_fact_components][INFO]: starting frontend
[2021-11-30 13:39:57][start_all_installed_fact_components][INFO]: starting backend
Traceback (most recent call last):
  File "/opt/FACT_core/src/../start_fact_frontend", line 83, in <module>
    FactFrontend().main()
  File "/opt/FACT_core/src/../start_fact_frontend", line 62, in __init__
    super().__init__()
  File "/opt/FACT_core/src/fact_base.py", line 31, in __init__
    self.work_load_stat = WorkLoadStatistic(config=self.config, component=self.COMPONENT)
  File "/opt/FACT_core/src/statistic/work_load.py", line 21, in __init__
    self.db = StatisticDbUpdater(config=self.config)
  File "/opt/FACT_core/src/storage/db_interface_statistic.py", line 15, in __init__
    super().__init__(config=config)
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 25, in __init__
    self._authenticate()
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 40, in _authenticate
    self.client.admin.authenticate(user, pw, mechanism='SCRAM-SHA-1')
  File "/usr/local/lib/python3.8/dist-packages/pymongo/collection.py", line 2579, in __call__
    raise TypeError("'Collection' object is not callable. If you "
TypeError: 'Collection' object is not callable. If you meant to call the 'authenticate' method on a 'Database' object it is failing because no such method exists.
Traceback (most recent call last):
  File "/opt/FACT_core/src/../start_fact_backend", line 91, in <module>
    FactBackend().main()
  File "/opt/FACT_core/src/../start_fact_backend", line 39, in __init__
    super().__init__()
  File "/opt/FACT_core/src/fact_base.py", line 31, in __init__
    self.work_load_stat = WorkLoadStatistic(config=self.config, component=self.COMPONENT)
  File "/opt/FACT_core/src/statistic/work_load.py", line 21, in __init__
    self.db = StatisticDbUpdater(config=self.config)
  File "/opt/FACT_core/src/storage/db_interface_statistic.py", line 15, in __init__
    super().__init__(config=config)
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 25, in __init__
    self._authenticate()
  File "/opt/FACT_core/src/storage/mongo_interface.py", line 40, in _authenticate
    self.client.admin.authenticate(user, pw, mechanism='SCRAM-SHA-1')
  File "/usr/local/lib/python3.8/dist-packages/pymongo/collection.py", line 2579, in __call__
    raise TypeError("'Collection' object is not callable. If you "
TypeError: 'Collection' object is not callable. If you meant to call the 'authenticate' method on a 'Database' object it is failing because no such method exists.
[2021-11-30 13:39:59][start_all_installed_fact_components][CRITICAL]: Backend did not start. Shutting down...

I tried touching /media/data/fact_wt_mongodb/REINITIALIZE_DB and restarting but that didn't help.

I found the monogodb log file:

$ cat fact_mongo.log
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] MongoDB starting : pid=59 port=27018 dbpath=/media/data/fact_wt_mongodb 64-bit host=Kubuntu18
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] db version v3.6.8
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1f  31 Mar 2020
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] modules: none
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] build environment:
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten]     distarch: x86_64
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2021-11-30T13:39:56.146+0000 I CONTROL  [initandlisten] options: { config: "/opt/FACT_core/src/config/mongod.conf", net: { bindIp: "127.0.0.1", port: 27018 }, processManagement: { fork: true }, security: { authorization: "enabled" }, storage: { dbPath: "/media/data/fact_wt_mongodb", engine: "wiredTiger", journal: { enabled: true } }, systemLog: { destination: "file", path: "/tmp/fact_mongo.log" } }
2021-11-30T13:39:56.147+0000 I STORAGE  [initandlisten]
2021-11-30T13:39:56.147+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2021-11-30T13:39:56.147+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2021-11-30T13:39:56.147+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=7732M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),cache_cursors=false,compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
2021-11-30T13:39:57.066+0000 I STORAGE  [initandlisten] WiredTiger message [1638279597:66316][59:0x7f270dce6ac0], txn-recover: Main recovery loop: starting at 283/5888
2021-11-30T13:39:57.221+0000 I STORAGE  [initandlisten] WiredTiger message [1638279597:221094][59:0x7f270dce6ac0], txn-recover: Recovering log 283 through 284
2021-11-30T13:39:57.324+0000 I STORAGE  [initandlisten] WiredTiger message [1638279597:324739][59:0x7f270dce6ac0], txn-recover: Recovering log 284 through 284
2021-11-30T13:39:57.400+0000 I STORAGE  [initandlisten] WiredTiger message [1638279597:400714][59:0x7f270dce6ac0], txn-recover: Set global recovery timestamp: 0
2021-11-30T13:39:57.680+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/media/data/fact_wt_mongodb/diagnostic.data'
2021-11-30T13:39:57.703+0000 I NETWORK  [initandlisten] waiting for connections on port 27018
2021-11-30T13:39:58.042+0000 I FTDC     [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
jstucke commented 3 years ago

This error is caused by an incompatibility with the newest version of pymongo that was recently released. It already fixed in FACT_core (https://github.com/fkie-cad/FACT_core/pull/708). If you don't want to rebuild the docker container you could simply exec into it and run python3 -m pip install pymongo<4 to install a compatible version.

frakman1 commented 3 years ago

Thank you. Unfortunately, the container exits soon after it is launched due to this error so I can't exec into it. How do you recommend preventing it from exiting/failing long enough to run the pip installation?

jstucke commented 3 years ago

There seem to be ("hacky") solutions to this: https://stackoverflow.com/questions/32353055/how-to-start-a-stopped-docker-container-with-a-different-command

Maybe it would make sense to restart the container or rebuild the image, though.