You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/03/24 19:26:26 UTC

Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1868

See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1868/changes>

Changes:

[alexr] Made `shutdown_grace_period` configurable in `ExecutorInfo`.

[alexr] Added validation for executor's shutdown grace period.

[alexr] Enabled mocking on `TestContainerizer::destroy`.

[alexr] Reordered function declarations in `TestContainerizer`.

[alexr] Added a test for executor shutdown grace period.

[alexr] Introduced `KillPolicy` protobuf.

[alexr] Added validation for task's kill policy.

[alexr] Used `KillPolicy` and shutdown grace period in command executor.

[alexr] Removed unused signal escalation constant.

------------------------------------------
[...truncated 178888 lines...]
I0324 18:18:32.727934  2941 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/HAnkzr/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/HAnkzr/master" --zk_session_timeout="10secs"
I0324 18:18:32.728379  2941 master.cpp:429] Master allowing unauthenticated frameworks to register
I0324 18:18:32.728396  2941 master.cpp:432] Master only allowing authenticated slaves to register
I0324 18:18:32.728407  2941 credentials.hpp:35] Loading credentials for authentication from '/tmp/HAnkzr/credentials'
I0324 18:18:32.732620  2941 master.cpp:474] Using default 'crammd5' authenticator
I0324 18:18:32.732856  2941 master.cpp:545] Using default 'basic' HTTP authenticator
I0324 18:18:32.733007  2941 master.cpp:583] Authorization enabled
I0324 18:18:32.735493  2941 hierarchical.cpp:144] Initialized hierarchical allocator process
I0324 18:18:32.735597  2941 whitelist_watcher.cpp:77] No whitelist given
I0324 18:18:32.737787  2941 master.cpp:1826] The newly elected leader is master@172.17.0.2:35752 with id 794da039-9ec6-49a7-a761-74fe953d93a5
I0324 18:18:32.737825  2941 master.cpp:1839] Elected as the leading master!
I0324 18:18:32.737846  2941 master.cpp:1526] Recovering from registrar
I0324 18:18:32.738122  2941 registrar.cpp:307] Recovering registrar
I0324 18:18:32.740619  2942 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 26.155751ms
I0324 18:18:32.740675  2942 replica.cpp:320] Persisted replica status to STARTING
I0324 18:18:32.740938  2940 recover.cpp:473] Replica is in STARTING status
I0324 18:18:32.742079  2940 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (16406)@172.17.0.2:35752
I0324 18:18:32.742527  2951 recover.cpp:193] Received a recover response from a replica in STARTING status
I0324 18:18:32.743185  2951 recover.cpp:564] Updating replica status to VOTING
I0324 18:18:32.784221  2951 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.772134ms
I0324 18:18:32.784302  2951 replica.cpp:320] Persisted replica status to VOTING
I0324 18:18:32.784559  2951 recover.cpp:578] Successfully joined the Paxos group
I0324 18:18:32.784781  2951 recover.cpp:462] Recover process terminated
I0324 18:18:32.785506  2951 log.cpp:659] Attempting to start the writer
I0324 18:18:32.787117  2951 replica.cpp:493] Replica received implicit promise request from (16407)@172.17.0.2:35752 with proposal 1
I0324 18:18:32.818982  2951 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.810053ms
I0324 18:18:32.819061  2951 replica.cpp:342] Persisted promised to 1
I0324 18:18:32.826491  2940 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0324 18:18:32.828384  2937 replica.cpp:388] Replica received explicit promise request from (16408)@172.17.0.2:35752 for position 0 with proposal 2
I0324 18:18:32.860795  2937 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 32.340666ms
I0324 18:18:32.860875  2937 replica.cpp:712] Persisted action at 0
I0324 18:18:32.862355  2939 replica.cpp:537] Replica received write request for position 0 from (16409)@172.17.0.2:35752
I0324 18:18:32.862434  2939 leveldb.cpp:436] Reading position from leveldb took 40092ns
I0324 18:18:32.894232  2939 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 31.738118ms
I0324 18:18:32.894310  2939 replica.cpp:712] Persisted action at 0
I0324 18:18:32.895125  2939 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0324 18:18:32.927736  2939 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.553703ms
I0324 18:18:32.927846  2939 replica.cpp:712] Persisted action at 0
I0324 18:18:32.927886  2939 replica.cpp:697] Replica learned NOP action at position 0
I0324 18:18:32.929328  2939 log.cpp:675] Writer started with ending position 0
I0324 18:18:32.931125  2948 leveldb.cpp:436] Reading position from leveldb took 68606ns
I0324 18:18:32.932698  2948 registrar.cpp:340] Successfully fetched the registry (0B) in 194.521856ms
I0324 18:18:32.932835  2948 registrar.cpp:439] Applied 1 operations in 36990ns; attempting to update the 'registry'
I0324 18:18:32.933801  2948 log.cpp:683] Attempting to append 170 bytes to the log
I0324 18:18:32.933955  2936 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0324 18:18:32.935029  2947 replica.cpp:537] Replica received write request for position 1 from (16410)@172.17.0.2:35752
I0324 18:18:32.969491  2947 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 34.398022ms
I0324 18:18:32.969568  2947 replica.cpp:712] Persisted action at 1
I0324 18:18:32.970724  2936 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0324 18:18:33.002945  2936 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.170171ms
I0324 18:18:33.003024  2936 replica.cpp:712] Persisted action at 1
I0324 18:18:33.003059  2936 replica.cpp:697] Replica learned APPEND action at position 1
I0324 18:18:33.005071  2936 registrar.cpp:484] Successfully updated the 'registry' in 72.169984ms
I0324 18:18:33.005205  2936 registrar.cpp:370] Successfully recovered registrar
I0324 18:18:33.005458  2936 log.cpp:702] Attempting to truncate the log to 1
I0324 18:18:33.005897  2936 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0324 18:18:33.006266  2947 master.cpp:1634] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0324 18:18:33.006755  2951 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0324 18:18:33.007586  2944 replica.cpp:537] Replica received write request for position 2 from (16411)@172.17.0.2:35752
I0324 18:18:33.036458  2944 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 28.790283ms
I0324 18:18:33.036573  2944 replica.cpp:712] Persisted action at 2
I0324 18:18:33.038312  2944 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0324 18:18:33.069902  2944 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 31.518669ms
I0324 18:18:33.070089  2944 leveldb.cpp:399] Deleting ~1 keys from leveldb took 91222ns
I0324 18:18:33.070125  2944 replica.cpp:712] Persisted action at 2
I0324 18:18:33.070168  2944 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0324 18:18:33.078348  2917 scheduler.cpp:172] Version: 0.29.0
I0324 18:18:33.079670  2938 scheduler.cpp:438] New master detected at master@172.17.0.2:35752
I0324 18:18:33.082869  2940 scheduler.cpp:338] Connected with the master at http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.084343  2940 scheduler.cpp:231] Sending SUBSCRIBE call to http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.085860  2940 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0324 18:18:33.086390  2940 http.cpp:313] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37865
I0324 18:18:33.086633  2940 master.cpp:2088] Received subscription request for HTTP framework 'default'
I0324 18:18:33.086709  2940 master.cpp:1865] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0324 18:18:33.087383  2940 master.cpp:2179] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0324 18:18:33.088001  2940 hierarchical.cpp:265] Added framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000
I0324 18:18:33.088093  2940 hierarchical.cpp:1487] No resources available to allocate!
I0324 18:18:33.088125  2940 hierarchical.cpp:1582] No inverse offers to send out!
I0324 18:18:33.088184  2940 hierarchical.cpp:1138] Performed allocation for 0 slaves in 159893ns
I0324 18:18:33.088309  2940 master.hpp:1715] Sending heartbeat to 794da039-9ec6-49a7-a761-74fe953d93a5-0000
I0324 18:18:33.090559  2939 scheduler.cpp:613] Enqueuing event SUBSCRIBED received from http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.091434  2939 scheduler.cpp:613] Enqueuing event HEARTBEAT received from http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.092252  2939 scheduler.cpp:231] Sending REQUEST call to http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.094259  2947 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0324 18:18:33.094821  2947 http.cpp:313] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37866
I0324 18:18:33.094966  2947 master.cpp:2785] Processing REQUEST call for framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
I0324 18:18:33.095186  2950 hierarchical.cpp:589] Received resource request from framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000
I0324 18:18:33.097659  2938 master.cpp:1269] Framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default) disconnected
I0324 18:18:33.097697  2938 master.cpp:2642] Disconnecting framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
I0324 18:18:33.097729  2938 master.cpp:2666] Deactivating framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
I0324 18:18:33.097836  2938 master.cpp:1293] Giving framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default) 0ns to failover
I0324 18:18:33.097915  2948 hierarchical.cpp:375] Deactivated framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000
I0324 18:18:33.098095  2946 master.cpp:5360] Framework failover timeout, removing framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
I0324 18:18:33.098125  2946 master.cpp:6093] Removing framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
I0324 18:18:33.098383  2946 hierarchical.cpp:326] Removed framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000
I0324 18:18:33.108203  2946 master.cpp:1083] Master terminating
[       OK ] ContentType/SchedulerTest.Request/0 (524 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
I0324 18:18:33.118060  2917 cluster.cpp:139] Creating default 'local' authorizer
I0324 18:18:33.244488  2917 leveldb.cpp:174] Opened db in 126.025641ms
I0324 18:18:33.269678  2917 leveldb.cpp:181] Compacted db in 25.08737ms
I0324 18:18:33.269819  2917 leveldb.cpp:196] Created db iterator in 37843ns
I0324 18:18:33.269840  2917 leveldb.cpp:202] Seeked to beginning of db in 4019ns
I0324 18:18:33.269851  2917 leveldb.cpp:271] Iterated through 0 keys in the db in 372ns
I0324 18:18:33.269918  2917 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0324 18:18:33.270630  2938 recover.cpp:447] Starting replica recovery
I0324 18:18:33.271091  2938 recover.cpp:473] Replica is in EMPTY status
I0324 18:18:33.272235  2942 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (16419)@172.17.0.2:35752
I0324 18:18:33.272658  2945 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0324 18:18:33.273293  2941 recover.cpp:564] Updating replica status to STARTING
I0324 18:18:33.275342  2943 master.cpp:376] Master 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8 (da8687b8fa54) started on 172.17.0.2:35752
I0324 18:18:33.275372  2943 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/0ylaz9/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/0ylaz9/master" --zk_session_timeout="10secs"
I0324 18:18:33.275810  2943 master.cpp:429] Master allowing unauthenticated frameworks to register
I0324 18:18:33.275823  2943 master.cpp:432] Master only allowing authenticated slaves to register
I0324 18:18:33.275833  2943 credentials.hpp:35] Loading credentials for authentication from '/tmp/0ylaz9/credentials'
I0324 18:18:33.276223  2943 master.cpp:474] Using default 'crammd5' authenticator
I0324 18:18:33.276381  2943 master.cpp:545] Using default 'basic' HTTP authenticator
I0324 18:18:33.276545  2943 master.cpp:583] Authorization enabled
I0324 18:18:33.276751  2945 whitelist_watcher.cpp:77] No whitelist given
I0324 18:18:33.276757  2951 hierarchical.cpp:144] Initialized hierarchical allocator process
I0324 18:18:33.279866  2938 master.cpp:1826] The newly elected leader is master@172.17.0.2:35752 with id 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8
I0324 18:18:33.279908  2938 master.cpp:1839] Elected as the leading master!
I0324 18:18:33.279927  2938 master.cpp:1526] Recovering from registrar
I0324 18:18:33.280071  2937 registrar.cpp:307] Recovering registrar
I0324 18:18:33.311316  2946 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.739218ms
I0324 18:18:33.311398  2946 replica.cpp:320] Persisted replica status to STARTING
I0324 18:18:33.311815  2948 recover.cpp:473] Replica is in STARTING status
I0324 18:18:33.313205  2941 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (16421)@172.17.0.2:35752
I0324 18:18:33.313823  2942 recover.cpp:193] Received a recover response from a replica in STARTING status
I0324 18:18:33.314445  2939 recover.cpp:564] Updating replica status to VOTING
I0324 18:18:33.353124  2949 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.314034ms
I0324 18:18:33.353224  2949 replica.cpp:320] Persisted replica status to VOTING
I0324 18:18:33.353498  2942 recover.cpp:578] Successfully joined the Paxos group
I0324 18:18:33.353858  2942 recover.cpp:462] Recover process terminated
I0324 18:18:33.354537  2937 log.cpp:659] Attempting to start the writer
I0324 18:18:33.356223  2947 replica.cpp:493] Replica received implicit promise request from (16422)@172.17.0.2:35752 with proposal 1
I0324 18:18:33.395563  2947 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.269943ms
I0324 18:18:33.395664  2947 replica.cpp:342] Persisted promised to 1
I0324 18:18:33.396785  2936 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0324 18:18:33.398362  2948 replica.cpp:388] Replica received explicit promise request from (16423)@172.17.0.2:35752 for position 0 with proposal 2
I0324 18:18:33.437350  2948 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 38.913343ms
I0324 18:18:33.437458  2948 replica.cpp:712] Persisted action at 0
I0324 18:18:33.439613  2948 replica.cpp:537] Replica received write request for position 0 from (16424)@172.17.0.2:35752
I0324 18:18:33.439769  2948 leveldb.cpp:436] Reading position from leveldb took 64592ns
I0324 18:18:33.479143  2948 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.293981ms
I0324 18:18:33.479254  2948 replica.cpp:712] Persisted action at 0
I0324 18:18:33.480187  2948 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0324 18:18:33.520982  2948 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.731571ms
I0324 18:18:33.521090  2948 replica.cpp:712] Persisted action at 0
I0324 18:18:33.521131  2948 replica.cpp:697] Replica learned NOP action at position 0
I0324 18:18:33.522296  2941 log.cpp:675] Writer started with ending position 0
I0324 18:18:33.524039  2941 leveldb.cpp:436] Reading position from leveldb took 82100ns
I0324 18:18:33.525632  2941 registrar.cpp:340] Successfully fetched the registry (0B) in 245.508096ms
I0324 18:18:33.526006  2941 registrar.cpp:439] Applied 1 operations in 47842ns; attempting to update the 'registry'
I0324 18:18:33.527345  2939 log.cpp:683] Attempting to append 170 bytes to the log
I0324 18:18:33.527500  2946 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0324 18:18:33.528369  2944 replica.cpp:537] Replica received write request for position 1 from (16425)@172.17.0.2:35752
I0324 18:18:33.567533  2944 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 39.086046ms
I0324 18:18:33.567646  2944 replica.cpp:712] Persisted action at 1
I0324 18:18:33.569286  2944 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0324 18:18:33.611896  2944 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 42.546192ms
I0324 18:18:33.612004  2944 replica.cpp:712] Persisted action at 1
I0324 18:18:33.612042  2944 replica.cpp:697] Replica learned APPEND action at position 1
I0324 18:18:33.614609  2940 registrar.cpp:484] Successfully updated the 'registry' in 88.496128ms
I0324 18:18:33.614696  2946 log.cpp:702] Attempting to truncate the log to 1
I0324 18:18:33.614866  2940 registrar.cpp:370] Successfully recovered registrar
I0324 18:18:33.614959  2947 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0324 18:18:33.615382  2946 master.cpp:1634] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0324 18:18:33.615574  2947 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0324 18:18:33.616358  2947 replica.cpp:537] Replica received write request for position 2 from (16426)@172.17.0.2:35752
I0324 18:18:33.638437  2947 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.014351ms
I0324 18:18:33.638525  2947 replica.cpp:712] Persisted action at 2
I0324 18:18:33.640084  2947 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0324 18:18:33.663570  2947 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.435655ms
I0324 18:18:33.663738  2947 leveldb.cpp:399] Deleting ~1 keys from leveldb took 87570ns
I0324 18:18:33.663769  2947 replica.cpp:712] Persisted action at 2
I0324 18:18:33.663805  2947 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0324 18:18:33.666810  2917 scheduler.cpp:172] Version: 0.29.0
I0324 18:18:33.667913  2951 scheduler.cpp:438] New master detected at master@172.17.0.2:35752
I0324 18:18:33.670063  2951 scheduler.cpp:338] Connected with the master at http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.671396  2950 scheduler.cpp:231] Sending SUBSCRIBE call to http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.672859  2944 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0324 18:18:33.673425  2951 http.cpp:313] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37868
I0324 18:18:33.673959  2951 master.cpp:2088] Received subscription request for HTTP framework 'default'
I0324 18:18:33.674038  2951 master.cpp:1865] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0324 18:18:33.674345  2951 master.cpp:2179] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0324 18:18:33.674947  2943 hierarchical.cpp:265] Added framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
I0324 18:18:33.675052  2943 hierarchical.cpp:1487] No resources available to allocate!
I0324 18:18:33.675093  2943 hierarchical.cpp:1582] No inverse offers to send out!
I0324 18:18:33.675159  2943 hierarchical.cpp:1138] Performed allocation for 0 slaves in 181728ns
I0324 18:18:33.675197  2943 master.hpp:1715] Sending heartbeat to 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
I0324 18:18:33.677348  2951 scheduler.cpp:613] Enqueuing event SUBSCRIBED received from http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.678287  2951 scheduler.cpp:613] Enqueuing event HEARTBEAT received from http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.679734  2941 scheduler.cpp:231] Sending REQUEST call to http://172.17.0.2:35752/master/api/v1/scheduler
I0324 18:18:33.680953  2938 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0324 18:18:33.681453  2938 http.cpp:313] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:37869
I0324 18:18:33.681818  2938 master.cpp:2785] Processing REQUEST call for framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
I0324 18:18:33.682054  2938 hierarchical.cpp:589] Received resource request from framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
I0324 18:18:33.685675  2951 master.cpp:1269] Framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default) disconnected
I0324 18:18:33.685739  2951 master.cpp:2642] Disconnecting framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
I0324 18:18:33.685763  2951 master.cpp:2666] Deactivating framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
I0324 18:18:33.685873  2951 master.cpp:1293] Giving framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default) 0ns to failover
I0324 18:18:33.685902  2938 hierarchical.cpp:375] Deactivated framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
I0324 18:18:33.686885  2946 master.cpp:5360] Framework failover timeout, removing framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
I0324 18:18:33.686914  2946 master.cpp:6093] Removing framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
I0324 18:18:33.687233  2945 hierarchical.cpp:326] Removed framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
I0324 18:18:33.695585  2917 master.cpp:1083] Master terminating
[       OK ] ContentType/SchedulerTest.Request/1 (592 ms)
[----------] 26 tests from ContentType/SchedulerTest (19838 ms total)

[----------] Global test environment tear-down
E0324 18:18:33.856365  2917 environment.cpp:778] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_kTIZtn': No such file or directory
E0324 18:18:33.856446  2917 environment.cpp:778] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_cqHtsH': No such file or directory
[==========] 1047 tests from 131 test cases ran. (799665 ms total)
[  PASSED  ] 1046 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ContainerLoggerTest.LOGROTATE_RotateInSandbox

 1 FAILED TEST
  YOU HAVE 6 DISABLED TESTS

make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1458840396-23336
Untagged: mesos-1458840396-23336:latest
Deleted: 1d0f6d051e9d0e3a5393bd60189dbd8953f85132df51261814b5e5e23865ec90
Deleted: 5b82909aae8a30813bc1a3aaf0195b4df74b26bbcb0282e29ad26ba127db04b6
Deleted: ee2327d921aa902700696c8dc1e0da93ecaa94c4bbb293d451fa952d350a9bbf
Deleted: 607f4f01b0f5d4dc056bf9e843e02d830f9e37a1879ca4e9c9e74c15fbcdd7a0
Deleted: 67ae2f802f1d414f37c78abcd0f3ecd5c78ddd0c908657196778a4e545baed6f
Deleted: c16cd0094ef8598fa723cb61a4851888a921c8913d6c698e23c4365a18b41bac
Deleted: 2f6e1c1fb5df7a41bddd6ca183261c764af4bd1d33cd83173e263f45b82a35ed
Deleted: 2fc8d1813ba8f8d18a50f08b1f32956cf7defda330eabfa1e67e662796e3f8fc
Deleted: 38bd8617d973b224a80808ad29eb6c4599e1c57f480432e8514fd3930c0edf81
Deleted: 070f6c31ae4e887905534a5e6e3a223e417bc2763840f4690e6de8ca63778cc7
Deleted: eea79dce0cbd215897d3f48880ebe30da7d019d00d3eca0715875988036a9e66
Deleted: a99168a63df342d9be756e33776dad7c1bd2a7db97eb8c63711593fa53ce93f1
Deleted: aecd1498b47ecdc2eda4b7f5251a51fe7eb7c4fcd7837d3ffaac65d0c4a47493
Deleted: 7cc7b907d512a3a83b72baae1b4a76e8673e139f64aaa3e075842ec0dba3c181
Deleted: 0eeb76e22e1985f96e7931225d09f8554d95524d71a79b94e1256db81207fe28
Deleted: bbcd90014d422faeecd8d1cedf98a43c0eb75899d138c2c55b7067445d25f6f7
Build step 'Execute shell' marked build as failure

Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1868

Posted by Alex R <al...@apache.org>.
Probably https://issues.apache.org/jira/browse/MESOS-4961

On 24 March 2016 at 19:26, Apache Jenkins Server <je...@builds.apache.org>
wrote:

> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1868/changes
> >
>
> Changes:
>
> [alexr] Made `shutdown_grace_period` configurable in `ExecutorInfo`.
>
> [alexr] Added validation for executor's shutdown grace period.
>
> [alexr] Enabled mocking on `TestContainerizer::destroy`.
>
> [alexr] Reordered function declarations in `TestContainerizer`.
>
> [alexr] Added a test for executor shutdown grace period.
>
> [alexr] Introduced `KillPolicy` protobuf.
>
> [alexr] Added validation for task's kill policy.
>
> [alexr] Used `KillPolicy` and shutdown grace period in command executor.
>
> [alexr] Removed unused signal escalation constant.
>
> ------------------------------------------
> [...truncated 178888 lines...]
> I0324 18:18:32.727934 2941 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/HAnkzr/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/HAnkzr/master" --zk_session_timeout="10secs"
> I0324 18:18:32.728379  2941 master.cpp:429] Master allowing
> unauthenticated frameworks to register
> I0324 18:18:32.728396  2941 master.cpp:432] Master only allowing
> authenticated slaves to register
> I0324 18:18:32.728407  2941 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/HAnkzr/credentials'
> I0324 18:18:32.732620  2941 master.cpp:474] Using default 'crammd5'
> authenticator
> I0324 18:18:32.732856  2941 master.cpp:545] Using default 'basic' HTTP
> authenticator
> I0324 18:18:32.733007  2941 master.cpp:583] Authorization enabled
> I0324 18:18:32.735493  2941 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0324 18:18:32.735597  2941 whitelist_watcher.cpp:77] No whitelist given
> I0324 18:18:32.737787  2941 master.cpp:1826] The newly elected leader is
> master@172.17.0.2:35752 with id 794da039-9ec6-49a7-a761-74fe953d93a5
> I0324 18:18:32.737825  2941 master.cpp:1839] Elected as the leading master!
> I0324 18:18:32.737846  2941 master.cpp:1526] Recovering from registrar
> I0324 18:18:32.738122  2941 registrar.cpp:307] Recovering registrar
> I0324 18:18:32.740619  2942 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 26.155751ms
> I0324 18:18:32.740675  2942 replica.cpp:320] Persisted replica status to
> STARTING
> I0324 18:18:32.740938  2940 recover.cpp:473] Replica is in STARTING status
> I0324 18:18:32.742079  2940 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (16406)@172.17.0.2:35752
> I0324 18:18:32.742527  2951 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0324 18:18:32.743185  2951 recover.cpp:564] Updating replica status to
> VOTING
> I0324 18:18:32.784221  2951 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 40.772134ms
> I0324 18:18:32.784302  2951 replica.cpp:320] Persisted replica status to
> VOTING
> I0324 18:18:32.784559  2951 recover.cpp:578] Successfully joined the Paxos
> group
> I0324 18:18:32.784781  2951 recover.cpp:462] Recover process terminated
> I0324 18:18:32.785506  2951 log.cpp:659] Attempting to start the writer
> I0324 18:18:32.787117  2951 replica.cpp:493] Replica received implicit
> promise request from (16407)@172.17.0.2:35752 with proposal 1
> I0324 18:18:32.818982 2951 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 31.810053ms
> I0324 18:18:32.819061  2951 replica.cpp:342] Persisted promised to 1
> I0324 18:18:32.826491  2940 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0324 18:18:32.828384  2937 replica.cpp:388] Replica received explicit
> promise request from (16408)@172.17.0.2:35752 for position 0 with
> proposal 2
> I0324 18:18:32.860795 2937 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 32.340666ms
> I0324 18:18:32.860875  2937 replica.cpp:712] Persisted action at 0
> I0324 18:18:32.862355  2939 replica.cpp:537] Replica received write
> request for position 0 from (16409)@172.17.0.2:35752
> I0324 18:18:32.862434 2939 leveldb.cpp:436] Reading position from leveldb
> took 40092ns
> I0324 18:18:32.894232  2939 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 31.738118ms
> I0324 18:18:32.894310  2939 replica.cpp:712] Persisted action at 0
> I0324 18:18:32.895125  2939 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0324 18:18:32.927736  2939 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 32.553703ms
> I0324 18:18:32.927846  2939 replica.cpp:712] Persisted action at 0
> I0324 18:18:32.927886  2939 replica.cpp:697] Replica learned NOP action at
> position 0
> I0324 18:18:32.929328  2939 log.cpp:675] Writer started with ending
> position 0
> I0324 18:18:32.931125  2948 leveldb.cpp:436] Reading position from leveldb
> took 68606ns
> I0324 18:18:32.932698  2948 registrar.cpp:340] Successfully fetched the
> registry (0B) in 194.521856ms
> I0324 18:18:32.932835  2948 registrar.cpp:439] Applied 1 operations in
> 36990ns; attempting to update the 'registry'
> I0324 18:18:32.933801  2948 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0324 18:18:32.933955  2936 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0324 18:18:32.935029  2947 replica.cpp:537] Replica received write
> request for position 1 from (16410)@172.17.0.2:35752
> I0324 18:18:32.969491  2947 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 34.398022ms
> I0324 18:18:32.969568  2947 replica.cpp:712] Persisted action at 1
> I0324 18:18:32.970724  2936 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0324 18:18:33.002945  2936 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 32.170171ms
> I0324 18:18:33.003024  2936 replica.cpp:712] Persisted action at 1
> I0324 18:18:33.003059  2936 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0324 18:18:33.005071  2936 registrar.cpp:484] Successfully updated the
> 'registry' in 72.169984ms
> I0324 18:18:33.005205  2936 registrar.cpp:370] Successfully recovered
> registrar
> I0324 18:18:33.005458  2936 log.cpp:702] Attempting to truncate the log to
> 1
> I0324 18:18:33.005897  2936 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0324 18:18:33.006266  2947 master.cpp:1634] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0324 18:18:33.006755  2951 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0324 18:18:33.007586  2944 replica.cpp:537] Replica received write
> request for position 2 from (16411)@172.17.0.2:35752
> I0324 18:18:33.036458  2944 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 28.790283ms
> I0324 18:18:33.036573  2944 replica.cpp:712] Persisted action at 2
> I0324 18:18:33.038312  2944 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0324 18:18:33.069902  2944 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 31.518669ms
> I0324 18:18:33.070089  2944 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 91222ns
> I0324 18:18:33.070125  2944 replica.cpp:712] Persisted action at 2
> I0324 18:18:33.070168  2944 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0324 18:18:33.078348  2917 scheduler.cpp:172] Version: 0.29.0
> I0324 18:18:33.079670  2938 scheduler.cpp:438] New master detected at
> master@172.17.0.2:35752
> I0324 18:18:33.082869  2940 scheduler.cpp:338] Connected with the master
> at http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.084343  2940 scheduler.cpp:231] Sending SUBSCRIBE call to
> http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.085860  2940 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0324 18:18:33.086390  2940 http.cpp:313] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37865
> I0324 18:18:33.086633  2940 master.cpp:2088] Received subscription request
> for HTTP framework 'default'
> I0324 18:18:33.086709  2940 master.cpp:1865] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0324 18:18:33.087383  2940 master.cpp:2179] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I0324 18:18:33.088001  2940 hierarchical.cpp:265] Added framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000
> I0324 18:18:33.088093  2940 hierarchical.cpp:1487] No resources available
> to allocate!
> I0324 18:18:33.088125  2940 hierarchical.cpp:1582] No inverse offers to
> send out!
> I0324 18:18:33.088184  2940 hierarchical.cpp:1138] Performed allocation
> for 0 slaves in 159893ns
> I0324 18:18:33.088309  2940 master.hpp:1715] Sending heartbeat to
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000
> I0324 18:18:33.090559  2939 scheduler.cpp:613] Enqueuing event SUBSCRIBED
> received from http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.091434  2939 scheduler.cpp:613] Enqueuing event HEARTBEAT
> received from http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.092252  2939 scheduler.cpp:231] Sending REQUEST call to
> http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.094259  2947 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0324 18:18:33.094821  2947 http.cpp:313] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37866
> I0324 18:18:33.094966  2947 master.cpp:2785] Processing REQUEST call for
> framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
> I0324 18:18:33.095186  2950 hierarchical.cpp:589] Received resource
> request from framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000
> I0324 18:18:33.097659  2938 master.cpp:1269] Framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default) disconnected
> I0324 18:18:33.097697  2938 master.cpp:2642] Disconnecting framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
> I0324 18:18:33.097729  2938 master.cpp:2666] Deactivating framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
> I0324 18:18:33.097836  2938 master.cpp:1293] Giving framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default) 0ns to failover
> I0324 18:18:33.097915  2948 hierarchical.cpp:375] Deactivated framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000
> I0324 18:18:33.098095  2946 master.cpp:5360] Framework failover timeout,
> removing framework 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
> I0324 18:18:33.098125  2946 master.cpp:6093] Removing framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000 (default)
> I0324 18:18:33.098383  2946 hierarchical.cpp:326] Removed framework
> 794da039-9ec6-49a7-a761-74fe953d93a5-0000
> I0324 18:18:33.108203  2946 master.cpp:1083] Master terminating
> [       OK ] ContentType/SchedulerTest.Request/0 (524 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/1
> I0324 18:18:33.118060  2917 cluster.cpp:139] Creating default 'local'
> authorizer
> I0324 18:18:33.244488  2917 leveldb.cpp:174] Opened db in 126.025641ms
> I0324 18:18:33.269678  2917 leveldb.cpp:181] Compacted db in 25.08737ms
> I0324 18:18:33.269819  2917 leveldb.cpp:196] Created db iterator in 37843ns
> I0324 18:18:33.269840  2917 leveldb.cpp:202] Seeked to beginning of db in
> 4019ns
> I0324 18:18:33.269851  2917 leveldb.cpp:271] Iterated through 0 keys in
> the db in 372ns
> I0324 18:18:33.269918  2917 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0324 18:18:33.270630  2938 recover.cpp:447] Starting replica recovery
> I0324 18:18:33.271091  2938 recover.cpp:473] Replica is in EMPTY status
> I0324 18:18:33.272235  2942 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (16419)@172.17.0.2:35752
> I0324 18:18:33.272658 2945 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0324 18:18:33.273293  2941 recover.cpp:564] Updating replica status to
> STARTING
> I0324 18:18:33.275342  2943 master.cpp:376] Master
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8 (da8687b8fa54) started on
> 172.17.0.2:35752
> I0324 18:18:33.275372  2943 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/0ylaz9/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/0ylaz9/master" --zk_session_timeout="10secs"
> I0324 18:18:33.275810  2943 master.cpp:429] Master allowing
> unauthenticated frameworks to register
> I0324 18:18:33.275823  2943 master.cpp:432] Master only allowing
> authenticated slaves to register
> I0324 18:18:33.275833  2943 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/0ylaz9/credentials'
> I0324 18:18:33.276223  2943 master.cpp:474] Using default 'crammd5'
> authenticator
> I0324 18:18:33.276381  2943 master.cpp:545] Using default 'basic' HTTP
> authenticator
> I0324 18:18:33.276545  2943 master.cpp:583] Authorization enabled
> I0324 18:18:33.276751  2945 whitelist_watcher.cpp:77] No whitelist given
> I0324 18:18:33.276757  2951 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0324 18:18:33.279866  2938 master.cpp:1826] The newly elected leader is
> master@172.17.0.2:35752 with id 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8
> I0324 18:18:33.279908  2938 master.cpp:1839] Elected as the leading master!
> I0324 18:18:33.279927  2938 master.cpp:1526] Recovering from registrar
> I0324 18:18:33.280071  2937 registrar.cpp:307] Recovering registrar
> I0324 18:18:33.311316  2946 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 37.739218ms
> I0324 18:18:33.311398  2946 replica.cpp:320] Persisted replica status to
> STARTING
> I0324 18:18:33.311815  2948 recover.cpp:473] Replica is in STARTING status
> I0324 18:18:33.313205  2941 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (16421)@172.17.0.2:35752
> I0324 18:18:33.313823 2942 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0324 18:18:33.314445  2939 recover.cpp:564] Updating replica status to
> VOTING
> I0324 18:18:33.353124  2949 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 38.314034ms
> I0324 18:18:33.353224  2949 replica.cpp:320] Persisted replica status to
> VOTING
> I0324 18:18:33.353498  2942 recover.cpp:578] Successfully joined the Paxos
> group
> I0324 18:18:33.353858  2942 recover.cpp:462] Recover process terminated
> I0324 18:18:33.354537  2937 log.cpp:659] Attempting to start the writer
> I0324 18:18:33.356223  2947 replica.cpp:493] Replica received implicit
> promise request from (16422)@172.17.0.2:35752 with proposal 1
> I0324 18:18:33.395563  2947 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 39.269943ms
> I0324 18:18:33.395664  2947 replica.cpp:342] Persisted promised to 1
> I0324 18:18:33.396785  2936 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0324 18:18:33.398362  2948 replica.cpp:388] Replica received explicit
> promise request from (16423)@172.17.0.2:35752 for position 0 with
> proposal 2
> I0324 18:18:33.437350 2948 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 38.913343ms
> I0324 18:18:33.437458  2948 replica.cpp:712] Persisted action at 0
> I0324 18:18:33.439613  2948 replica.cpp:537] Replica received write
> request for position 0 from (16424)@172.17.0.2:35752
> I0324 18:18:33.439769  2948 leveldb.cpp:436] Reading position from leveldb
> took 64592ns
> I0324 18:18:33.479143  2948 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 39.293981ms
> I0324 18:18:33.479254  2948 replica.cpp:712] Persisted action at 0
> I0324 18:18:33.480187  2948 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0324 18:18:33.520982 2948 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 40.731571ms
> I0324 18:18:33.521090  2948 replica.cpp:712] Persisted action at 0
> I0324 18:18:33.521131  2948 replica.cpp:697] Replica learned NOP action at
> position 0
> I0324 18:18:33.522296  2941 log.cpp:675] Writer started with ending
> position 0
> I0324 18:18:33.524039  2941 leveldb.cpp:436] Reading position from leveldb
> took 82100ns
> I0324 18:18:33.525632  2941 registrar.cpp:340] Successfully fetched the
> registry (0B) in 245.508096ms
> I0324 18:18:33.526006  2941 registrar.cpp:439] Applied 1 operations in
> 47842ns; attempting to update the 'registry'
> I0324 18:18:33.527345  2939 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0324 18:18:33.527500  2946 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0324 18:18:33.528369  2944 replica.cpp:537] Replica received write
> request for position 1 from (16425)@172.17.0.2:35752
> I0324 18:18:33.567533 2944 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 39.086046ms
> I0324 18:18:33.567646  2944 replica.cpp:712] Persisted action at 1
> I0324 18:18:33.569286  2944 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0324 18:18:33.611896  2944 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 42.546192ms
> I0324 18:18:33.612004  2944 replica.cpp:712] Persisted action at 1
> I0324 18:18:33.612042  2944 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0324 18:18:33.614609  2940 registrar.cpp:484] Successfully updated the
> 'registry' in 88.496128ms
> I0324 18:18:33.614696  2946 log.cpp:702] Attempting to truncate the log to
> 1
> I0324 18:18:33.614866  2940 registrar.cpp:370] Successfully recovered
> registrar
> I0324 18:18:33.614959  2947 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0324 18:18:33.615382  2946 master.cpp:1634] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0324 18:18:33.615574  2947 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0324 18:18:33.616358  2947 replica.cpp:537] Replica received write
> request for position 2 from (16426)@172.17.0.2:35752
> I0324 18:18:33.638437  2947 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 22.014351ms
> I0324 18:18:33.638525  2947 replica.cpp:712] Persisted action at 2
> I0324 18:18:33.640084  2947 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0324 18:18:33.663570  2947 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 23.435655ms
> I0324 18:18:33.663738  2947 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 87570ns
> I0324 18:18:33.663769  2947 replica.cpp:712] Persisted action at 2
> I0324 18:18:33.663805  2947 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0324 18:18:33.666810  2917 scheduler.cpp:172] Version: 0.29.0
> I0324 18:18:33.667913  2951 scheduler.cpp:438] New master detected at
> master@172.17.0.2:35752
> I0324 18:18:33.670063  2951 scheduler.cpp:338] Connected with the master
> at http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.671396  2950 scheduler.cpp:231] Sending SUBSCRIBE call to
> http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.672859  2944 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0324 18:18:33.673425  2951 http.cpp:313] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37868
> I0324 18:18:33.673959  2951 master.cpp:2088] Received subscription request
> for HTTP framework 'default'
> I0324 18:18:33.674038  2951 master.cpp:1865] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0324 18:18:33.674345  2951 master.cpp:2179] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I0324 18:18:33.674947  2943 hierarchical.cpp:265] Added framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
> I0324 18:18:33.675052  2943 hierarchical.cpp:1487] No resources available
> to allocate!
> I0324 18:18:33.675093  2943 hierarchical.cpp:1582] No inverse offers to
> send out!
> I0324 18:18:33.675159  2943 hierarchical.cpp:1138] Performed allocation
> for 0 slaves in 181728ns
> I0324 18:18:33.675197  2943 master.hpp:1715] Sending heartbeat to
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
> I0324 18:18:33.677348  2951 scheduler.cpp:613] Enqueuing event SUBSCRIBED
> received from http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.678287 2951 scheduler.cpp:613] Enqueuing event HEARTBEAT
> received from http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.679734  2941 scheduler.cpp:231] Sending REQUEST call to
> http://172.17.0.2:35752/master/api/v1/scheduler
> I0324 18:18:33.680953  2938 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0324 18:18:33.681453  2938 http.cpp:313] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:37869
> I0324 18:18:33.681818 2938 master.cpp:2785] Processing REQUEST call for
> framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
> I0324 18:18:33.682054  2938 hierarchical.cpp:589] Received resource
> request from framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
> I0324 18:18:33.685675  2951 master.cpp:1269] Framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default) disconnected
> I0324 18:18:33.685739  2951 master.cpp:2642] Disconnecting framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
> I0324 18:18:33.685763  2951 master.cpp:2666] Deactivating framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
> I0324 18:18:33.685873  2951 master.cpp:1293] Giving framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default) 0ns to failover
> I0324 18:18:33.685902  2938 hierarchical.cpp:375] Deactivated framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
> I0324 18:18:33.686885  2946 master.cpp:5360] Framework failover timeout,
> removing framework 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
> I0324 18:18:33.686914  2946 master.cpp:6093] Removing framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000 (default)
> I0324 18:18:33.687233  2945 hierarchical.cpp:326] Removed framework
> 6ea7d8ac-0065-408d-b4f2-1a80bc9ac3c8-0000
> I0324 18:18:33.695585  2917 master.cpp:1083] Master terminating
> [       OK ] ContentType/SchedulerTest.Request/1 (592 ms)
> [----------] 26 tests from ContentType/SchedulerTest (19838 ms total)
>
> [----------] Global test environment tear-down
> E0324 18:18:33.856365  2917 environment.cpp:778] Failed to remove
> '/tmp/LogZooKeeperTest_WriteRead_kTIZtn': No such file or directory
> E0324 18:18:33.856446  2917 environment.cpp:778] Failed to remove
> '/tmp/LogZooKeeperTest_LostZooKeeper_cqHtsH': No such file or directory
> [==========] 1047 tests from 131 test cases ran. (799665 ms total)
> [  PASSED  ] 1046 tests.
> [  FAILED  ] 1 test, listed below:
> [  FAILED  ] ContainerLoggerTest.LOGROTATE_RotateInSandbox
>
>  1 FAILED TEST
>   YOU HAVE 6 DISABLED TESTS
>
> make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[4]: *** [check-local] Error 1
> make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
> make[1]: *** [check-recursive] Error 1
> make: *** [distcheck] Error 1
> + docker rmi mesos-1458840396-23336
> Untagged: mesos-1458840396-23336:latest
> Deleted: 1d0f6d051e9d0e3a5393bd60189dbd8953f85132df51261814b5e5e23865ec90
> Deleted: 5b82909aae8a30813bc1a3aaf0195b4df74b26bbcb0282e29ad26ba127db04b6
> Deleted: ee2327d921aa902700696c8dc1e0da93ecaa94c4bbb293d451fa952d350a9bbf
> Deleted: 607f4f01b0f5d4dc056bf9e843e02d830f9e37a1879ca4e9c9e74c15fbcdd7a0
> Deleted: 67ae2f802f1d414f37c78abcd0f3ecd5c78ddd0c908657196778a4e545baed6f
> Deleted: c16cd0094ef8598fa723cb61a4851888a921c8913d6c698e23c4365a18b41bac
> Deleted: 2f6e1c1fb5df7a41bddd6ca183261c764af4bd1d33cd83173e263f45b82a35ed
> Deleted: 2fc8d1813ba8f8d18a50f08b1f32956cf7defda330eabfa1e67e662796e3f8fc
> Deleted: 38bd8617d973b224a80808ad29eb6c4599e1c57f480432e8514fd3930c0edf81
> Deleted: 070f6c31ae4e887905534a5e6e3a223e417bc2763840f4690e6de8ca63778cc7
> Deleted: eea79dce0cbd215897d3f48880ebe30da7d019d00d3eca0715875988036a9e66
> Deleted: a99168a63df342d9be756e33776dad7c1bd2a7db97eb8c63711593fa53ce93f1
> Deleted: aecd1498b47ecdc2eda4b7f5251a51fe7eb7c4fcd7837d3ffaac65d0c4a47493
> Deleted: 7cc7b907d512a3a83b72baae1b4a76e8673e139f64aaa3e075842ec0dba3c181
> Deleted: 0eeb76e22e1985f96e7931225d09f8554d95524d71a79b94e1256db81207fe28
> Deleted: bbcd90014d422faeecd8d1cedf98a43c0eb75899d138c2c55b7067445d25f6f7
> Build step 'Execute shell' marked build as failure
>

Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1869

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1869/changes>