Issue after updating meteor: laika hangs and requires to clear mongod's data files every time

[VasilySizov]

Like stopped working after Meteor update from 0.7.0.1 to 0.7.2 (the same problems with 0.8.0).

This is the log from "laika -V" for 0.7.0.1 project:

vasilysizov@ubuntu:~/projects/test$ sudo laika -V
[laika log] accepting the following extensions: (js|coffee)

  injecting laika...
  loading phantomjs...
[app touch log] [[[[[ ~/projects/test ]]]]]

  loading initial app pool...
[app touch log] => Meteor server running on: http://localhost:25797/
[laika log] using nodejs bin(from meteor): /home/vasilysizov/.meteor/tools/09b63f1ed5/bin/node
[laika log] using nodejs bin(from meteor): /home/vasilysizov/.meteor/tools/09b63f1ed5/bin/node
[server log] laika code injected and listening on: 18700
[server log] LISTENING
[laika log] adding compiler module: coffee-script
[laika log] adding test file: /home/vasilysizov/projects/test/tests/$setup.coffee
[laika log] adding test file: /home/vasilysizov/projects/test/tests/test.coffee
1..1
[server log] laika code injected and listening on: 17740
[server log] LISTENING
[laika log] start running test
[laika log] using nodejs bin(from meteor): /home/vasilysizov/.meteor/tools/09b63f1ed5/bin/node
[laika log] running test
[laika log] test completed
[laika log] closing app
ok 1 Score calculation should check joining and leaving project
- tests 1
- pass 1
- fail 0
  cleaning up injected code

...and this one from "laika -V" for the same project updated to 0.7.2:

vasilysizov@ubuntu:~/projects/test$ sudo laika -V
[laika log] accepting the following extensions: (js|coffee)

  injecting laika...
  loading phantomjs...
[app touch log] [[[[[ ~/projects/test ]]]]]

=> Started proxy.
[app touch log] I20140405-15:38:46.607(4)? laika code injected and listening on: 11024
[app touch log] => Started your app.
[app touch log] 
=> App running at: http://localhost:11965/
[app touch log] => Meteor 0.8.0 is available. Update this project with 'meteor update'.

So, it just hangs!

I have a feeling that the problem is with the DB.
Mongod's log shows nothing:

vasilysizov@ubuntu:~/projects/test$ mongod --smallfiles --noprealloc --nojournal --dbpath ./etc/testmongo --nohttpinterface
note: noprealloc may hurt performance in many applications
Sat Apr  5 15:51:44 [initandlisten] MongoDB starting : pid=20632 port=27017 dbpath=./etc/testmongo 64-bit host=ubuntu
Sat Apr  5 15:51:44 [initandlisten] db version v2.0.4, pdfile version 4.5
Sat Apr  5 15:51:44 [initandlisten] git version: nogitversion
Sat Apr  5 15:51:44 [initandlisten] build info: Linux lamiak 2.6.42-37-generic #58-Ubuntu SMP Thu Jan 24 15:28:10 UTC 2013 x86_64 BOOST_LIB_VERSION=1_46_1
Sat Apr  5 15:51:44 [initandlisten] options: { dbpath: "./etc/testmongo", nohttpinterface: true, nojournal: true, noprealloc: true, smallfiles: true }
Sat Apr  5 15:51:44 [initandlisten] waiting for connections on port 27017
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32957 #1
Sat Apr  5 15:51:50 [conn1] end connection 127.0.0.1:32957
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32958 #2
Sat Apr  5 15:51:50 [conn2] end connection 127.0.0.1:32958
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32959 #3
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32960 #4
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32961 #5
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32962 #6
Sat Apr  5 15:51:50 [initandlisten] connection accepted from 127.0.0.1:32963 #7
Sat Apr  5 15:51:50 [conn3] end connection 127.0.0.1:32959
Sat Apr  5 15:51:50 [conn4] end connection 127.0.0.1:32960
Sat Apr  5 15:51:50 [conn6] end connection 127.0.0.1:32962
Sat Apr  5 15:51:50 [conn5] end connection 127.0.0.1:32961
Sat Apr  5 15:51:50 [conn7] end connection 127.0.0.1:32963
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32967 #8
Sat Apr  5 15:51:52 [conn8] end connection 127.0.0.1:32967
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32968 #9
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32969 #10
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32970 #11
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32971 #12
Sat Apr  5 15:51:52 [initandlisten] connection accepted from 127.0.0.1:32972 #13

(hangs here)

I have tried to restart mongod, but it didn't help.
But when I clear mongod's files (rm * in mongod data directory) and then run "laika -V" everything works fine, like in the previous example. Next time I run application, it also hangs, so I need to clear the files every time I run laika.

This is the log of DB for successful run:

vasilysizov@ubuntu:~/projects/test$ mongod --smallfiles --noprealloc --nojournal --dbpath ./etc/testmongo --nohttpinterface
note: noprealloc may hurt performance in many applications
Sat Apr  5 15:53:53 [initandlisten] MongoDB starting : pid=20756 port=27017 dbpath=./etc/testmongo 64-bit host=ubuntu
Sat Apr  5 15:53:53 [initandlisten] db version v2.0.4, pdfile version 4.5
Sat Apr  5 15:53:53 [initandlisten] git version: nogitversion
Sat Apr  5 15:53:53 [initandlisten] build info: Linux lamiak 2.6.42-37-generic #58-Ubuntu SMP Thu Jan 24 15:28:10 UTC 2013 x86_64 BOOST_LIB_VERSION=1_46_1
Sat Apr  5 15:53:53 [initandlisten] options: { dbpath: "./etc/testmongo", nohttpinterface: true, nojournal: true, noprealloc: true, smallfiles: true }
Sat Apr  5 15:53:53 [initandlisten] waiting for connections on port 27017
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:32995 #1
Sat Apr  5 15:54:00 [conn1] end connection 127.0.0.1:32995
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:32996 #2
Sat Apr  5 15:54:00 [conn2] end connection 127.0.0.1:32996
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:32997 #3
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:32998 #4
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:32999 #5
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:33000 #6
Sat Apr  5 15:54:00 [initandlisten] connection accepted from 127.0.0.1:33001 #7
Sat Apr  5 15:54:00 [conn3] end connection 127.0.0.1:32997
Sat Apr  5 15:54:00 [conn4] end connection 127.0.0.1:32998
Sat Apr  5 15:54:00 [conn5] end connection 127.0.0.1:32999
Sat Apr  5 15:54:00 [conn6] end connection 127.0.0.1:33000
Sat Apr  5 15:54:00 [conn7] end connection 127.0.0.1:33001
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33005 #8
Sat Apr  5 15:54:01 [conn8] end connection 127.0.0.1:33005
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33006 #9
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33007 #10
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33008 #11
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33009 #12
Sat Apr  5 15:54:01 [initandlisten] connection accepted from 127.0.0.1:33010 #13
Sat Apr  5 15:54:01 [FileAllocator] allocating new datafile ./etc/testmongo/_laika.ns, filling with zeroes...
Sat Apr  5 15:54:01 [FileAllocator] creating directory ./etc/testmongo/_tmp
Sat Apr  5 15:54:01 [FileAllocator] done allocating datafile ./etc/testmongo/_laika.ns, size: 16MB,  took 0 secs
Sat Apr  5 15:54:01 [FileAllocator] allocating new datafile ./etc/testmongo/_laika.0, filling with zeroes...
Sat Apr  5 15:54:01 [FileAllocator] done allocating datafile ./etc/testmongo/_laika.0, size: 16MB,  took 0.001 secs
Sat Apr  5 15:54:01 [conn11] build index _laika.users { _id: 1 }
Sat Apr  5 15:54:01 [conn11] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn11] info: creating collection _laika.users on add index
Sat Apr  5 15:54:01 [conn11] build index _laika.users { username: 1 }
Sat Apr  5 15:54:01 [conn11] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn13] build index _laika.users { emails.address: 1 }
Sat Apr  5 15:54:01 [conn13] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn10] build index _laika.users { services.resume.loginTokens.hashedToken: 1 }
Sat Apr  5 15:54:01 [conn10] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn12] build index _laika.users { services.resume.loginTokens.token: 1 }
Sat Apr  5 15:54:01 [conn12] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn9] build index _laika.users { services.resume.haveLoginTokensToDelete: 1 }
Sat Apr  5 15:54:01 [conn9] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn11] build index _laika.users { services.resume.loginTokens.when: 1 }
Sat Apr  5 15:54:01 [conn11] build index done 0 records 0 secs
Sat Apr  5 15:54:01 [conn9] end connection 127.0.0.1:33006
Sat Apr  5 15:54:01 [conn10] end connection 127.0.0.1:33007
Sat Apr  5 15:54:01 [conn11] end connection 127.0.0.1:33008
Sat Apr  5 15:54:01 [conn12] end connection 127.0.0.1:33009
Sat Apr  5 15:54:01 [conn13] end connection 127.0.0.1:33010
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33011 #14
Sat Apr  5 15:54:02 [conn14] end connection 127.0.0.1:33011
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33012 #15
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33013 #16
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33014 #17
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33015 #18
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33016 #19
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33017 #20
Sat Apr  5 15:54:02 [conn20] end connection 127.0.0.1:33017
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33018 #21
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33019 #22
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33020 #23
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33021 #24
Sat Apr  5 15:54:02 [initandlisten] connection accepted from 127.0.0.1:33022 #25
Sat Apr  5 15:54:02 [FileAllocator] allocating new datafile ./etc/testmongo/laika-P0N0F45ww1.ns, filling with zeroes...
Sat Apr  5 15:54:02 [FileAllocator] done allocating datafile ./etc/testmongo/laika-P0N0F45ww1.ns, size: 16MB,  took 0.002 secs
Sat Apr  5 15:54:02 [FileAllocator] allocating new datafile ./etc/testmongo/laika-P0N0F45ww1.0, filling with zeroes...
Sat Apr  5 15:54:02 [FileAllocator] done allocating datafile ./etc/testmongo/laika-P0N0F45ww1.0, size: 16MB,  took 0.001 secs
Sat Apr  5 15:54:02 [conn23] build index laika-P0N0F45ww1.users { _id: 1 }
Sat Apr  5 15:54:02 [conn23] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn23] info: creating collection laika-P0N0F45ww1.users on add index
Sat Apr  5 15:54:02 [conn23] build index laika-P0N0F45ww1.users { username: 1 }
Sat Apr  5 15:54:02 [conn23] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn25] build index laika-P0N0F45ww1.users { emails.address: 1 }
Sat Apr  5 15:54:02 [conn25] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn22] build index laika-P0N0F45ww1.users { services.resume.loginTokens.hashedToken: 1 }
Sat Apr  5 15:54:02 [conn22] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn24] build index laika-P0N0F45ww1.users { services.resume.loginTokens.token: 1 }
Sat Apr  5 15:54:02 [conn24] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn21] build index laika-P0N0F45ww1.users { services.resume.haveLoginTokensToDelete: 1 }
Sat Apr  5 15:54:02 [conn21] build index done 0 records 0 secs
Sat Apr  5 15:54:02 [conn23] build index laika-P0N0F45ww1.users { services.resume.loginTokens.when: 1 }
Sat Apr  5 15:54:02 [conn23] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33023 #26
Sat Apr  5 15:54:03 [conn26] end connection 127.0.0.1:33023
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33024 #27
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33025 #28
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33026 #29
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33027 #30
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33028 #31
Sat Apr  5 15:54:03 [FileAllocator] allocating new datafile ./etc/testmongo/laika-Y8OA3i25EH.ns, filling with zeroes...
Sat Apr  5 15:54:03 [FileAllocator] done allocating datafile ./etc/testmongo/laika-Y8OA3i25EH.ns, size: 16MB,  took 0.001 secs
Sat Apr  5 15:54:03 [FileAllocator] allocating new datafile ./etc/testmongo/laika-Y8OA3i25EH.0, filling with zeroes...
Sat Apr  5 15:54:03 [FileAllocator] done allocating datafile ./etc/testmongo/laika-Y8OA3i25EH.0, size: 16MB,  took 0.001 secs
Sat Apr  5 15:54:03 [conn29] build index laika-Y8OA3i25EH.users { _id: 1 }
Sat Apr  5 15:54:03 [conn29] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn29] info: creating collection laika-Y8OA3i25EH.users on add index
Sat Apr  5 15:54:03 [conn29] build index laika-Y8OA3i25EH.users { username: 1 }
Sat Apr  5 15:54:03 [conn29] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn31] build index laika-Y8OA3i25EH.users { emails.address: 1 }
Sat Apr  5 15:54:03 [conn31] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn28] build index laika-Y8OA3i25EH.users { services.resume.loginTokens.hashedToken: 1 }
Sat Apr  5 15:54:03 [conn28] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn30] build index laika-Y8OA3i25EH.users { services.resume.loginTokens.token: 1 }
Sat Apr  5 15:54:03 [conn30] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn27] build index laika-Y8OA3i25EH.users { services.resume.haveLoginTokensToDelete: 1 }
Sat Apr  5 15:54:03 [conn27] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn29] build index laika-Y8OA3i25EH.users { services.resume.loginTokens.when: 1 }
Sat Apr  5 15:54:03 [conn29] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [conn25] build index laika-P0N0F45ww1.projectUserResults { _id: 1 }
Sat Apr  5 15:54:03 [conn25] build index done 0 records 0 secs
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33036 #32
Sat Apr  5 15:54:03 [conn32] end connection 127.0.0.1:33036
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33038 #33
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33039 #34
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33040 #35
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33041 #36
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33042 #37
Sat Apr  5 15:54:03 [conn34] dropDatabase laika-P0N0F45ww1
Sat Apr  5 15:54:03 [conn33] end connection 127.0.0.1:33038
Sat Apr  5 15:54:03 [conn35] end connection 127.0.0.1:33040
Sat Apr  5 15:54:03 [conn34] end connection 127.0.0.1:33039
Sat Apr  5 15:54:03 [conn36] end connection 127.0.0.1:33041
Sat Apr  5 15:54:03 [conn37] end connection 127.0.0.1:33042
Sat Apr  5 15:54:03 [conn27] end connection 127.0.0.1:33024
Sat Apr  5 15:54:03 [conn28] end connection 127.0.0.1:33025
Sat Apr  5 15:54:03 [conn29] end connection 127.0.0.1:33026
Sat Apr  5 15:54:03 [conn30] end connection 127.0.0.1:33027
Sat Apr  5 15:54:03 [conn31] end connection 127.0.0.1:33028
Sat Apr  5 15:54:03 [conn21] end connection 127.0.0.1:33018
Sat Apr  5 15:54:03 [conn22] end connection 127.0.0.1:33019
Sat Apr  5 15:54:03 [conn23] end connection 127.0.0.1:33020
Sat Apr  5 15:54:03 [conn24] end connection 127.0.0.1:33021
Sat Apr  5 15:54:03 [conn25] end connection 127.0.0.1:33022
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33043 #38
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33044 #39
Sat Apr  5 15:54:03 [conn38] end connection 127.0.0.1:33043
Sat Apr  5 15:54:03 [conn39] end connection 127.0.0.1:33044
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33045 #40
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33046 #41
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33047 #42
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33048 #43
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33049 #44
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33050 #45
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33051 #46
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33052 #47
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33053 #48
Sat Apr  5 15:54:03 [initandlisten] connection accepted from 127.0.0.1:33054 #49
Sat Apr  5 15:54:03 [conn42] dropDatabase laika-Y8OA3i25EH
Sat Apr  5 15:54:03 [conn43] dropDatabase laika-2Sv1KbJm53
Sat Apr  5 15:54:03 [conn40] end connection 127.0.0.1:33045
Sat Apr  5 15:54:03 [conn42] end connection 127.0.0.1:33047
Sat Apr  5 15:54:03 [conn44] end connection 127.0.0.1:33049
Sat Apr  5 15:54:03 [conn46] end connection 127.0.0.1:33051
Sat Apr  5 15:54:03 [conn48] end connection 127.0.0.1:33053
Sat Apr  5 15:54:03 [conn41] end connection 127.0.0.1:33046
Sat Apr  5 15:54:03 [conn43] end connection 127.0.0.1:33048
Sat Apr  5 15:54:03 [conn45] end connection 127.0.0.1:33050
Sat Apr  5 15:54:03 [conn47] end connection 127.0.0.1:33052
Sat Apr  5 15:54:03 [conn49] end connection 127.0.0.1:33054
Sat Apr  5 15:54:11 [conn16] end connection 127.0.0.1:33013

[pawelos88]

It's the same for me - I have to clear mongodb working directory after each test run.

[nickmccurdy]

@VasilySizov If possible, please edit your post and surround the log info with ``` to make a markdown code block. It seems like a bunch of issues were accidentally tagged because of the line numbers.