[SERVER-10195] mongos abrupt early exit in auth.js on OS X 10.5 64-bit DUR OFF Created: 12/Jul/13  Updated: 10/Dec/14  Resolved: 26/Jul/13

Status: Closed
Project: Core Server
Component/s: Testing Infrastructure
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Matt Kangas Assignee: Andy Schwerin
Resolution: Done Votes: 0
Labels: buildbot
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OS X 10.5 64-bit DUR OFF Build #2444


Operating System: ALL
Participants:

 Description   

Andy, does this smell logging-related to you? mongos starts at 14:51:05.768, exits suddenly at 14:51:05.789.

OS X 10.5 64-bit DUR OFF Build #2444

http://buildbot.mongodb.org/builders/OS%20X%2010.5%2064-bit%20DUR%20OFF/builds/2444/steps/test_11/logs/stdio
http://buildlogs.mongodb.org/OS%20X%2010.5%2064-bit%20DUR%20OFF/builds/2444/test/sharding/auth.js

Fri Jul 12 14:51:05.767 No db started on port: 31000
Fri Jul 12 14:51:05.767 shell: stopped mongo program on port 31000
Fri Jul 12 14:51:05.768 shell: started program /data/buildslaves/OS_X_105_64bit_DUR_OFF/mongo/mongos --port 31000 -vv --configdb bs-osx-106-x86-64-3.10gen.cc:29000 --keyFile jstests/libs/key1 --chunkSize 1 --setParameter enableTestCommands=1
 m31000| Fri Jul 12 14:51:05.776 warning: running with 1 config server should be done only for testing purposes and is not recommended for production
 m31000| Fri Jul 12 14:51:05.776 kern.sched unavailable
 m31000| Fri Jul 12 14:51:05.776 security key: foopdedoop
 m31000| Fri Jul 12 14:51:05.776 [mongosMain] MongoS version 2.5.1-pre- starting: pid=40811 port=31000 64-bit host=bs-osx-106-x86-64-3.10gen.cc (--help for usage)
 m31000| Fri Jul 12 14:51:05.776 [mongosMain] git version: 42b8033f86de1e51283118bf00c0f13493536109
 m31000| Fri Jul 12 14:51:05.776 [mongosMain] build info: Darwin bs-osx-106-x86-64-3.10gen.cc 10.8.0 Darwin Kernel Version 10.8.0: Tue Jun  7 16:32:41 PDT 2011; root:xnu-1504.15.3~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49
 m31000| Fri Jul 12 14:51:05.776 [mongosMain] options: { chunkSize: 1, configdb: "bs-osx-106-x86-64-3.10gen.cc:29000", keyFile: "jstests/libs/key1", port: 31000, setParameter: [ "enableTestCommands=1" ], vv: true }
 m31000| Fri Jul 12 14:51:05.778 [mongosMain]  config string : bs-osx-106-x86-64-3.10gen.cc:29000
 m31000| Fri Jul 12 14:51:05.778 [mongosMain] creating new connection to:bs-osx-106-x86-64-3.10gen.cc:29000
 m31000| Fri Jul 12 14:51:05.779 BackgroundJob starting: ConnectBG
 m31000| Fri Jul 12 14:51:05.779 [mongosMain] connected connection!
 m31000| Fri Jul 12 14:51:05.779 [mongosMain] calling onCreate auth for bs-osx-106-x86-64-3.10gen.cc:29000
 m29000| Fri Jul 12 14:51:05.779 [initandlisten] connection accepted from 208.52.185.85:52471 #7 (6 connections now open)
 m29000| Fri Jul 12 14:51:05.780 [conn7]  authenticate db: local { authenticate: 1, nonce: "1dcc79a6cf09a2b5", user: "__system", key: "ad1396bd7c2378a8ea76627a218c9d15" }
 m31000| Fri Jul 12 14:51:05.782 creating new connection to:bs-osx-106-x86-64-3.10gen.cc:29000
 m31000| Fri Jul 12 14:51:05.783 [mongosMain] MaxChunkSize: 1
 m31000| Fri Jul 12 14:51:05.783 BackgroundJob starting: ConnectBG
 m31000| Fri Jul 12 14:51:05.783 connected connection!
 m31000| Fri Jul 12 14:51:05.783 BackgroundJob starting: Balancer
 m31000| Fri Jul 12 14:51:05.783 [Balancer] about to contact config servers and shards
 m31000| Fri Jul 12 14:51:05.783 BackgroundJob starting: cursorTimeout
 m29000| Fri Jul 12 14:51:05.783 [initandlisten] connection accepted from 208.52.185.85:52472 #8 (7 connections now open)
 m31000| Fri Jul 12 14:51:05.783 [mongosMain] fd limit hard:10240 soft:10240 max conn: 8192
 m31000| Fri Jul 12 14:51:05.783 BackgroundJob starting: PeriodicTask::Runner
 m31000| Fri Jul 12 14:51:05.783 [Balancer] config servers and shards contacted successfully
 m31000| Fri Jul 12 14:51:05.783 [Balancer] balancer id: bs-osx-106-x86-64-3.10gen.cc:31000 started at Jul 12 14:51:05
 m31000| Fri Jul 12 14:51:05.783 [Balancer] created new distributed lock for balancer on bs-osx-106-x86-64-3.10gen.cc:29000 ( lock timeout : 900000, ping interval : 30000, process : 0 )
 m31000| Fri Jul 12 14:51:05.783 [mongosMain] waiting for connections on port 31000
 m31000| Fri Jul 12 14:51:05.784 [Balancer] creating new connection to:bs-osx-106-x86-64-3.10gen.cc:29000
 m31000| Fri Jul 12 14:51:05.785 BackgroundJob starting: ConnectBG
 m29000| Fri Jul 12 14:51:05.785 [initandlisten] connection accepted from 208.52.185.85:52473 #9 (8 connections now open)
 m31000| Fri Jul 12 14:51:05.785 [Balancer] connected connection!
 m31000| Fri Jul 12 14:51:05.785 [Balancer] calling onCreate auth for bs-osx-106-x86-64-3.10gen.cc:29000
 m29000| Fri Jul 12 14:51:05.785 [conn9]  authenticate db: local { authenticate: 1, nonce: "8ffca542ac4e0d85", user: "__system", key: "b6447055b4c932c8a3ac6675e4d41b77" }
 m31000| Fri Jul 12 14:51:05.785 [Balancer] Refreshing MaxChunkSize: 1
 m31000| Fri Jul 12 14:51:05.785 [Balancer] creating new connection to:bs-osx-106-x86-64-3.10gen.cc:29000
 m31000| Fri Jul 12 14:51:05.786 BackgroundJob starting: ConnectBG
 m31000| Fri Jul 12 14:51:05.786 [Balancer] connected connection!
 m29000| Fri Jul 12 14:51:05.786 [initandlisten] connection accepted from 208.52.185.85:52474 #10 (9 connections now open)
 m31000| Fri Jul 12 14:51:05.786 [Balancer] calling onCreate auth for bs-osx-106-x86-64-3.10gen.cc:29000
 m29000| Fri Jul 12 14:51:05.787 [conn10]  authenticate db: local { authenticate: 1, nonce: "bdc18cf22d073413", user: "__system", key: "c5280771c55d2ef154433c1b9adecb58" }
 m31000| Fri Jul 12 14:51:05.787 [Balancer] skew from remote server bs-osx-106-x86-64-3.10gen.cc:29000 found: 0
 m31000| Fri Jul 12 14:51:05.787 [Balancer] skew from remote server bs-osx-106-x86-64-3.10gen.cc:29000 found: 0
 m31000| Fri Jul 12 14:51:05.787 [Balancer] skew from remote server bs-osx-106-x86-64-3.10gen.cc:29000 found: 0
 m31000| Fri Jul 12 14:51:05.787 [Balancer] total clock skew of 0ms for servers bs-osx-106-x86-64-3.10gen.cc:29000 is in 30000ms bounds.
 m31000| Fri Jul 12 14:51:05.787 [Balancer] trying to acquire new distributed lock for balancer on bs-osx-106-x86-64-3.10gen.cc:29000 ( lock timeout : 900000, ping interval : 30000, process : bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807 )
 m31000| Fri Jul 12 14:51:05.787 [LockPinger] creating distributed lock ping thread for bs-osx-106-x86-64-3.10gen.cc:29000 and process bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807 (sleeping for 30000ms)
 m31000| Fri Jul 12 14:51:05.788 [Balancer] about to acquire distributed lock 'balancer/bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807:
 m31000| { "state" : 1,
 m31000|   "who" : "bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807:Balancer:282475249",
 m31000|   "process" : "bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807",
 m31000|   "when" : { "$date" : "Fri Jul 12 14:51:05 2013" },
 m31000|   "why" : "doing balance round",
 m31000|   "ts" : { "$oid" : "51e050193525900ac2392802" } }
 m31000| { "_id" : "balancer",
 m31000|   "state" : 0,
 m31000|   "ts" : { "$oid" : "51e05019dc76b97af6cd733a" } }
 m31000| Fri Jul 12 14:51:05.789 [LockPinger] cluster bs-osx-106-x86-64-3.10gen.cc:29000 pinged successfully at Fri Jul 12 14:51:05 2013 by distributed lock pinger 'bs-osx-106-x86-64-3.10gen.cc:29000/bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807', sleeping for 30000ms
 m31000| Fri Jul 12 14:51:05.789 [Balancer] distributed lock 'balancer/bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807' acquired, ts : 51e050193525900ac2392802
 m31000| Fri Jul 12 14:51:05.789 [Balancer] *** start balancing round
 m31000| Fri Jul 12 14:51:05.789 [Balancer] waitForDelete: 0
 m31000| Fri Jul 12 14:51:05.789 [Balancer] secondaryThrottle: 1
 m31000| Fri Jul 12 14:51:05.789 [Balancer] no collections to balance
 m31000| Fri Jul 12 14:51:05.789 [Balancer] no need to move any chunk
 m31000| Fri Jul 12 14:51:05.789 [Balancer] *** end of balancing round
 m31000| Fri Jul 12 14:51:05.789 [Balancer] distributed lock 'balancer/bs-osx-106-x86-64-3.10gen.cc:31000:1373655065:16807' unlocked. 
 m29000| Fri Jul 12 14:51:05.800 [conn9] end connection 208.52.185.85:52473 (8 connections now open)
 m29000| Fri Jul 12 14:51:05.800 [conn10] end connection 208.52.185.85:52474 (8 connections now open)
 m29000| Fri Jul 12 14:51:05.800 [conn7] end connection 208.52.185.85:52471 (8 connections now open)
 m29000| Fri Jul 12 14:51:05.800 [conn8] end connection 208.52.185.85:52472 (8 connections now open)
 m29000| Fri Jul 12 14:51:05.890 [FileAllocator] done allocating datafile /data/db/auth1-config0/admin.1, size: 32MB,  took 0.134 secs
Could not start mongo program at 31000, process ended
Fri Jul 12 14:51:05.972 TypeError: Cannot call method 'getDB' of null at src/mongo/shell/shardingtest.js:430
failed to load: /data/buildslaves/OS_X_105_64bit_DUR_OFF/mongo/jstests/sharding/auth.js



 Comments   
Comment by Matt Kangas [ 26/Jul/13 ]

Seems to be resolved. Hasn't recurred within the last two weeks.

Generated at Thu Feb 08 03:22:32 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.