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/04/28 18:00:04 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2095
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2095/>
------------------------------------------
[...truncated 5711 lines...]
I0428 16:00:02.257123 12910 sched.cpp:529] Scheduler::resourceOffers took 223588ns
I0428 16:00:02.257308 12913 master.hpp:596] Removing offer 20140428-160001-453759884-35073-12543-1 with resources disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024 on slave 20140428-160001-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.257372 12913 master.cpp:1806] Processing reply for offers: [ 20140428-160001-453759884-35073-12543-1 ] on slave 20140428-160001-453759884-35073-12543-0 (hemera.apache.org) for framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.257431 12913 master.hpp:558] Adding task 0 with resources cpus(*):2; mem(*):1024 on slave 20140428-160001-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.257462 12913 master.cpp:2919] Launching task 0 of framework 20140428-160001-453759884-35073-12543-0000 with resources cpus(*):2; mem(*):1024 on slave 20140428-160001-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.257585 12913 hierarchical_allocator_process.hpp:547] Framework 20140428-160001-453759884-35073-12543-0000 left disk(*):1024; ports(*):[31000-32000] unused on slave 20140428-160001-453759884-35073-12543-0
I0428 16:00:02.257591 12910 slave.cpp:905] Got assigned task 0 for framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.257652 12913 hierarchical_allocator_process.hpp:590] Framework 20140428-160001-453759884-35073-12543-0000 filtered slave 20140428-160001-453759884-35073-12543-0 for 5secs
I0428 16:00:02.257894 12910 gc.cpp:84] Unscheduling '/tmp/GarbageCollectorIntegrationTest_Unschedule_iXYmV4/slaves/20140428-160001-453759884-35073-12543-0/frameworks/20140428-160001-453759884-35073-12543-0000' from gc
I0428 16:00:02.258018 12915 slave.cpp:1015] Launching task 0 for framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.262248 12915 exec.cpp:131] Version: 0.19.0
I0428 16:00:02.262312 12894 exec.cpp:181] Executor started at: executor(7)@140.211.11.27:35073 with pid 12543
I0428 16:00:02.262390 12915 slave.cpp:1125] Queuing task '0' for executor executor-2 of framework '20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.262464 12915 slave.cpp:486] Successfully attached file '/tmp/GarbageCollectorIntegrationTest_Unschedule_iXYmV4/slaves/20140428-160001-453759884-35073-12543-0/frameworks/20140428-160001-453759884-35073-12543-0000/executors/executor-2/runs/6de316ff-ef68-4a45-8deb-2e6111c81819'
I0428 16:00:02.262505 12915 slave.cpp:1598] Got registration for executor 'executor-2' of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.262624 12915 slave.cpp:1717] Flushing queued task 0 for executor 'executor-2' of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.262696 12914 exec.cpp:205] Executor registered on slave 20140428-160001-453759884-35073-12543-0
I0428 16:00:02.262711 12915 slave.cpp:2282] Monitoring executor 'executor-2' of framework '20140428-160001-453759884-35073-12543-0000' in container '6de316ff-ef68-4a45-8deb-2e6111c81819'
I0428 16:00:02.264513 12914 exec.cpp:217] Executor::registered took 19500ns
I0428 16:00:02.264590 12914 exec.cpp:292] Executor asked to run task '0'
I0428 16:00:02.264657 12914 exec.cpp:301] Executor::launchTask took 49717ns
I0428 16:00:02.266593 12914 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.266716 12909 slave.cpp:1953] Handling status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000 from executor(7)@140.211.11.27:35073
I0428 16:00:02.266849 12914 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.266908 12914 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.266998 12914 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000 to master@140.211.11.27:35073
I0428 16:00:02.267144 12909 slave.cpp:2070] Status update manager successfully handled status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.267170 12909 slave.cpp:2076] Sending acknowledgement for status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000 to executor(7)@140.211.11.27:35073
I0428 16:00:02.267173 12915 master.cpp:2444] Status update TASK_RUNNING (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000 from slave(7)@140.211.11.27:35073
I0428 16:00:02.267256 12915 exec.cpp:338] Executor received status update acknowledgement b35958f7-bbcc-4b96-a94e-58b37363aa5d for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.267273 12910 sched.cpp:620] Scheduler::statusUpdate took 15096ns
I0428 16:00:02.267436 12897 status_update_manager.cpp:398] Received status update acknowledgement (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.267535 12897 slave.cpp:1538] Status update manager successfully handled status update acknowledgement (UUID: b35958f7-bbcc-4b96-a94e-58b37363aa5d) for task 0 of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.286553 12543 master.cpp:551] Master terminating
I0428 16:00:02.286576 12897 sched.cpp:731] Stopping framework '20140428-160001-453759884-35073-12543-0000'
I0428 16:00:02.286619 12543 master.hpp:576] Removing task 0 with resources cpus(*):2; mem(*):1024 on slave 20140428-160001-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.286741 12900 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024; ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave 20140428-160001-453759884-35073-12543-0 from framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.287065 12900 slave.cpp:2151] master@140.211.11.27:35073 exited
W0428 16:00:02.287088 12900 slave.cpp:2154] Master disconnected! Waiting for a new master to be elected
I0428 16:00:02.290055 12543 slave.cpp:414] Slave terminating
I0428 16:00:02.290071 12543 slave.cpp:1309] Asked to shut down framework 20140428-160001-453759884-35073-12543-0000 by @0.0.0.0:0
I0428 16:00:02.290081 12543 slave.cpp:1334] Shutting down framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.290089 12543 slave.cpp:2625] Shutting down executor 'executor-2' of framework 20140428-160001-453759884-35073-12543-0000
I0428 16:00:02.290123 12894 exec.cpp:378] Executor asked to shutdown
I0428 16:00:02.290222 12894 exec.cpp:393] Executor::shutdown took 85585ns
[ OK ] GarbageCollectorIntegrationTest.Unschedule (395 ms)
[----------] 5 tests from GarbageCollectorIntegrationTest (2128 ms total)
[----------] 7 tests from MesosContainerizerProcessTest
[ RUN ] MesosContainerizerProcessTest.NoHadoop
[ OK ] MesosContainerizerProcessTest.NoHadoop (0 ms)
[ RUN ] MesosContainerizerProcessTest.NoUser
[ OK ] MesosContainerizerProcessTest.NoUser (0 ms)
[ RUN ] MesosContainerizerProcessTest.EmptyHadoop
[ OK ] MesosContainerizerProcessTest.EmptyHadoop (0 ms)
[ RUN ] MesosContainerizerProcessTest.NoExtract
[ OK ] MesosContainerizerProcessTest.NoExtract (0 ms)
[ RUN ] MesosContainerizerProcessTest.Simple
[ OK ] MesosContainerizerProcessTest.Simple (0 ms)
[ RUN ] MesosContainerizerProcessTest.NoExtractExecutable
[ OK ] MesosContainerizerProcessTest.NoExtractExecutable (0 ms)
[ RUN ] MesosContainerizerProcessTest.MultipleURIs
[ OK ] MesosContainerizerProcessTest.MultipleURIs (0 ms)
[----------] 7 tests from MesosContainerizerProcessTest (1 ms total)
[----------] 1 test from ExternalContainerizerTest
[ RUN ] ExternalContainerizerTest.Launch
I0428 16:00:02.340895 12543 leveldb.cpp:174] Opened db in 48.172651ms
I0428 16:00:02.357269 12543 leveldb.cpp:181] Compacted db in 16.353102ms
I0428 16:00:02.357292 12543 leveldb.cpp:196] Created db iterator in 4041ns
I0428 16:00:02.357300 12543 leveldb.cpp:202] Seeked to beginning of db in 666ns
I0428 16:00:02.357306 12543 leveldb.cpp:271] Iterated through 0 keys in the db in 301ns
I0428 16:00:02.357319 12543 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0428 16:00:02.357566 12917 recover.cpp:425] Starting replica recovery
I0428 16:00:02.357954 12916 master.cpp:266] Master 20140428-160002-453759884-35073-12543 (hemera.apache.org) started on 140.211.11.27:35073
I0428 16:00:02.357976 12897 recover.cpp:451] Replica is in EMPTY status
I0428 16:00:02.357983 12916 master.cpp:303] Master only allowing authenticated frameworks to register
I0428 16:00:02.358031 12916 master.cpp:308] Master only allowing authenticated slaves to register
I0428 16:00:02.358039 12916 credentials.hpp:35] Loading credentials for authentication
W0428 16:00:02.358146 12916 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_vWFfWy/credentials': No such file or directory
I0428 16:00:02.358522 12914 master.cpp:104] No whitelist given. Advertising offers for all slaves
I0428 16:00:02.358592 12899 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@140.211.11.27:35073
I0428 16:00:02.358732 12902 replica.cpp:626] Replica in EMPTY status received a broadcasted recover request
I0428 16:00:02.358999 12907 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0428 16:00:02.359308 12917 master.cpp:922] The newly elected leader is master@140.211.11.27:35073 with id 20140428-160002-453759884-35073-12543
I0428 16:00:02.359380 12917 master.cpp:932] Elected as the leading master!
I0428 16:00:02.359386 12917 master.cpp:753] Recovering from registrar
I0428 16:00:02.359639 12903 registrar.cpp:275] Recovering registrar
I0428 16:00:02.359868 12896 recover.cpp:542] Updating replica status to STARTING
I0428 16:00:02.373303 12902 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.739312ms
I0428 16:00:02.373324 12902 replica.cpp:320] Persisted replica status to STARTING
I0428 16:00:02.373386 12902 recover.cpp:451] Replica is in STARTING status
I0428 16:00:02.374486 12915 replica.cpp:626] Replica in STARTING status received a broadcasted recover request
I0428 16:00:02.374752 12904 recover.cpp:188] Received a recover response from a replica in STARTING status
I0428 16:00:02.375953 12911 recover.cpp:542] Updating replica status to VOTING
I0428 16:00:02.385390 12911 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 8.63671ms
I0428 16:00:02.385408 12911 replica.cpp:320] Persisted replica status to VOTING
I0428 16:00:02.385468 12911 recover.cpp:556] Successfully joined the Paxos group
I0428 16:00:02.385516 12911 recover.cpp:440] Recover process terminated
I0428 16:00:02.385853 12910 log.cpp:656] Attempting to start the writer
I0428 16:00:02.387519 12910 replica.cpp:474] Replica received implicit promise request with proposal 1
I0428 16:00:02.397522 12910 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 9.973951ms
I0428 16:00:02.397552 12910 replica.cpp:342] Persisted promised to 1
I0428 16:00:02.398980 12905 coordinator.cpp:229] Coordinator attemping to fill missing position
I0428 16:00:02.399971 12906 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0428 16:00:02.409569 12906 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 9.573327ms
I0428 16:00:02.409598 12906 replica.cpp:664] Persisted action at 0
I0428 16:00:02.411128 12899 replica.cpp:508] Replica received write request for position 0
I0428 16:00:02.411152 12899 leveldb.cpp:436] Reading position from leveldb took 11977ns
I0428 16:00:02.421641 12899 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 10.477552ms
I0428 16:00:02.421661 12899 replica.cpp:664] Persisted action at 0
I0428 16:00:02.422251 12915 replica.cpp:643] Replica received learned notice for position 0
I0428 16:00:02.433766 12915 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 11.491455ms
I0428 16:00:02.433797 12915 replica.cpp:664] Persisted action at 0
I0428 16:00:02.433809 12915 replica.cpp:649] Replica learned NOP action at position 0
I0428 16:00:02.434239 12896 log.cpp:672] Writer started with ending position 0
I0428 16:00:02.435423 12895 leveldb.cpp:436] Reading position from leveldb took 9215ns
I0428 16:00:02.437248 12898 registrar.cpp:308] Successfully recovered registrar
I0428 16:00:02.437279 12898 registrar.cpp:379] Attempting to update the 'registry'
I0428 16:00:02.439064 12916 log.cpp:680] Attempting to append 138 bytes to the log
I0428 16:00:02.439527 12915 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1
I0428 16:00:02.441226 12896 replica.cpp:508] Replica received write request for position 1
I0428 16:00:02.449812 12896 leveldb.cpp:341] Persisting action (157 bytes) to leveldb took 8.569294ms
I0428 16:00:02.449832 12896 replica.cpp:664] Persisted action at 1
I0428 16:00:02.450150 12896 replica.cpp:643] Replica received learned notice for position 1
I0428 16:00:02.461909 12896 leveldb.cpp:341] Persisting action (159 bytes) to leveldb took 11.744459ms
I0428 16:00:02.461930 12896 replica.cpp:664] Persisted action at 1
I0428 16:00:02.461937 12896 replica.cpp:649] Replica learned APPEND action at position 1
I0428 16:00:02.462373 12913 registrar.cpp:427] Successfully updated 'registry'
I0428 16:00:02.463577 12909 log.cpp:699] Attempting to truncate the log to 1
I0428 16:00:02.463837 12908 master.cpp:780] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0428 16:00:02.463969 12902 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2
I0428 16:00:02.465935 12901 replica.cpp:508] Replica received write request for position 2
I0428 16:00:02.466832 12916 slave.cpp:140] Slave started on 8)@140.211.11.27:35073
I0428 16:00:02.466850 12916 credentials.hpp:35] Loading credentials for authentication
W0428 16:00:02.467068 12916 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_oPOdv3/credential': No such file or directory
I0428 16:00:02.467150 12916 slave.cpp:231] Slave using credential for: test-principal
I0428 16:00:02.467243 12916 slave.cpp:244] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 16:00:02.467326 12916 slave.cpp:272] Slave hostname: hemera.apache.org
I0428 16:00:02.467339 12916 slave.cpp:273] Slave checkpoint: false
I0428 16:00:02.467818 12906 state.cpp:33] Recovering state from '/tmp/ExternalContainerizerTest_Launch_oPOdv3/meta'
I0428 16:00:02.467993 12911 status_update_manager.cpp:193] Recovering status update manager
I0428 16:00:02.468261 12894 slave.cpp:2943] Finished recovery
I0428 16:00:02.468559 12894 slave.cpp:525] New master detected at master@140.211.11.27:35073
I0428 16:00:02.468585 12894 slave.cpp:585] Authenticating with master master@140.211.11.27:35073
I0428 16:00:02.468615 12894 slave.cpp:558] Detecting new master
I0428 16:00:02.468696 12911 status_update_manager.cpp:167] New master detected at master@140.211.11.27:35073
I0428 16:00:02.468761 12894 authenticatee.hpp:128] Creating new client SASL connection
I0428 16:00:02.468897 12543 sched.cpp:121] Version: 0.19.0
I0428 16:00:02.469069 12905 master.cpp:2795] Authenticating slave(8)@140.211.11.27:35073
I0428 16:00:02.469511 12912 authenticator.hpp:148] Creating new server SASL connection
I0428 16:00:02.469753 12905 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 16:00:02.469826 12905 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 16:00:02.469818 12914 sched.cpp:217] New master detected at master@140.211.11.27:35073
I0428 16:00:02.469882 12914 sched.cpp:268] Authenticating with master master@140.211.11.27:35073
I0428 16:00:02.469969 12913 authenticatee.hpp:128] Creating new client SASL connection
I0428 16:00:02.470269 12910 master.cpp:2795] Authenticating scheduler(7)@140.211.11.27:35073
I0428 16:00:02.470461 12899 authenticator.hpp:254] Received SASL authentication start
I0428 16:00:02.470500 12899 authenticator.hpp:342] Authentication requires more steps
I0428 16:00:02.470641 12908 authenticatee.hpp:265] Received SASL authentication step
I0428 16:00:02.470788 12900 authenticator.hpp:148] Creating new server SASL connection
I0428 16:00:02.471194 12895 authenticator.hpp:282] Received SASL authentication step
I0428 16:00:02.471215 12895 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 16:00:02.471225 12895 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 16:00:02.471233 12895 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 16:00:02.471241 12895 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 16:00:02.471246 12895 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 16:00:02.471249 12895 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 16:00:02.471258 12895 authenticator.hpp:334] Authentication success
I0428 16:00:02.471338 12902 authenticatee.hpp:305] Authentication success
I0428 16:00:02.471674 12898 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 16:00:02.471699 12898 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 16:00:02.471765 12913 slave.cpp:642] Successfully authenticated with master master@140.211.11.27:35073
I0428 16:00:02.471843 12910 authenticator.hpp:254] Received SASL authentication start
I0428 16:00:02.471951 12910 authenticator.hpp:342] Authentication requires more steps
I0428 16:00:02.471951 12913 slave.cpp:871] Will retry registration in 9.60804613secs if necessary
I0428 16:00:02.471982 12909 master.cpp:2835] Successfully authenticated slave(8)@140.211.11.27:35073
I0428 16:00:02.472069 12916 authenticatee.hpp:265] Received SASL authentication step
I0428 16:00:02.472141 12905 authenticator.hpp:282] Received SASL authentication step
I0428 16:00:02.472157 12905 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 16:00:02.472162 12905 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 16:00:02.472167 12905 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 16:00:02.472172 12905 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 16:00:02.472177 12905 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 16:00:02.472179 12905 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 16:00:02.472187 12905 authenticator.hpp:334] Authentication success
I0428 16:00:02.472599 12912 authenticatee.hpp:305] Authentication success
I0428 16:00:02.472636 12909 master.cpp:2835] Successfully authenticated scheduler(7)@140.211.11.27:35073
I0428 16:00:02.472643 12911 registrar.cpp:379] Attempting to update the 'registry'
I0428 16:00:02.472981 12907 sched.cpp:342] Successfully authenticated with master master@140.211.11.27:35073
I0428 16:00:02.473001 12907 sched.cpp:461] Sending registration request to master@140.211.11.27:35073
I0428 16:00:02.473069 12902 master.cpp:981] Received registration request from scheduler(7)@140.211.11.27:35073
I0428 16:00:02.473141 12902 master.cpp:999] Registering framework 20140428-160002-453759884-35073-12543-0000 at scheduler(7)@140.211.11.27:35073
I0428 16:00:02.473228 12897 sched.cpp:392] Framework registered with 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.473322 12900 hierarchical_allocator_process.hpp:332] Added framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.473326 12897 sched.cpp:406] Scheduler::registered took 71326ns
I0428 16:00:02.473358 12900 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0428 16:00:02.473387 12900 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 26812ns
I0428 16:00:02.478169 12901 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 12.218818ms
I0428 16:00:02.478185 12901 replica.cpp:664] Persisted action at 2
I0428 16:00:02.478386 12911 replica.cpp:643] Replica received learned notice for position 2
I0428 16:00:02.490278 12911 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 11.862075ms
I0428 16:00:02.490314 12911 leveldb.cpp:399] Deleting ~1 keys from leveldb took 16337ns
I0428 16:00:02.490324 12911 replica.cpp:664] Persisted action at 2
I0428 16:00:02.490331 12911 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0428 16:00:02.491200 12899 log.cpp:680] Attempting to append 332 bytes to the log
I0428 16:00:02.491495 12906 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0428 16:00:02.492511 12915 replica.cpp:508] Replica received write request for position 3
I0428 16:00:02.502383 12915 leveldb.cpp:341] Persisting action (351 bytes) to leveldb took 9.846269ms
I0428 16:00:02.502414 12915 replica.cpp:664] Persisted action at 3
I0428 16:00:02.502840 12912 replica.cpp:643] Replica received learned notice for position 3
I0428 16:00:02.514464 12912 leveldb.cpp:341] Persisting action (353 bytes) to leveldb took 11.537694ms
I0428 16:00:02.514495 12912 replica.cpp:664] Persisted action at 3
I0428 16:00:02.514507 12912 replica.cpp:649] Replica learned APPEND action at position 3
I0428 16:00:02.514791 12905 registrar.cpp:427] Successfully updated 'registry'
I0428 16:00:02.515210 12896 master.cpp:2169] Admitted slave on hemera.apache.org at slave(8)@140.211.11.27:35073
I0428 16:00:02.515225 12896 master.cpp:3283] Adding slave 20140428-160002-453759884-35073-12543-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 16:00:02.515394 12897 log.cpp:699] Attempting to truncate the log to 3
I0428 16:00:02.515413 12913 slave.cpp:675] Registered with master master@140.211.11.27:35073; given slave ID 20140428-160002-453759884-35073-12543-0
I0428 16:00:02.515547 12896 hierarchical_allocator_process.hpp:445] Added slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0428 16:00:02.515658 12913 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0428 16:00:02.515683 12896 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-160002-453759884-35073-12543-0 to framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.515745 12896 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140428-160002-453759884-35073-12543-0 in 80476ns
I0428 16:00:02.515789 12896 master.hpp:586] Adding offer 20140428-160002-453759884-35073-12543-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.515830 12896 master.cpp:2744] Sending 1 offers to framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.516471 12901 sched.cpp:529] Scheduler::resourceOffers took 382996ns
I0428 16:00:02.517318 12899 master.hpp:596] Removing offer 20140428-160002-453759884-35073-12543-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.517356 12899 master.cpp:1806] Processing reply for offers: [ 20140428-160002-453759884-35073-12543-0 ] on slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org) for framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.517403 12899 master.hpp:558] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.517442 12899 master.cpp:2919] Launching task 1 of framework 20140428-160002-453759884-35073-12543-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-160002-453759884-35073-12543-0 (hemera.apache.org)
I0428 16:00:02.517693 12897 slave.cpp:905] Got assigned task 1 for framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.517957 12897 slave.cpp:1015] Launching task 1 for framework 20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.518523 12902 replica.cpp:508] Replica received write request for position 4
I0428 16:00:02.520025 12897 slave.cpp:1125] Queuing task '1' for executor 1 of framework '20140428-160002-453759884-35073-12543-0000
I0428 16:00:02.520045 12912 external_containerizer.cpp:266] Launching container 'b757cf3d-ab7a-4f78-a177-acc862081bbe'
I0428 16:00:02.520081 12897 slave.cpp:486] Successfully attached file '/tmp/ExternalContainerizerTest_Launch_oPOdv3/slaves/20140428-160002-453759884-35073-12543-0/frameworks/20140428-160002-453759884-35073-12543-0000/executors/1/runs/b757cf3d-ab7a-4f78-a177-acc862081bbe'
I0428 16:00:02.520180 12912 external_containerizer.cpp:804] Invoking external containerizer for method 'launch'
I0428 16:00:02.520216 12912 external_containerizer.cpp:818] user: jenkins
I0428 16:00:02.530993 12902 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 12.432026ms
I0428 16:00:02.531069 12902 replica.cpp:664] Persisted action at 4
make[3]: *** [check-local] Broken pipe
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
I0428 16:00:04.833143 13947 exec.cpp:85] Committing suicide by killing the process group
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2099
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/2099/changes>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2098
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/2098/changes>
Changes:
[niklas] Fixed incorrect invocation of the mesos-executor within test_containerizer.py.
------------------------------------------
[...truncated 24122 lines...]
W0429 03:30:50.537499 28593 slave.cpp:2154] Master disconnected! Waiting for a new master to be elected
I0429 03:30:50.552508 28598 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 17.22174ms
I0429 03:30:50.552538 28598 replica.cpp:664] Persisted action at 8
I0429 03:30:50.552947 28560 slave.cpp:414] Slave terminating
I0429 03:30:50.553570 28598 slave.cpp:414] Slave terminating
I0429 03:30:50.554628 28560 slave.cpp:414] Slave terminating
I0429 03:30:50.554940 28595 slave.cpp:414] Slave terminating
I0429 03:30:50.555789 28560 slave.cpp:414] Slave terminating
[ OK ] ReservationAllocatorTest.ReservedResources (433 ms)
[----------] 2 tests from ReservationAllocatorTest (861 ms total)
[----------] 3 tests from SASL
[ RUN ] SASL.failed2
I0429 03:30:50.558298 28597 authenticatee.hpp:128] Creating new client SASL connection
I0429 03:30:50.559202 28597 authenticator.hpp:148] Creating new server SASL connection
I0429 03:30:50.559531 28588 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0429 03:30:50.559552 28588 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0429 03:30:50.559819 28593 authenticator.hpp:254] Received SASL authentication start
I0429 03:30:50.559895 28593 authenticator.hpp:342] Authentication requires more steps
I0429 03:30:50.560009 28591 authenticatee.hpp:265] Received SASL authentication step
I0429 03:30:50.560118 28591 authenticator.hpp:282] Received SASL authentication step
I0429 03:30:50.560138 28591 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0429 03:30:50.560148 28591 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0429 03:30:50.560155 28591 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0429 03:30:50.560163 28591 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0429 03:30:50.560170 28591 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.560176 28591 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
W0429 03:30:50.560190 28591 authenticator.hpp:348] Authentication failure: user not found
[ OK ] SASL.failed2 (3 ms)
[ RUN ] SASL.success
I0429 03:30:50.561733 28592 authenticatee.hpp:128] Creating new client SASL connection
I0429 03:30:50.562535 28599 authenticator.hpp:148] Creating new server SASL connection
I0429 03:30:50.562861 28590 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0429 03:30:50.562890 28590 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0429 03:30:50.563078 28595 authenticator.hpp:254] Received SASL authentication start
I0429 03:30:50.563141 28595 authenticator.hpp:342] Authentication requires more steps
I0429 03:30:50.563195 28595 authenticatee.hpp:265] Received SASL authentication step
I0429 03:30:50.563419 28586 authenticator.hpp:282] Received SASL authentication step
I0429 03:30:50.563447 28586 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0429 03:30:50.563457 28586 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0429 03:30:50.563467 28586 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0429 03:30:50.563477 28586 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0429 03:30:50.563483 28586 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.563489 28586 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.563503 28586 authenticator.hpp:334] Authentication success
I0429 03:30:50.563704 28579 authenticatee.hpp:305] Authentication success
[ OK ] SASL.success (3 ms)
[ RUN ] SASL.failed1
I0429 03:30:50.564553 28580 authenticatee.hpp:128] Creating new client SASL connection
I0429 03:30:50.565032 28582 authenticator.hpp:148] Creating new server SASL connection
I0429 03:30:50.565114 28582 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0429 03:30:50.565129 28582 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0429 03:30:50.565150 28582 authenticator.hpp:254] Received SASL authentication start
I0429 03:30:50.565189 28582 authenticator.hpp:342] Authentication requires more steps
I0429 03:30:50.565229 28582 authenticatee.hpp:265] Received SASL authentication step
I0429 03:30:50.565304 28594 authenticator.hpp:282] Received SASL authentication step
I0429 03:30:50.565335 28594 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0429 03:30:50.565348 28594 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0429 03:30:50.565366 28594 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0429 03:30:50.565381 28594 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0429 03:30:50.565389 28594 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.565395 28594 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
W0429 03:30:50.565412 28594 authenticator.hpp:348] Authentication failure: authentication failure
[ OK ] SASL.failed1 (1 ms)
[----------] 3 tests from SASL (7 ms total)
[----------] 1 test from ExternalContainerizerTest
[ RUN ] ExternalContainerizerTest.Launch
I0429 03:30:50.605607 28560 leveldb.cpp:174] Opened db in 39.115463ms
I0429 03:30:50.617965 28560 leveldb.cpp:181] Compacted db in 12.328317ms
I0429 03:30:50.618000 28560 leveldb.cpp:196] Created db iterator in 3958ns
I0429 03:30:50.618010 28560 leveldb.cpp:202] Seeked to beginning of db in 527ns
I0429 03:30:50.618018 28560 leveldb.cpp:271] Iterated through 0 keys in the db in 252ns
I0429 03:30:50.618031 28560 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0429 03:30:50.618206 28600 recover.cpp:425] Starting replica recovery
I0429 03:30:50.619087 28586 master.cpp:266] Master 20140429-033050-453759884-59062-28560 (hemera.apache.org) started on 140.211.11.27:59062
I0429 03:30:50.619154 28586 master.cpp:303] Master only allowing authenticated frameworks to register
I0429 03:30:50.619161 28586 master.cpp:308] Master only allowing authenticated slaves to register
I0429 03:30:50.619168 28586 credentials.hpp:35] Loading credentials for authentication
W0429 03:30:50.619290 28586 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_tBH73M/credentials': No such file or directory
I0429 03:30:50.619323 28598 recover.cpp:451] Replica is in EMPTY status
I0429 03:30:50.620216 28588 replica.cpp:626] Replica in EMPTY status received a broadcasted recover request
I0429 03:30:50.620332 28588 master.cpp:104] No whitelist given. Advertising offers for all slaves
I0429 03:30:50.620337 28598 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@140.211.11.27:59062
I0429 03:30:50.620622 28594 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0429 03:30:50.621466 28582 master.cpp:922] The newly elected leader is master@140.211.11.27:59062 with id 20140429-033050-453759884-59062-28560
I0429 03:30:50.621517 28582 master.cpp:932] Elected as the leading master!
I0429 03:30:50.621522 28582 master.cpp:753] Recovering from registrar
I0429 03:30:50.621760 28594 recover.cpp:542] Updating replica status to STARTING
I0429 03:30:50.621912 28592 registrar.cpp:275] Recovering registrar
I0429 03:30:50.633973 28584 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.092609ms
I0429 03:30:50.634001 28584 replica.cpp:320] Persisted replica status to STARTING
I0429 03:30:50.634078 28584 recover.cpp:451] Replica is in STARTING status
I0429 03:30:50.635457 28602 replica.cpp:626] Replica in STARTING status received a broadcasted recover request
I0429 03:30:50.636451 28594 recover.cpp:188] Received a recover response from a replica in STARTING status
I0429 03:30:50.636855 28597 recover.cpp:542] Updating replica status to VOTING
I0429 03:30:50.650187 28586 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.908087ms
I0429 03:30:50.650214 28586 replica.cpp:320] Persisted replica status to VOTING
I0429 03:30:50.650275 28586 recover.cpp:556] Successfully joined the Paxos group
I0429 03:30:50.650341 28586 recover.cpp:440] Recover process terminated
I0429 03:30:50.652024 28581 log.cpp:656] Attempting to start the writer
I0429 03:30:50.653322 28593 replica.cpp:474] Replica received implicit promise request with proposal 1
I0429 03:30:50.666172 28593 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.822892ms
I0429 03:30:50.666203 28593 replica.cpp:342] Persisted promised to 1
I0429 03:30:50.666581 28597 coordinator.cpp:229] Coordinator attemping to fill missing position
I0429 03:30:50.668771 28582 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0429 03:30:50.682281 28582 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 13.485508ms
I0429 03:30:50.682378 28582 replica.cpp:664] Persisted action at 0
I0429 03:30:50.683292 28580 replica.cpp:508] Replica received write request for position 0
I0429 03:30:50.683317 28580 leveldb.cpp:436] Reading position from leveldb took 11730ns
I0429 03:30:50.694387 28580 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 11.052561ms
I0429 03:30:50.694407 28580 replica.cpp:664] Persisted action at 0
I0429 03:30:50.694986 28597 replica.cpp:643] Replica received learned notice for position 0
I0429 03:30:50.706881 28597 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 11.870391ms
I0429 03:30:50.706913 28597 replica.cpp:664] Persisted action at 0
I0429 03:30:50.706925 28597 replica.cpp:649] Replica learned NOP action at position 0
I0429 03:30:50.707185 28597 log.cpp:672] Writer started with ending position 0
I0429 03:30:50.707849 28583 leveldb.cpp:436] Reading position from leveldb took 14821ns
I0429 03:30:50.710788 28592 registrar.cpp:308] Successfully recovered registrar
I0429 03:30:50.710819 28592 registrar.cpp:379] Attempting to update the 'registry'
I0429 03:30:50.712402 28593 log.cpp:680] Attempting to append 138 bytes to the log
I0429 03:30:50.712615 28581 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1
I0429 03:30:50.713554 28589 replica.cpp:508] Replica received write request for position 1
I0429 03:30:50.726922 28589 leveldb.cpp:341] Persisting action (157 bytes) to leveldb took 13.350063ms
I0429 03:30:50.726992 28589 replica.cpp:664] Persisted action at 1
I0429 03:30:50.727803 28579 replica.cpp:643] Replica received learned notice for position 1
I0429 03:30:50.743057 28579 leveldb.cpp:341] Persisting action (159 bytes) to leveldb took 15.23997ms
I0429 03:30:50.743150 28579 replica.cpp:664] Persisted action at 1
I0429 03:30:50.743165 28579 replica.cpp:649] Replica learned APPEND action at position 1
I0429 03:30:50.743759 28585 registrar.cpp:427] Successfully updated 'registry'
I0429 03:30:50.744256 28585 log.cpp:699] Attempting to truncate the log to 1
I0429 03:30:50.744503 28592 master.cpp:780] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0429 03:30:50.744644 28584 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2
I0429 03:30:50.746143 28595 replica.cpp:508] Replica received write request for position 2
I0429 03:30:50.747640 28593 slave.cpp:140] Slave started on 64)@140.211.11.27:59062
I0429 03:30:50.747661 28593 credentials.hpp:35] Loading credentials for authentication
W0429 03:30:50.747869 28593 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_0mN3wg/credential': No such file or directory
I0429 03:30:50.747951 28593 slave.cpp:231] Slave using credential for: test-principal
I0429 03:30:50.748036 28593 slave.cpp:244] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0429 03:30:50.748168 28593 slave.cpp:272] Slave hostname: hemera.apache.org
I0429 03:30:50.748184 28593 slave.cpp:273] Slave checkpoint: false
I0429 03:30:50.748600 28593 state.cpp:33] Recovering state from '/tmp/ExternalContainerizerTest_Launch_0mN3wg/meta'
I0429 03:30:50.748865 28601 status_update_manager.cpp:193] Recovering status update manager
I0429 03:30:50.749477 28587 slave.cpp:2943] Finished recovery
I0429 03:30:50.749943 28587 slave.cpp:525] New master detected at master@140.211.11.27:59062
I0429 03:30:50.750010 28587 slave.cpp:585] Authenticating with master master@140.211.11.27:59062
I0429 03:30:50.750078 28580 status_update_manager.cpp:167] New master detected at master@140.211.11.27:59062
I0429 03:30:50.750443 28587 slave.cpp:558] Detecting new master
I0429 03:30:50.750469 28585 authenticatee.hpp:128] Creating new client SASL connection
I0429 03:30:50.751050 28560 sched.cpp:121] Version: 0.19.0
I0429 03:30:50.751191 28589 master.cpp:2795] Authenticating slave(64)@140.211.11.27:59062
I0429 03:30:50.751356 28600 sched.cpp:217] New master detected at master@140.211.11.27:59062
I0429 03:30:50.751425 28600 sched.cpp:268] Authenticating with master master@140.211.11.27:59062
I0429 03:30:50.751641 28583 authenticator.hpp:148] Creating new server SASL connection
I0429 03:30:50.751788 28592 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0429 03:30:50.751798 28582 authenticatee.hpp:128] Creating new client SASL connection
I0429 03:30:50.751808 28592 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0429 03:30:50.751840 28592 authenticator.hpp:254] Received SASL authentication start
I0429 03:30:50.751878 28592 authenticator.hpp:342] Authentication requires more steps
I0429 03:30:50.751943 28592 authenticatee.hpp:265] Received SASL authentication step
I0429 03:30:50.751987 28592 authenticator.hpp:282] Received SASL authentication step
I0429 03:30:50.752009 28592 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0429 03:30:50.752023 28592 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0429 03:30:50.752033 28592 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0429 03:30:50.752043 28592 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0429 03:30:50.752051 28592 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.752058 28592 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.752069 28592 authenticator.hpp:334] Authentication success
I0429 03:30:50.752084 28587 master.cpp:2795] Authenticating scheduler(65)@140.211.11.27:59062
I0429 03:30:50.752137 28585 authenticatee.hpp:305] Authentication success
I0429 03:30:50.752226 28585 authenticator.hpp:148] Creating new server SASL connection
I0429 03:30:50.752257 28587 master.cpp:2835] Successfully authenticated slave(64)@140.211.11.27:59062
I0429 03:30:50.752773 28588 slave.cpp:642] Successfully authenticated with master master@140.211.11.27:59062
I0429 03:30:50.752774 28583 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0429 03:30:50.752882 28583 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0429 03:30:50.753039 28588 slave.cpp:871] Will retry registration in 5.482255709secs if necessary
I0429 03:30:50.753322 28589 authenticator.hpp:254] Received SASL authentication start
I0429 03:30:50.753376 28589 authenticator.hpp:342] Authentication requires more steps
I0429 03:30:50.753402 28589 authenticatee.hpp:265] Received SASL authentication step
I0429 03:30:50.753536 28586 authenticator.hpp:282] Received SASL authentication step
I0429 03:30:50.753581 28586 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0429 03:30:50.753586 28590 registrar.cpp:379] Attempting to update the 'registry'
I0429 03:30:50.753590 28586 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0429 03:30:50.753653 28586 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0429 03:30:50.753664 28586 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0429 03:30:50.753671 28586 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.753677 28586 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0429 03:30:50.753690 28586 authenticator.hpp:334] Authentication success
I0429 03:30:50.753769 28596 authenticatee.hpp:305] Authentication success
I0429 03:30:50.753805 28586 master.cpp:2835] Successfully authenticated scheduler(65)@140.211.11.27:59062
I0429 03:30:50.753870 28596 sched.cpp:342] Successfully authenticated with master master@140.211.11.27:59062
I0429 03:30:50.753893 28596 sched.cpp:461] Sending registration request to master@140.211.11.27:59062
I0429 03:30:50.754076 28586 master.cpp:981] Received registration request from scheduler(65)@140.211.11.27:59062
I0429 03:30:50.754181 28586 master.cpp:999] Registering framework 20140429-033050-453759884-59062-28560-0000 at scheduler(65)@140.211.11.27:59062
I0429 03:30:50.754279 28596 sched.cpp:392] Framework registered with 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.754304 28596 sched.cpp:406] Scheduler::registered took 14572ns
I0429 03:30:50.754303 28586 hierarchical_allocator_process.hpp:332] Added framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.754323 28586 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0429 03:30:50.754334 28586 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 13166ns
I0429 03:30:50.762735 28595 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 16.568214ms
I0429 03:30:50.762771 28595 replica.cpp:664] Persisted action at 2
I0429 03:30:50.763458 28593 replica.cpp:643] Replica received learned notice for position 2
I0429 03:30:50.778848 28593 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 15.370662ms
I0429 03:30:50.778909 28593 leveldb.cpp:399] Deleting ~1 keys from leveldb took 29618ns
I0429 03:30:50.778931 28593 replica.cpp:664] Persisted action at 2
I0429 03:30:50.778946 28593 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0429 03:30:50.779325 28582 log.cpp:680] Attempting to append 332 bytes to the log
I0429 03:30:50.779392 28589 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0429 03:30:50.781484 28592 replica.cpp:508] Replica received write request for position 3
I0429 03:30:50.794966 28592 leveldb.cpp:341] Persisting action (351 bytes) to leveldb took 13.456731ms
I0429 03:30:50.795001 28592 replica.cpp:664] Persisted action at 3
I0429 03:30:50.795593 28585 replica.cpp:643] Replica received learned notice for position 3
I0429 03:30:50.811063 28585 leveldb.cpp:341] Persisting action (353 bytes) to leveldb took 15.453456ms
I0429 03:30:50.811085 28585 replica.cpp:664] Persisted action at 3
I0429 03:30:50.811092 28585 replica.cpp:649] Replica learned APPEND action at position 3
I0429 03:30:50.811419 28600 registrar.cpp:427] Successfully updated 'registry'
I0429 03:30:50.811578 28595 master.cpp:2169] Admitted slave on hemera.apache.org at slave(64)@140.211.11.27:59062
I0429 03:30:50.811604 28595 master.cpp:3283] Adding slave 20140429-033050-453759884-59062-28560-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0429 03:30:50.811676 28593 log.cpp:699] Attempting to truncate the log to 3
I0429 03:30:50.811723 28583 slave.cpp:675] Registered with master master@140.211.11.27:59062; given slave ID 20140429-033050-453759884-59062-28560-0
I0429 03:30:50.811768 28588 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0429 03:30:50.812239 28583 replica.cpp:508] Replica received write request for position 4
I0429 03:30:50.812368 28599 hierarchical_allocator_process.hpp:445] Added slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0429 03:30:50.812443 28599 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140429-033050-453759884-59062-28560-0 to framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.812580 28599 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140429-033050-453759884-59062-28560-0 in 162611ns
I0429 03:30:50.812718 28589 master.hpp:586] Adding offer 20140429-033050-453759884-59062-28560-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org)
I0429 03:30:50.812777 28589 master.cpp:2744] Sending 1 offers to framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.812924 28589 sched.cpp:529] Scheduler::resourceOffers took 47589ns
I0429 03:30:50.813936 28582 master.hpp:596] Removing offer 20140429-033050-453759884-59062-28560-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org)
I0429 03:30:50.814002 28582 master.cpp:1806] Processing reply for offers: [ 20140429-033050-453759884-59062-28560-0 ] on slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org) for framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.814071 28582 master.hpp:558] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org)
I0429 03:30:50.814101 28582 master.cpp:2919] Launching task 1 of framework 20140429-033050-453759884-59062-28560-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140429-033050-453759884-59062-28560-0 (hemera.apache.org)
I0429 03:30:50.814200 28599 slave.cpp:905] Got assigned task 1 for framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.814422 28599 slave.cpp:1015] Launching task 1 for framework 20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.816411 28599 slave.cpp:1125] Queuing task '1' for executor 1 of framework '20140429-033050-453759884-59062-28560-0000
I0429 03:30:50.816447 28598 external_containerizer.cpp:266] Launching container '9c388f76-1343-4dc0-be32-136d46c0b091'
I0429 03:30:50.816460 28599 slave.cpp:486] Successfully attached file '/tmp/ExternalContainerizerTest_Launch_0mN3wg/slaves/20140429-033050-453759884-59062-28560-0/frameworks/20140429-033050-453759884-59062-28560-0000/executors/1/runs/9c388f76-1343-4dc0-be32-136d46c0b091'
I0429 03:30:50.816509 28598 external_containerizer.cpp:804] Invoking external containerizer for method 'launch'
I0429 03:30:50.816534 28598 external_containerizer.cpp:818] user: jenkins
I0429 03:30:50.827695 28583 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.363901ms
I0429 03:30:50.827760 28583 replica.cpp:664] Persisted action at 4
make[3]: *** [check-local] Broken pipe
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2097
Posted by Till Toenshoff <to...@me.com>.
Turned out that the issue is not strictly related to MESOS-1257.
This specific problem was triggered by a build configured with —disable-python.
I have proposed a fix at https://reviews.apache.org/r/20823/
The issue visible in https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/2096 should also be fixed, the fix already got committed: https://reviews.apache.org/r/20819/
So now all the issues that popped up today, caused by the ExternalContainerizer(test) should be fixed.
Sorry for any inconveniences these have caused.
On Apr 29, 2014, at 12:34 AM, Jie Yu <yu...@gmail.com> wrote:
> Should be related to
> https://issues.apache.org/jira/browse/MESOS-1257
>
>
> On Mon, Apr 28, 2014 at 3:32 PM, Vinod Kone <vi...@gmail.com> wrote:
> +till
>
> can't seem to figure out what the error is here. @till, mind taking a look?
>
>
> On Mon, Apr 28, 2014 at 1:59 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2097/changes
> > >
> >
> > Changes:
> >
> > [bmahler] Added count to metric statistics.
> >
> > [benjamin.hindman] [MESOS-1252]: Support ENV MAVEN_HOME on the build.
> >
> > ------------------------------------------
> > [...truncated 5332 lines...]
> > I0428 20:59:24.682000 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.682694 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.683544 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.683954 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.686210 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.687655 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.688208 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.688606 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.689003 15955 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.689481 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.ReadTest (11 ms)
> > [ RUN ] FilesTest.ResolveTest
> > Using temporary directory '/tmp/FilesTest_ResolveTest_OtVcdW'
> > I0428 20:59:24.693207 15963 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.693959 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.694476 15965 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.695181 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.695780 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.696813 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.697413 15972 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.698425 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.699270 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.700206 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.700775 15957 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.701326 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.702167 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.702430 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.703665 15970 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.704807 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.705673 15967 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.705952 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.706401 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.707334 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.ResolveTest (18 ms)
> > [ RUN ] FilesTest.BrowseTest
> > Using temporary directory '/tmp/FilesTest_BrowseTest_09PycP'
> > I0428 20:59:24.710582 15958 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.711107 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.712327 15975 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.713183 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.713877 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.714687 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.715458 15964 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.716001 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.717205 15968 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.718169 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.BrowseTest (11 ms)
> > [ RUN ] FilesTest.DownloadTest
> > Using temporary directory '/tmp/FilesTest_DownloadTest_YE82dI'
> > I0428 20:59:24.721535 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.722095 15975 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/binary' with length 17
> > I0428 20:59:24.722409 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.723152 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.724043 15961 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/black.gif' with length 42
> > I0428 20:59:24.724460 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.DownloadTest (6 ms)
> > [ RUN ] FilesTest.AttachTest
> > Using temporary directory '/tmp/FilesTest_AttachTest_rofKgB'
> > [ OK ] FilesTest.AttachTest (7 ms)
> > [----------] 6 tests from FilesTest (55 ms total)
> >
> > [----------] 1 test from ExternalContainerizerTest
> > [ RUN ] ExternalContainerizerTest.Launch
> > I0428 20:59:24.772775 15732 leveldb.cpp:174] Opened db in 39.638232ms
> > I0428 20:59:24.785150 15732 leveldb.cpp:181] Compacted db in 12.344983ms
> > I0428 20:59:24.785184 15732 leveldb.cpp:196] Created db iterator in 3296ns
> > I0428 20:59:24.785197 15732 leveldb.cpp:202] Seeked to beginning of db in
> > 455ns
> > I0428 20:59:24.785202 15732 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 127ns
> > I0428 20:59:24.785215 15732 replica.cpp:729] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0428 20:59:24.785486 15970 recover.cpp:425] Starting replica recovery
> > I0428 20:59:24.785936 15957 master.cpp:266] Master
> > 20140428-205924-453759884-46217-15732 (hemera.apache.org) started on
> > 140.211.11.27:46217
> > I0428 20:59:24.785960 15957 master.cpp:303] Master only allowing
> > authenticated frameworks to register
> > I0428 20:59:24.785967 15957 master.cpp:308] Master only allowing
> > authenticated slaves to register
> > I0428 20:59:24.785974 15957 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.786023 15957 credentials.hpp:48] Failed to stat credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_NEMSku/credentials': No
> > such file or directory
> > I0428 20:59:24.786319 15965 hierarchical_allocator_process.hpp:302]
> > Initializing hierarchical allocator process with master :
> > master@140.211.11.27:46217
> > I0428 20:59:24.786321 15964 master.cpp:104] No whitelist given.
> > Advertising offers for all slaves
> > I0428 20:59:24.786841 15953 recover.cpp:451] Replica is in EMPTY status
> > I0428 20:59:24.786959 15957 master.cpp:922] The newly elected leader is
> > master@140.211.11.27:46217 with id 20140428-205924-453759884-46217-15732
> > I0428 20:59:24.786977 15957 master.cpp:932] Elected as the leading master!
> > I0428 20:59:24.786984 15957 master.cpp:753] Recovering from registrar
> > I0428 20:59:24.787045 15954 registrar.cpp:275] Recovering registrar
> > I0428 20:59:24.789015 15962 replica.cpp:626] Replica in EMPTY status
> > received a broadcasted recover request
> > I0428 20:59:24.789623 15954 recover.cpp:188] Received a recover response
> > from a replica in EMPTY status
> > I0428 20:59:24.790539 15955 recover.cpp:542] Updating replica status to
> > STARTING
> > I0428 20:59:24.801323 15954 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.406883ms
> > I0428 20:59:24.801355 15954 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0428 20:59:24.801453 15954 recover.cpp:451] Replica is in STARTING status
> > I0428 20:59:24.802309 15969 replica.cpp:626] Replica in STARTING status
> > received a broadcasted recover request
> > I0428 20:59:24.802391 15964 recover.cpp:188] Received a recover response
> > from a replica in STARTING status
> > I0428 20:59:24.802681 15954 recover.cpp:542] Updating replica status to
> > VOTING
> > I0428 20:59:24.813487 15963 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.134698ms
> > I0428 20:59:24.813516 15963 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0428 20:59:24.813585 15963 recover.cpp:556] Successfully joined the Paxos
> > group
> > I0428 20:59:24.813649 15963 recover.cpp:440] Recover process terminated
> > I0428 20:59:24.813904 15963 log.cpp:656] Attempting to start the writer
> > I0428 20:59:24.815146 15958 replica.cpp:474] Replica received implicit
> > promise request with proposal 1
> > I0428 20:59:24.825553 15958 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.387839ms
> > I0428 20:59:24.825580 15958 replica.cpp:342] Persisted promised to 1
> > I0428 20:59:24.826100 15972 coordinator.cpp:229] Coordinator attemping to
> > fill missing position
> > I0428 20:59:24.827474 15957 replica.cpp:375] Replica received explicit
> > promise request for position 0 with proposal 2
> > I0428 20:59:24.841668 15957 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 14.170623ms
> > I0428 20:59:24.841699 15957 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.843376 15968 replica.cpp:508] Replica received write
> > request for position 0
> > I0428 20:59:24.843410 15968 leveldb.cpp:436] Reading position from leveldb
> > took 11625ns
> > I0428 20:59:24.858222 15968 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 14.794701ms
> > I0428 20:59:24.858254 15968 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.858547 15961 replica.cpp:643] Replica received learned
> > notice for position 0
> > I0428 20:59:24.870362 15961 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 11.789972ms
> > I0428 20:59:24.870393 15961 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.870404 15961 replica.cpp:649] Replica learned NOP action at
> > position 0
> > I0428 20:59:24.871217 15956 log.cpp:672] Writer started with ending
> > position 0
> > I0428 20:59:24.872596 15971 leveldb.cpp:436] Reading position from leveldb
> > took 14921ns
> > I0428 20:59:24.873814 15955 registrar.cpp:308] Successfully recovered
> > registrar
> > I0428 20:59:24.873834 15955 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.875111 15966 log.cpp:680] Attempting to append 138 bytes to
> > the log
> > I0428 20:59:24.875331 15957 coordinator.cpp:339] Coordinator attempting to
> > write APPEND action at position 1
> > I0428 20:59:24.876457 15958 replica.cpp:508] Replica received write
> > request for position 1
> > I0428 20:59:24.890455 15958 leveldb.cpp:341] Persisting action (157 bytes)
> > to leveldb took 13.858394ms
> > I0428 20:59:24.890476 15958 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.891136 15974 replica.cpp:643] Replica received learned
> > notice for position 1
> > I0428 20:59:24.906605 15974 leveldb.cpp:341] Persisting action (159 bytes)
> > to leveldb took 15.443876ms
> > I0428 20:59:24.906637 15974 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.906649 15974 replica.cpp:649] Replica learned APPEND action
> > at position 1
> > I0428 20:59:24.907068 15974 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.907209 15971 log.cpp:699] Attempting to truncate the log to
> > 1
> > I0428 20:59:24.907500 15971 coordinator.cpp:339] Coordinator attempting to
> > write TRUNCATE action at position 2
> > I0428 20:59:24.909026 15971 master.cpp:780] Recovered 0 slaves from the
> > Registry (100B) ; allowing 10mins for slaves to re-register
> > I0428 20:59:24.909487 15970 replica.cpp:508] Replica received write
> > request for position 2
> > I0428 20:59:24.912192 15971 slave.cpp:140] Slave started on 14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.912210 15971 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.912390 15971 credentials.hpp:48] Failed to stat credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_Xlp4Xn/credential': No
> > such file or directory
> > I0428 20:59:24.912412 15971 slave.cpp:231] Slave using credential for:
> > test-principal
> > I0428 20:59:24.912499 15971 slave.cpp:244] Slave resources: cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.912636 15971 slave.cpp:272] Slave hostname:
> > hemera.apache.org
> > I0428 20:59:24.912662 15971 slave.cpp:273] Slave checkpoint: false
> > I0428 20:59:24.913218 15971 state.cpp:33] Recovering state from
> > '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/meta'
> > I0428 20:59:24.913355 15966 status_update_manager.cpp:193] Recovering
> > status update manager
> > I0428 20:59:24.913879 15966 slave.cpp:2943] Finished recovery
> > I0428 20:59:24.914572 15732 sched.cpp:121] Version: 0.19.0
> > I0428 20:59:24.914970 15955 sched.cpp:217] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.915102 15955 sched.cpp:268] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.915230 15954 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.915446 15954 master.cpp:2795] Authenticating scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.915745 15969 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.916017 15969 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.916031 15969 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.916050 15969 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.916157 15969 authenticator.hpp:342] Authentication requires
> > more steps
> > I0428 20:59:24.916192 15969 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.916241 15969 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.916254 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.916260 15969 auxprop.cpp:153] Looking up auxiliary property
> > '*userPassword'
> > I0428 20:59:24.916266 15969 auxprop.cpp:153] Looking up auxiliary property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.916272 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.916276 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916280 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916288 15969 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.916367 15953 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.916576 15963 master.cpp:2835] Successfully authenticated
> > scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916590 15956 sched.cpp:342] Successfully authenticated with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.916671 15956 sched.cpp:461] Sending registration request to
> > master@140.211.11.27:46217
> > I0428 20:59:24.916857 15963 master.cpp:981] Received registration request
> > from scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916887 15963 master.cpp:999] Registering framework
> > 20140428-205924-453759884-46217-15732-0000 at scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.917032 15974 sched.cpp:392] Framework registered with
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917067 15963 hierarchical_allocator_process.hpp:332] Added
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917083 15963 hierarchical_allocator_process.hpp:726] No
> > resources available to allocate!
> > I0428 20:59:24.917093 15963 hierarchical_allocator_process.hpp:688]
> > Performed allocation for 0 slaves in 10385ns
> > I0428 20:59:24.917156 15974 sched.cpp:406] Scheduler::registered took
> > 104111ns
> > I0428 20:59:24.918953 15966 slave.cpp:525] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.918984 15966 slave.cpp:585] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.919020 15954 status_update_manager.cpp:167] New master
> > detected at master@140.211.11.27:46217
> > I0428 20:59:24.919047 15961 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.919028 15966 slave.cpp:558] Detecting new master
> > I0428 20:59:24.919312 15968 master.cpp:2795] Authenticating slave(14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.919371 15968 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.919842 15955 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.919857 15955 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.919914 15955 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.919999 15955 authenticator.hpp:342] Authentication requires
> > more steps
> > I0428 20:59:24.920488 15973 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.920598 15973 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.920613 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.920617 15973 auxprop.cpp:153] Looking up auxiliary property
> > '*userPassword'
> > I0428 20:59:24.920624 15973 auxprop.cpp:153] Looking up auxiliary property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.920629 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.920632 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920635 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920642 15973 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.920753 15973 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.920769 15955 master.cpp:2835] Successfully authenticated
> > slave(14)@140.211.11.27:46217
> > I0428 20:59:24.921393 15976 slave.cpp:642] Successfully authenticated with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.921447 15976 slave.cpp:871] Will retry registration in
> > 6.085179816secs if necessary
> > I0428 20:59:24.921664 15953 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.922801 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 13.290713ms
> > I0428 20:59:24.922821 15970 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.923069 15968 replica.cpp:643] Replica received learned
> > notice for position 2
> > I0428 20:59:24.939198 15968 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 16.114121ms
> > I0428 20:59:24.939267 15968 leveldb.cpp:399] Deleting ~1 keys from leveldb
> > took 47686ns
> > I0428 20:59:24.939277 15968 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.939283 15968 replica.cpp:649] Replica learned TRUNCATE
> > action at position 2
> > I0428 20:59:24.939585 15974 log.cpp:680] Attempting to append 332 bytes to
> > the log
> > I0428 20:59:24.939746 15975 coordinator.cpp:339] Coordinator attempting to
> > write APPEND action at position 3
> > I0428 20:59:24.941287 15958 replica.cpp:508] Replica received write
> > request for position 3
> > I0428 20:59:24.955303 15958 leveldb.cpp:341] Persisting action (351 bytes)
> > to leveldb took 14.000606ms
> > I0428 20:59:24.955324 15958 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.956228 15957 replica.cpp:643] Replica received learned
> > notice for position 3
> > I0428 20:59:24.971446 15957 leveldb.cpp:341] Persisting action (353 bytes)
> > to leveldb took 15.190795ms
> > I0428 20:59:24.971477 15957 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.971489 15957 replica.cpp:649] Replica learned APPEND action
> > at position 3
> > I0428 20:59:24.971849 15976 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.972170 15974 master.cpp:2169] Admitted slave on
> > hemera.apache.org at slave(14)@140.211.11.27:46217
> > I0428 20:59:24.972194 15974 master.cpp:3283] Adding slave
> > 20140428-205924-453759884-46217-15732-0 at hemera.apache.org with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.972244 15967 log.cpp:699] Attempting to truncate the log to
> > 3
> > I0428 20:59:24.972283 15959 slave.cpp:675] Registered with master
> > master@140.211.11.27:46217; given slave ID
> > 20140428-205924-453759884-46217-15732-0
> > I0428 20:59:24.972452 15972 hierarchical_allocator_process.hpp:445] Added
> > slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> > I0428 20:59:24.972508 15971 coordinator.cpp:339] Coordinator attempting to
> > write TRUNCATE action at position 4
> > I0428 20:59:24.972529 15972 hierarchical_allocator_process.hpp:752]
> > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> > slave 20140428-205924-453759884-46217-15732-0 to framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972769 15972 hierarchical_allocator_process.hpp:708]
> > Performed allocation for slave 20140428-205924-453759884-46217-15732-0 in
> > 267569ns
> > I0428 20:59:24.972786 15955 master.hpp:586] Adding offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.972829 15955 master.cpp:2744] Sending 1 offers to framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972977 15955 sched.cpp:529] Scheduler::resourceOffers took
> > 49221ns
> > I0428 20:59:24.973989 15970 replica.cpp:508] Replica received write
> > request for position 4
> > I0428 20:59:24.974783 15960 master.hpp:596] Removing offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974851 15960 master.cpp:1806] Processing reply for offers:
> > [ 20140428-205924-453759884-46217-15732-0 ] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) for framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.974926 15960 master.hpp:558] Adding task 1 with resources
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974983 15960 master.cpp:2919] Launching task 1 of framework
> > 20140428-205924-453759884-46217-15732-0000 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.975106 15964 slave.cpp:905] Got assigned task 1 for
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.975277 15964 slave.cpp:1015] Launching task 1 for framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976796 15964 slave.cpp:1125] Queuing task '1' for executor
> > 1 of framework '20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976812 15960 external_containerizer.cpp:266] Launching
> > container 'cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976842 15964 slave.cpp:486] Successfully attached file
> > '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/slaves/20140428-205924-453759884-46217-15732-0/frameworks/20140428-205924-453759884-46217-15732-0000/executors/1/runs/cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976888 15960 external_containerizer.cpp:804] Invoking
> > external containerizer for method 'launch'
> > I0428 20:59:24.976913 15960 external_containerizer.cpp:818] user: jenkins
> > I0428 20:59:24.988150 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 14.136354ms
> > I0428 20:59:24.988204 15970 replica.cpp:664] Persisted action at 4
> > I0428 20:59:24.991509 15954 replica.cpp:643] Replica received learned
> > notice for position 4
> > I0428 20:59:25.004228 15954 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 12.701325ms
> > I0428 20:59:25.004286 15954 leveldb.cpp:399] Deleting ~2 keys from leveldb
> > took 34958ns
> > I0428 20:59:25.004297 15954 replica.cpp:664] Persisted action at 4
> > I0428 20:59:25.004302 15954 replica.cpp:649] Replica learned TRUNCATE
> > action at position 4
> > make[3]: *** [check-local] Broken pipe
> > make[3]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[2]: *** [check-am] Error 2
> > make[2]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[1]: *** [check] Error 2
> > make[1]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make: *** [check-recursive] Error 1
> > Build step 'Execute shell' marked build as failure
> >
>
Re: Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2097
Posted by Till Toenshoff <to...@me.com>.
Am looking into it already - thanks for bringing it to my attention!
On Apr 29, 2014, at 12:34 AM, Jie Yu <yu...@gmail.com> wrote:
> Should be related to
> https://issues.apache.org/jira/browse/MESOS-1257
>
>
> On Mon, Apr 28, 2014 at 3:32 PM, Vinod Kone <vi...@gmail.com> wrote:
> +till
>
> can't seem to figure out what the error is here. @till, mind taking a look?
>
>
> On Mon, Apr 28, 2014 at 1:59 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2097/changes
> > >
> >
> > Changes:
> >
> > [bmahler] Added count to metric statistics.
> >
> > [benjamin.hindman] [MESOS-1252]: Support ENV MAVEN_HOME on the build.
> >
> > ------------------------------------------
> > [...truncated 5332 lines...]
> > I0428 20:59:24.682000 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.682694 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.683544 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.683954 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.686210 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.687655 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.688208 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.688606 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.689003 15955 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.689481 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.ReadTest (11 ms)
> > [ RUN ] FilesTest.ResolveTest
> > Using temporary directory '/tmp/FilesTest_ResolveTest_OtVcdW'
> > I0428 20:59:24.693207 15963 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.693959 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.694476 15965 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.695181 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.695780 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.696813 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.697413 15972 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.698425 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.699270 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.700206 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.700775 15957 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.701326 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.702167 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.702430 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.703665 15970 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.704807 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.705673 15967 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.705952 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.706401 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.707334 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.ResolveTest (18 ms)
> > [ RUN ] FilesTest.BrowseTest
> > Using temporary directory '/tmp/FilesTest_BrowseTest_09PycP'
> > I0428 20:59:24.710582 15958 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.711107 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.712327 15975 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.713183 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.713877 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.714687 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.715458 15964 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.716001 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.717205 15968 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.718169 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.BrowseTest (11 ms)
> > [ RUN ] FilesTest.DownloadTest
> > Using temporary directory '/tmp/FilesTest_DownloadTest_YE82dI'
> > I0428 20:59:24.721535 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.722095 15975 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/binary' with length 17
> > I0428 20:59:24.722409 15977 process.cpp:1013] Socket closed while receiving
> > I0428 20:59:24.723152 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.724043 15961 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/black.gif' with length 42
> > I0428 20:59:24.724460 15977 process.cpp:1013] Socket closed while receiving
> > [ OK ] FilesTest.DownloadTest (6 ms)
> > [ RUN ] FilesTest.AttachTest
> > Using temporary directory '/tmp/FilesTest_AttachTest_rofKgB'
> > [ OK ] FilesTest.AttachTest (7 ms)
> > [----------] 6 tests from FilesTest (55 ms total)
> >
> > [----------] 1 test from ExternalContainerizerTest
> > [ RUN ] ExternalContainerizerTest.Launch
> > I0428 20:59:24.772775 15732 leveldb.cpp:174] Opened db in 39.638232ms
> > I0428 20:59:24.785150 15732 leveldb.cpp:181] Compacted db in 12.344983ms
> > I0428 20:59:24.785184 15732 leveldb.cpp:196] Created db iterator in 3296ns
> > I0428 20:59:24.785197 15732 leveldb.cpp:202] Seeked to beginning of db in
> > 455ns
> > I0428 20:59:24.785202 15732 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 127ns
> > I0428 20:59:24.785215 15732 replica.cpp:729] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0428 20:59:24.785486 15970 recover.cpp:425] Starting replica recovery
> > I0428 20:59:24.785936 15957 master.cpp:266] Master
> > 20140428-205924-453759884-46217-15732 (hemera.apache.org) started on
> > 140.211.11.27:46217
> > I0428 20:59:24.785960 15957 master.cpp:303] Master only allowing
> > authenticated frameworks to register
> > I0428 20:59:24.785967 15957 master.cpp:308] Master only allowing
> > authenticated slaves to register
> > I0428 20:59:24.785974 15957 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.786023 15957 credentials.hpp:48] Failed to stat credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_NEMSku/credentials': No
> > such file or directory
> > I0428 20:59:24.786319 15965 hierarchical_allocator_process.hpp:302]
> > Initializing hierarchical allocator process with master :
> > master@140.211.11.27:46217
> > I0428 20:59:24.786321 15964 master.cpp:104] No whitelist given.
> > Advertising offers for all slaves
> > I0428 20:59:24.786841 15953 recover.cpp:451] Replica is in EMPTY status
> > I0428 20:59:24.786959 15957 master.cpp:922] The newly elected leader is
> > master@140.211.11.27:46217 with id 20140428-205924-453759884-46217-15732
> > I0428 20:59:24.786977 15957 master.cpp:932] Elected as the leading master!
> > I0428 20:59:24.786984 15957 master.cpp:753] Recovering from registrar
> > I0428 20:59:24.787045 15954 registrar.cpp:275] Recovering registrar
> > I0428 20:59:24.789015 15962 replica.cpp:626] Replica in EMPTY status
> > received a broadcasted recover request
> > I0428 20:59:24.789623 15954 recover.cpp:188] Received a recover response
> > from a replica in EMPTY status
> > I0428 20:59:24.790539 15955 recover.cpp:542] Updating replica status to
> > STARTING
> > I0428 20:59:24.801323 15954 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.406883ms
> > I0428 20:59:24.801355 15954 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0428 20:59:24.801453 15954 recover.cpp:451] Replica is in STARTING status
> > I0428 20:59:24.802309 15969 replica.cpp:626] Replica in STARTING status
> > received a broadcasted recover request
> > I0428 20:59:24.802391 15964 recover.cpp:188] Received a recover response
> > from a replica in STARTING status
> > I0428 20:59:24.802681 15954 recover.cpp:542] Updating replica status to
> > VOTING
> > I0428 20:59:24.813487 15963 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.134698ms
> > I0428 20:59:24.813516 15963 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0428 20:59:24.813585 15963 recover.cpp:556] Successfully joined the Paxos
> > group
> > I0428 20:59:24.813649 15963 recover.cpp:440] Recover process terminated
> > I0428 20:59:24.813904 15963 log.cpp:656] Attempting to start the writer
> > I0428 20:59:24.815146 15958 replica.cpp:474] Replica received implicit
> > promise request with proposal 1
> > I0428 20:59:24.825553 15958 leveldb.cpp:304] Persisting metadata (8 bytes)
> > to leveldb took 10.387839ms
> > I0428 20:59:24.825580 15958 replica.cpp:342] Persisted promised to 1
> > I0428 20:59:24.826100 15972 coordinator.cpp:229] Coordinator attemping to
> > fill missing position
> > I0428 20:59:24.827474 15957 replica.cpp:375] Replica received explicit
> > promise request for position 0 with proposal 2
> > I0428 20:59:24.841668 15957 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 14.170623ms
> > I0428 20:59:24.841699 15957 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.843376 15968 replica.cpp:508] Replica received write
> > request for position 0
> > I0428 20:59:24.843410 15968 leveldb.cpp:436] Reading position from leveldb
> > took 11625ns
> > I0428 20:59:24.858222 15968 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 14.794701ms
> > I0428 20:59:24.858254 15968 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.858547 15961 replica.cpp:643] Replica received learned
> > notice for position 0
> > I0428 20:59:24.870362 15961 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 11.789972ms
> > I0428 20:59:24.870393 15961 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.870404 15961 replica.cpp:649] Replica learned NOP action at
> > position 0
> > I0428 20:59:24.871217 15956 log.cpp:672] Writer started with ending
> > position 0
> > I0428 20:59:24.872596 15971 leveldb.cpp:436] Reading position from leveldb
> > took 14921ns
> > I0428 20:59:24.873814 15955 registrar.cpp:308] Successfully recovered
> > registrar
> > I0428 20:59:24.873834 15955 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.875111 15966 log.cpp:680] Attempting to append 138 bytes to
> > the log
> > I0428 20:59:24.875331 15957 coordinator.cpp:339] Coordinator attempting to
> > write APPEND action at position 1
> > I0428 20:59:24.876457 15958 replica.cpp:508] Replica received write
> > request for position 1
> > I0428 20:59:24.890455 15958 leveldb.cpp:341] Persisting action (157 bytes)
> > to leveldb took 13.858394ms
> > I0428 20:59:24.890476 15958 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.891136 15974 replica.cpp:643] Replica received learned
> > notice for position 1
> > I0428 20:59:24.906605 15974 leveldb.cpp:341] Persisting action (159 bytes)
> > to leveldb took 15.443876ms
> > I0428 20:59:24.906637 15974 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.906649 15974 replica.cpp:649] Replica learned APPEND action
> > at position 1
> > I0428 20:59:24.907068 15974 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.907209 15971 log.cpp:699] Attempting to truncate the log to
> > 1
> > I0428 20:59:24.907500 15971 coordinator.cpp:339] Coordinator attempting to
> > write TRUNCATE action at position 2
> > I0428 20:59:24.909026 15971 master.cpp:780] Recovered 0 slaves from the
> > Registry (100B) ; allowing 10mins for slaves to re-register
> > I0428 20:59:24.909487 15970 replica.cpp:508] Replica received write
> > request for position 2
> > I0428 20:59:24.912192 15971 slave.cpp:140] Slave started on 14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.912210 15971 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.912390 15971 credentials.hpp:48] Failed to stat credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_Xlp4Xn/credential': No
> > such file or directory
> > I0428 20:59:24.912412 15971 slave.cpp:231] Slave using credential for:
> > test-principal
> > I0428 20:59:24.912499 15971 slave.cpp:244] Slave resources: cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.912636 15971 slave.cpp:272] Slave hostname:
> > hemera.apache.org
> > I0428 20:59:24.912662 15971 slave.cpp:273] Slave checkpoint: false
> > I0428 20:59:24.913218 15971 state.cpp:33] Recovering state from
> > '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/meta'
> > I0428 20:59:24.913355 15966 status_update_manager.cpp:193] Recovering
> > status update manager
> > I0428 20:59:24.913879 15966 slave.cpp:2943] Finished recovery
> > I0428 20:59:24.914572 15732 sched.cpp:121] Version: 0.19.0
> > I0428 20:59:24.914970 15955 sched.cpp:217] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.915102 15955 sched.cpp:268] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.915230 15954 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.915446 15954 master.cpp:2795] Authenticating scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.915745 15969 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.916017 15969 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.916031 15969 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.916050 15969 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.916157 15969 authenticator.hpp:342] Authentication requires
> > more steps
> > I0428 20:59:24.916192 15969 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.916241 15969 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.916254 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.916260 15969 auxprop.cpp:153] Looking up auxiliary property
> > '*userPassword'
> > I0428 20:59:24.916266 15969 auxprop.cpp:153] Looking up auxiliary property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.916272 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.916276 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916280 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916288 15969 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.916367 15953 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.916576 15963 master.cpp:2835] Successfully authenticated
> > scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916590 15956 sched.cpp:342] Successfully authenticated with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.916671 15956 sched.cpp:461] Sending registration request to
> > master@140.211.11.27:46217
> > I0428 20:59:24.916857 15963 master.cpp:981] Received registration request
> > from scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916887 15963 master.cpp:999] Registering framework
> > 20140428-205924-453759884-46217-15732-0000 at scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.917032 15974 sched.cpp:392] Framework registered with
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917067 15963 hierarchical_allocator_process.hpp:332] Added
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917083 15963 hierarchical_allocator_process.hpp:726] No
> > resources available to allocate!
> > I0428 20:59:24.917093 15963 hierarchical_allocator_process.hpp:688]
> > Performed allocation for 0 slaves in 10385ns
> > I0428 20:59:24.917156 15974 sched.cpp:406] Scheduler::registered took
> > 104111ns
> > I0428 20:59:24.918953 15966 slave.cpp:525] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.918984 15966 slave.cpp:585] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.919020 15954 status_update_manager.cpp:167] New master
> > detected at master@140.211.11.27:46217
> > I0428 20:59:24.919047 15961 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.919028 15966 slave.cpp:558] Detecting new master
> > I0428 20:59:24.919312 15968 master.cpp:2795] Authenticating slave(14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.919371 15968 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.919842 15955 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.919857 15955 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.919914 15955 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.919999 15955 authenticator.hpp:342] Authentication requires
> > more steps
> > I0428 20:59:24.920488 15973 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.920598 15973 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.920613 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.920617 15973 auxprop.cpp:153] Looking up auxiliary property
> > '*userPassword'
> > I0428 20:59:24.920624 15973 auxprop.cpp:153] Looking up auxiliary property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.920629 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.920632 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920635 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920642 15973 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.920753 15973 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.920769 15955 master.cpp:2835] Successfully authenticated
> > slave(14)@140.211.11.27:46217
> > I0428 20:59:24.921393 15976 slave.cpp:642] Successfully authenticated with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.921447 15976 slave.cpp:871] Will retry registration in
> > 6.085179816secs if necessary
> > I0428 20:59:24.921664 15953 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.922801 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 13.290713ms
> > I0428 20:59:24.922821 15970 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.923069 15968 replica.cpp:643] Replica received learned
> > notice for position 2
> > I0428 20:59:24.939198 15968 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 16.114121ms
> > I0428 20:59:24.939267 15968 leveldb.cpp:399] Deleting ~1 keys from leveldb
> > took 47686ns
> > I0428 20:59:24.939277 15968 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.939283 15968 replica.cpp:649] Replica learned TRUNCATE
> > action at position 2
> > I0428 20:59:24.939585 15974 log.cpp:680] Attempting to append 332 bytes to
> > the log
> > I0428 20:59:24.939746 15975 coordinator.cpp:339] Coordinator attempting to
> > write APPEND action at position 3
> > I0428 20:59:24.941287 15958 replica.cpp:508] Replica received write
> > request for position 3
> > I0428 20:59:24.955303 15958 leveldb.cpp:341] Persisting action (351 bytes)
> > to leveldb took 14.000606ms
> > I0428 20:59:24.955324 15958 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.956228 15957 replica.cpp:643] Replica received learned
> > notice for position 3
> > I0428 20:59:24.971446 15957 leveldb.cpp:341] Persisting action (353 bytes)
> > to leveldb took 15.190795ms
> > I0428 20:59:24.971477 15957 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.971489 15957 replica.cpp:649] Replica learned APPEND action
> > at position 3
> > I0428 20:59:24.971849 15976 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.972170 15974 master.cpp:2169] Admitted slave on
> > hemera.apache.org at slave(14)@140.211.11.27:46217
> > I0428 20:59:24.972194 15974 master.cpp:3283] Adding slave
> > 20140428-205924-453759884-46217-15732-0 at hemera.apache.org with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.972244 15967 log.cpp:699] Attempting to truncate the log to
> > 3
> > I0428 20:59:24.972283 15959 slave.cpp:675] Registered with master
> > master@140.211.11.27:46217; given slave ID
> > 20140428-205924-453759884-46217-15732-0
> > I0428 20:59:24.972452 15972 hierarchical_allocator_process.hpp:445] Added
> > slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> > I0428 20:59:24.972508 15971 coordinator.cpp:339] Coordinator attempting to
> > write TRUNCATE action at position 4
> > I0428 20:59:24.972529 15972 hierarchical_allocator_process.hpp:752]
> > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> > slave 20140428-205924-453759884-46217-15732-0 to framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972769 15972 hierarchical_allocator_process.hpp:708]
> > Performed allocation for slave 20140428-205924-453759884-46217-15732-0 in
> > 267569ns
> > I0428 20:59:24.972786 15955 master.hpp:586] Adding offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.972829 15955 master.cpp:2744] Sending 1 offers to framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972977 15955 sched.cpp:529] Scheduler::resourceOffers took
> > 49221ns
> > I0428 20:59:24.973989 15970 replica.cpp:508] Replica received write
> > request for position 4
> > I0428 20:59:24.974783 15960 master.hpp:596] Removing offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974851 15960 master.cpp:1806] Processing reply for offers:
> > [ 20140428-205924-453759884-46217-15732-0 ] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) for framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.974926 15960 master.hpp:558] Adding task 1 with resources
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974983 15960 master.cpp:2919] Launching task 1 of framework
> > 20140428-205924-453759884-46217-15732-0000 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.975106 15964 slave.cpp:905] Got assigned task 1 for
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.975277 15964 slave.cpp:1015] Launching task 1 for framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976796 15964 slave.cpp:1125] Queuing task '1' for executor
> > 1 of framework '20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976812 15960 external_containerizer.cpp:266] Launching
> > container 'cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976842 15964 slave.cpp:486] Successfully attached file
> > '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/slaves/20140428-205924-453759884-46217-15732-0/frameworks/20140428-205924-453759884-46217-15732-0000/executors/1/runs/cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976888 15960 external_containerizer.cpp:804] Invoking
> > external containerizer for method 'launch'
> > I0428 20:59:24.976913 15960 external_containerizer.cpp:818] user: jenkins
> > I0428 20:59:24.988150 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 14.136354ms
> > I0428 20:59:24.988204 15970 replica.cpp:664] Persisted action at 4
> > I0428 20:59:24.991509 15954 replica.cpp:643] Replica received learned
> > notice for position 4
> > I0428 20:59:25.004228 15954 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 12.701325ms
> > I0428 20:59:25.004286 15954 leveldb.cpp:399] Deleting ~2 keys from leveldb
> > took 34958ns
> > I0428 20:59:25.004297 15954 replica.cpp:664] Persisted action at 4
> > I0428 20:59:25.004302 15954 replica.cpp:649] Replica learned TRUNCATE
> > action at position 4
> > make[3]: *** [check-local] Broken pipe
> > make[3]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[2]: *** [check-am] Error 2
> > make[2]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[1]: *** [check] Error 2
> > make[1]: Leaving directory
> > `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make: *** [check-recursive] Error 1
> > Build step 'Execute shell' marked build as failure
> >
>
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2097
Posted by Jie Yu <yu...@gmail.com>.
Should be related to
https://issues.apache.org/jira/browse/MESOS-1257
On Mon, Apr 28, 2014 at 3:32 PM, Vinod Kone <vi...@gmail.com> wrote:
> +till
>
> can't seem to figure out what the error is here. @till, mind taking a look?
>
>
> On Mon, Apr 28, 2014 at 1:59 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> >
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2097/changes
> > >
> >
> > Changes:
> >
> > [bmahler] Added count to metric statistics.
> >
> > [benjamin.hindman] [MESOS-1252]: Support ENV MAVEN_HOME on the build.
> >
> > ------------------------------------------
> > [...truncated 5332 lines...]
> > I0428 20:59:24.682000 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.682694 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.683544 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.683954 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.686210 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.687655 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.688208 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.688606 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.689003 15955 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.689481 15977 process.cpp:1013] Socket closed while
> receiving
> > [ OK ] FilesTest.ReadTest (11 ms)
> > [ RUN ] FilesTest.ResolveTest
> > Using temporary directory '/tmp/FilesTest_ResolveTest_OtVcdW'
> > I0428 20:59:24.693207 15963 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.693959 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.694476 15965 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.695181 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.695780 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.696813 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.697413 15972 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.698425 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.699270 15976 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.700206 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.700775 15957 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.701326 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.702167 15959 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.702430 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.703665 15970 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.704807 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.705673 15967 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.705952 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.706401 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/read.json'
> > I0428 20:59:24.707334 15977 process.cpp:1013] Socket closed while
> receiving
> > [ OK ] FilesTest.ResolveTest (18 ms)
> > [ RUN ] FilesTest.BrowseTest
> > Using temporary directory '/tmp/FilesTest_BrowseTest_09PycP'
> > I0428 20:59:24.710582 15958 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.711107 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.712327 15975 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.713183 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.713877 15953 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.714687 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.715458 15964 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.716001 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.717205 15968 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/browse.json'
> > I0428 20:59:24.718169 15977 process.cpp:1013] Socket closed while
> receiving
> > [ OK ] FilesTest.BrowseTest (11 ms)
> > [ RUN ] FilesTest.DownloadTest
> > Using temporary directory '/tmp/FilesTest_DownloadTest_YE82dI'
> > I0428 20:59:24.721535 15960 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.722095 15975 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/binary' with length 17
> > I0428 20:59:24.722409 15977 process.cpp:1013] Socket closed while
> receiving
> > I0428 20:59:24.723152 15961 process.cpp:3201] Handling HTTP event for
> > process 'files' with path: '/files/download.json'
> > I0428 20:59:24.724043 15961 process.cpp:1746] Sending file at
> > '/tmp/FilesTest_DownloadTest_YE82dI/black.gif' with length 42
> > I0428 20:59:24.724460 15977 process.cpp:1013] Socket closed while
> receiving
> > [ OK ] FilesTest.DownloadTest (6 ms)
> > [ RUN ] FilesTest.AttachTest
> > Using temporary directory '/tmp/FilesTest_AttachTest_rofKgB'
> > [ OK ] FilesTest.AttachTest (7 ms)
> > [----------] 6 tests from FilesTest (55 ms total)
> >
> > [----------] 1 test from ExternalContainerizerTest
> > [ RUN ] ExternalContainerizerTest.Launch
> > I0428 20:59:24.772775 15732 leveldb.cpp:174] Opened db in 39.638232ms
> > I0428 20:59:24.785150 15732 leveldb.cpp:181] Compacted db in 12.344983ms
> > I0428 20:59:24.785184 15732 leveldb.cpp:196] Created db iterator in
> 3296ns
> > I0428 20:59:24.785197 15732 leveldb.cpp:202] Seeked to beginning of db in
> > 455ns
> > I0428 20:59:24.785202 15732 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 127ns
> > I0428 20:59:24.785215 15732 replica.cpp:729] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0428 20:59:24.785486 15970 recover.cpp:425] Starting replica recovery
> > I0428 20:59:24.785936 15957 master.cpp:266] Master
> > 20140428-205924-453759884-46217-15732 (hemera.apache.org) started on
> > 140.211.11.27:46217
> > I0428 20:59:24.785960 15957 master.cpp:303] Master only allowing
> > authenticated frameworks to register
> > I0428 20:59:24.785967 15957 master.cpp:308] Master only allowing
> > authenticated slaves to register
> > I0428 20:59:24.785974 15957 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.786023 15957 credentials.hpp:48] Failed to stat
> credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_NEMSku/credentials':
> No
> > such file or directory
> > I0428 20:59:24.786319 15965 hierarchical_allocator_process.hpp:302]
> > Initializing hierarchical allocator process with master :
> > master@140.211.11.27:46217
> > I0428 20:59:24.786321 15964 master.cpp:104] No whitelist given.
> > Advertising offers for all slaves
> > I0428 20:59:24.786841 15953 recover.cpp:451] Replica is in EMPTY status
> > I0428 20:59:24.786959 15957 master.cpp:922] The newly elected leader is
> > master@140.211.11.27:46217 with id 20140428-205924-453759884-46217-15732
> > I0428 20:59:24.786977 15957 master.cpp:932] Elected as the leading
> master!
> > I0428 20:59:24.786984 15957 master.cpp:753] Recovering from registrar
> > I0428 20:59:24.787045 15954 registrar.cpp:275] Recovering registrar
> > I0428 20:59:24.789015 15962 replica.cpp:626] Replica in EMPTY status
> > received a broadcasted recover request
> > I0428 20:59:24.789623 15954 recover.cpp:188] Received a recover response
> > from a replica in EMPTY status
> > I0428 20:59:24.790539 15955 recover.cpp:542] Updating replica status to
> > STARTING
> > I0428 20:59:24.801323 15954 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 10.406883ms
> > I0428 20:59:24.801355 15954 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0428 20:59:24.801453 15954 recover.cpp:451] Replica is in STARTING
> status
> > I0428 20:59:24.802309 15969 replica.cpp:626] Replica in STARTING status
> > received a broadcasted recover request
> > I0428 20:59:24.802391 15964 recover.cpp:188] Received a recover response
> > from a replica in STARTING status
> > I0428 20:59:24.802681 15954 recover.cpp:542] Updating replica status to
> > VOTING
> > I0428 20:59:24.813487 15963 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 10.134698ms
> > I0428 20:59:24.813516 15963 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0428 20:59:24.813585 15963 recover.cpp:556] Successfully joined the
> Paxos
> > group
> > I0428 20:59:24.813649 15963 recover.cpp:440] Recover process terminated
> > I0428 20:59:24.813904 15963 log.cpp:656] Attempting to start the writer
> > I0428 20:59:24.815146 15958 replica.cpp:474] Replica received implicit
> > promise request with proposal 1
> > I0428 20:59:24.825553 15958 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 10.387839ms
> > I0428 20:59:24.825580 15958 replica.cpp:342] Persisted promised to 1
> > I0428 20:59:24.826100 15972 coordinator.cpp:229] Coordinator attemping to
> > fill missing position
> > I0428 20:59:24.827474 15957 replica.cpp:375] Replica received explicit
> > promise request for position 0 with proposal 2
> > I0428 20:59:24.841668 15957 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 14.170623ms
> > I0428 20:59:24.841699 15957 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.843376 15968 replica.cpp:508] Replica received write
> > request for position 0
> > I0428 20:59:24.843410 15968 leveldb.cpp:436] Reading position from
> leveldb
> > took 11625ns
> > I0428 20:59:24.858222 15968 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 14.794701ms
> > I0428 20:59:24.858254 15968 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.858547 15961 replica.cpp:643] Replica received learned
> > notice for position 0
> > I0428 20:59:24.870362 15961 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 11.789972ms
> > I0428 20:59:24.870393 15961 replica.cpp:664] Persisted action at 0
> > I0428 20:59:24.870404 15961 replica.cpp:649] Replica learned NOP action
> at
> > position 0
> > I0428 20:59:24.871217 15956 log.cpp:672] Writer started with ending
> > position 0
> > I0428 20:59:24.872596 15971 leveldb.cpp:436] Reading position from
> leveldb
> > took 14921ns
> > I0428 20:59:24.873814 15955 registrar.cpp:308] Successfully recovered
> > registrar
> > I0428 20:59:24.873834 15955 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.875111 15966 log.cpp:680] Attempting to append 138 bytes
> to
> > the log
> > I0428 20:59:24.875331 15957 coordinator.cpp:339] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0428 20:59:24.876457 15958 replica.cpp:508] Replica received write
> > request for position 1
> > I0428 20:59:24.890455 15958 leveldb.cpp:341] Persisting action (157
> bytes)
> > to leveldb took 13.858394ms
> > I0428 20:59:24.890476 15958 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.891136 15974 replica.cpp:643] Replica received learned
> > notice for position 1
> > I0428 20:59:24.906605 15974 leveldb.cpp:341] Persisting action (159
> bytes)
> > to leveldb took 15.443876ms
> > I0428 20:59:24.906637 15974 replica.cpp:664] Persisted action at 1
> > I0428 20:59:24.906649 15974 replica.cpp:649] Replica learned APPEND
> action
> > at position 1
> > I0428 20:59:24.907068 15974 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.907209 15971 log.cpp:699] Attempting to truncate the log
> to
> > 1
> > I0428 20:59:24.907500 15971 coordinator.cpp:339] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0428 20:59:24.909026 15971 master.cpp:780] Recovered 0 slaves from the
> > Registry (100B) ; allowing 10mins for slaves to re-register
> > I0428 20:59:24.909487 15970 replica.cpp:508] Replica received write
> > request for position 2
> > I0428 20:59:24.912192 15971 slave.cpp:140] Slave started on 14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.912210 15971 credentials.hpp:35] Loading credentials for
> > authentication
> > W0428 20:59:24.912390 15971 credentials.hpp:48] Failed to stat
> credentials
> > file 'file:///tmp/ExternalContainerizerTest_Launch_Xlp4Xn/credential': No
> > such file or directory
> > I0428 20:59:24.912412 15971 slave.cpp:231] Slave using credential for:
> > test-principal
> > I0428 20:59:24.912499 15971 slave.cpp:244] Slave resources: cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.912636 15971 slave.cpp:272] Slave hostname:
> > hemera.apache.org
> > I0428 20:59:24.912662 15971 slave.cpp:273] Slave checkpoint: false
> > I0428 20:59:24.913218 15971 state.cpp:33] Recovering state from
> > '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/meta'
> > I0428 20:59:24.913355 15966 status_update_manager.cpp:193] Recovering
> > status update manager
> > I0428 20:59:24.913879 15966 slave.cpp:2943] Finished recovery
> > I0428 20:59:24.914572 15732 sched.cpp:121] Version: 0.19.0
> > I0428 20:59:24.914970 15955 sched.cpp:217] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.915102 15955 sched.cpp:268] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.915230 15954 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.915446 15954 master.cpp:2795] Authenticating
> scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.915745 15969 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.916017 15969 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.916031 15969 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.916050 15969 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.916157 15969 authenticator.hpp:342] Authentication
> requires
> > more steps
> > I0428 20:59:24.916192 15969 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.916241 15969 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.916254 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.916260 15969 auxprop.cpp:153] Looking up auxiliary
> property
> > '*userPassword'
> > I0428 20:59:24.916266 15969 auxprop.cpp:153] Looking up auxiliary
> property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.916272 15969 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.916276 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916280 15969 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.916288 15969 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.916367 15953 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.916576 15963 master.cpp:2835] Successfully authenticated
> > scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916590 15956 sched.cpp:342] Successfully authenticated
> with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.916671 15956 sched.cpp:461] Sending registration request
> to
> > master@140.211.11.27:46217
> > I0428 20:59:24.916857 15963 master.cpp:981] Received registration request
> > from scheduler(11)@140.211.11.27:46217
> > I0428 20:59:24.916887 15963 master.cpp:999] Registering framework
> > 20140428-205924-453759884-46217-15732-0000 at scheduler(11)@
> > 140.211.11.27:46217
> > I0428 20:59:24.917032 15974 sched.cpp:392] Framework registered with
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917067 15963 hierarchical_allocator_process.hpp:332] Added
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.917083 15963 hierarchical_allocator_process.hpp:726] No
> > resources available to allocate!
> > I0428 20:59:24.917093 15963 hierarchical_allocator_process.hpp:688]
> > Performed allocation for 0 slaves in 10385ns
> > I0428 20:59:24.917156 15974 sched.cpp:406] Scheduler::registered took
> > 104111ns
> > I0428 20:59:24.918953 15966 slave.cpp:525] New master detected at
> > master@140.211.11.27:46217
> > I0428 20:59:24.918984 15966 slave.cpp:585] Authenticating with master
> > master@140.211.11.27:46217
> > I0428 20:59:24.919020 15954 status_update_manager.cpp:167] New master
> > detected at master@140.211.11.27:46217
> > I0428 20:59:24.919047 15961 authenticatee.hpp:128] Creating new client
> > SASL connection
> > I0428 20:59:24.919028 15966 slave.cpp:558] Detecting new master
> > I0428 20:59:24.919312 15968 master.cpp:2795] Authenticating slave(14)@
> > 140.211.11.27:46217
> > I0428 20:59:24.919371 15968 authenticator.hpp:148] Creating new server
> > SASL connection
> > I0428 20:59:24.919842 15955 authenticatee.hpp:219] Received SASL
> > authentication mechanisms: CRAM-MD5
> > I0428 20:59:24.919857 15955 authenticatee.hpp:245] Attempting to
> > authenticate with mechanism 'CRAM-MD5'
> > I0428 20:59:24.919914 15955 authenticator.hpp:254] Received SASL
> > authentication start
> > I0428 20:59:24.919999 15955 authenticator.hpp:342] Authentication
> requires
> > more steps
> > I0428 20:59:24.920488 15973 authenticatee.hpp:265] Received SASL
> > authentication step
> > I0428 20:59:24.920598 15973 authenticator.hpp:282] Received SASL
> > authentication step
> > I0428 20:59:24.920613 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> > I0428 20:59:24.920617 15973 auxprop.cpp:153] Looking up auxiliary
> property
> > '*userPassword'
> > I0428 20:59:24.920624 15973 auxprop.cpp:153] Looking up auxiliary
> property
> > '*cmusaslsecretCRAM-MD5'
> > I0428 20:59:24.920629 15973 auxprop.cpp:81] Request to lookup properties
> > for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> > hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> > I0428 20:59:24.920632 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*userPassword' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920635 15973 auxprop.cpp:103] Skipping auxiliary property
> > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> > I0428 20:59:24.920642 15973 authenticator.hpp:334] Authentication success
> > I0428 20:59:24.920753 15973 authenticatee.hpp:305] Authentication success
> > I0428 20:59:24.920769 15955 master.cpp:2835] Successfully authenticated
> > slave(14)@140.211.11.27:46217
> > I0428 20:59:24.921393 15976 slave.cpp:642] Successfully authenticated
> with
> > master master@140.211.11.27:46217
> > I0428 20:59:24.921447 15976 slave.cpp:871] Will retry registration in
> > 6.085179816secs if necessary
> > I0428 20:59:24.921664 15953 registrar.cpp:379] Attempting to update the
> > 'registry'
> > I0428 20:59:24.922801 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 13.290713ms
> > I0428 20:59:24.922821 15970 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.923069 15968 replica.cpp:643] Replica received learned
> > notice for position 2
> > I0428 20:59:24.939198 15968 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 16.114121ms
> > I0428 20:59:24.939267 15968 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 47686ns
> > I0428 20:59:24.939277 15968 replica.cpp:664] Persisted action at 2
> > I0428 20:59:24.939283 15968 replica.cpp:649] Replica learned TRUNCATE
> > action at position 2
> > I0428 20:59:24.939585 15974 log.cpp:680] Attempting to append 332 bytes
> to
> > the log
> > I0428 20:59:24.939746 15975 coordinator.cpp:339] Coordinator attempting
> to
> > write APPEND action at position 3
> > I0428 20:59:24.941287 15958 replica.cpp:508] Replica received write
> > request for position 3
> > I0428 20:59:24.955303 15958 leveldb.cpp:341] Persisting action (351
> bytes)
> > to leveldb took 14.000606ms
> > I0428 20:59:24.955324 15958 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.956228 15957 replica.cpp:643] Replica received learned
> > notice for position 3
> > I0428 20:59:24.971446 15957 leveldb.cpp:341] Persisting action (353
> bytes)
> > to leveldb took 15.190795ms
> > I0428 20:59:24.971477 15957 replica.cpp:664] Persisted action at 3
> > I0428 20:59:24.971489 15957 replica.cpp:649] Replica learned APPEND
> action
> > at position 3
> > I0428 20:59:24.971849 15976 registrar.cpp:427] Successfully updated
> > 'registry'
> > I0428 20:59:24.972170 15974 master.cpp:2169] Admitted slave on
> > hemera.apache.org at slave(14)@140.211.11.27:46217
> > I0428 20:59:24.972194 15974 master.cpp:3283] Adding slave
> > 20140428-205924-453759884-46217-15732-0 at hemera.apache.org with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> > I0428 20:59:24.972244 15967 log.cpp:699] Attempting to truncate the log
> to
> > 3
> > I0428 20:59:24.972283 15959 slave.cpp:675] Registered with master
> > master@140.211.11.27:46217; given slave ID
> > 20140428-205924-453759884-46217-15732-0
> > I0428 20:59:24.972452 15972 hierarchical_allocator_process.hpp:445] Added
> > slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) with
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> > I0428 20:59:24.972508 15971 coordinator.cpp:339] Coordinator attempting
> to
> > write TRUNCATE action at position 4
> > I0428 20:59:24.972529 15972 hierarchical_allocator_process.hpp:752]
> > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> > slave 20140428-205924-453759884-46217-15732-0 to framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972769 15972 hierarchical_allocator_process.hpp:708]
> > Performed allocation for slave 20140428-205924-453759884-46217-15732-0 in
> > 267569ns
> > I0428 20:59:24.972786 15955 master.hpp:586] Adding offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.972829 15955 master.cpp:2744] Sending 1 offers to
> framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.972977 15955 sched.cpp:529] Scheduler::resourceOffers took
> > 49221ns
> > I0428 20:59:24.973989 15970 replica.cpp:508] Replica received write
> > request for position 4
> > I0428 20:59:24.974783 15960 master.hpp:596] Removing offer
> > 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974851 15960 master.cpp:1806] Processing reply for offers:
> > [ 20140428-205924-453759884-46217-15732-0 ] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) for
> framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.974926 15960 master.hpp:558] Adding task 1 with resources
> > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.974983 15960 master.cpp:2919] Launching task 1 of
> framework
> > 20140428-205924-453759884-46217-15732-0000 with resources cpus(*):2;
> > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> > 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> > I0428 20:59:24.975106 15964 slave.cpp:905] Got assigned task 1 for
> > framework 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.975277 15964 slave.cpp:1015] Launching task 1 for
> framework
> > 20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976796 15964 slave.cpp:1125] Queuing task '1' for executor
> > 1 of framework '20140428-205924-453759884-46217-15732-0000
> > I0428 20:59:24.976812 15960 external_containerizer.cpp:266] Launching
> > container 'cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976842 15964 slave.cpp:486] Successfully attached file
> >
> '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/slaves/20140428-205924-453759884-46217-15732-0/frameworks/20140428-205924-453759884-46217-15732-0000/executors/1/runs/cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> > I0428 20:59:24.976888 15960 external_containerizer.cpp:804] Invoking
> > external containerizer for method 'launch'
> > I0428 20:59:24.976913 15960 external_containerizer.cpp:818] user: jenkins
> > I0428 20:59:24.988150 15970 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 14.136354ms
> > I0428 20:59:24.988204 15970 replica.cpp:664] Persisted action at 4
> > I0428 20:59:24.991509 15954 replica.cpp:643] Replica received learned
> > notice for position 4
> > I0428 20:59:25.004228 15954 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 12.701325ms
> > I0428 20:59:25.004286 15954 leveldb.cpp:399] Deleting ~2 keys from
> leveldb
> > took 34958ns
> > I0428 20:59:25.004297 15954 replica.cpp:664] Persisted action at 4
> > I0428 20:59:25.004302 15954 replica.cpp:649] Replica learned TRUNCATE
> > action at position 4
> > make[3]: *** [check-local] Broken pipe
> > make[3]: Leaving directory
> >
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[2]: *** [check-am] Error 2
> > make[2]: Leaving directory
> >
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make[1]: *** [check] Error 2
> > make[1]: Leaving directory
> >
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> > make: *** [check-recursive] Error 1
> > Build step 'Execute shell' marked build as failure
> >
>
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2097
Posted by Vinod Kone <vi...@gmail.com>.
+till
can't seem to figure out what the error is here. @till, mind taking a look?
On Mon, Apr 28, 2014 at 1:59 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2097/changes
> >
>
> Changes:
>
> [bmahler] Added count to metric statistics.
>
> [benjamin.hindman] [MESOS-1252]: Support ENV MAVEN_HOME on the build.
>
> ------------------------------------------
> [...truncated 5332 lines...]
> I0428 20:59:24.682000 15960 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.682694 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.683544 15959 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.683954 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.686210 15961 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.687655 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.688208 15953 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.688606 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.689003 15955 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.689481 15977 process.cpp:1013] Socket closed while receiving
> [ OK ] FilesTest.ReadTest (11 ms)
> [ RUN ] FilesTest.ResolveTest
> Using temporary directory '/tmp/FilesTest_ResolveTest_OtVcdW'
> I0428 20:59:24.693207 15963 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.693959 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.694476 15965 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.695181 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.695780 15976 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.696813 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.697413 15972 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.698425 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.699270 15976 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.700206 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.700775 15957 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.701326 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.702167 15959 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.702430 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.703665 15970 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.704807 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.705673 15967 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.705952 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.706401 15960 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/read.json'
> I0428 20:59:24.707334 15977 process.cpp:1013] Socket closed while receiving
> [ OK ] FilesTest.ResolveTest (18 ms)
> [ RUN ] FilesTest.BrowseTest
> Using temporary directory '/tmp/FilesTest_BrowseTest_09PycP'
> I0428 20:59:24.710582 15958 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0428 20:59:24.711107 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.712327 15975 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0428 20:59:24.713183 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.713877 15953 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0428 20:59:24.714687 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.715458 15964 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0428 20:59:24.716001 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.717205 15968 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/browse.json'
> I0428 20:59:24.718169 15977 process.cpp:1013] Socket closed while receiving
> [ OK ] FilesTest.BrowseTest (11 ms)
> [ RUN ] FilesTest.DownloadTest
> Using temporary directory '/tmp/FilesTest_DownloadTest_YE82dI'
> I0428 20:59:24.721535 15960 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/download.json'
> I0428 20:59:24.722095 15975 process.cpp:1746] Sending file at
> '/tmp/FilesTest_DownloadTest_YE82dI/binary' with length 17
> I0428 20:59:24.722409 15977 process.cpp:1013] Socket closed while receiving
> I0428 20:59:24.723152 15961 process.cpp:3201] Handling HTTP event for
> process 'files' with path: '/files/download.json'
> I0428 20:59:24.724043 15961 process.cpp:1746] Sending file at
> '/tmp/FilesTest_DownloadTest_YE82dI/black.gif' with length 42
> I0428 20:59:24.724460 15977 process.cpp:1013] Socket closed while receiving
> [ OK ] FilesTest.DownloadTest (6 ms)
> [ RUN ] FilesTest.AttachTest
> Using temporary directory '/tmp/FilesTest_AttachTest_rofKgB'
> [ OK ] FilesTest.AttachTest (7 ms)
> [----------] 6 tests from FilesTest (55 ms total)
>
> [----------] 1 test from ExternalContainerizerTest
> [ RUN ] ExternalContainerizerTest.Launch
> I0428 20:59:24.772775 15732 leveldb.cpp:174] Opened db in 39.638232ms
> I0428 20:59:24.785150 15732 leveldb.cpp:181] Compacted db in 12.344983ms
> I0428 20:59:24.785184 15732 leveldb.cpp:196] Created db iterator in 3296ns
> I0428 20:59:24.785197 15732 leveldb.cpp:202] Seeked to beginning of db in
> 455ns
> I0428 20:59:24.785202 15732 leveldb.cpp:271] Iterated through 0 keys in
> the db in 127ns
> I0428 20:59:24.785215 15732 replica.cpp:729] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0428 20:59:24.785486 15970 recover.cpp:425] Starting replica recovery
> I0428 20:59:24.785936 15957 master.cpp:266] Master
> 20140428-205924-453759884-46217-15732 (hemera.apache.org) started on
> 140.211.11.27:46217
> I0428 20:59:24.785960 15957 master.cpp:303] Master only allowing
> authenticated frameworks to register
> I0428 20:59:24.785967 15957 master.cpp:308] Master only allowing
> authenticated slaves to register
> I0428 20:59:24.785974 15957 credentials.hpp:35] Loading credentials for
> authentication
> W0428 20:59:24.786023 15957 credentials.hpp:48] Failed to stat credentials
> file 'file:///tmp/ExternalContainerizerTest_Launch_NEMSku/credentials': No
> such file or directory
> I0428 20:59:24.786319 15965 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> master@140.211.11.27:46217
> I0428 20:59:24.786321 15964 master.cpp:104] No whitelist given.
> Advertising offers for all slaves
> I0428 20:59:24.786841 15953 recover.cpp:451] Replica is in EMPTY status
> I0428 20:59:24.786959 15957 master.cpp:922] The newly elected leader is
> master@140.211.11.27:46217 with id 20140428-205924-453759884-46217-15732
> I0428 20:59:24.786977 15957 master.cpp:932] Elected as the leading master!
> I0428 20:59:24.786984 15957 master.cpp:753] Recovering from registrar
> I0428 20:59:24.787045 15954 registrar.cpp:275] Recovering registrar
> I0428 20:59:24.789015 15962 replica.cpp:626] Replica in EMPTY status
> received a broadcasted recover request
> I0428 20:59:24.789623 15954 recover.cpp:188] Received a recover response
> from a replica in EMPTY status
> I0428 20:59:24.790539 15955 recover.cpp:542] Updating replica status to
> STARTING
> I0428 20:59:24.801323 15954 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 10.406883ms
> I0428 20:59:24.801355 15954 replica.cpp:320] Persisted replica status to
> STARTING
> I0428 20:59:24.801453 15954 recover.cpp:451] Replica is in STARTING status
> I0428 20:59:24.802309 15969 replica.cpp:626] Replica in STARTING status
> received a broadcasted recover request
> I0428 20:59:24.802391 15964 recover.cpp:188] Received a recover response
> from a replica in STARTING status
> I0428 20:59:24.802681 15954 recover.cpp:542] Updating replica status to
> VOTING
> I0428 20:59:24.813487 15963 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 10.134698ms
> I0428 20:59:24.813516 15963 replica.cpp:320] Persisted replica status to
> VOTING
> I0428 20:59:24.813585 15963 recover.cpp:556] Successfully joined the Paxos
> group
> I0428 20:59:24.813649 15963 recover.cpp:440] Recover process terminated
> I0428 20:59:24.813904 15963 log.cpp:656] Attempting to start the writer
> I0428 20:59:24.815146 15958 replica.cpp:474] Replica received implicit
> promise request with proposal 1
> I0428 20:59:24.825553 15958 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 10.387839ms
> I0428 20:59:24.825580 15958 replica.cpp:342] Persisted promised to 1
> I0428 20:59:24.826100 15972 coordinator.cpp:229] Coordinator attemping to
> fill missing position
> I0428 20:59:24.827474 15957 replica.cpp:375] Replica received explicit
> promise request for position 0 with proposal 2
> I0428 20:59:24.841668 15957 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 14.170623ms
> I0428 20:59:24.841699 15957 replica.cpp:664] Persisted action at 0
> I0428 20:59:24.843376 15968 replica.cpp:508] Replica received write
> request for position 0
> I0428 20:59:24.843410 15968 leveldb.cpp:436] Reading position from leveldb
> took 11625ns
> I0428 20:59:24.858222 15968 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 14.794701ms
> I0428 20:59:24.858254 15968 replica.cpp:664] Persisted action at 0
> I0428 20:59:24.858547 15961 replica.cpp:643] Replica received learned
> notice for position 0
> I0428 20:59:24.870362 15961 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 11.789972ms
> I0428 20:59:24.870393 15961 replica.cpp:664] Persisted action at 0
> I0428 20:59:24.870404 15961 replica.cpp:649] Replica learned NOP action at
> position 0
> I0428 20:59:24.871217 15956 log.cpp:672] Writer started with ending
> position 0
> I0428 20:59:24.872596 15971 leveldb.cpp:436] Reading position from leveldb
> took 14921ns
> I0428 20:59:24.873814 15955 registrar.cpp:308] Successfully recovered
> registrar
> I0428 20:59:24.873834 15955 registrar.cpp:379] Attempting to update the
> 'registry'
> I0428 20:59:24.875111 15966 log.cpp:680] Attempting to append 138 bytes to
> the log
> I0428 20:59:24.875331 15957 coordinator.cpp:339] Coordinator attempting to
> write APPEND action at position 1
> I0428 20:59:24.876457 15958 replica.cpp:508] Replica received write
> request for position 1
> I0428 20:59:24.890455 15958 leveldb.cpp:341] Persisting action (157 bytes)
> to leveldb took 13.858394ms
> I0428 20:59:24.890476 15958 replica.cpp:664] Persisted action at 1
> I0428 20:59:24.891136 15974 replica.cpp:643] Replica received learned
> notice for position 1
> I0428 20:59:24.906605 15974 leveldb.cpp:341] Persisting action (159 bytes)
> to leveldb took 15.443876ms
> I0428 20:59:24.906637 15974 replica.cpp:664] Persisted action at 1
> I0428 20:59:24.906649 15974 replica.cpp:649] Replica learned APPEND action
> at position 1
> I0428 20:59:24.907068 15974 registrar.cpp:427] Successfully updated
> 'registry'
> I0428 20:59:24.907209 15971 log.cpp:699] Attempting to truncate the log to
> 1
> I0428 20:59:24.907500 15971 coordinator.cpp:339] Coordinator attempting to
> write TRUNCATE action at position 2
> I0428 20:59:24.909026 15971 master.cpp:780] Recovered 0 slaves from the
> Registry (100B) ; allowing 10mins for slaves to re-register
> I0428 20:59:24.909487 15970 replica.cpp:508] Replica received write
> request for position 2
> I0428 20:59:24.912192 15971 slave.cpp:140] Slave started on 14)@
> 140.211.11.27:46217
> I0428 20:59:24.912210 15971 credentials.hpp:35] Loading credentials for
> authentication
> W0428 20:59:24.912390 15971 credentials.hpp:48] Failed to stat credentials
> file 'file:///tmp/ExternalContainerizerTest_Launch_Xlp4Xn/credential': No
> such file or directory
> I0428 20:59:24.912412 15971 slave.cpp:231] Slave using credential for:
> test-principal
> I0428 20:59:24.912499 15971 slave.cpp:244] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0428 20:59:24.912636 15971 slave.cpp:272] Slave hostname:
> hemera.apache.org
> I0428 20:59:24.912662 15971 slave.cpp:273] Slave checkpoint: false
> I0428 20:59:24.913218 15971 state.cpp:33] Recovering state from
> '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/meta'
> I0428 20:59:24.913355 15966 status_update_manager.cpp:193] Recovering
> status update manager
> I0428 20:59:24.913879 15966 slave.cpp:2943] Finished recovery
> I0428 20:59:24.914572 15732 sched.cpp:121] Version: 0.19.0
> I0428 20:59:24.914970 15955 sched.cpp:217] New master detected at
> master@140.211.11.27:46217
> I0428 20:59:24.915102 15955 sched.cpp:268] Authenticating with master
> master@140.211.11.27:46217
> I0428 20:59:24.915230 15954 authenticatee.hpp:128] Creating new client
> SASL connection
> I0428 20:59:24.915446 15954 master.cpp:2795] Authenticating scheduler(11)@
> 140.211.11.27:46217
> I0428 20:59:24.915745 15969 authenticator.hpp:148] Creating new server
> SASL connection
> I0428 20:59:24.916017 15969 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0428 20:59:24.916031 15969 authenticatee.hpp:245] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0428 20:59:24.916050 15969 authenticator.hpp:254] Received SASL
> authentication start
> I0428 20:59:24.916157 15969 authenticator.hpp:342] Authentication requires
> more steps
> I0428 20:59:24.916192 15969 authenticatee.hpp:265] Received SASL
> authentication step
> I0428 20:59:24.916241 15969 authenticator.hpp:282] Received SASL
> authentication step
> I0428 20:59:24.916254 15969 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0428 20:59:24.916260 15969 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0428 20:59:24.916266 15969 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0428 20:59:24.916272 15969 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0428 20:59:24.916276 15969 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0428 20:59:24.916280 15969 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0428 20:59:24.916288 15969 authenticator.hpp:334] Authentication success
> I0428 20:59:24.916367 15953 authenticatee.hpp:305] Authentication success
> I0428 20:59:24.916576 15963 master.cpp:2835] Successfully authenticated
> scheduler(11)@140.211.11.27:46217
> I0428 20:59:24.916590 15956 sched.cpp:342] Successfully authenticated with
> master master@140.211.11.27:46217
> I0428 20:59:24.916671 15956 sched.cpp:461] Sending registration request to
> master@140.211.11.27:46217
> I0428 20:59:24.916857 15963 master.cpp:981] Received registration request
> from scheduler(11)@140.211.11.27:46217
> I0428 20:59:24.916887 15963 master.cpp:999] Registering framework
> 20140428-205924-453759884-46217-15732-0000 at scheduler(11)@
> 140.211.11.27:46217
> I0428 20:59:24.917032 15974 sched.cpp:392] Framework registered with
> 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.917067 15963 hierarchical_allocator_process.hpp:332] Added
> framework 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.917083 15963 hierarchical_allocator_process.hpp:726] No
> resources available to allocate!
> I0428 20:59:24.917093 15963 hierarchical_allocator_process.hpp:688]
> Performed allocation for 0 slaves in 10385ns
> I0428 20:59:24.917156 15974 sched.cpp:406] Scheduler::registered took
> 104111ns
> I0428 20:59:24.918953 15966 slave.cpp:525] New master detected at
> master@140.211.11.27:46217
> I0428 20:59:24.918984 15966 slave.cpp:585] Authenticating with master
> master@140.211.11.27:46217
> I0428 20:59:24.919020 15954 status_update_manager.cpp:167] New master
> detected at master@140.211.11.27:46217
> I0428 20:59:24.919047 15961 authenticatee.hpp:128] Creating new client
> SASL connection
> I0428 20:59:24.919028 15966 slave.cpp:558] Detecting new master
> I0428 20:59:24.919312 15968 master.cpp:2795] Authenticating slave(14)@
> 140.211.11.27:46217
> I0428 20:59:24.919371 15968 authenticator.hpp:148] Creating new server
> SASL connection
> I0428 20:59:24.919842 15955 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0428 20:59:24.919857 15955 authenticatee.hpp:245] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0428 20:59:24.919914 15955 authenticator.hpp:254] Received SASL
> authentication start
> I0428 20:59:24.919999 15955 authenticator.hpp:342] Authentication requires
> more steps
> I0428 20:59:24.920488 15973 authenticatee.hpp:265] Received SASL
> authentication step
> I0428 20:59:24.920598 15973 authenticator.hpp:282] Received SASL
> authentication step
> I0428 20:59:24.920613 15973 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0428 20:59:24.920617 15973 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0428 20:59:24.920624 15973 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0428 20:59:24.920629 15973 auxprop.cpp:81] Request to lookup properties
> for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: '
> hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0428 20:59:24.920632 15973 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0428 20:59:24.920635 15973 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0428 20:59:24.920642 15973 authenticator.hpp:334] Authentication success
> I0428 20:59:24.920753 15973 authenticatee.hpp:305] Authentication success
> I0428 20:59:24.920769 15955 master.cpp:2835] Successfully authenticated
> slave(14)@140.211.11.27:46217
> I0428 20:59:24.921393 15976 slave.cpp:642] Successfully authenticated with
> master master@140.211.11.27:46217
> I0428 20:59:24.921447 15976 slave.cpp:871] Will retry registration in
> 6.085179816secs if necessary
> I0428 20:59:24.921664 15953 registrar.cpp:379] Attempting to update the
> 'registry'
> I0428 20:59:24.922801 15970 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 13.290713ms
> I0428 20:59:24.922821 15970 replica.cpp:664] Persisted action at 2
> I0428 20:59:24.923069 15968 replica.cpp:643] Replica received learned
> notice for position 2
> I0428 20:59:24.939198 15968 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 16.114121ms
> I0428 20:59:24.939267 15968 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 47686ns
> I0428 20:59:24.939277 15968 replica.cpp:664] Persisted action at 2
> I0428 20:59:24.939283 15968 replica.cpp:649] Replica learned TRUNCATE
> action at position 2
> I0428 20:59:24.939585 15974 log.cpp:680] Attempting to append 332 bytes to
> the log
> I0428 20:59:24.939746 15975 coordinator.cpp:339] Coordinator attempting to
> write APPEND action at position 3
> I0428 20:59:24.941287 15958 replica.cpp:508] Replica received write
> request for position 3
> I0428 20:59:24.955303 15958 leveldb.cpp:341] Persisting action (351 bytes)
> to leveldb took 14.000606ms
> I0428 20:59:24.955324 15958 replica.cpp:664] Persisted action at 3
> I0428 20:59:24.956228 15957 replica.cpp:643] Replica received learned
> notice for position 3
> I0428 20:59:24.971446 15957 leveldb.cpp:341] Persisting action (353 bytes)
> to leveldb took 15.190795ms
> I0428 20:59:24.971477 15957 replica.cpp:664] Persisted action at 3
> I0428 20:59:24.971489 15957 replica.cpp:649] Replica learned APPEND action
> at position 3
> I0428 20:59:24.971849 15976 registrar.cpp:427] Successfully updated
> 'registry'
> I0428 20:59:24.972170 15974 master.cpp:2169] Admitted slave on
> hemera.apache.org at slave(14)@140.211.11.27:46217
> I0428 20:59:24.972194 15974 master.cpp:3283] Adding slave
> 20140428-205924-453759884-46217-15732-0 at hemera.apache.org with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0428 20:59:24.972244 15967 log.cpp:699] Attempting to truncate the log to
> 3
> I0428 20:59:24.972283 15959 slave.cpp:675] Registered with master
> master@140.211.11.27:46217; given slave ID
> 20140428-205924-453759884-46217-15732-0
> I0428 20:59:24.972452 15972 hierarchical_allocator_process.hpp:445] Added
> slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0428 20:59:24.972508 15971 coordinator.cpp:339] Coordinator attempting to
> write TRUNCATE action at position 4
> I0428 20:59:24.972529 15972 hierarchical_allocator_process.hpp:752]
> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
> slave 20140428-205924-453759884-46217-15732-0 to framework
> 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.972769 15972 hierarchical_allocator_process.hpp:708]
> Performed allocation for slave 20140428-205924-453759884-46217-15732-0 in
> 267569ns
> I0428 20:59:24.972786 15955 master.hpp:586] Adding offer
> 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> I0428 20:59:24.972829 15955 master.cpp:2744] Sending 1 offers to framework
> 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.972977 15955 sched.cpp:529] Scheduler::resourceOffers took
> 49221ns
> I0428 20:59:24.973989 15970 replica.cpp:508] Replica received write
> request for position 4
> I0428 20:59:24.974783 15960 master.hpp:596] Removing offer
> 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> I0428 20:59:24.974851 15960 master.cpp:1806] Processing reply for offers:
> [ 20140428-205924-453759884-46217-15732-0 ] on slave
> 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) for framework
> 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.974926 15960 master.hpp:558] Adding task 1 with resources
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> I0428 20:59:24.974983 15960 master.cpp:2919] Launching task 1 of framework
> 20140428-205924-453759884-46217-15732-0000 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
> I0428 20:59:24.975106 15964 slave.cpp:905] Got assigned task 1 for
> framework 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.975277 15964 slave.cpp:1015] Launching task 1 for framework
> 20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.976796 15964 slave.cpp:1125] Queuing task '1' for executor
> 1 of framework '20140428-205924-453759884-46217-15732-0000
> I0428 20:59:24.976812 15960 external_containerizer.cpp:266] Launching
> container 'cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> I0428 20:59:24.976842 15964 slave.cpp:486] Successfully attached file
> '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/slaves/20140428-205924-453759884-46217-15732-0/frameworks/20140428-205924-453759884-46217-15732-0000/executors/1/runs/cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
> I0428 20:59:24.976888 15960 external_containerizer.cpp:804] Invoking
> external containerizer for method 'launch'
> I0428 20:59:24.976913 15960 external_containerizer.cpp:818] user: jenkins
> I0428 20:59:24.988150 15970 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 14.136354ms
> I0428 20:59:24.988204 15970 replica.cpp:664] Persisted action at 4
> I0428 20:59:24.991509 15954 replica.cpp:643] Replica received learned
> notice for position 4
> I0428 20:59:25.004228 15954 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 12.701325ms
> I0428 20:59:25.004286 15954 leveldb.cpp:399] Deleting ~2 keys from leveldb
> took 34958ns
> I0428 20:59:25.004297 15954 replica.cpp:664] Persisted action at 4
> I0428 20:59:25.004302 15954 replica.cpp:649] Replica learned TRUNCATE
> action at position 4
> make[3]: *** [check-local] Broken pipe
> make[3]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> make[2]: *** [check-am] Error 2
> make[2]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> make[1]: *** [check] Error 2
> make[1]: Leaving directory
> `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
> make: *** [check-recursive] Error 1
> Build step 'Execute shell' marked build as failure
>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2097
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/2097/changes>
Changes:
[bmahler] Added count to metric statistics.
[benjamin.hindman] [MESOS-1252]: Support ENV MAVEN_HOME on the build.
------------------------------------------
[...truncated 5332 lines...]
I0428 20:59:24.682000 15960 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.682694 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.683544 15959 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.683954 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.686210 15961 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.687655 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.688208 15953 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.688606 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.689003 15955 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.689481 15977 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.ReadTest (11 ms)
[ RUN ] FilesTest.ResolveTest
Using temporary directory '/tmp/FilesTest_ResolveTest_OtVcdW'
I0428 20:59:24.693207 15963 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.693959 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.694476 15965 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.695181 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.695780 15976 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.696813 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.697413 15972 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.698425 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.699270 15976 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.700206 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.700775 15957 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.701326 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.702167 15959 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.702430 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.703665 15970 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.704807 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.705673 15967 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.705952 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.706401 15960 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/read.json'
I0428 20:59:24.707334 15977 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.ResolveTest (18 ms)
[ RUN ] FilesTest.BrowseTest
Using temporary directory '/tmp/FilesTest_BrowseTest_09PycP'
I0428 20:59:24.710582 15958 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0428 20:59:24.711107 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.712327 15975 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0428 20:59:24.713183 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.713877 15953 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0428 20:59:24.714687 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.715458 15964 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0428 20:59:24.716001 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.717205 15968 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/browse.json'
I0428 20:59:24.718169 15977 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.BrowseTest (11 ms)
[ RUN ] FilesTest.DownloadTest
Using temporary directory '/tmp/FilesTest_DownloadTest_YE82dI'
I0428 20:59:24.721535 15960 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/download.json'
I0428 20:59:24.722095 15975 process.cpp:1746] Sending file at '/tmp/FilesTest_DownloadTest_YE82dI/binary' with length 17
I0428 20:59:24.722409 15977 process.cpp:1013] Socket closed while receiving
I0428 20:59:24.723152 15961 process.cpp:3201] Handling HTTP event for process 'files' with path: '/files/download.json'
I0428 20:59:24.724043 15961 process.cpp:1746] Sending file at '/tmp/FilesTest_DownloadTest_YE82dI/black.gif' with length 42
I0428 20:59:24.724460 15977 process.cpp:1013] Socket closed while receiving
[ OK ] FilesTest.DownloadTest (6 ms)
[ RUN ] FilesTest.AttachTest
Using temporary directory '/tmp/FilesTest_AttachTest_rofKgB'
[ OK ] FilesTest.AttachTest (7 ms)
[----------] 6 tests from FilesTest (55 ms total)
[----------] 1 test from ExternalContainerizerTest
[ RUN ] ExternalContainerizerTest.Launch
I0428 20:59:24.772775 15732 leveldb.cpp:174] Opened db in 39.638232ms
I0428 20:59:24.785150 15732 leveldb.cpp:181] Compacted db in 12.344983ms
I0428 20:59:24.785184 15732 leveldb.cpp:196] Created db iterator in 3296ns
I0428 20:59:24.785197 15732 leveldb.cpp:202] Seeked to beginning of db in 455ns
I0428 20:59:24.785202 15732 leveldb.cpp:271] Iterated through 0 keys in the db in 127ns
I0428 20:59:24.785215 15732 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0428 20:59:24.785486 15970 recover.cpp:425] Starting replica recovery
I0428 20:59:24.785936 15957 master.cpp:266] Master 20140428-205924-453759884-46217-15732 (hemera.apache.org) started on 140.211.11.27:46217
I0428 20:59:24.785960 15957 master.cpp:303] Master only allowing authenticated frameworks to register
I0428 20:59:24.785967 15957 master.cpp:308] Master only allowing authenticated slaves to register
I0428 20:59:24.785974 15957 credentials.hpp:35] Loading credentials for authentication
W0428 20:59:24.786023 15957 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_NEMSku/credentials': No such file or directory
I0428 20:59:24.786319 15965 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@140.211.11.27:46217
I0428 20:59:24.786321 15964 master.cpp:104] No whitelist given. Advertising offers for all slaves
I0428 20:59:24.786841 15953 recover.cpp:451] Replica is in EMPTY status
I0428 20:59:24.786959 15957 master.cpp:922] The newly elected leader is master@140.211.11.27:46217 with id 20140428-205924-453759884-46217-15732
I0428 20:59:24.786977 15957 master.cpp:932] Elected as the leading master!
I0428 20:59:24.786984 15957 master.cpp:753] Recovering from registrar
I0428 20:59:24.787045 15954 registrar.cpp:275] Recovering registrar
I0428 20:59:24.789015 15962 replica.cpp:626] Replica in EMPTY status received a broadcasted recover request
I0428 20:59:24.789623 15954 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0428 20:59:24.790539 15955 recover.cpp:542] Updating replica status to STARTING
I0428 20:59:24.801323 15954 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 10.406883ms
I0428 20:59:24.801355 15954 replica.cpp:320] Persisted replica status to STARTING
I0428 20:59:24.801453 15954 recover.cpp:451] Replica is in STARTING status
I0428 20:59:24.802309 15969 replica.cpp:626] Replica in STARTING status received a broadcasted recover request
I0428 20:59:24.802391 15964 recover.cpp:188] Received a recover response from a replica in STARTING status
I0428 20:59:24.802681 15954 recover.cpp:542] Updating replica status to VOTING
I0428 20:59:24.813487 15963 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 10.134698ms
I0428 20:59:24.813516 15963 replica.cpp:320] Persisted replica status to VOTING
I0428 20:59:24.813585 15963 recover.cpp:556] Successfully joined the Paxos group
I0428 20:59:24.813649 15963 recover.cpp:440] Recover process terminated
I0428 20:59:24.813904 15963 log.cpp:656] Attempting to start the writer
I0428 20:59:24.815146 15958 replica.cpp:474] Replica received implicit promise request with proposal 1
I0428 20:59:24.825553 15958 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 10.387839ms
I0428 20:59:24.825580 15958 replica.cpp:342] Persisted promised to 1
I0428 20:59:24.826100 15972 coordinator.cpp:229] Coordinator attemping to fill missing position
I0428 20:59:24.827474 15957 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0428 20:59:24.841668 15957 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 14.170623ms
I0428 20:59:24.841699 15957 replica.cpp:664] Persisted action at 0
I0428 20:59:24.843376 15968 replica.cpp:508] Replica received write request for position 0
I0428 20:59:24.843410 15968 leveldb.cpp:436] Reading position from leveldb took 11625ns
I0428 20:59:24.858222 15968 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 14.794701ms
I0428 20:59:24.858254 15968 replica.cpp:664] Persisted action at 0
I0428 20:59:24.858547 15961 replica.cpp:643] Replica received learned notice for position 0
I0428 20:59:24.870362 15961 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 11.789972ms
I0428 20:59:24.870393 15961 replica.cpp:664] Persisted action at 0
I0428 20:59:24.870404 15961 replica.cpp:649] Replica learned NOP action at position 0
I0428 20:59:24.871217 15956 log.cpp:672] Writer started with ending position 0
I0428 20:59:24.872596 15971 leveldb.cpp:436] Reading position from leveldb took 14921ns
I0428 20:59:24.873814 15955 registrar.cpp:308] Successfully recovered registrar
I0428 20:59:24.873834 15955 registrar.cpp:379] Attempting to update the 'registry'
I0428 20:59:24.875111 15966 log.cpp:680] Attempting to append 138 bytes to the log
I0428 20:59:24.875331 15957 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1
I0428 20:59:24.876457 15958 replica.cpp:508] Replica received write request for position 1
I0428 20:59:24.890455 15958 leveldb.cpp:341] Persisting action (157 bytes) to leveldb took 13.858394ms
I0428 20:59:24.890476 15958 replica.cpp:664] Persisted action at 1
I0428 20:59:24.891136 15974 replica.cpp:643] Replica received learned notice for position 1
I0428 20:59:24.906605 15974 leveldb.cpp:341] Persisting action (159 bytes) to leveldb took 15.443876ms
I0428 20:59:24.906637 15974 replica.cpp:664] Persisted action at 1
I0428 20:59:24.906649 15974 replica.cpp:649] Replica learned APPEND action at position 1
I0428 20:59:24.907068 15974 registrar.cpp:427] Successfully updated 'registry'
I0428 20:59:24.907209 15971 log.cpp:699] Attempting to truncate the log to 1
I0428 20:59:24.907500 15971 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2
I0428 20:59:24.909026 15971 master.cpp:780] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0428 20:59:24.909487 15970 replica.cpp:508] Replica received write request for position 2
I0428 20:59:24.912192 15971 slave.cpp:140] Slave started on 14)@140.211.11.27:46217
I0428 20:59:24.912210 15971 credentials.hpp:35] Loading credentials for authentication
W0428 20:59:24.912390 15971 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_Xlp4Xn/credential': No such file or directory
I0428 20:59:24.912412 15971 slave.cpp:231] Slave using credential for: test-principal
I0428 20:59:24.912499 15971 slave.cpp:244] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 20:59:24.912636 15971 slave.cpp:272] Slave hostname: hemera.apache.org
I0428 20:59:24.912662 15971 slave.cpp:273] Slave checkpoint: false
I0428 20:59:24.913218 15971 state.cpp:33] Recovering state from '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/meta'
I0428 20:59:24.913355 15966 status_update_manager.cpp:193] Recovering status update manager
I0428 20:59:24.913879 15966 slave.cpp:2943] Finished recovery
I0428 20:59:24.914572 15732 sched.cpp:121] Version: 0.19.0
I0428 20:59:24.914970 15955 sched.cpp:217] New master detected at master@140.211.11.27:46217
I0428 20:59:24.915102 15955 sched.cpp:268] Authenticating with master master@140.211.11.27:46217
I0428 20:59:24.915230 15954 authenticatee.hpp:128] Creating new client SASL connection
I0428 20:59:24.915446 15954 master.cpp:2795] Authenticating scheduler(11)@140.211.11.27:46217
I0428 20:59:24.915745 15969 authenticator.hpp:148] Creating new server SASL connection
I0428 20:59:24.916017 15969 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 20:59:24.916031 15969 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 20:59:24.916050 15969 authenticator.hpp:254] Received SASL authentication start
I0428 20:59:24.916157 15969 authenticator.hpp:342] Authentication requires more steps
I0428 20:59:24.916192 15969 authenticatee.hpp:265] Received SASL authentication step
I0428 20:59:24.916241 15969 authenticator.hpp:282] Received SASL authentication step
I0428 20:59:24.916254 15969 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 20:59:24.916260 15969 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 20:59:24.916266 15969 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 20:59:24.916272 15969 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 20:59:24.916276 15969 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 20:59:24.916280 15969 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 20:59:24.916288 15969 authenticator.hpp:334] Authentication success
I0428 20:59:24.916367 15953 authenticatee.hpp:305] Authentication success
I0428 20:59:24.916576 15963 master.cpp:2835] Successfully authenticated scheduler(11)@140.211.11.27:46217
I0428 20:59:24.916590 15956 sched.cpp:342] Successfully authenticated with master master@140.211.11.27:46217
I0428 20:59:24.916671 15956 sched.cpp:461] Sending registration request to master@140.211.11.27:46217
I0428 20:59:24.916857 15963 master.cpp:981] Received registration request from scheduler(11)@140.211.11.27:46217
I0428 20:59:24.916887 15963 master.cpp:999] Registering framework 20140428-205924-453759884-46217-15732-0000 at scheduler(11)@140.211.11.27:46217
I0428 20:59:24.917032 15974 sched.cpp:392] Framework registered with 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.917067 15963 hierarchical_allocator_process.hpp:332] Added framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.917083 15963 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0428 20:59:24.917093 15963 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 10385ns
I0428 20:59:24.917156 15974 sched.cpp:406] Scheduler::registered took 104111ns
I0428 20:59:24.918953 15966 slave.cpp:525] New master detected at master@140.211.11.27:46217
I0428 20:59:24.918984 15966 slave.cpp:585] Authenticating with master master@140.211.11.27:46217
I0428 20:59:24.919020 15954 status_update_manager.cpp:167] New master detected at master@140.211.11.27:46217
I0428 20:59:24.919047 15961 authenticatee.hpp:128] Creating new client SASL connection
I0428 20:59:24.919028 15966 slave.cpp:558] Detecting new master
I0428 20:59:24.919312 15968 master.cpp:2795] Authenticating slave(14)@140.211.11.27:46217
I0428 20:59:24.919371 15968 authenticator.hpp:148] Creating new server SASL connection
I0428 20:59:24.919842 15955 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 20:59:24.919857 15955 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 20:59:24.919914 15955 authenticator.hpp:254] Received SASL authentication start
I0428 20:59:24.919999 15955 authenticator.hpp:342] Authentication requires more steps
I0428 20:59:24.920488 15973 authenticatee.hpp:265] Received SASL authentication step
I0428 20:59:24.920598 15973 authenticator.hpp:282] Received SASL authentication step
I0428 20:59:24.920613 15973 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 20:59:24.920617 15973 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 20:59:24.920624 15973 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 20:59:24.920629 15973 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 20:59:24.920632 15973 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 20:59:24.920635 15973 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 20:59:24.920642 15973 authenticator.hpp:334] Authentication success
I0428 20:59:24.920753 15973 authenticatee.hpp:305] Authentication success
I0428 20:59:24.920769 15955 master.cpp:2835] Successfully authenticated slave(14)@140.211.11.27:46217
I0428 20:59:24.921393 15976 slave.cpp:642] Successfully authenticated with master master@140.211.11.27:46217
I0428 20:59:24.921447 15976 slave.cpp:871] Will retry registration in 6.085179816secs if necessary
I0428 20:59:24.921664 15953 registrar.cpp:379] Attempting to update the 'registry'
I0428 20:59:24.922801 15970 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 13.290713ms
I0428 20:59:24.922821 15970 replica.cpp:664] Persisted action at 2
I0428 20:59:24.923069 15968 replica.cpp:643] Replica received learned notice for position 2
I0428 20:59:24.939198 15968 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 16.114121ms
I0428 20:59:24.939267 15968 leveldb.cpp:399] Deleting ~1 keys from leveldb took 47686ns
I0428 20:59:24.939277 15968 replica.cpp:664] Persisted action at 2
I0428 20:59:24.939283 15968 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0428 20:59:24.939585 15974 log.cpp:680] Attempting to append 332 bytes to the log
I0428 20:59:24.939746 15975 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0428 20:59:24.941287 15958 replica.cpp:508] Replica received write request for position 3
I0428 20:59:24.955303 15958 leveldb.cpp:341] Persisting action (351 bytes) to leveldb took 14.000606ms
I0428 20:59:24.955324 15958 replica.cpp:664] Persisted action at 3
I0428 20:59:24.956228 15957 replica.cpp:643] Replica received learned notice for position 3
I0428 20:59:24.971446 15957 leveldb.cpp:341] Persisting action (353 bytes) to leveldb took 15.190795ms
I0428 20:59:24.971477 15957 replica.cpp:664] Persisted action at 3
I0428 20:59:24.971489 15957 replica.cpp:649] Replica learned APPEND action at position 3
I0428 20:59:24.971849 15976 registrar.cpp:427] Successfully updated 'registry'
I0428 20:59:24.972170 15974 master.cpp:2169] Admitted slave on hemera.apache.org at slave(14)@140.211.11.27:46217
I0428 20:59:24.972194 15974 master.cpp:3283] Adding slave 20140428-205924-453759884-46217-15732-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 20:59:24.972244 15967 log.cpp:699] Attempting to truncate the log to 3
I0428 20:59:24.972283 15959 slave.cpp:675] Registered with master master@140.211.11.27:46217; given slave ID 20140428-205924-453759884-46217-15732-0
I0428 20:59:24.972452 15972 hierarchical_allocator_process.hpp:445] Added slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0428 20:59:24.972508 15971 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0428 20:59:24.972529 15972 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-205924-453759884-46217-15732-0 to framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.972769 15972 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140428-205924-453759884-46217-15732-0 in 267569ns
I0428 20:59:24.972786 15955 master.hpp:586] Adding offer 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
I0428 20:59:24.972829 15955 master.cpp:2744] Sending 1 offers to framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.972977 15955 sched.cpp:529] Scheduler::resourceOffers took 49221ns
I0428 20:59:24.973989 15970 replica.cpp:508] Replica received write request for position 4
I0428 20:59:24.974783 15960 master.hpp:596] Removing offer 20140428-205924-453759884-46217-15732-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
I0428 20:59:24.974851 15960 master.cpp:1806] Processing reply for offers: [ 20140428-205924-453759884-46217-15732-0 ] on slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org) for framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.974926 15960 master.hpp:558] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
I0428 20:59:24.974983 15960 master.cpp:2919] Launching task 1 of framework 20140428-205924-453759884-46217-15732-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-205924-453759884-46217-15732-0 (hemera.apache.org)
I0428 20:59:24.975106 15964 slave.cpp:905] Got assigned task 1 for framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.975277 15964 slave.cpp:1015] Launching task 1 for framework 20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.976796 15964 slave.cpp:1125] Queuing task '1' for executor 1 of framework '20140428-205924-453759884-46217-15732-0000
I0428 20:59:24.976812 15960 external_containerizer.cpp:266] Launching container 'cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
I0428 20:59:24.976842 15964 slave.cpp:486] Successfully attached file '/tmp/ExternalContainerizerTest_Launch_Xlp4Xn/slaves/20140428-205924-453759884-46217-15732-0/frameworks/20140428-205924-453759884-46217-15732-0000/executors/1/runs/cf7caacc-a6cd-4111-a09d-32f3f59e23b7'
I0428 20:59:24.976888 15960 external_containerizer.cpp:804] Invoking external containerizer for method 'launch'
I0428 20:59:24.976913 15960 external_containerizer.cpp:818] user: jenkins
I0428 20:59:24.988150 15970 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 14.136354ms
I0428 20:59:24.988204 15970 replica.cpp:664] Persisted action at 4
I0428 20:59:24.991509 15954 replica.cpp:643] Replica received learned notice for position 4
I0428 20:59:25.004228 15954 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 12.701325ms
I0428 20:59:25.004286 15954 leveldb.cpp:399] Deleting ~2 keys from leveldb took 34958ns
I0428 20:59:25.004297 15954 replica.cpp:664] Persisted action at 4
I0428 20:59:25.004302 15954 replica.cpp:649] Replica learned TRUNCATE action at position 4
make[3]: *** [check-local] Broken pipe
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2096
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/2096/changes>
Changes:
[niklas] Updated CHANGELOG for 0.18.1-rc2.
[vinod] Fixed distcheck failure due to test_containerizer.py missing in
------------------------------------------
[...truncated 11169 lines...]
[ RUN ] ResourcesTest.RangesSubtraction4
[ OK ] ResourcesTest.RangesSubtraction4 (0 ms)
[ RUN ] ResourcesTest.RangesSubset
[ OK ] ResourcesTest.RangesSubset (0 ms)
[ RUN ] ResourcesTest.BadResourcesNotAllocatable
[ OK ] ResourcesTest.BadResourcesNotAllocatable (0 ms)
[ RUN ] ResourcesTest.RangesAddition
[ OK ] ResourcesTest.RangesAddition (0 ms)
[ RUN ] ResourcesTest.RangesEquals
[ OK ] ResourcesTest.RangesEquals (0 ms)
[ RUN ] ResourcesTest.ScalarSubset2
[ OK ] ResourcesTest.ScalarSubset2 (0 ms)
[ RUN ] ResourcesTest.RangesAdditon3
[ OK ] ResourcesTest.RangesAdditon3 (0 ms)
[ RUN ] ResourcesTest.Resources
[ OK ] ResourcesTest.Resources (0 ms)
[ RUN ] ResourcesTest.Parsing
[ OK ] ResourcesTest.Parsing (0 ms)
[ RUN ] ResourcesTest.ScalarSubtraction2
[ OK ] ResourcesTest.ScalarSubtraction2 (0 ms)
[ RUN ] ResourcesTest.RangesSubtraction2
[ OK ] ResourcesTest.RangesSubtraction2 (0 ms)
[ RUN ] ResourcesTest.SetEquals
[ OK ] ResourcesTest.SetEquals (0 ms)
[ RUN ] ResourcesTest.ScalarSubtraction
[ OK ] ResourcesTest.ScalarSubtraction (0 ms)
[ RUN ] ResourcesTest.SetSubtraction
[ OK ] ResourcesTest.SetSubtraction (0 ms)
[ RUN ] ResourcesTest.SetSubset
[ OK ] ResourcesTest.SetSubset (0 ms)
[ RUN ] ResourcesTest.FlattenRoles
[ OK ] ResourcesTest.FlattenRoles (0 ms)
[ RUN ] ResourcesTest.Printing
[ OK ] ResourcesTest.Printing (0 ms)
[ RUN ] ResourcesTest.ScalarEquals
[ OK ] ResourcesTest.ScalarEquals (1 ms)
[ RUN ] ResourcesTest.RangesSubtraction
[ OK ] ResourcesTest.RangesSubtraction (0 ms)
[ RUN ] ResourcesTest.SetAddition
[ OK ] ResourcesTest.SetAddition (0 ms)
[ RUN ] ResourcesTest.ParseError
[ OK ] ResourcesTest.ParseError (0 ms)
[ RUN ] ResourcesTest.RangesSubtraction6
[ OK ] ResourcesTest.RangesSubtraction6 (0 ms)
[ RUN ] ResourcesTest.ScalarAddition
[ OK ] ResourcesTest.ScalarAddition (0 ms)
[ RUN ] ResourcesTest.Find
[ OK ] ResourcesTest.Find (0 ms)
[ RUN ] ResourcesTest.RangesAddition4
[ OK ] ResourcesTest.RangesAddition4 (0 ms)
[ RUN ] ResourcesTest.RangesSubtraction3
[ OK ] ResourcesTest.RangesSubtraction3 (0 ms)
[ RUN ] ResourcesTest.RangesSubtraction5
[ OK ] ResourcesTest.RangesSubtraction5 (0 ms)
[ RUN ] ResourcesTest.EmptyUnequal
[ OK ] ResourcesTest.EmptyUnequal (0 ms)
[ RUN ] ResourcesTest.RangesSubtraction1
[ OK ] ResourcesTest.RangesSubtraction1 (1 ms)
[ RUN ] ResourcesTest.ScalarAddition2
[ OK ] ResourcesTest.ScalarAddition2 (0 ms)
[ RUN ] ResourcesTest.InitializedIsEmpty
[ OK ] ResourcesTest.InitializedIsEmpty (0 ms)
[ RUN ] ResourcesTest.RangesAddition2
[ OK ] ResourcesTest.RangesAddition2 (0 ms)
[----------] 34 tests from ResourcesTest (3 ms total)
[----------] 1 test from ExternalContainerizerTest
[ RUN ] ExternalContainerizerTest.Launch
I0428 18:35:52.052281 17588 leveldb.cpp:174] Opened db in 38.420571ms
I0428 18:35:52.064613 17588 leveldb.cpp:181] Compacted db in 12.303028ms
I0428 18:35:52.064646 17588 leveldb.cpp:196] Created db iterator in 3859ns
I0428 18:35:52.064657 17588 leveldb.cpp:202] Seeked to beginning of db in 475ns
I0428 18:35:52.064664 17588 leveldb.cpp:271] Iterated through 0 keys in the db in 137ns
I0428 18:35:52.064677 17588 replica.cpp:729] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0428 18:35:52.064975 17686 recover.cpp:425] Starting replica recovery
I0428 18:35:52.065284 17680 master.cpp:266] Master 20140428-183552-453759884-44510-17588 (hemera.apache.org) started on 140.211.11.27:44510
I0428 18:35:52.065310 17680 master.cpp:303] Master only allowing authenticated frameworks to register
I0428 18:35:52.065317 17680 master.cpp:308] Master only allowing authenticated slaves to register
I0428 18:35:52.065325 17680 credentials.hpp:35] Loading credentials for authentication
W0428 18:35:52.065644 17680 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_5Z054S/credentials': No such file or directory
I0428 18:35:52.066946 17690 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@140.211.11.27:44510
I0428 18:35:52.066958 17675 master.cpp:104] No whitelist given. Advertising offers for all slaves
I0428 18:35:52.067008 17685 recover.cpp:451] Replica is in EMPTY status
I0428 18:35:52.067581 17688 master.cpp:922] The newly elected leader is master@140.211.11.27:44510 with id 20140428-183552-453759884-44510-17588
I0428 18:35:52.067600 17688 master.cpp:932] Elected as the leading master!
I0428 18:35:52.067607 17688 master.cpp:753] Recovering from registrar
I0428 18:35:52.067682 17688 registrar.cpp:275] Recovering registrar
I0428 18:35:52.068497 17680 replica.cpp:626] Replica in EMPTY status received a broadcasted recover request
I0428 18:35:52.069206 17670 recover.cpp:188] Received a recover response from a replica in EMPTY status
I0428 18:35:52.070250 17685 recover.cpp:542] Updating replica status to STARTING
I0428 18:35:52.084547 17682 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 13.926644ms
I0428 18:35:52.084575 17682 replica.cpp:320] Persisted replica status to STARTING
I0428 18:35:52.084676 17682 recover.cpp:451] Replica is in STARTING status
I0428 18:35:52.086498 17670 replica.cpp:626] Replica in STARTING status received a broadcasted recover request
I0428 18:35:52.086902 17686 recover.cpp:188] Received a recover response from a replica in STARTING status
I0428 18:35:52.087479 17688 recover.cpp:542] Updating replica status to VOTING
I0428 18:35:52.100673 17690 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.754568ms
I0428 18:35:52.100704 17690 replica.cpp:320] Persisted replica status to VOTING
I0428 18:35:52.100764 17690 recover.cpp:556] Successfully joined the Paxos group
I0428 18:35:52.100839 17690 recover.cpp:440] Recover process terminated
I0428 18:35:52.102170 17675 log.cpp:656] Attempting to start the writer
I0428 18:35:52.104004 17691 replica.cpp:474] Replica received implicit promise request with proposal 1
I0428 18:35:52.116780 17691 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 12.751647ms
I0428 18:35:52.116809 17691 replica.cpp:342] Persisted promised to 1
I0428 18:35:52.117239 17687 coordinator.cpp:229] Coordinator attemping to fill missing position
I0428 18:35:52.119802 17676 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
I0428 18:35:52.132858 17676 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 13.032191ms
I0428 18:35:52.132889 17676 replica.cpp:664] Persisted action at 0
I0428 18:35:52.133785 17680 replica.cpp:508] Replica received write request for position 0
I0428 18:35:52.133822 17680 leveldb.cpp:436] Reading position from leveldb took 12243ns
I0428 18:35:52.148928 17680 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 15.088988ms
I0428 18:35:52.148959 17680 replica.cpp:664] Persisted action at 0
I0428 18:35:52.149319 17680 replica.cpp:643] Replica received learned notice for position 0
I0428 18:35:52.165082 17680 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.695676ms
I0428 18:35:52.165114 17680 replica.cpp:664] Persisted action at 0
I0428 18:35:52.165127 17680 replica.cpp:649] Replica learned NOP action at position 0
I0428 18:35:52.165325 17671 log.cpp:672] Writer started with ending position 0
I0428 18:35:52.166028 17678 leveldb.cpp:436] Reading position from leveldb took 12511ns
I0428 18:35:52.168623 17672 registrar.cpp:308] Successfully recovered registrar
I0428 18:35:52.168668 17672 registrar.cpp:379] Attempting to update the 'registry'
I0428 18:35:52.170413 17676 log.cpp:680] Attempting to append 138 bytes to the log
I0428 18:35:52.170567 17689 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1
I0428 18:35:52.171490 17679 replica.cpp:508] Replica received write request for position 1
I0428 18:35:52.185103 17679 leveldb.cpp:341] Persisting action (157 bytes) to leveldb took 13.588126ms
I0428 18:35:52.185133 17679 replica.cpp:664] Persisted action at 1
I0428 18:35:52.185551 17676 replica.cpp:643] Replica received learned notice for position 1
I0428 18:35:52.201190 17676 leveldb.cpp:341] Persisting action (159 bytes) to leveldb took 15.576149ms
I0428 18:35:52.201222 17676 replica.cpp:664] Persisted action at 1
I0428 18:35:52.201234 17676 replica.cpp:649] Replica learned APPEND action at position 1
I0428 18:35:52.201649 17676 registrar.cpp:427] Successfully updated 'registry'
I0428 18:35:52.201879 17676 master.cpp:780] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register
I0428 18:35:52.201930 17687 log.cpp:699] Attempting to truncate the log to 1
I0428 18:35:52.202872 17685 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2
I0428 18:35:52.203744 17675 replica.cpp:508] Replica received write request for position 2
I0428 18:35:52.205273 17672 slave.cpp:140] Slave started on 22)@140.211.11.27:44510
I0428 18:35:52.205292 17672 credentials.hpp:35] Loading credentials for authentication
W0428 18:35:52.205593 17672 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/ExternalContainerizerTest_Launch_t0DrP6/credential': No such file or directory
I0428 18:35:52.205617 17672 slave.cpp:231] Slave using credential for: test-principal
I0428 18:35:52.205698 17672 slave.cpp:244] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 18:35:52.205780 17672 slave.cpp:272] Slave hostname: hemera.apache.org
I0428 18:35:52.205793 17672 slave.cpp:273] Slave checkpoint: false
I0428 18:35:52.206197 17686 state.cpp:33] Recovering state from '/tmp/ExternalContainerizerTest_Launch_t0DrP6/meta'
I0428 18:35:52.206881 17672 status_update_manager.cpp:193] Recovering status update manager
I0428 18:35:52.208335 17687 slave.cpp:2943] Finished recovery
I0428 18:35:52.208868 17588 sched.cpp:121] Version: 0.19.0
I0428 18:35:52.209179 17669 sched.cpp:217] New master detected at master@140.211.11.27:44510
I0428 18:35:52.209206 17669 sched.cpp:268] Authenticating with master master@140.211.11.27:44510
I0428 18:35:52.209408 17689 authenticatee.hpp:128] Creating new client SASL connection
I0428 18:35:52.209611 17670 master.cpp:2795] Authenticating scheduler(20)@140.211.11.27:44510
I0428 18:35:52.209882 17682 authenticator.hpp:148] Creating new server SASL connection
I0428 18:35:52.210285 17682 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 18:35:52.210307 17682 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 18:35:52.210479 17668 authenticator.hpp:254] Received SASL authentication start
I0428 18:35:52.210536 17668 authenticator.hpp:342] Authentication requires more steps
I0428 18:35:52.210578 17668 authenticatee.hpp:265] Received SASL authentication step
I0428 18:35:52.211019 17672 authenticator.hpp:282] Received SASL authentication step
I0428 18:35:52.211052 17672 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 18:35:52.211066 17672 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 18:35:52.211076 17672 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 18:35:52.211086 17672 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 18:35:52.211097 17672 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 18:35:52.211107 17672 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 18:35:52.211225 17672 authenticator.hpp:334] Authentication success
I0428 18:35:52.211272 17672 authenticatee.hpp:305] Authentication success
I0428 18:35:52.211313 17672 master.cpp:2835] Successfully authenticated scheduler(20)@140.211.11.27:44510
I0428 18:35:52.211529 17682 sched.cpp:342] Successfully authenticated with master master@140.211.11.27:44510
I0428 18:35:52.211597 17682 sched.cpp:461] Sending registration request to master@140.211.11.27:44510
I0428 18:35:52.211794 17670 master.cpp:981] Received registration request from scheduler(20)@140.211.11.27:44510
I0428 18:35:52.211896 17670 master.cpp:999] Registering framework 20140428-183552-453759884-44510-17588-0000 at scheduler(20)@140.211.11.27:44510
I0428 18:35:52.212422 17684 sched.cpp:392] Framework registered with 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.212460 17670 hierarchical_allocator_process.hpp:332] Added framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.212658 17684 sched.cpp:406] Scheduler::registered took 22368ns
I0428 18:35:52.212674 17670 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I0428 18:35:52.212785 17670 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 119810ns
I0428 18:35:52.213575 17687 slave.cpp:525] New master detected at master@140.211.11.27:44510
I0428 18:35:52.213608 17687 slave.cpp:585] Authenticating with master master@140.211.11.27:44510
I0428 18:35:52.213639 17685 status_update_manager.cpp:167] New master detected at master@140.211.11.27:44510
I0428 18:35:52.213680 17687 slave.cpp:558] Detecting new master
I0428 18:35:52.213696 17674 authenticatee.hpp:128] Creating new client SASL connection
I0428 18:35:52.214243 17683 master.cpp:2795] Authenticating slave(22)@140.211.11.27:44510
I0428 18:35:52.214949 17682 authenticator.hpp:148] Creating new server SASL connection
I0428 18:35:52.215312 17682 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
I0428 18:35:52.215334 17682 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
I0428 18:35:52.215649 17690 authenticator.hpp:254] Received SASL authentication start
I0428 18:35:52.215734 17690 authenticator.hpp:342] Authentication requires more steps
I0428 18:35:52.215965 17676 authenticatee.hpp:265] Received SASL authentication step
I0428 18:35:52.216153 17679 authenticator.hpp:282] Received SASL authentication step
I0428 18:35:52.216181 17679 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0428 18:35:52.216189 17679 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0428 18:35:52.216199 17679 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0428 18:35:52.216209 17679 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0428 18:35:52.216217 17679 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0428 18:35:52.216223 17679 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0428 18:35:52.216236 17679 authenticator.hpp:334] Authentication success
I0428 18:35:52.216421 17686 authenticatee.hpp:305] Authentication success
I0428 18:35:52.216485 17673 master.cpp:2835] Successfully authenticated slave(22)@140.211.11.27:44510
I0428 18:35:52.216995 17673 slave.cpp:642] Successfully authenticated with master master@140.211.11.27:44510
I0428 18:35:52.217090 17673 slave.cpp:871] Will retry registration in 9.709265432secs if necessary
I0428 18:35:52.217336 17672 registrar.cpp:379] Attempting to update the 'registry'
I0428 18:35:52.217339 17675 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 13.57161ms
I0428 18:35:52.217365 17675 replica.cpp:664] Persisted action at 2
I0428 18:35:52.217965 17681 replica.cpp:643] Replica received learned notice for position 2
I0428 18:35:52.233587 17681 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 15.598124ms
I0428 18:35:52.233634 17681 leveldb.cpp:399] Deleting ~1 keys from leveldb took 22553ns
I0428 18:35:52.233649 17681 replica.cpp:664] Persisted action at 2
I0428 18:35:52.233656 17681 replica.cpp:649] Replica learned TRUNCATE action at position 2
I0428 18:35:52.234020 17677 log.cpp:680] Attempting to append 332 bytes to the log
I0428 18:35:52.234163 17684 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
I0428 18:35:52.235707 17670 replica.cpp:508] Replica received write request for position 3
I0428 18:35:52.249655 17670 leveldb.cpp:341] Persisting action (351 bytes) to leveldb took 13.922716ms
I0428 18:35:52.249683 17670 replica.cpp:664] Persisted action at 3
I0428 18:35:52.250257 17672 replica.cpp:643] Replica received learned notice for position 3
I0428 18:35:52.265818 17672 leveldb.cpp:341] Persisting action (353 bytes) to leveldb took 15.536383ms
I0428 18:35:52.265849 17672 replica.cpp:664] Persisted action at 3
I0428 18:35:52.265861 17672 replica.cpp:649] Replica learned APPEND action at position 3
I0428 18:35:52.267107 17670 registrar.cpp:427] Successfully updated 'registry'
I0428 18:35:52.267316 17675 log.cpp:699] Attempting to truncate the log to 3
I0428 18:35:52.267627 17672 master.cpp:2169] Admitted slave on hemera.apache.org at slave(22)@140.211.11.27:44510
I0428 18:35:52.267650 17672 master.cpp:3283] Adding slave 20140428-183552-453759884-44510-17588-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0428 18:35:52.267771 17672 slave.cpp:675] Registered with master master@140.211.11.27:44510; given slave ID 20140428-183552-453759884-44510-17588-0
I0428 18:35:52.267982 17691 hierarchical_allocator_process.hpp:445] Added slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0428 18:35:52.268054 17691 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-183552-453759884-44510-17588-0 to framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.268226 17691 hierarchical_allocator_process.hpp:708] Performed allocation for slave 20140428-183552-453759884-44510-17588-0 in 198169ns
I0428 18:35:52.268291 17668 master.hpp:586] Adding offer 20140428-183552-453759884-44510-17588-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org)
I0428 18:35:52.268352 17668 master.cpp:2744] Sending 1 offers to framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.268772 17670 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
I0428 18:35:52.269053 17686 sched.cpp:529] Scheduler::resourceOffers took 523637ns
I0428 18:35:52.270239 17690 master.hpp:596] Removing offer 20140428-183552-453759884-44510-17588-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org)
I0428 18:35:52.270308 17690 master.cpp:1806] Processing reply for offers: [ 20140428-183552-453759884-44510-17588-0 ] on slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org) for framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.270386 17690 master.hpp:558] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org)
I0428 18:35:52.270527 17690 master.cpp:2919] Launching task 1 of framework 20140428-183552-453759884-44510-17588-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140428-183552-453759884-44510-17588-0 (hemera.apache.org)
I0428 18:35:52.270647 17668 slave.cpp:905] Got assigned task 1 for framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.270912 17668 slave.cpp:1015] Launching task 1 for framework 20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.271471 17671 replica.cpp:508] Replica received write request for position 4
I0428 18:35:52.273149 17681 external_containerizer.cpp:266] Launching container '91bcb0f3-3745-40a7-b61d-d42e0063409a'
I0428 18:35:52.273185 17668 slave.cpp:1125] Queuing task '1' for executor 1 of framework '20140428-183552-453759884-44510-17588-0000
I0428 18:35:52.273246 17681 external_containerizer.cpp:804] Invoking external containerizer for method 'launch'
I0428 18:35:52.273274 17681 external_containerizer.cpp:818] user: jenkins
I0428 18:35:52.273322 17668 slave.cpp:486] Successfully attached file '/tmp/ExternalContainerizerTest_Launch_t0DrP6/slaves/20140428-183552-453759884-44510-17588-0/frameworks/20140428-183552-453759884-44510-17588-0000/executors/1/runs/91bcb0f3-3745-40a7-b61d-d42e0063409a'
I0428 18:35:52.286264 17671 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 14.752824ms
I0428 18:35:52.286325 17671 replica.cpp:664] Persisted action at 4
make[3]: *** [check-local] Broken pipe
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2095
Posted by Till Toenshoff <to...@me.com>.
> I0428 16:00:02.520180 12912 external_containerizer.cpp:804] Invoking external containerizer for method 'launch'
> I0428 16:00:02.520216 12912 external_containerizer.cpp:818] user: jenkins
> I0428 16:00:02.530993 12902 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 12.432026ms
> I0428 16:00:02.531069 12902 replica.cpp:664] Persisted action at 4
> make[3]: *** [check-local] Broken pipe
Also will be looking into this one.
Thanks for your patience and sorry for these issues,
Till