Mailing-List: contact dev-help@mesos.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@mesos.apache.org
Date: Mon, 13 Apr 2015 17:58:35 +0000 (UTC)
From: Apache Jenkins Server  <jenkins@builds.apache.org>
To: dev@mesos.apache.org
Message-ID: <1230949483.12158.1428947915804.JavaMail.jenkins@crius>
Subject: Build failed in Jenkins:
 Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
 #2880
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: quoted-printable

See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disa=
ble-Java-Disable-Python-Disable-Webui/2880/changes>

Changes:

[vinodkone] Should install apr-util-devel in CentOS 6.5.

------------------------------------------
[...truncated 73720 lines...]
IRe-registered executor on proserpina.apache.org
0413 17:58:32.181589 31730 exec.cpp:241] Executor::reregistered took 91445n=
s
I0413 17:58:32.181962 20773 slave.cpp:2503] Handling status update TASK_LOS=
T (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b7912) for task f7f156f8-f9ba-4ee4-=
bcc2-9a434e9a65c2 of framework 20150413-175831-3176252227-60468-20747-0000 =
from @0.0.0.0:0
I0413 17:58:32.182065 20773 slave.cpp:4519] Terminating task f7f156f8-f9ba-=
4ee4-bcc2-9a434e9a65c2
I0413 17:58:32.206502 20764 status_update_manager.cpp:317] Received status =
update TASK_LOST (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b7912) for task f7f1=
56f8-f9ba-4ee4-bcc2-9a434e9a65c2 of framework 20150413-175831-3176252227-60=
468-20747-0000
I0413 17:58:32.206568 20764 status_update_manager.cpp:494] Creating StatusU=
pdate stream for task f7f156f8-f9ba-4ee4-bcc2-9a434e9a65c2 of framework 201=
50413-175831-3176252227-60468-20747-0000
I0413 17:58:32.206914 20765 containerizer.cpp:950] Destroying container '95=
035a3f-79ce-453b-935f-a0e0b650f34e'
I0413 17:58:32.207056 20764 status_update_manager.hpp:346] Checkpointing UP=
DATE for status update TASK_LOST (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b791=
2) for task f7f156f8-f9ba-4ee4-bcc2-9a434e9a65c2 of framework 20150413-1758=
31-3176252227-60468-20747-0000
I0413 17:58:32.294944 20764 status_update_manager.cpp:371] Forwarding updat=
e TASK_LOST (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b7912) for task f7f156f8-=
f9ba-4ee4-bcc2-9a434e9a65c2 of framework 20150413-175831-3176252227-60468-2=
0747-0000 to the slave
W0413 17:58:32.295214 20776 slave.cpp:2713] Dropping status update TASK_LOS=
T (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b7912) for task f7f156f8-f9ba-4ee4-=
bcc2-9a434e9a65c2 of framework 20150413-175831-3176252227-60468-20747-0000 =
sent by status update manager because the slave is in RECOVERING state
I0413 17:58:32.295289 20776 slave.cpp:2685] Status update manager successfu=
lly handled status update TASK_LOST (UUID: 60f127b7-b58a-461e-95c7-8ea7b79b=
7912) for task f7f156f8-f9ba-4ee4-bcc2-9a434e9a65c2 of framework 20150413-1=
75831-3176252227-60468-20747-0000
I0413 17:58:32.350344 20767 containerizer.cpp:1159] Executor for container =
'95035a3f-79ce-453b-935f-a0e0b650f34e' has exited
I0413 17:58:32.351619 20771 slave.cpp:3194] Executor 'f7f156f8-f9ba-4ee4-bc=
c2-9a434e9a65c2' of framework 20150413-175831-3176252227-60468-20747-0000 t=
erminated with signal Killed
I0413 17:58:32.351910 20747 sched.cpp:1589] Asked to stop the driver
I0413 17:58:32.352051 20747 master.cpp:788] Master terminating
I0413 17:58:32.352062 20763 sched.cpp:831] Stopping framework '20150413-175=
831-3176252227-60468-20747-0000'
I0413 17:58:32.352313 20771 hierarchical.hpp:470] Removed slave 20150413-17=
5831-3176252227-60468-20747-S0
W0413 17:58:32.352293 20747 master.cpp:4707] Removing task f7f156f8-f9ba-4e=
e4-bcc2-9a434e9a65c2 with resources cpus(*):2; mem(*):1024; disk(*):1024; p=
orts(*):[31000-32000] of framework 20150413-175831-3176252227-60468-20747-0=
000 on slave 20150413-175831-3176252227-60468-20747-S0 at slave(231)@67.195=
.81.189:60468 (proserpina.apache.org) in non-terminal state TASK_STAGING
I0413 17:58:32.353174 20776 hierarchical.hpp:354] Removed framework 2015041=
3-175831-3176252227-60468-20747-0000
I0413 17:58:32.358019 20775 slave.cpp:509] Slave terminating
[       OK ] MesosContainerizerSlaveRecoveryTest.ResourceStatistics (846 ms=
)
[----------] 1 test from MesosContainerizerSlaveRecoveryTest (846 ms total)

[----------] 1 test from MasterContenderDetectorTest
[ RUN      ] MasterContenderDetectorTest.File
Using temporary directory '/tmp/MasterContenderDetectorTest_File_HXHDNc'
I0413 17:58:32.486649 20747 leveldb.cpp:176] Opened db in 122.163085ms
I0413 17:58:32.528734 20747 leveldb.cpp:183] Compacted db in 42.000124ms
I0413 17:58:32.528802 20747 leveldb.cpp:198] Created db iterator in 24914ns
I0413 17:58:32.528820 20747 leveldb.cpp:204] Seeked to beginning of db in 2=
504ns
I0413 17:58:32.528830 20747 leveldb.cpp:273] Iterated through 0 keys in the=
 db in 393ns
I0413 17:58:32.528878 20747 replica.cpp:744] Replica recovered with log pos=
itions 0 -> 0 with 1 holes and 0 unlearned
I0413 17:58:32.529469 20770 recover.cpp:449] Starting replica recovery
I0413 17:58:32.529829 20770 recover.cpp:475] Replica is in EMPTY status
I0413 17:58:32.531082 20774 replica.cpp:641] Replica in EMPTY status receiv=
ed a broadcasted recover request
I0413 17:58:32.531353 20769 recover.cpp:195] Received a recover response fr=
om a replica in EMPTY status
I0413 17:58:32.532062 20772 recover.cpp:566] Updating replica status to STA=
RTING
I0413 17:58:32.533360 20765 master.cpp:359] Master 20150413-175832-31762522=
27-60468-20747 (proserpina.apache.org) started on 67.195.81.189:60468
I0413 17:58:32.533390 20765 master.cpp:361] Flags at startup: --acls=3D"" -=
-allocation_interval=3D"1secs" --authenticate=3D"true" --authenticate_slave=
s=3D"true" --authenticators=3D"crammd5" --credentials=3D"/tmp/MasterContend=
erDetectorTest_File_HXHDNc/credentials" --framework_sorter=3D"drf" --initia=
lize_driver_logging=3D"true" --log_auto_initialize=3D"true" --logbufsecs=3D=
"0" --logging_level=3D"INFO" --quiet=3D"false" --recovery_slave_removal_lim=
it=3D"100%" --registry=3D"replicated_log" --registry_fetch_timeout=3D"1mins=
" --registry_store_timeout=3D"25secs" --registry_strict=3D"true" --root_sub=
missions=3D"true" --slave_reregister_timeout=3D"10mins" --user_sorter=3D"dr=
f" --version=3D"false" --webui_dir=3D"/usr/local/share/mesos/webui" --work_=
dir=3D"/tmp/MasterContenderDetectorTest_File_HXHDNc/master" --zk_session_ti=
meout=3D"10secs"
I0413 17:58:32.533808 20765 master.cpp:406] Master only allowing authentica=
ted frameworks to register
I0413 17:58:32.533823 20765 master.cpp:411] Master only allowing authentica=
ted slaves to register
I0413 17:58:32.533830 20765 credentials.hpp:37] Loading credentials for aut=
hentication from '/tmp/MasterContenderDetectorTest_File_HXHDNc/credentials'
I0413 17:58:32.534075 20765 master.cpp:450] Using default 'crammd5' authent=
icator
I0413 17:58:32.534219 20765 master.cpp:487] Authorization enabled
I0413 17:58:32.535002 20763 whitelist_watcher.cpp:79] No whitelist given
I0413 17:58:32.535074 20772 hierarchical.hpp:287] Initialized hierarchical =
allocator process
I0413 17:58:32.536412 20768 master.cpp:1419] The newly elected leader is ma=
ster@67.195.81.189:60468 with id 20150413-175832-3176252227-60468-20747
I0413 17:58:32.536455 20768 master.cpp:1432] Elected as the leading master!
I0413 17:58:32.536485 20768 master.cpp:1205] Recovering from registrar
I0413 17:58:32.536625 20770 registrar.cpp:313] Recovering registrar
I0413 17:58:32.570184 20767 leveldb.cpp:306] Persisting metadata (8 bytes) =
to leveldb took 37.935942ms
I0413 17:58:32.570252 20767 replica.cpp:323] Persisted replica status to ST=
ARTING
I0413 17:58:32.570576 20763 recover.cpp:475] Replica is in STARTING status
I0413 17:58:32.571846 20771 replica.cpp:641] Replica in STARTING status rec=
eived a broadcasted recover request
I0413 17:58:32.572268 20769 recover.cpp:195] Received a recover response fr=
om a replica in STARTING status
I0413 17:58:32.572789 20767 recover.cpp:566] Updating replica status to VOT=
ING
I0413 17:58:32.611865 20777 leveldb.cpp:306] Persisting metadata (8 bytes) =
to leveldb took 38.838338ms
I0413 17:58:32.611915 20777 replica.cpp:323] Persisted replica status to VO=
TING
I0413 17:58:32.612074 20772 recover.cpp:580] Successfully joined the Paxos =
group
I0413 17:58:32.612311 20772 recover.cpp:464] Recover process terminated
I0413 17:58:32.612977 20776 log.cpp:660] Attempting to start the writer
I0413 17:58:32.614465 20767 replica.cpp:477] Replica received implicit prom=
ise request with proposal 1
I0413 17:58:32.653548 20767 leveldb.cpp:306] Persisting metadata (8 bytes) =
to leveldb took 39.040415ms
I0413 17:58:32.653597 20767 replica.cpp:345] Persisted promised to 1
I0413 17:58:32.654314 20773 coordinator.cpp:230] Coordinator attemping to f=
ill missing position
I0413 17:58:32.655735 20764 replica.cpp:378] Replica received explicit prom=
ise request for position 0 with proposal 2
I0413 17:58:32.687118 20764 leveldb.cpp:343] Persisting action (8 bytes) to=
 leveldb took 31.339251ms
I0413 17:58:32.687163 20764 replica.cpp:679] Persisted action at 0
I0413 17:58:32.688657 20768 replica.cpp:511] Replica received write request=
 for position 0
I0413 17:58:32.688747 20768 leveldb.cpp:438] Reading position from leveldb =
took 54318ns
I0413 17:58:32.720556 20768 leveldb.cpp:343] Persisting action (14 bytes) t=
o leveldb took 31.767308ms
I0413 17:58:32.720600 20768 replica.cpp:679] Persisted action at 0
I0413 17:58:32.721408 20769 replica.cpp:658] Replica received learned notic=
e for position 0
I0413 17:58:32.753944 20769 leveldb.cpp:343] Persisting action (16 bytes) t=
o leveldb took 32.499029ms
I0413 17:58:32.753983 20769 replica.cpp:679] Persisted action at 0
I0413 17:58:32.754005 20769 replica.cpp:664] Replica learned NOP action at =
position 0
I0413 17:58:32.754655 20771 log.cpp:676] Writer started with ending positio=
n 0
I0413 17:58:32.755919 20772 leveldb.cpp:438] Reading position from leveldb =
took 32199ns
I0413 17:58:32.758930 20771 registrar.cpp:346] Successfully fetched the reg=
istry (0B) in 222.258944ms
I0413 17:58:32.759048 20771 registrar.cpp:445] Applied 1 operations in 2823=
9ns; attempting to update the 'registry'
I0413 17:58:32.761981 20774 log.cpp:684] Attempting to append 143 bytes to =
the log
I0413 17:58:32.762141 20764 coordinator.cpp:340] Coordinator attempting to =
write APPEND action at position 1
I0413 17:58:32.763157 20768 replica.cpp:511] Replica received write request=
 for position 1
I0413 17:58:32.795750 20768 leveldb.cpp:343] Persisting action (162 bytes) =
to leveldb took 32.550399ms
I0413 17:58:32.795804 20768 replica.cpp:679] Persisted action at 1
I0413 17:58:32.796527 20770 replica.cpp:658] Replica received learned notic=
e for position 1
I0413 17:58:32.829246 20770 leveldb.cpp:343] Persisting action (164 bytes) =
to leveldb took 32.686488ms
I0413 17:58:32.829291 20770 replica.cpp:679] Persisted action at 1
I0413 17:58:32.829318 20770 replica.cpp:664] Replica learned APPEND action =
at position 1
I0413 17:58:32.830348 20770 registrar.cpp:490] Successfully updated the 're=
gistry' in 71.234048ms
I0413 17:58:32.830536 20770 registrar.cpp:376] Successfully recovered regis=
trar
I0413 17:58:32.830595 20774 log.cpp:703] Attempting to truncate the log to =
1
I0413 17:58:32.830829 20771 coordinator.cpp:340] Coordinator attempting to =
write TRUNCATE action at position 2
I0413 17:58:32.830888 20767 master.cpp:1232] Recovered 0 slaves from the Re=
gistry (105B) ; allowing 10mins for slaves to re-register
I0413 17:58:32.831692 20776 replica.cpp:511] Replica received write request=
 for position 2
I0413 17:58:32.868948 20776 leveldb.cpp:343] Persisting action (16 bytes) t=
o leveldb took 37.197874ms
I0413 17:58:32.868999 20776 replica.cpp:679] Persisted action at 2
I0413 17:58:32.869799 20764 replica.cpp:658] Replica received learned notic=
e for position 2
I0413 17:58:32.904435 20764 leveldb.cpp:343] Persisting action (18 bytes) t=
o leveldb took 34.599291ms
I0413 17:58:32.904521 20764 leveldb.cpp:401] Deleting ~1 keys from leveldb =
took 43084ns
I0413 17:58:32.904546 20764 replica.cpp:679] Persisted action at 2
I0413 17:58:32.904567 20764 replica.cpp:664] Replica learned TRUNCATE actio=
n at position 2
W0413 17:58:32.913843 20747 detector.cpp:228] Specifying master detection m=
echanism / ZooKeeper URL to be read out of a file via 'file://' is deprecat=
ed inside Mesos and will be removed in a future release.
I0413 17:58:32.917676 20747 containerizer.cpp:113] Using isolation: posix/c=
pu,posix/mem
I0413 17:58:32.919158 20766 slave.cpp:176] Slave started on 233)@67.195.81.=
189:60468
I0413 17:58:32.919179 20766 slave.cpp:177] Flags at startup: --authenticate=
e=3D"crammd5" --cgroups_cpu_enable_pids_and_tids_count=3D"false" --cgroups_=
enable_cfs=3D"false" --cgroups_hierarchy=3D"/sys/fs/cgroup" --cgroups_limit=
_swap=3D"false" --cgroups_root=3D"mesos" --container_disk_watch_interval=3D=
"15secs" --containerizers=3D"mesos" --credential=3D"/tmp/MasterContenderDet=
ectorTest_File_IEHCNA/credential" --default_role=3D"*" --disk_watch_interva=
l=3D"1mins" --docker=3D"docker" --docker_remove_delay=3D"6hrs" --docker_san=
dbox_directory=3D"/mnt/mesos/sandbox" --docker_stop_timeout=3D"0ns" --enfor=
ce_container_disk_quota=3D"false" --executor_registration_timeout=3D"1mins"=
 --executor_shutdown_grace_period=3D"5secs" --frameworks_home=3D"" --gc_del=
ay=3D"1weeks" --gc_disk_headroom=3D"0.1" --hadoop_home=3D"" --initialize_dr=
iver_logging=3D"true" --isolation=3D"posix/cpu,posix/mem" --launcher_dir=3D=
"<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable=
-Java-Disable-Python-Disable-Webui/ws/build/src"> --logbufsecs=3D"0" --logg=
ing_level=3D"INFO" --perf_duration=3D"10secs" --perf_interval=3D"1mins" --q=
uiet=3D"false" --recover=3D"reconnect" --recovery_timeout=3D"15mins" --regi=
stration_backoff_factor=3D"10ms" --resource_monitoring_interval=3D"1secs" -=
-resources=3D"cpus:2;mem:1024;disk:1024;ports:[31000-32000]" --strict=3D"tr=
ue" --switch_user=3D"true" --version=3D"false" --work_dir=3D"/tmp/MasterCon=
tenderDetectorTest_File_IEHCNA"
I0413 17:58:32.919451 20766 credentials.hpp:85] Loading credential for auth=
entication from '/tmp/MasterContenderDetectorTest_File_IEHCNA/credential'
I0413 17:58:32.919564 20766 slave.cpp:298] Slave using credential for: test=
-principal
I0413 17:58:32.919769 20766 slave.cpp:316] Slave resources: cpus(*):2; mem(=
*):1024; disk(*):1024; ports(*):[31000-32000]
I0413 17:58:32.919847 20766 slave.cpp:346] Slave hostname: proserpina.apach=
e.org
I0413 17:58:32.919862 20766 slave.cpp:351] Slave checkpoint: true
I0413 17:58:32.920517 20765 state.cpp:35] Recovering state from '/tmp/Maste=
rContenderDetectorTest_File_IEHCNA/meta'
I0413 17:58:32.920773 20769 status_update_manager.cpp:197] Recovering statu=
s update manager
I0413 17:58:32.920924 20777 containerizer.cpp:310] Recovering containerizer
I0413 17:58:32.921628 20765 slave.cpp:3806] Finished recovery
I0413 17:58:32.922309 20771 status_update_manager.cpp:171] Pausing sending =
status updates
I0413 17:58:32.922327 20777 slave.cpp:627] New master detected at master@67=
.195.81.189:60468
I0413 17:58:32.922472 20777 slave.cpp:690] Authenticating with master maste=
r@67.195.81.189:60468
I0413 17:58:32.922503 20777 slave.cpp:695] Using default CRAM-MD5 authentic=
atee
I0413 17:58:32.922667 20777 slave.cpp:663] Detecting new master
I0413 17:58:32.922695 20765 authenticatee.hpp:139] Creating new client SASL=
 connection
I0413 17:58:32.923018 20764 master.cpp:3884] Authenticating slave(233)@67.1=
95.81.189:60468
I0413 17:58:32.923228 20770 authenticator.cpp:406] Starting authentication =
session for crammd5_authenticatee(527)@67.195.81.189:60468
I0413 17:58:32.923475 20765 authenticator.cpp:92] Creating new server SASL =
connection
I0413 17:58:32.923846 20778 authenticatee.hpp:230] Received SASL authentica=
tion mechanisms: CRAM-MD5
I0413 17:58:32.923889 20778 authenticatee.hpp:256] Attempting to authentica=
te with mechanism 'CRAM-MD5'
I0413 17:58:32.924008 20778 authenticator.cpp:197] Received SASL authentica=
tion start
I0413 17:58:32.924144 20778 authenticator.cpp:319] Authentication requires =
more steps
I0413 17:58:32.924270 20765 authenticatee.hpp:276] Received SASL authentica=
tion step
I0413 17:58:32.924432 20775 authenticator.cpp:225] Received SASL authentica=
tion step
I0413 17:58:32.924476 20775 auxprop.cpp:101] Request to lookup properties f=
or user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'pros=
erpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVE=
RRIDE: false SASL_AUXPROP_AUTHZID: false=20
I0413 17:58:32.924494 20775 auxprop.cpp:173] Looking up auxiliary property =
'*userPassword'
I0413 17:58:32.924554 20775 auxprop.cpp:173] Looking up auxiliary property =
'*cmusaslsecretCRAM-MD5'
I0413 17:58:32.924587 20775 auxprop.cpp:101] Request to lookup properties f=
or user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'pros=
erpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVE=
RRIDE: false SASL_AUXPROP_AUTHZID: true=20
I0413 17:58:32.924602 20775 auxprop.cpp:123] Skipping auxiliary property '*=
userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true
I0413 17:58:32.924612 20775 auxprop.cpp:123] Skipping auxiliary property '*=
cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true
I0413 17:58:32.924631 20775 authenticator.cpp:311] Authentication success
I0413 17:58:32.924757 20774 authenticatee.hpp:316] Authentication success
I0413 17:58:32.924779 20770 master.cpp:3914] Successfully authenticated pri=
ncipal 'test-principal' at slave(233)@67.195.81.189:60468
I0413 17:58:32.924944 20747 sched.cpp:157] Version: 0.23.0
I0413 17:58:32.924969 20765 authenticator.cpp:424] Authentication session c=
leanup for crammd5_authenticatee(527)@67.195.81.189:60468
I0413 17:58:32.925184 20776 slave.cpp:761] Successfully authenticated with =
master master@67.195.81.189:60468
I0413 17:58:32.925561 20766 sched.cpp:254] New master detected at master@67=
.195.81.189:60468
I0413 17:58:32.925573 20776 slave.cpp:1088] Will retry registration in 5.64=
693ms if necessary
I0413 17:58:32.925668 20766 sched.cpp:310] Authenticating with master maste=
r@67.195.81.189:60468
I0413 17:58:32.925751 20766 sched.cpp:317] Using default CRAM-MD5 authentic=
atee
I0413 17:58:32.925811 20778 master.cpp:2991] Registering slave at slave(233=
)@67.195.81.189:60468 (proserpina.apache.org) with id 20150413-175832-31762=
52227-60468-20747-S0
I0413 17:58:32.925966 20769 authenticatee.hpp:139] Creating new client SASL=
 connection
I0413 17:58:32.926213 20778 master.cpp:3884] Authenticating scheduler-a6503=
1fc-b0c2-4df8-bba5-20c8fb961369@67.195.81.189:60468
I0413 17:58:32.926331 20766 authenticator.cpp:406] Starting authentication =
session for crammd5_authenticatee(528)@67.195.81.189:60468
I0413 17:58:32.926342 20777 registrar.cpp:445] Applied 1 operations in 8801=
9ns; attempting to update the 'registry'
I0413 17:58:32.926626 20769 authenticator.cpp:92] Creating new server SASL =
connection
I0413 17:58:32.926802 20773 authenticatee.hpp:230] Received SASL authentica=
tion mechanisms: CRAM-MD5
I0413 17:58:32.926839 20773 authenticatee.hpp:256] Attempting to authentica=
te with mechanism 'CRAM-MD5'
I0413 17:58:32.926949 20774 authenticator.cpp:197] Received SASL authentica=
tion start
I0413 17:58:32.927008 20774 authenticator.cpp:319] Authentication requires =
more steps
I0413 17:58:32.927125 20773 authenticatee.hpp:276] Received SASL authentica=
tion step
I0413 17:58:32.927263 20774 authenticator.cpp:225] Received SASL authentica=
tion step
I0413 17:58:32.927309 20774 auxprop.cpp:101] Request to lookup properties f=
or user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'pros=
erpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVE=
RRIDE: false SASL_AUXPROP_AUTHZID: false=20
I0413 17:58:32.927331 20774 auxprop.cpp:173] Looking up auxiliary property =
'*userPassword'
I0413 17:58:32.927381 20774 auxprop.cpp:173] Looking up auxiliary property =
'*cmusaslsecretCRAM-MD5'
I0413 17:58:32.927431 20774 auxprop.cpp:101] Request to lookup properties f=
or user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'pros=
erpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVE=
RRIDE: false SASL_AUXPROP_AUTHZID: true=20
I0413 17:58:32.927458 20774 auxprop.cpp:123] Skipping auxiliary property '*=
userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true
I0413 17:58:32.927474 20774 auxprop.cpp:123] Skipping auxiliary property '*=
cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true
I0413 17:58:32.927502 20774 authenticator.cpp:311] Authentication success
I0413 17:58:32.927602 20766 authenticatee.hpp:316] Authentication success
I0413 17:58:32.927635 20773 master.cpp:3914] Successfully authenticated pri=
ncipal 'test-principal' at scheduler-a65031fc-b0c2-4df8-bba5-20c8fb961369@6=
7.195.81.189:60468
I0413 17:58:32.927690 20778 authenticator.cpp:424] Authentication session c=
leanup for crammd5_authenticatee(528)@67.195.81.189:60468
I0413 17:58:32.927983 20774 sched.cpp:398] Successfully authenticated with =
master master@67.195.81.189:60468
I0413 17:58:32.928010 20774 sched.cpp:521] Sending registration request to =
master@67.195.81.189:60468
I0413 17:58:32.928072 20774 sched.cpp:554] Will retry registration in 1.139=
051994secs if necessary
I0413 17:58:32.928170 20766 master.cpp:1637] Received registration request =
for framework 'default' at scheduler-a65031fc-b0c2-4df8-bba5-20c8fb961369@6=
7.195.81.189:60468
I0413 17:58:32.928266 20766 master.cpp:1498] Authorizing framework principa=
l 'test-principal' to receive offers for role '*'
I0413 17:58:32.928660 20776 master.cpp:1704] Registering framework 20150413=
-175832-3176252227-60468-20747-0000 (default) at scheduler-a65031fc-b0c2-4d=
f8-bba5-20c8fb961369@67.195.81.189:60468
I0413 17:58:32.929060 20772 hierarchical.hpp:321] Added framework 20150413-=
175832-3176252227-60468-20747-0000
I0413 17:58:32.929101 20772 hierarchical.hpp:818] No resources available to=
 allocate!
I0413 17:58:32.929123 20772 hierarchical.hpp:725] Performed allocation for =
0 slaves in 32085ns
I0413 17:58:32.929218 20772 sched.cpp:448] Framework registered with 201504=
13-175832-3176252227-60468-20747-0000
I0413 17:58:32.929275 20772 sched.cpp:462] Scheduler::registered took 37118=
ns
I0413 17:58:32.929385 20770 log.cpp:684] Attempting to append 324 bytes to =
the log
I0413 17:58:32.929509 20767 coordinator.cpp:340] Coordinator attempting to =
write APPEND action at position 3
I0413 17:58:32.930294 20773 replica.cpp:511] Replica received write request=
 for position 3
I0413 17:58:32.932085 20767 slave.cpp:1088] Will retry registration in 17.5=
74244ms if necessary
I0413 17:58:32.932209 20776 master.cpp:2979] Ignoring register slave messag=
e from slave(233)@67.195.81.189:60468 (proserpina.apache.org) as admission =
is already in progress
I0413 17:58:32.950625 20774 slave.cpp:1088] Will retry registration in 56.7=
01364ms if necessary
I0413 17:58:32.950817 20777 master.cpp:2979] Ignoring register slave messag=
e from slave(233)@67.195.81.189:60468 (proserpina.apache.org) as admission =
is already in progress
I0413 17:58:32.963193 20773 leveldb.cpp:343] Persisting action (343 bytes) =
to leveldb took 32.85285ms
I0413 17:58:32.963244 20773 replica.cpp:679] Persisted action at 3
I0413 17:58:32.964040 20765 replica.cpp:658] Replica received learned notic=
e for position 3
I0413 17:58:33.003015 20765 leveldb.cpp:343] Persisting action (345 bytes) =
to leveldb took 38.928349ms
I0413 17:58:33.003067 20765 replica.cpp:679] Persisted action at 3
I0413 17:58:33.003099 20765 replica.cpp:664] Replica learned APPEND action =
at position 3
I0413 17:58:33.004876 20773 registrar.cpp:490] Successfully updated the 're=
gistry' in 78.436864ms
I0413 17:58:33.005249 20773 log.cpp:703] Attempting to truncate the log to =
3
I0413 17:58:33.005396 20778 coordinator.cpp:340] Coordinator attempting to =
write TRUNCATE action at position 4
I0413 17:58:33.005841 20771 master.cpp:3048] Registered slave 20150413-1758=
32-3176252227-60468-20747-S0 at slave(233)@67.195.81.189:60468 (proserpina.=
apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-3200=
0]
I0413 17:58:33.005897 20768 slave.cpp:2834] Received ping from slave-observ=
er(205)@67.195.81.189:60468
I0413 17:58:33.005965 20778 hierarchical.hpp:439] Added slave 20150413-1758=
32-3176252227-60468-20747-S0 (proserpina.apache.org) with cpus(*):2; mem(*)=
:1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; di=
sk(*):1024; ports(*):[31000-32000] available)
I0413 17:58:33.006142 20768 slave.cpp:795] Registered with master master@67=
.195.81.189:60468; given slave ID 20150413-175832-3176252227-60468-20747-S0
I0413 17:58:33.006309 20767 status_update_manager.cpp:178] Resuming sending=
 status updates
I0413 17:58:33.006463 20778 hierarchical.hpp:743] Performed allocation for =
slave 20150413-175832-3176252227-60468-20747-S0 in 444991ns
I0413 17:58:33.006490 20768 slave.cpp:810] Checkpointing SlaveInfo to '/tmp=
/MasterContenderDetectorTest_File_IEHCNA/meta/slaves/20150413-175832-317625=
2227-60468-20747-S0/slave.info'
I0413 17:58:33.006505 20776 replica.cpp:511] Replica received write request=
 for position 4
I0413 17:58:33.007000 20765 master.cpp:3803] Sending 1 offers to framework =
20150413-175832-3176252227-60468-20747-0000 (default) at scheduler-a65031fc=
-b0c2-4df8-bba5-20c8fb961369@67.195.81.189:60468
I0413 17:58:33.007438 20765 sched.cpp:611] Scheduler::resourceOffers took 7=
9956ns
I0413 17:58:33.007753 20747 sched.cpp:1589] Asked to stop the driver
I0413 17:58:33.007865 20747 master.cpp:788] Master terminating
I0413 17:58:33.007906 20765 sched.cpp:831] Stopping framework '20150413-175=
832-3176252227-60468-20747-0000'
I0413 17:58:33.008077 20769 hierarchical.hpp:470] Removed slave 20150413-17=
5832-3176252227-60468-20747-S0
I0413 17:58:33.008569 20767 hierarchical.hpp:354] Removed framework 2015041=
3-175832-3176252227-60468-20747-0000
I0413 17:58:33.008887 20774 slave.cpp:2919] master@67.195.81.189:60468 exit=
ed
W0413 17:58:33.008924 20774 slave.cpp:2922] Master disconnected! Waiting fo=
r a new master to be elected
I0413 17:58:33.045502 20776 leveldb.cpp:343] Persisting action (16 bytes) t=
o leveldb took 38.95226ms
I0413 17:58:33.045545 20776 replica.cpp:679] Persisted action at 4
I0413 17:58:33.047497 20747 slave.cpp:509] Slave terminating
[       OK ] MasterContenderDetectorTest.File (689 ms)
[----------] 1 test from MasterContenderDetectorTest (690 ms total)

[----------] 4 tests from SorterTest
[ RUN      ] SorterTest.WDRFSorter
[       OK ] SorterTest.WDRFSorter (1 ms)
[ RUN      ] SorterTest.Update
[       OK ] SorterTest.Update (1 ms)
[ RUN      ] SorterTest.DRFSorter
[       OK ] SorterTest.DRFSorter (1 ms)
[ RUN      ] SorterTest.SplitResourceShares
[       OK ] SorterTest.SplitResourceShares (1 ms)
[----------] 4 tests from SorterTest (4 ms total)

[----------] Global test environment tear-down
[=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D] 507 tests from 78 test cases ran. (335305 =
ms total)
[  PASSED  ] 506 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ExamplesTest.NoExecutorFramework

 1 FAILED TEST
  YOU HAVE 8 DISABLED TESTS

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubun=
tu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'=
>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubun=
tu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'=
>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubun=
tu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'=
>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results