You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/11/08 03:55:22 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2538
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2538/changes>
Changes:
[vinodkone] Added slave metrics for total and used resources.
[toenshoff] Fixed invalid characters in external-containerizer.md
------------------------------------------
[...truncated 64936 lines...]
I1108 02:53:19.338738 25885 slave.cpp:1556] Shutting down framework 20141108-025319-3125920579-41701-25865-0000
I1108 02:53:19.338789 25885 slave.cpp:3005] Cleaning up executor 'default' of framework 20141108-025319-3125920579-41701-25865-0000
I1108 02:53:19.339010 25885 slave.cpp:3082] Cleaning up framework 20141108-025319-3125920579-41701-25865-0000
I1108 02:53:19.339022 25886 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_ic7Pmh/slaves/20141108-025319-3125920579-41701-25865-S0/frameworks/20141108-025319-3125920579-41701-25865-0000/executors/default/runs/277c214d-20f1-4603-84a7-dc0d4c8003f8' for gc 6.99999607806815days in the future
I1108 02:53:19.339112 25889 status_update_manager.cpp:279] Closing status update streams for framework 20141108-025319-3125920579-41701-25865-0000
I1108 02:53:19.339190 25889 status_update_manager.cpp:525] Cleaning up status update stream for task 1 of framework 20141108-025319-3125920579-41701-25865-0000
I1108 02:53:19.339259 25886 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_ic7Pmh/slaves/20141108-025319-3125920579-41701-25865-S0/frameworks/20141108-025319-3125920579-41701-25865-0000/executors/default' for gc 6.99999607682667days in the future
I1108 02:53:19.339406 25886 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_ic7Pmh/slaves/20141108-025319-3125920579-41701-25865-S0/frameworks/20141108-025319-3125920579-41701-25865-0000' for gc 6.99999607552days in the future
[ OK ] SchedulerTest.TaskRunning (95 ms)
[----------] 1 test from SchedulerTest (95 ms total)
[----------] 3 tests from GarbageCollectorTest
[ RUN ] GarbageCollectorTest.Unschedule
Using temporary directory '/tmp/GarbageCollectorTest_Unschedule_N4q1Wq'
I1108 02:53:19.342380 25886 gc.cpp:84] Unscheduling 'bogus' from gc
I1108 02:53:19.342840 25888 gc.cpp:56] Scheduling 'file1' for gc 10secs in the future
I1108 02:53:19.342973 25888 gc.cpp:56] Scheduling 'file2' for gc 10secs in the future
I1108 02:53:19.343062 25888 gc.cpp:56] Scheduling 'file3' for gc 10secs in the future
I1108 02:53:19.343144 25888 gc.cpp:84] Unscheduling 'file2' from gc
I1108 02:53:19.353092 25891 gc.cpp:84] Unscheduling 'file3' from gc
I1108 02:53:19.363229 25883 gc.cpp:84] Unscheduling 'file1' from gc
I1108 02:53:19.374130 25891 gc.cpp:155] Ignoring gc event at 0ns as the paths were already removed, or were unscheduled
[ OK ] GarbageCollectorTest.Unschedule (72 ms)
[ RUN ] GarbageCollectorTest.Schedule
Using temporary directory '/tmp/GarbageCollectorTest_Schedule_4L5TIA'
I1108 02:53:19.414825 25881 gc.cpp:56] Scheduling 'file1' for gc 10secs in the future
I1108 02:53:19.414985 25881 gc.cpp:56] Scheduling 'file2' for gc 10secs in the future
I1108 02:53:19.415099 25881 gc.cpp:56] Scheduling 'file3' for gc 15secs in the future
I1108 02:53:19.455865 25884 gc.cpp:134] Deleting file1
I1108 02:53:19.455934 25884 gc.cpp:143] Deleted 'file1'
I1108 02:53:19.455965 25884 gc.cpp:134] Deleting file2
I1108 02:53:19.455997 25884 gc.cpp:143] Deleted 'file2'
I1108 02:53:19.486083 25888 gc.cpp:134] Deleting file3
I1108 02:53:19.486142 25888 gc.cpp:143] Deleted 'file3'
[ OK ] GarbageCollectorTest.Schedule (92 ms)
[ RUN ] GarbageCollectorTest.Prune
Using temporary directory '/tmp/GarbageCollectorTest_Prune_3GCKJK'
I1108 02:53:19.506672 25879 gc.cpp:56] Scheduling 'file1' for gc 10secs in the future
I1108 02:53:19.506801 25879 gc.cpp:56] Scheduling 'file2' for gc 10secs in the future
I1108 02:53:19.506908 25879 gc.cpp:56] Scheduling 'file3' for gc 15secs in the future
I1108 02:53:19.506994 25879 gc.cpp:56] Scheduling 'file4' for gc 15secs in the future
I1108 02:53:19.507074 25879 gc.cpp:84] Unscheduling 'file3' from gc
I1108 02:53:19.527171 25883 gc.cpp:167] Pruning directories with remaining removal time 10secs
I1108 02:53:19.527248 25883 gc.cpp:134] Deleting file1
I1108 02:53:19.527297 25883 gc.cpp:143] Deleted 'file1'
I1108 02:53:19.527323 25883 gc.cpp:134] Deleting file2
I1108 02:53:19.527354 25883 gc.cpp:143] Deleted 'file2'
I1108 02:53:19.547471 25885 gc.cpp:167] Pruning directories with remaining removal time 15secs
I1108 02:53:19.547575 25885 gc.cpp:134] Deleting file4
I1108 02:53:19.547633 25885 gc.cpp:143] Deleted 'file4'
[ OK ] GarbageCollectorTest.Prune (51 ms)
[----------] 3 tests from GarbageCollectorTest (215 ms total)
[----------] 4 tests from ReplicaTest
[ RUN ] ReplicaTest.Restore
Using temporary directory '/tmp/ReplicaTest_Restore_EONZSU'
I1108 02:53:19.561199 25865 leveldb.cpp:176] Opened db in 3.022731ms
I1108 02:53:19.562335 25865 leveldb.cpp:183] Compacted db in 1.101381ms
I1108 02:53:19.562388 25865 leveldb.cpp:198] Created db iterator in 16575ns
I1108 02:53:19.562407 25865 leveldb.cpp:204] Seeked to beginning of db in 1715ns
I1108 02:53:19.562418 25865 leveldb.cpp:273] Iterated through 0 keys in the db in 350ns
I1108 02:53:19.562450 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.563913 25893 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 678983ns
I1108 02:53:19.563946 25893 replica.cpp:320] Persisted replica status to VOTING
I1108 02:53:19.567039 25865 leveldb.cpp:176] Opened db in 2.586217ms
I1108 02:53:19.570047 25865 leveldb.cpp:183] Compacted db in 2.981007ms
I1108 02:53:19.570101 25865 leveldb.cpp:198] Created db iterator in 17495ns
I1108 02:53:19.570138 25865 leveldb.cpp:204] Seeked to beginning of db in 18131ns
I1108 02:53:19.570178 25865 leveldb.cpp:273] Iterated through 1 keys in the db in 23652ns
I1108 02:53:19.570210 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.570590 25883 replica.cpp:474] Replica received implicit promise request with proposal 1
I1108 02:53:19.571100 25883 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 474548ns
I1108 02:53:19.571128 25883 replica.cpp:342] Persisted promised to 1
I1108 02:53:19.572089 25881 replica.cpp:508] Replica received write request for position 1
I1108 02:53:19.572466 25881 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 341006ns
I1108 02:53:19.572497 25881 replica.cpp:676] Persisted action at 1
I1108 02:53:19.573211 25890 leveldb.cpp:438] Reading position from leveldb took 44471ns
I1108 02:53:19.576428 25865 leveldb.cpp:176] Opened db in 2.748406ms
I1108 02:53:19.578843 25865 leveldb.cpp:183] Compacted db in 2.389796ms
I1108 02:53:19.578884 25865 leveldb.cpp:198] Created db iterator in 14030ns
I1108 02:53:19.578913 25865 leveldb.cpp:204] Seeked to beginning of db in 14269ns
I1108 02:53:19.578974 25865 leveldb.cpp:273] Iterated through 2 keys in the db in 48373ns
I1108 02:53:19.579025 25865 replica.cpp:741] Replica recovered with log positions 0 -> 1 with 1 holes and 1 unlearned
I1108 02:53:19.579277 25891 leveldb.cpp:438] Reading position from leveldb took 64762ns
[ OK ] ReplicaTest.Restore (23 ms)
[ RUN ] ReplicaTest.NonVoting
Using temporary directory '/tmp/ReplicaTest_NonVoting_HBBW54'
I1108 02:53:19.583242 25865 leveldb.cpp:176] Opened db in 2.32999ms
I1108 02:53:19.584153 25865 leveldb.cpp:183] Compacted db in 884498ns
I1108 02:53:19.584195 25865 leveldb.cpp:198] Created db iterator in 13305ns
I1108 02:53:19.584214 25865 leveldb.cpp:204] Seeked to beginning of db in 1613ns
I1108 02:53:19.584224 25865 leveldb.cpp:273] Iterated through 0 keys in the db in 200ns
I1108 02:53:19.584254 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.584689 25886 replica.cpp:369] Replica ignoring promise request as it is in EMPTY status
I1108 02:53:19.594954 25891 replica.cpp:503] Replica ignoring write request as it is in EMPTY status
[ OK ] ReplicaTest.NonVoting (25 ms)
[ RUN ] ReplicaTest.Append
Using temporary directory '/tmp/ReplicaTest_Append_MCNSmf'
I1108 02:53:19.607792 25865 leveldb.cpp:176] Opened db in 2.336045ms
I1108 02:53:19.608794 25865 leveldb.cpp:183] Compacted db in 969194ns
I1108 02:53:19.608839 25865 leveldb.cpp:198] Created db iterator in 13904ns
I1108 02:53:19.608858 25865 leveldb.cpp:204] Seeked to beginning of db in 1595ns
I1108 02:53:19.608868 25865 leveldb.cpp:273] Iterated through 0 keys in the db in 218ns
I1108 02:53:19.608897 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.610112 25887 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 687241ns
I1108 02:53:19.610142 25887 replica.cpp:320] Persisted replica status to VOTING
I1108 02:53:19.612984 25865 leveldb.cpp:176] Opened db in 2.199748ms
I1108 02:53:19.615424 25865 leveldb.cpp:183] Compacted db in 2.405398ms
I1108 02:53:19.615478 25865 leveldb.cpp:198] Created db iterator in 17612ns
I1108 02:53:19.615543 25865 leveldb.cpp:204] Seeked to beginning of db in 44681ns
I1108 02:53:19.615583 25865 leveldb.cpp:273] Iterated through 1 keys in the db in 21434ns
I1108 02:53:19.615618 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.615994 25894 replica.cpp:474] Replica received implicit promise request with proposal 1
I1108 02:53:19.616709 25894 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 683561ns
I1108 02:53:19.616739 25894 replica.cpp:342] Persisted promised to 1
I1108 02:53:19.617465 25884 replica.cpp:508] Replica received write request for position 1
I1108 02:53:19.617905 25884 leveldb.cpp:343] Persisting action (27 bytes) to leveldb took 404951ns
I1108 02:53:19.617936 25884 replica.cpp:676] Persisted action at 1
I1108 02:53:19.618535 25894 leveldb.cpp:438] Reading position from leveldb took 34622ns
[ OK ] ReplicaTest.Append (14 ms)
[ RUN ] ReplicaTest.Promise
Using temporary directory '/tmp/ReplicaTest_Promise_HGsbGp'
I1108 02:53:19.622789 25865 leveldb.cpp:176] Opened db in 2.749878ms
I1108 02:53:19.623788 25865 leveldb.cpp:183] Compacted db in 966944ns
I1108 02:53:19.623831 25865 leveldb.cpp:198] Created db iterator in 13339ns
I1108 02:53:19.623849 25865 leveldb.cpp:204] Seeked to beginning of db in 1639ns
I1108 02:53:19.623859 25865 leveldb.cpp:273] Iterated through 0 keys in the db in 200ns
I1108 02:53:19.623889 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.625113 25886 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 745294ns
I1108 02:53:19.625144 25886 replica.cpp:320] Persisted replica status to VOTING
I1108 02:53:19.627836 25865 leveldb.cpp:176] Opened db in 2.13511ms
I1108 02:53:19.630780 25865 leveldb.cpp:183] Compacted db in 2.910206ms
I1108 02:53:19.630833 25865 leveldb.cpp:198] Created db iterator in 17732ns
I1108 02:53:19.630870 25865 leveldb.cpp:204] Seeked to beginning of db in 17494ns
I1108 02:53:19.630905 25865 leveldb.cpp:273] Iterated through 1 keys in the db in 20797ns
I1108 02:53:19.630939 25865 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1108 02:53:19.631296 25894 replica.cpp:474] Replica received implicit promise request with proposal 2
I1108 02:53:19.632073 25894 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 747684ns
I1108 02:53:19.632099 25894 replica.cpp:342] Persisted promised to 2
I1108 02:53:19.632877 25889 replica.cpp:474] Replica received implicit promise request with proposal 1
I1108 02:53:19.632904 25889 replica.cpp:479] Replica denying promise request with proposal 1
I1108 02:53:19.633469 25890 replica.cpp:474] Replica received implicit promise request with proposal 3
I1108 02:53:19.634016 25890 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 513702ns
I1108 02:53:19.634045 25890 replica.cpp:342] Persisted promised to 3
[ OK ] ReplicaTest.Promise (16 ms)
[----------] 4 tests from ReplicaTest (78 ms total)
[----------] 6 tests from FilesTest
[ RUN ] FilesTest.BrowseTest
Using temporary directory '/tmp/FilesTest_BrowseTest_049W1z'
I1108 02:53:19.637013 25879 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/browse.json'
I1108 02:53:19.640193 25888 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/browse.json'
I1108 02:53:19.643056 25885 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/browse.json'
I1108 02:53:19.645869 25884 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/browse.json'
Shutting down
Sending SIGTERM to process tree at pid 30347
I1108 02:53:19.647814 25883 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/browse.json'
[ OK ] FilesTest.BrowseTest (14 ms)
[ RUN ] FilesTest.ReadTest
Using temporary directory '/tmp/FilesTest_ReadTest_X2u5pK'
I1108 02:53:19.650080 25891 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.651950 25887 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Shutting down
Sending SIGTERM to process tree at pid 30348
I1108 02:53:19.653877 25885 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Shutting down
Sending SIGTERM to process tree at pid 30349
I1108 02:53:19.656651 25884 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.659047 25889 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Shutting down
Sending SIGTERM to process tree at pid 30367
I1108 02:53:19.661238 25884 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
[ OK ] FilesTest.ReadTest (13 ms)
[ RUN ] FilesTest.ResolveTest
Using temporary directory '/tmp/FilesTest_ResolveTest_IeAmQU'
I1108 02:53:19.665184 25883 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.667208 25881 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.668906 25888 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.670418 25892 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.671985 25891 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Killing the following process trees:
[
]
I1108 02:53:19.673606 25887 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
I1108 02:53:19.675093 25887 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Shutting down
Sending SIGTERM to process tree at pid 30368
I1108 02:53:19.676839 25894 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Killing the following process trees:
[
]
I1108 02:53:19.678535 25891 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Killing the following process trees:
[
]
I1108 02:53:19.680181 25881 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/read.json'
Killing the following process trees:
[
]
[ OK ] FilesTest.ResolveTest (19 ms)
[ RUN ] FilesTest.DownloadTest
Using temporary directory '/tmp/FilesTest_DownloadTest_JQwKj5'
I1108 02:53:19.683179 25893 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/download.json'
I1108 02:53:19.683640 25888 process.cpp:1822] Sending file at '/tmp/FilesTest_DownloadTest_JQwKj5/binary' with length 17
I1108 02:53:19.685248 25889 process.cpp:3358] Handling HTTP event for process 'files' with path: '/files/download.json'
I1108 02:53:19.685708 25882 process.cpp:1822] Sending file at '/tmp/FilesTest_DownloadTest_JQwKj5/black.gif' with length 42
[ OK ] FilesTest.DownloadTest (6 ms)
[ RUN ] FilesTest.DetachTest
Using temporary directory '/tmp/FilesTest_DetachTest_0uuXNf'
[ OK ] FilesTest.DetachTest (0 ms)
[ RUN ] FilesTest.AttachTest
Using temporary directory '/tmp/FilesTest_AttachTest_WXiiiq'
[ OK ] FilesTest.AttachTest (3 ms)
[----------] 6 tests from FilesTest (55 ms total)
[----------] 1 test from PerfTest
[ RUN ] PerfTest.Parse
W1108 02:53:19.691162 25865 perf.cpp:374] Unsupported perf counter, ignoring: <not supported>,cycles
[ OK ] PerfTest.Parse (1 ms)
[----------] 1 test from PerfTest (1 ms total)
[----------] Global test environment tear-down
Killing the following process trees:
[
]
[==========] 414 tests from 64 test cases ran. (259267 ms total)
[ PASSED ] 413 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MesosContainerizerExecuteTest.IoRedirection
1 FAILED TEST
YOU HAVE 5 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2540
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2540/changes>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2539
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2539/changes>
Changes:
[benjamin.hindman] Abstracted out invoking 'mesos-fetcher'.
------------------------------------------
[...truncated 51158 lines...]
I1108 04:44:52.405315 28639 replica.cpp:676] Persisted action at 0
I1108 04:44:52.405799 28629 replica.cpp:655] Replica received learned notice for position 0
I1108 04:44:52.406230 28629 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 412560ns
I1108 04:44:52.406249 28629 replica.cpp:676] Persisted action at 0
I1108 04:44:52.406262 28629 replica.cpp:661] Replica learned NOP action at position 0
I1108 04:44:52.406666 28638 log.cpp:672] Writer started with ending position 0
I1108 04:44:52.407613 28634 leveldb.cpp:438] Reading position from leveldb took 22363ns
I1108 04:44:52.409680 28627 registrar.cpp:346] Successfully fetched the registry (0B) in 10.11584ms
I1108 04:44:52.409771 28627 registrar.cpp:445] Applied 1 operations in 15655ns; attempting to update the 'registry'
I1108 04:44:52.411700 28632 log.cpp:680] Attempting to append 143 bytes to the log
I1108 04:44:52.411818 28624 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I1108 04:44:52.412412 28638 replica.cpp:508] Replica received write request for position 1
I1108 04:44:52.412874 28638 leveldb.cpp:343] Persisting action (162 bytes) to leveldb took 438499ns
I1108 04:44:52.412892 28638 replica.cpp:676] Persisted action at 1
I1108 04:44:52.413326 28626 replica.cpp:655] Replica received learned notice for position 1
I1108 04:44:52.413765 28626 leveldb.cpp:343] Persisting action (164 bytes) to leveldb took 419350ns
I1108 04:44:52.413784 28626 replica.cpp:676] Persisted action at 1
I1108 04:44:52.413799 28626 replica.cpp:661] Replica learned APPEND action at position 1
I1108 04:44:52.414469 28636 registrar.cpp:490] Successfully updated the 'registry' in 4.655104ms
I1108 04:44:52.414584 28636 registrar.cpp:376] Successfully recovered registrar
I1108 04:44:52.414657 28627 log.cpp:699] Attempting to truncate the log to 1
I1108 04:44:52.414768 28628 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I1108 04:44:52.414787 28632 master.cpp:1121] Recovered 0 slaves from the Registry (105B) ; allowing 10mins for slaves to re-register
I1108 04:44:52.415380 28639 replica.cpp:508] Replica received write request for position 2
I1108 04:44:52.415827 28639 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 422800ns
I1108 04:44:52.415845 28639 replica.cpp:676] Persisted action at 2
I1108 04:44:52.416314 28635 replica.cpp:655] Replica received learned notice for position 2
I1108 04:44:52.416710 28635 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 377788ns
I1108 04:44:52.416750 28635 leveldb.cpp:401] Deleting ~1 keys from leveldb took 22716ns
I1108 04:44:52.416764 28635 replica.cpp:676] Persisted action at 2
I1108 04:44:52.416779 28635 replica.cpp:661] Replica learned TRUNCATE action at position 2
I1108 04:44:52.428979 28637 slave.cpp:169] Slave started on 179)@67.195.81.189:38578
I1108 04:44:52.429020 28637 credentials.hpp:84] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/credential'
I1108 04:44:52.429195 28637 slave.cpp:276] Slave using credential for: test-principal
I1108 04:44:52.429373 28637 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1108 04:44:52.429440 28637 slave.cpp:318] Slave hostname: proserpina.apache.org
I1108 04:44:52.429451 28637 slave.cpp:319] Slave checkpoint: false
W1108 04:44:52.429457 28637 slave.cpp:321] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag
I1108 04:44:52.430110 28634 state.cpp:33] Recovering state from '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/meta'
I1108 04:44:52.430361 28626 status_update_manager.cpp:197] Recovering status update manager
I1108 04:44:52.430608 28631 slave.cpp:3464] Finished recovery
I1108 04:44:52.430999 28634 status_update_manager.cpp:171] Pausing sending status updates
I1108 04:44:52.431013 28638 slave.cpp:602] New master detected at master@67.195.81.189:38578
I1108 04:44:52.431051 28638 slave.cpp:665] Authenticating with master master@67.195.81.189:38578
I1108 04:44:52.431187 28638 slave.cpp:638] Detecting new master
I1108 04:44:52.431207 28637 authenticatee.hpp:133] Creating new client SASL connection
I1108 04:44:52.431361 28633 master.cpp:3901] Authenticating slave(179)@67.195.81.189:38578
I1108 04:44:52.431391 28633 master.cpp:3912] Using default CRAM-MD5 authenticator
I1108 04:44:52.431519 28635 authenticator.hpp:166] Creating new server SASL connection
I1108 04:44:52.431630 28637 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1108 04:44:52.431650 28637 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1108 04:44:52.431726 28625 authenticator.hpp:272] Received SASL authentication start
I1108 04:44:52.431764 28625 authenticator.hpp:394] Authentication requires more steps
I1108 04:44:52.431841 28637 authenticatee.hpp:270] Received SASL authentication step
I1108 04:44:52.431926 28626 authenticator.hpp:300] Received SASL authentication step
I1108 04:44:52.431948 28626 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1108 04:44:52.431957 28626 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I1108 04:44:52.431987 28626 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1108 04:44:52.432003 28626 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1108 04:44:52.432009 28626 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1108 04:44:52.432015 28626 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1108 04:44:52.432027 28626 authenticator.hpp:386] Authentication success
I1108 04:44:52.432127 28626 authenticatee.hpp:310] Authentication success
I1108 04:44:52.432152 28637 master.cpp:3959] Successfully authenticated principal 'test-principal' at slave(179)@67.195.81.189:38578
I1108 04:44:52.432302 28624 slave.cpp:722] Successfully authenticated with master master@67.195.81.189:38578
I1108 04:44:52.432401 28624 slave.cpp:1050] Will retry registration in 248341ns if necessary
I1108 04:44:52.432543 28632 master.cpp:3068] Registering slave at slave(179)@67.195.81.189:38578 (proserpina.apache.org) with id 20141108-044452-3176252227-38578-28610-S0
I1108 04:44:52.432847 28638 registrar.cpp:445] Applied 1 operations in 42087ns; attempting to update the 'registry'
I1108 04:44:52.433658 28629 slave.cpp:1050] Will retry registration in 26.149965ms if necessary
I1108 04:44:52.433745 28630 master.cpp:3056] Ignoring register slave message from slave(179)@67.195.81.189:38578 (proserpina.apache.org) as admission is already in progress
I1108 04:44:52.434818 28634 log.cpp:680] Attempting to append 324 bytes to the log
I1108 04:44:52.434931 28636 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I1108 04:44:52.435570 28626 replica.cpp:508] Replica received write request for position 3
I1108 04:44:52.435797 28626 leveldb.cpp:343] Persisting action (343 bytes) to leveldb took 204299ns
I1108 04:44:52.435817 28626 replica.cpp:676] Persisted action at 3
I1108 04:44:52.436295 28633 replica.cpp:655] Replica received learned notice for position 3
I1108 04:44:52.436775 28633 leveldb.cpp:343] Persisting action (345 bytes) to leveldb took 461841ns
I1108 04:44:52.436794 28633 replica.cpp:676] Persisted action at 3
I1108 04:44:52.436807 28633 replica.cpp:661] Replica learned APPEND action at position 3
I1108 04:44:52.437563 28628 registrar.cpp:490] Successfully updated the 'registry' in 4.670976ms
I1108 04:44:52.437741 28639 log.cpp:699] Attempting to truncate the log to 3
I1108 04:44:52.437836 28633 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I1108 04:44:52.437952 28635 slave.cpp:2536] Received ping from slave-observer(156)@67.195.81.189:38578
I1108 04:44:52.438035 28624 master.cpp:3122] Registered slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1108 04:44:52.438165 28632 hierarchical_allocator_process.hpp:442] Added slave 20141108-044452-3176252227-38578-28610-S0 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I1108 04:44:52.438233 28635 slave.cpp:756] Registered with master master@67.195.81.189:38578; given slave ID 20141108-044452-3176252227-38578-28610-S0
I1108 04:44:52.438289 28632 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141108-044452-3176252227-38578-28610-S0 in 60692ns
I1108 04:44:52.438371 28634 status_update_manager.cpp:178] Resuming sending status updates
I1108 04:44:52.438556 28626 replica.cpp:508] Replica received write request for position 4
I1108 04:44:52.438941 28626 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 359075ns
I1108 04:44:52.438958 28626 replica.cpp:676] Persisted action at 4
I1108 04:44:52.439426 28634 replica.cpp:655] Replica received learned notice for position 4
I1108 04:44:52.439821 28634 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 372567ns
I1108 04:44:52.439865 28634 leveldb.cpp:401] Deleting ~2 keys from leveldb took 27350ns
I1108 04:44:52.439878 28634 replica.cpp:676] Persisted action at 4
I1108 04:44:52.439893 28634 replica.cpp:661] Replica learned TRUNCATE action at position 4
I1108 04:44:52.442332 28610 sched.cpp:143] Version: 0.22.0
I1108 04:44:52.442729 28638 sched.cpp:239] New master detected at master@67.195.81.189:38578
I1108 04:44:52.442760 28638 sched.cpp:295] Authenticating with master master@67.195.81.189:38578
I1108 04:44:52.442875 28635 authenticatee.hpp:133] Creating new client SASL connection
I1108 04:44:52.443037 28631 master.cpp:3901] Authenticating scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.443075 28631 master.cpp:3912] Using default CRAM-MD5 authenticator
I1108 04:44:52.443200 28630 authenticator.hpp:166] Creating new server SASL connection
I1108 04:44:52.443296 28637 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5
I1108 04:44:52.443320 28637 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5'
I1108 04:44:52.478956 28634 authenticator.hpp:272] Received SASL authentication start
I1108 04:44:52.479027 28634 authenticator.hpp:394] Authentication requires more steps
I1108 04:44:52.479115 28634 authenticatee.hpp:270] Received SASL authentication step
I1108 04:44:52.479207 28626 authenticator.hpp:300] Received SASL authentication step
I1108 04:44:52.479236 28626 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1108 04:44:52.479245 28626 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I1108 04:44:52.479286 28626 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1108 04:44:52.479301 28626 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1108 04:44:52.479308 28626 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1108 04:44:52.479313 28626 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1108 04:44:52.479326 28626 authenticator.hpp:386] Authentication success
I1108 04:44:52.479442 28628 authenticatee.hpp:310] Authentication success
I1108 04:44:52.479465 28634 master.cpp:3959] Successfully authenticated principal 'test-principal' at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.479681 28628 sched.cpp:369] Successfully authenticated with master master@67.195.81.189:38578
I1108 04:44:52.479699 28628 sched.cpp:488] Sending registration request to master@67.195.81.189:38578
I1108 04:44:52.479743 28628 sched.cpp:521] Will retry registration in 55.159075ms if necessary
I1108 04:44:52.479854 28634 master.cpp:1383] Received registration request for framework 'default' at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.479912 28634 master.cpp:1342] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1108 04:44:52.480294 28636 master.cpp:1447] Registering framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.480546 28633 hierarchical_allocator_process.hpp:329] Added framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.480660 28624 sched.cpp:419] Framework registered with 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.480732 28624 sched.cpp:433] Scheduler::registered took 52127ns
I1108 04:44:52.480732 28633 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141108-044452-3176252227-38578-28610-S0 to framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.480999 28633 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 428857ns
I1108 04:44:52.481227 28634 master.cpp:3843] Sending 1 offers to framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.481792 28634 sched.cpp:578] Scheduler::resourceOffers took 301213ns
I1108 04:44:52.482383 28634 master.cpp:2344] Processing reply for offers: [ 20141108-044452-3176252227-38578-28610-O0 ] on slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org) for framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
W1108 04:44:52.482462 28634 master.cpp:1990] Executor default for task 0 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W1108 04:44:52.482486 28634 master.cpp:2001] Executor default for task 0 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I1108 04:44:52.482559 28634 master.cpp:2440] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins'
I1108 04:44:52.483317 28624 master.hpp:877] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20141108-044452-3176252227-38578-28610-S0 (proserpina.apache.org)
I1108 04:44:52.483367 28624 master.cpp:2503] Launching task 0 of framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578 with resources cpus(*):2; mem(*):1024 on slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.483585 28627 slave.cpp:1081] Got assigned task 0 for framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.483785 28633 hierarchical_allocator_process.hpp:563] Recovered disk(*):1024; ports(*):[31000-32000] (total allocatable: disk(*):1024; ports(*):[31000-32000]) on slave 20141108-044452-3176252227-38578-28610-S0 from framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.483829 28633 hierarchical_allocator_process.hpp:599] Framework 20141108-044452-3176252227-38578-28610-0000 filtered slave 20141108-044452-3176252227-38578-28610-S0 for 5secs
I1108 04:44:52.484076 28627 slave.cpp:1191] Launching task 0 for framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.485821 28627 slave.cpp:3995] Launching executor default of framework 20141108-044452-3176252227-38578-28610-0000 in work directory '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default/runs/ae08ba85-19d8-446b-9fc4-8bf976e8d611'
I1108 04:44:52.487684 28627 exec.cpp:132] Version: 0.22.0
I1108 04:44:52.487900 28631 exec.cpp:182] Executor started at: executor(55)@67.195.81.189:38578 with pid 28610
I1108 04:44:52.488025 28627 slave.cpp:1314] Queuing task '0' for executor default of framework '20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.488157 28627 slave.cpp:555] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default/runs/ae08ba85-19d8-446b-9fc4-8bf976e8d611'
I1108 04:44:52.488214 28627 slave.cpp:1858] Got registration for executor 'default' of framework 20141108-044452-3176252227-38578-28610-0000 from executor(55)@67.195.81.189:38578
I1108 04:44:52.488453 28627 slave.cpp:1977] Flushing queued task 0 for executor 'default' of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.488520 28628 exec.cpp:206] Executor registered on slave 20141108-044452-3176252227-38578-28610-S0
I1108 04:44:52.488633 28627 slave.cpp:2838] Monitoring executor 'default' of framework '20141108-044452-3176252227-38578-28610-0000' in container 'ae08ba85-19d8-446b-9fc4-8bf976e8d611'
I1108 04:44:52.489879 28628 exec.cpp:218] Executor::registered took 21994ns
I1108 04:44:52.489994 28628 exec.cpp:293] Executor asked to run task '0'
I1108 04:44:52.490048 28628 exec.cpp:302] Executor::launchTask took 40282ns
I1108 04:44:52.491394 28628 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.491572 28628 slave.cpp:2213] Handling status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 from executor(55)@67.195.81.189:38578
I1108 04:44:52.491776 28627 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.491816 28627 status_update_manager.cpp:494] Creating StatusUpdate stream for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.562410 28627 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to the slave
I1108 04:44:52.562630 28624 slave.cpp:2456] Forwarding the update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to master@67.195.81.189:38578
I1108 04:44:52.562767 28624 slave.cpp:2383] Status update manager successfully handled status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.562793 28624 slave.cpp:2389] Sending acknowledgement for status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to executor(55)@67.195.81.189:38578
I1108 04:44:52.562913 28624 exec.cpp:339] Executor received status update acknowledgement 3ade2736-0d1c-4677-9111-337098ea203c for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.562991 28625 master.cpp:3446] Forwarding status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.563104 28625 master.cpp:3418] Status update TASK_RUNNING (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 from slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.563148 28625 master.cpp:4693] Updating the latest state of task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to TASK_RUNNING
I1108 04:44:52.563230 28626 sched.cpp:669] Scheduler::statusUpdate took 60543ns
I1108 04:44:52.563495 28639 master.cpp:2918] Forwarding status update acknowledgement 3ade2736-0d1c-4677-9111-337098ea203c for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578 to slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.563760 28633 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.563789 28624 slave.cpp:2896] Executor 'default' of framework 20141108-044452-3176252227-38578-28610-0000 exited with status 0
I1108 04:44:52.565389 28624 slave.cpp:2213] Handling status update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 from @0.0.0.0:0
I1108 04:44:52.565448 28624 slave.cpp:4303] Terminating task 0
I1108 04:44:52.565760 28624 slave.cpp:1798] Status update manager successfully handled status update acknowledgement (UUID: 3ade2736-0d1c-4677-9111-337098ea203c) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.565853 28638 master.cpp:3498] Executor default of framework 20141108-044452-3176252227-38578-28610-0000 on slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org) exited with status 0
I1108 04:44:52.565906 28638 master.cpp:4781] Removing executor 'default' with resources of framework 20141108-044452-3176252227-38578-28610-0000 on slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.565949 28633 status_update_manager.cpp:317] Received status update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.566035 28633 status_update_manager.cpp:371] Forwarding update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to the slave
I1108 04:44:52.566228 28639 slave.cpp:2456] Forwarding the update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to master@67.195.81.189:38578
I1108 04:44:52.566367 28639 slave.cpp:2383] Status update manager successfully handled status update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.566431 28634 master.cpp:3446] Forwarding status update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.566530 28634 master.cpp:3418] Status update TASK_LOST (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 from slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.566567 28634 master.cpp:4693] Updating the latest state of task 0 of framework 20141108-044452-3176252227-38578-28610-0000 to TASK_LOST
I1108 04:44:52.566613 28632 sched.cpp:669] Scheduler::statusUpdate took 12467ns
I1108 04:44:52.566766 28636 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20141108-044452-3176252227-38578-28610-S0 from framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.566788 28634 master.cpp:4752] Removing task 0 with resources cpus(*):2; mem(*):1024 of framework 20141108-044452-3176252227-38578-28610-0000 on slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.566894 28634 master.cpp:2918] Forwarding status update acknowledgement fb405646-e4ab-4b6b-b402-18fba84d3ffd for task 0 of framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578 to slave 20141108-044452-3176252227-38578-28610-S0 at slave(179)@67.195.81.189:38578 (proserpina.apache.org)
I1108 04:44:52.567129 28626 status_update_manager.cpp:389] Received status update acknowledgement (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567194 28626 status_update_manager.cpp:525] Cleaning up status update stream for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567356 28624 slave.cpp:1798] Status update manager successfully handled status update acknowledgement (UUID: fb405646-e4ab-4b6b-b402-18fba84d3ffd) for task 0 of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567394 28624 slave.cpp:4342] Completing task 0
I1108 04:44:52.567417 28624 slave.cpp:3005] Cleaning up executor 'default' of framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567570 28633 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default/runs/ae08ba85-19d8-446b-9fc4-8bf976e8d611' for gc 6.99999347810074days in the future
I1108 04:44:52.567687 28624 slave.cpp:3082] Cleaning up framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567723 28633 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default' for gc 6.99999347810074days in the future
I1108 04:44:52.567757 28626 status_update_manager.cpp:279] Closing status update streams for framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.567813 28633 gc.cpp:56] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000' for gc 6.99999347810074days in the future
I1108 04:44:52.685833 28638 master.cpp:126] No whitelist given. Advertising offers for all slaves
I1108 04:44:52.685940 28628 hierarchical_allocator_process.hpp:734] Offering disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20141108-044452-3176252227-38578-28610-S0 to framework 20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.686216 28630 slave.cpp:2536] Received ping from slave-observer(156)@67.195.81.189:38578
I1108 04:44:52.686254 28637 slave.cpp:3235] Framework 20141108-044449-3176252227-38578-28610-0000 seems to have exited. Ignoring registration timeout for executor 'default'
I1108 04:44:52.686316 28628 hierarchical_allocator_process.hpp:659] Performed allocation for 1 slaves in 618551ns
I1108 04:44:52.686383 28637 slave.cpp:3319] Current usage 6.38%. Max allowed age: 5.853397189562581days
I1108 04:44:52.686460 28628 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000/executors/default/runs/d8a65de6-66ea-4bc2-ae33-2c36ad8681d2
I1108 04:44:52.686470 28634 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default/runs/ae08ba85-19d8-446b-9fc4-8bf976e8d611
I1108 04:44:52.686477 28630 slave.cpp:3235] Framework 20141108-044452-3176252227-38578-28610-0000 seems to have exited. Ignoring registration timeout for executor 'default'
I1108 04:44:52.686501 28637 slave.cpp:2611] No pings from master received within 75secs
I1108 04:44:52.686547 28630 slave.cpp:3319] Current usage 6.38%. Max allowed age: 5.853397189562581days
I1108 04:44:52.686605 28628 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000/executors/default/runs/d8a65de6-66ea-4bc2-ae33-2c36ad8681d2'
I1108 04:44:52.686606 28634 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default/runs/ae08ba85-19d8-446b-9fc4-8bf976e8d611'
I1108 04:44:52.686673 28637 slave.cpp:3319] Current usage 6.38%. Max allowed age: 5.853397189562581days
*** Aborted at 1415421892 (unix time) try "date -d @1415421892" if you are using GNU date ***
I1108 04:44:52.686699 28639 master.cpp:3843] Sending 1 offers to framework 20141108-044452-3176252227-38578-28610-0000 (default) at scheduler-8819c4c8-422d-43f3-9835-b9f59cc04eed@67.195.81.189:38578
I1108 04:44:52.686724 28628 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000/executors/default
I1108 04:44:52.686738 28634 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default
PC: @ 0x2b4bb16e12da (unknown)
I1108 04:44:52.687100 28634 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000/executors/default'
I1108 04:44:52.687136 28634 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000
I1108 04:44:52.687180 28628 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000/executors/default'
I1108 04:44:52.687206 28627 sched.cpp:578] Scheduler::resourceOffers took 22796ns
I1108 04:44:52.687214 28628 gc.cpp:134] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000
I1108 04:44:52.687229 28634 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_zbfttx/slaves/20141108-044452-3176252227-38578-28610-S0/frameworks/20141108-044452-3176252227-38578-28610-0000'
I1108 04:44:52.687299 28628 gc.cpp:143] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_3HQIk5/slaves/20141108-044449-3176252227-38578-28610-S0/frameworks/20141108-044449-3176252227-38578-28610-0000'
*** SIGSEGV (@0x0) received by PID 28610 (TID 0x2b4bb5851700) from PID 0; stack trace: ***
@ 0x2b4bb1eb4340 (unknown)
@ 0x2b4bb16e12da (unknown)
@ 0x2b4baf1ff753 process::Process<>::self()
@ 0x2b4baf1fd82c process::dispatch<>()
@ 0x2b4baf1f904c mesos::internal::Files::detach()
@ 0x2b4baf50827f mesos::internal::slave::Slave::detachFile()
@ 0x2b4baf54fcb6 _ZZN7process8dispatchI7NothingN5mesos8internal5slave5SlaveERKSsSsEENS_6FutureIT_EERKNS_3PIDIT0_EEMSC_FS9_T1_ET2_ENKUlPNS_11ProcessBaseEE_clESL_
@ 0x2b4baf574469 _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchI7NothingN5mesos8internal5slave5SlaveERKSsSsEENS0_6FutureIT_EERKNS0_3PIDIT0_EEMSG_FSD_T1_ET2_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
@ 0x2b4bafb72a25 std::function<>::operator()()
@ 0x2b4bafb53ced process::ProcessBase::visit()
@ 0x2b4bafb5e622 process::DispatchEvent::visit()
@ 0x8f4636 process::ProcessBase::serve()
@ 0x2b4bafb4ff62 process::ProcessManager::resume()
@ 0x2b4bafb46627 process::schedule()
@ 0x2b4bb1eac182 start_thread
@ 0x2b4bb21bcfbd (unknown)
make[3]: *** [check-local] Segmentation fault
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results