[SERVER-11236] jstests/logprocessdetails.js occasionally failing via passthrough Created: 17/Oct/13  Updated: 11/Jul/16  Resolved: 25/Oct/13

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

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

Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

Two examples seen thus far. I suspect the test is racy because it's trying to examine log output.

Nightly Linux RHEL 64-bit Build #714
Test : dur_passthrough.js
http://buildlogs.mongodb.org/Nightly%20Linux%20RHEL%2064-bit/builds/714/test/recent%20failures/dur_passthrough.js

 *******************************************
         Test : jstests/logprocessdetails.js ...
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] pid=2649 port=30200 64-bit host=bs-rhel-57-64-2
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] db version v2.5.3-pre-
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] git version: d908b872604852be119317fd6b2d63e6149d023d
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] 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
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] allocator: tcmalloc
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] options: { dbpath: "/data/db/dur_passthrough", dur: true, durOptions: 8, nopreallocj: true, port: 30200, setParameter: [ "enableTestCommands=1" ], smallfiles: true }
 m30200| 2013-10-17T00:28:12.534-0400 [conn1] command admin.$cmd command: { logRotate: 1.0 } ntoreturn:1 keyUpdates:0  reslen:37 135ms
assert: [null] != [null] are equal : undefined
Error: Printing Stack Trace
    at printStackTrace (src/mongo/shell/utils.js:38:15)
    at doassert (src/mongo/shell/assert.js:6:5)
    at Function.assert.neq (src/mongo/shell/assert.js:108:5)
    at doTest (jstests/logprocessdetails.js:22:12)
    at jstests/logprocessdetails.js:25:1
    at /data/buildslaves/Linux_RHEL_64bit_Nightly/mongo/jstests/dur/dur_passthrough.js:35:68
    at Function.Date.timeFunc (src/mongo/shell/types.js:27:17)
    at /data/buildslaves/Linux_RHEL_64bit_Nightly/mongo/jstests/dur/dur_passthrough.js:35:45
    at Array.forEach (native)
    at doTest (/data/buildslaves/Linux_RHEL_64bit_Nightly/mongo/jstests/dur/dur_passthrough.js:18:11)
2013-10-17T00:28:12.537-0400 [null] != [null] are equal : undefined at src/mongo/shell/assert.js:7
2013-10-17T00:28:12.538-0400 Error: error loading js file: jstests/logprocessdetails.js at /data/buildslaves/Linux_RHEL_64bit_Nightly/mongo/jstests/dur/dur_passthrough.js:35
failed to load: /data/buildslaves/Linux_RHEL_64bit_Nightly/mongo/jstests/dur/dur_passthrough.js


Nightly Solaris-SmartOS 64-bit Build #562
Test : parallel/basic.js
http://buildlogs.mongodb.org/Nightly%20Solaris-SmartOS%2064-bit/builds/562/test/parallel/basic.js

         S3 Test : jstests/logprocessdetails.js ...
2013-10-17T11:27:56.436+0000 [FileAllocator] allocating new datafile /data/db/sconsTests/admin.0, filling with zeroes...
2013-10-17T11:27:56.436+0000 [FileAllocator] done allocating datafile /data/db/sconsTests/admin.0, size: 64MB,  took 0 secs
2013-10-17T11:27:56.437+0000 [conn30] pid=26765 port=27999 64-bit host=bs-smartos-x86-64-1.10gen.cc
2013-10-17T11:27:56.437+0000 [conn30] db version v2.5.3-pre-
2013-10-17T11:27:56.437+0000 [conn30] git version: d908b872604852be119317fd6b2d63e6149d023d
2013-10-17T11:27:56.437+0000 [conn30] build info: SunOS bs-smartos-x86-64-1.10gen.cc 5.11 joyent_20130322T181205Z i86pc BOOST_LIB_VERSION=1_49
2013-10-17T11:27:56.437+0000 [conn30] allocator: system
2013-10-17T11:27:56.437+0000 [conn30] options: { dbpath: "/data/db/sconsTests/", httpinterface: true, port: 27999, setParameter: [ "enableTestCommands=1" ] }
2013-10-17T11:27:56.437+0000 [conn29] build index on: admin.system.users properties: { "v" : 1, "key" : { "user" : 1, "db" : 1 }, "unique" : true, "ns" : "admin.system.users", "name" : "user_1_db_1" }
2013-10-17T11:27:56.438+0000 [conn29] have free list for admin.$freelist
2013-10-17T11:27:56.439+0000 [conn29] build index done.  scanned 0 total records. 0.002 secs
2013-10-17T11:27:56.439+0000 [conn29] build index on: admin.system.users properties: { "v" : 1, "key" : { "_id" : 1 }, "ns" : "admin.system.users", "name" : "_id_" }
assert: [null] != [null] are equal : undefined
Error: Printing Stack Trace
    at printStackTrace (src/mongo/shell/utils.js:38:15)
    at doassert (src/mongo/shell/assert.js:6:5)
    at Function.assert.neq (src/mongo/shell/assert.js:108:5)
    at doTest (jstests/logprocessdetails.js:22:12)
    at jstests/logprocessdetails.js:25:1
    at <anonymous>:7:61
    at Function.Date.timeFunc (src/mongo/shell/types.js:27:17)
    at <anonymous>:7:38
    at Array.forEach (native)
    at Number.__parallelTests__fun (<anonymous>:4:14)
********** Parallel Test FAILED: Error: error loading js file: jstests/logprocessdetails.js



 Comments   
Comment by auto [ 25/Oct/13 ]

Author:

{u'username': u'3rf', u'name': u'Kyle Erf', u'email': u'erf@mongodb.com'}

Message: SERVER-11236 changed logprocessdetails.js to check entire log
Branch: master
https://github.com/mongodb/mongo/commit/cc54c2a1a85a4943ac818ad5310660082a1966b7

Comment by Eric Milkie [ 17/Oct/13 ]

Right, if there is something else running at the same time that causes a lot of logging, it will flush out the thing that logprocessdetails.js is looking for.

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