-
Type:
Question
-
Resolution: Cannot Reproduce
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: None
-
None
MongoDB server 3.2.x
Mongo java driver 3.4.2
Hostname used for connection: 127.0.0.1. Server is a secondary of a replica set
I am running the fsyncunlock command directly using (new BasicDBObject("fsyncUnlock", 1) to work around issue https://jira.mongodb.org/browse/JAVA-2501. The fsyncUnlock is also being run on the same connection as shown in the logs below
However sometimes I notice that fsyncunlock initiates but does not complete. Traces are below
2017-07-19T00:12:17.309+0000 I ACCESS [conn3540] Successfully authenticated as principal admin on admin
2017-07-19T00:12:17.310+0000 I NETWORK [initandlisten] connection accepted from 127.0.0.1:35222 #3541 (6 connections now open)
2017-07-19T00:12:17.325+0000 I ACCESS [conn3541] Successfully authenticated as principal admin on admin
2017-07-19T00:12:17.325+0000 I COMMAND [conn3541] CMD fsync: sync:1 lock:1
2017-07-19T00:12:27.777+0000 I COMMAND [conn3541] db is now locked, no writes allowed. db.fsyncUnlock() to unlock
2017-07-19T00:12:27.777+0000 I COMMAND [conn3541] For more info see http://dochub.mongodb.org/core/fsynccommand
2017-07-19T00:12:27.779+0000 I COMMAND [conn3541] command admin.$cmd command: fsync
{ fsync: 1, lock: 1 }
keyUpdates:0 writeConflicts:0 numYields:0 reslen:162 locks:{} protocol:op_
query 10454ms
2017-07-19T00:12:59.792+0000 I COMMAND [conn3541] command: unlock requested
2017-07-19T00:12:59.796+0000 I NETWORK [conn3540] end connection 127.0.0.1:35220 (5 connections now open)
2017-07-19T00:12:59.796+0000 I NETWORK [conn3541] end connection 127.0.0.1:35222 (4 connections now open)
2017-07-19T00:14:02.671+0000 I NETWORK [initandlisten] connection accepted from 10.83.16.163:45556 #3542 (5 connections now open)
2017-07-19T00:14:02.685+0000 I ACCESS [conn3542] Successfully authenticated as principal admin on admin
2017-07-19T00:14:02.686+0000 I NETWORK [initandlisten] connection accepted from 10.83.16.163:45558 #3543 (6 connections now open)
2017-07-19T00:14:02.701+0000 I ACCESS [conn3543] Successfully authenticated as principal admin on admin
2017-07-19T00:14:02.760+0000 I NETWORK [initandlisten] connection accepted from 127.0.0.1:35232 #3544 (7 connections now open)
2017-07-19T00:14:02.774+0000 I ACCESS [conn3544] Successfully authenticated as principal admin on admin
2017-07-19T00:14:02.778+0000 I NETWORK [conn3544] end connection 127.0.0.1:35232 (6 connections now open)
2017-07-19T00:14:02.781+0000 I NETWORK [conn3543] end connection 10.83.16.163:45558 (5 connections now open)
2017-07-19T00:14:02.782+0000 I NETWORK [conn3542] end connection 10.83.16.163:45556 (4 connections now open)
2017-07-19T00:14:26.393+0000 I NETWORK [conn3506] end connection 109.173.132.164:64795 (3 connections now open)
2017-07-19T00:15:52.324+0000 I CONTROL [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2017-07-19T00:15:52.324+0000 I FTDC [signalProcessingThread] Shutting down full-time diagnostic data capture
2017-07-19T00:15:52.328+0000 I REPL [signalProcessingThread] Stopping replication applier threads
2017-07-19T00:15:52.378+0000 W EXECUTOR [rsBackgroundSync] killCursors command task failed: CallbackCanceled: Callback canceled
2017-07-19T00:15:52.501+0000 I STORAGE [conn1757] got request after shutdown()
2017-07-19T00:15:53.210+0000 I STORAGE [conn1758] got request after shutdown()
2017-07-19T00:15:54.295+0000 I CONTROL [signalProcessingThread] now exiting
2017-07-19T00:15:54.295+0000 I NETWORK [signalProcessingThread] shutdown: going to close listening sockets...
2017-07-19T00:15:54.295+0000 I NETWORK [signalProcessingThread] closing listening socket: 6
2017-07-19T00:15:54.295+0000 I NETWORK [signalProcessingThread] closing listening socket: 7
2017-07-19T00:15:54.295+0000 I NETWORK [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
2017-07-19T00:15:54.295+0000 I NETWORK [signalProcessingThread] shutdown: going to flush diaglog...