Details
-
Bug
-
Resolution: Duplicate
-
Major - P3
-
None
-
2.5.2
-
None
-
ALL
Description
A good example from buildbot, where there is 6-second time skew between the logs from the different mongod's:
m31102| 2013-10-16T00:24:45.139-0400 [conn44] end connection 10.12.15.100:55716 (2 connections now open)
|
m31102| 2013-10-16T00:24:45.139-0400 [initandlisten] connection accepted from 10.12.15.100:55742 #46 (3 connections now open)
|
m31102| 2013-10-16T00:24:45.143-0400 [conn45] end connection 10.12.15.100:55717 (2 connections now open)
|
m31102| 2013-10-16T00:24:45.143-0400 [initandlisten] connection accepted from 10.12.15.100:55743 #47 (3 connections now open)
|
m31202| 2013-10-16T00:20:09.346-0400 [initandlisten] db version v2.5.3-pre-
|
m31202| 2013-10-16T00:20:09.346-0400 [initandlisten] git version: 94ce941611abf2fd3826936a90d93b09e483d99c
|
m31202| 2013-10-16T00:20:09.346-0400 [initandlisten] build info: Linux bs-rhel-57-64-2 2.6.18-274.el5xen #1 SMP Fri Jul 8 17:45:44 EDT 2011 x86_64 BOOST_LIB_VERSION=1_49
|
m31202| 2013-10-16T00:20:09.346-0400 [initandlisten] allocator: tcmalloc
|
m31202| 2013-10-16T00:20:09.346-0400 [initandlisten] options: { dbpath: "/data/db/clusteredstale-rs1-2", noprealloc: true, oplogSize: 40, port: 31202, replSet: "clusteredstale-rs1", rest: true, setParameter: [ "enableTestCommands=1" ], smallfiles: true }
|
m31202| 2013-10-16T00:20:09.352-0400 [initandlisten] journal dir=/data/db/clusteredstale-rs1-2/journal
|
m31202| 2013-10-16T00:20:09.352-0400 [initandlisten] recover : no journal files present, no recovery needed
|
m31200| 2013-10-16T00:18:52.339-0400 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
|
m31200| 2013-10-16T00:18:53.343-0400 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
|
m31200| 2013-10-16T00:18:54.347-0400 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
|
m31200| 2013-10-16T00:18:55.350-0400 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
|
m31200| 2013-10-16T00:18:56.354-0400 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
|
and another from MCI:
m29001| 2013-10-16T17:59:57.245+0000 [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:6 0ms
|
m29002| 2013-10-16T18:01:22.093+0000 [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:3 0ms
|
m30999| 2013-10-16T18:05:26.674+0000 [Balancer] trying reconnect to ip-10-149-6-32:29001
|
m29000| 2013-10-16T17:59:49.324+0000 [conn9] command admin.$cmd command: { getlasterror: 1, fsync: 1 } ntoreturn:1 keyUpdates:0 reslen:95 28ms
|
m29001| 2013-10-16T17:59:57.261+0000 [conn9] insert config.changelog ninserted:1 keyUpdates:0 locks(micros) w:226 0ms
|
The essential issue seems to be that the mongod's that the js tests spawn do not flush their stdout buffers in a way that the timestamps across the different mongod's match up. If you look at the logs, it is clear that the time skew occurs between logs from different mongod's (different colors in the logs).
Attachments
Issue Links
- duplicates
-
SERVER-24263 Order of log output across processes started by the mongo shell and resmoke.py depends on thread scheduling
-
- Open
-