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/05/10 17:49:24 UTC
Build failed in Jenkins: mesos-reviewbot #12988
See <https://builds.apache.org/job/mesos-reviewbot/12988/changes>
Changes:
[alexr] Ensured subsequent kills are ignored after the task is reaped.
[alexr] Added KillPolicy to scheduler and executor Kill protobuf messages.
[alexr] Propagated KillPolicy in kill task from scheduler to executor.
[alexr] Updated HTTP command executor to support kill policy in Kill event.
------------------------------------------
[...truncated 115569 lines...]
I0510 16:04:36.985224 2470 replica.cpp:537] Replica received write request for position 1 from (8633)@172.17.0.2:35810
I0510 16:04:37.020961 2470 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 35.67265ms
I0510 16:04:37.021062 2470 replica.cpp:712] Persisted action at 1
I0510 16:04:37.022627 2460 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0510 16:04:37.031172 2462 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.031287 2462 hierarchical.cpp:1139] Performed allocation for 0 agents in 191107ns
I0510 16:04:37.062695 2460 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 39.995795ms
I0510 16:04:37.062793 2460 replica.cpp:712] Persisted action at 1
I0510 16:04:37.062826 2460 replica.cpp:697] Replica learned APPEND action at position 1
I0510 16:04:37.064206 2470 registrar.cpp:508] Successfully updated the 'registry' in 80.824064ms
I0510 16:04:37.064350 2470 registrar.cpp:394] Successfully recovered registrar
I0510 16:04:37.064450 2460 log.cpp:567] Attempting to truncate the log to 1
I0510 16:04:37.064645 2470 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0510 16:04:37.064921 2460 master.cpp:1747] Recovered 0 agents from the Registry (131B) ; allowing 10mins for agents to re-register
I0510 16:04:37.064961 2471 hierarchical.cpp:169] Skipping recovery of hierarchical allocator: nothing to recover
I0510 16:04:37.065843 2461 replica.cpp:537] Replica received write request for position 2 from (8634)@172.17.0.2:35810
I0510 16:04:37.104619 2461 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.70964ms
I0510 16:04:37.104708 2461 replica.cpp:712] Persisted action at 2
I0510 16:04:37.105574 2469 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0510 16:04:37.143060 2469 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 37.432214ms
I0510 16:04:37.143229 2469 leveldb.cpp:399] Deleting ~1 keys from leveldb took 84990ns
I0510 16:04:37.143291 2469 replica.cpp:712] Persisted action at 2
I0510 16:04:37.143337 2469 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0510 16:04:37.147747 2466 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.147862 2466 hierarchical.cpp:1139] Performed allocation for 0 agents in 196545ns
I0510 16:04:37.149996 2439 containerizer.cpp:178] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W0510 16:04:37.150810 2439 backend.cpp:66] Failed to create 'bind' backend: BindBackend requires root privileges
I0510 16:04:37.152228 2439 cluster.cpp:398] Creating default 'local' authorizer
I0510 16:04:37.154201 2470 slave.cpp:204] Agent started on 230)@172.17.0.2:35810
I0510 16:04:37.154224 2470 slave.cpp:205] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true" --authenticatee="crammd5" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.29.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="disk(role1):1024" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00"
I0510 16:04:37.154665 2470 credentials.hpp:86] Loading credential for authentication from '/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/credential'
I0510 16:04:37.154914 2470 slave.cpp:342] Agent using credential for: test-principal
I0510 16:04:37.154945 2470 credentials.hpp:37] Loading credentials for authentication from '/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/http_credentials'
I0510 16:04:37.155191 2470 slave.cpp:394] Using default 'basic' HTTP authenticator
I0510 16:04:37.155508 2470 resources.cpp:572] Parsing resources as JSON failed: disk(role1):1024
Trying semicolon-delimited string format instead
I0510 16:04:37.155936 2470 slave.cpp:593] Agent resources: disk(role1):1024; cpus(*):16; mem(*):47270; ports(*):[31000-32000]
I0510 16:04:37.155995 2470 slave.cpp:601] Agent attributes: [ ]
I0510 16:04:37.156007 2470 slave.cpp:606] Agent hostname: e6116108716a
I0510 16:04:37.157539 2466 state.cpp:57] Recovering state from '/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/meta'
I0510 16:04:37.157939 2471 status_update_manager.cpp:200] Recovering status update manager
I0510 16:04:37.158144 2471 containerizer.cpp:444] Recovering containerizer
I0510 16:04:37.159590 2468 provisioner.cpp:245] Provisioner recovery complete
I0510 16:04:37.159886 2469 slave.cpp:4812] Finished recovery
I0510 16:04:37.160434 2469 slave.cpp:4984] Querying resource estimator for oversubscribable resources
I0510 16:04:37.160866 2459 status_update_manager.cpp:174] Pausing sending status updates
I0510 16:04:37.160882 2464 slave.cpp:951] New master detected at master@172.17.0.2:35810
I0510 16:04:37.160910 2464 slave.cpp:963] Delaying registration for 4.183044ms
I0510 16:04:37.161041 2464 slave.cpp:971] Detecting new master
I0510 16:04:37.161172 2464 slave.cpp:4998] Received oversubscribable resources from the resource estimator
I0510 16:04:37.165508 2472 slave.cpp:1020] Authenticating with master master@172.17.0.2:35810
I0510 16:04:37.165540 2472 slave.cpp:1025] Using default CRAM-MD5 authenticatee
I0510 16:04:37.165828 2467 authenticatee.cpp:121] Creating new client SASL connection
I0510 16:04:37.166179 2471 master.cpp:5833] Authenticating slave(230)@172.17.0.2:35810
I0510 16:04:37.166338 2462 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(496)@172.17.0.2:35810
I0510 16:04:37.166577 2464 authenticator.cpp:98] Creating new server SASL connection
I0510 16:04:37.166839 2459 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0510 16:04:37.166877 2459 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0510 16:04:37.167014 2469 authenticator.cpp:203] Received SASL authentication start
I0510 16:04:37.167078 2469 authenticator.cpp:325] Authentication requires more steps
I0510 16:04:37.167189 2458 authenticatee.cpp:258] Received SASL authentication step
I0510 16:04:37.167487 2471 authenticator.cpp:231] Received SASL authentication step
I0510 16:04:37.167522 2471 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'e6116108716a' server FQDN: 'e6116108716a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0510 16:04:37.167532 2471 auxprop.cpp:179] Looking up auxiliary property '*userPassword'
I0510 16:04:37.167572 2471 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0510 16:04:37.167588 2471 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'e6116108716a' server FQDN: 'e6116108716a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0510 16:04:37.167596 2471 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0510 16:04:37.167603 2471 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0510 16:04:37.167616 2471 authenticator.cpp:317] Authentication success
I0510 16:04:37.167692 2461 authenticatee.cpp:298] Authentication success
I0510 16:04:37.167773 2465 master.cpp:5863] Successfully authenticated principal 'test-principal' at slave(230)@172.17.0.2:35810
I0510 16:04:37.167834 2466 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(496)@172.17.0.2:35810
I0510 16:04:37.168089 2471 slave.cpp:1090] Successfully authenticated with master master@172.17.0.2:35810
I0510 16:04:37.168256 2471 slave.cpp:1486] Will retry registration in 7.66941ms if necessary
I0510 16:04:37.168431 2461 master.cpp:4544] Registering agent at slave(230)@172.17.0.2:35810 (e6116108716a) with id 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0
I0510 16:04:37.168969 2467 registrar.cpp:463] Applied 1 operations in 93475ns; attempting to update the 'registry'
I0510 16:04:37.169811 2462 log.cpp:548] Attempting to append 343 bytes to the log
I0510 16:04:37.169944 2463 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I0510 16:04:37.170811 2471 replica.cpp:537] Replica received write request for position 3 from (8650)@172.17.0.2:35810
I0510 16:04:37.176978 2465 slave.cpp:1486] Will retry registration in 943175ns if necessary
I0510 16:04:37.177211 2473 master.cpp:4532] Ignoring register agent message from slave(230)@172.17.0.2:35810 (e6116108716a) as admission is already in progress
I0510 16:04:37.178488 2470 slave.cpp:1486] Will retry registration in 79.081088ms if necessary
I0510 16:04:37.178624 2464 master.cpp:4532] Ignoring register agent message from slave(230)@172.17.0.2:35810 (e6116108716a) as admission is already in progress
I0510 16:04:37.198976 2466 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.199105 2466 hierarchical.cpp:1139] Performed allocation for 0 agents in 230742ns
I0510 16:04:37.210088 2471 leveldb.cpp:341] Persisting action (362 bytes) to leveldb took 39.219589ms
I0510 16:04:37.210170 2471 replica.cpp:712] Persisted action at 3
I0510 16:04:37.211155 2471 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I0510 16:04:37.235370 2471 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 24.159427ms
I0510 16:04:37.235468 2471 replica.cpp:712] Persisted action at 3
I0510 16:04:37.235507 2471 replica.cpp:697] Replica learned APPEND action at position 3
I0510 16:04:37.237362 2471 registrar.cpp:508] Successfully updated the 'registry' in 68.321024ms
I0510 16:04:37.237593 2472 log.cpp:567] Attempting to truncate the log to 3
I0510 16:04:37.237776 2468 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I0510 16:04:37.238404 2469 slave.cpp:3712] Received ping from slave-observer(214)@172.17.0.2:35810
I0510 16:04:37.238483 2470 master.cpp:4612] Registered agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 at slave(230)@172.17.0.2:35810 (e6116108716a) with disk(role1):1024; cpus(*):16; mem(*):47270; ports(*):[31000-32000]
I0510 16:04:37.238548 2469 slave.cpp:1134] Registered with master master@172.17.0.2:35810; given agent ID 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0
I0510 16:04:37.238571 2469 fetcher.cpp:81] Clearing fetcher cache
I0510 16:04:37.238800 2468 hierarchical.cpp:473] Added agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 (e6116108716a) with disk(role1):1024; cpus(*):16; mem(*):47270; ports(*):[31000-32000] (allocated: )
I0510 16:04:37.238950 2470 status_update_manager.cpp:181] Resuming sending status updates
I0510 16:04:37.238970 2468 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.238997 2469 slave.cpp:1157] Checkpointing SlaveInfo to '/tmp/PersistentVolumeEndpointsTest_BadCredentials_UtXk00/meta/slaves/0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0/slave.info'
I0510 16:04:37.239020 2470 replica.cpp:537] Replica received write request for position 4 from (8651)@172.17.0.2:35810
I0510 16:04:37.239032 2468 hierarchical.cpp:1162] Performed allocation for agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 in 186060ns
I0510 16:04:37.239440 2469 slave.cpp:1194] Forwarding total oversubscribed resources
I0510 16:04:37.239611 2468 master.cpp:4956] Received update of agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 at slave(230)@172.17.0.2:35810 (e6116108716a) with total oversubscribed resources
I0510 16:04:37.240283 2468 hierarchical.cpp:531] Agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 (e6116108716a) updated with oversubscribed resources (total: disk(role1):1024; cpus(*):16; mem(*):47270; ports(*):[31000-32000], allocated: )
I0510 16:04:37.240442 2468 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.240505 2468 hierarchical.cpp:1162] Performed allocation for agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 in 172810ns
I0510 16:04:37.241276 2460 process.cpp:3206] Handling HTTP event for process 'master' with path: '/master/create-volumes'
I0510 16:04:37.245966 2473 process.cpp:3206] Handling HTTP event for process 'master' with path: '/master/destroy-volumes'
I0510 16:04:37.249969 2473 hierarchical.cpp:1488] No resources available to allocate!
I0510 16:04:37.250228 2473 hierarchical.cpp:1139] Performed allocation for 1 agents in 514356ns
I0510 16:04:37.251801 2460 slave.cpp:823] Agent terminating
I0510 16:04:37.252429 2473 master.cpp:1343] Agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 at slave(230)@172.17.0.2:35810 (e6116108716a) disconnected
I0510 16:04:37.252472 2473 master.cpp:2849] Disconnecting agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 at slave(230)@172.17.0.2:35810 (e6116108716a)
I0510 16:04:37.252558 2473 master.cpp:2868] Deactivating agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 at slave(230)@172.17.0.2:35810 (e6116108716a)
I0510 16:04:37.252751 2471 hierarchical.cpp:560] Agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0 deactivated
I0510 16:04:37.258271 2439 master.cpp:1190] Master terminating
I0510 16:04:37.259174 2472 hierarchical.cpp:505] Removed agent 0db53e5d-8988-4a39-95ac-6ed9d3071b48-S0
I0510 16:04:37.269857 2470 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.747646ms
I0510 16:04:37.269949 2470 replica.cpp:712] Persisted action at 4
[ OK ] PersistentVolumeEndpointsTest.BadCredentials (712 ms)
[ RUN ] PersistentVolumeEndpointsTest.GoodCreateAndDestroyACL
I0510 16:04:37.277546 2439 cluster.cpp:149] Creating default 'local' authorizer
I0510 16:04:37.413784 2439 leveldb.cpp:174] Opened db in 135.778573ms
I0510 16:04:37.468405 2439 leveldb.cpp:181] Compacted db in 54.536509ms
I0510 16:04:37.468493 2439 leveldb.cpp:196] Created db iterator in 24186ns
I0510 16:04:37.468511 2439 leveldb.cpp:202] Seeked to beginning of db in 2885ns
I0510 16:04:37.468523 2439 leveldb.cpp:271] Iterated through 0 keys in the db in 362ns
I0510 16:04:37.468572 2439 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0510 16:04:37.469426 2459 recover.cpp:447] Starting replica recovery
I0510 16:04:37.470043 2459 recover.cpp:473] Replica is in EMPTY status
I0510 16:04:37.471251 2460 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (8658)@172.17.0.2:35810
I0510 16:04:37.471678 2467 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0510 16:04:37.472209 2463 recover.cpp:564] Updating replica status to STARTING
I0510 16:04:37.474328 2458 master.cpp:383] Master 0a842bbb-1a41-4e18-94d5-e32946296e75 (e6116108716a) started on 172.17.0.2:35810
I0510 16:04:37.474364 2458 master.cpp:385] Flags at startup: --acls="create_volumes {
principals {
values: "test-principal"
}
roles {
type: ANY
}
}
destroy_volumes {
principals {
values: "test-principal"
}
creator_principals {
values: "test-principal"
}
}
" --allocation_interval="50ms" --allocator="HierarchicalDRF" --authenticate="true" --authenticate_http="true" --authenticate_http_frameworks="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/fsM9OM/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_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" --roles="role1" --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/fsM9OM/master" --zk_session_timeout="10secs"
I0510 16:04:37.474860 2458 master.cpp:434] Master only allowing authenticated frameworks to register
I0510 16:04:37.474870 2458 master.cpp:440] Master only allowing authenticated agents to register
I0510 16:04:37.474876 2458 master.cpp:446] Master only allowing authenticated HTTP frameworks to register
I0510 16:04:37.474882 2458 credentials.hpp:37] Loading credentials for authentication from '/tmp/fsM9OM/credentials'
I0510 16:04:37.475220 2458 master.cpp:490] Using default 'crammd5' authenticator
I0510 16:04:37.475405 2458 master.cpp:561] Using default 'basic' HTTP authenticator
I0510 16:04:37.475658 2458 master.cpp:641] Using default 'basic' HTTP framework authenticator
I0510 16:04:37.475883 2458 master.cpp:688] Authorization enabled
W0510 16:04:37.475901 2458 master.cpp:751] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
I0510 16:04:37.476155 2467 whitelist_watcher.cpp:77] No whitelist given
I0510 16:04:37.476191 2466 hierarchical.cpp:142] Initialized hierarchical allocator process
I0510 16:04:37.478541 2467 master.cpp:1939] The newly elected leader is master@172.17.0.2:35810 with id 0a842bbb-1a41-4e18-94d5-e32946296e75
I0510 16:04:37.478600 2467 master.cpp:1952] Elected as the leading master!
I0510 16:04:37.478623 2467 master.cpp:1639] Recovering from registrar
I0510 16:04:37.478960 2467 registrar.cpp:331] Recovering registrar
I0510 16:04:37.510094 2464 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.679877ms
I0510 16:04:37.510181 2464 replica.cpp:320] Persisted replica status to STARTING
I0510 16:04:37.510552 2467 recover.cpp:473] Replica is in STARTING status
I0510 16:04:37.512071 2462 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (8661)@172.17.0.2:35810
I0510 16:04:37.512614 2468 recover.cpp:193] Received a recover response from a replica in STARTING status
I0510 16:04:37.513082 2466 recover.cpp:564] Updating replica status to VOTING
I0510 16:04:37.551941 2467 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.618306ms
I0510 16:04:37.552023 2467 replica.cpp:320] Persisted replica status to VOTING
I0510 16:04:37.552264 2470 recover.cpp:578] Successfully joined the Paxos group
I0510 16:04:37.552564 2470 recover.cpp:462] Recover process terminated
I0510 16:04:37.553243 2467 log.cpp:524] Attempting to start the writer
I0510 16:04:37.554998 2464 replica.cpp:493] Replica received implicit promise request from (8662)@172.17.0.2:35810 with proposal 1
I0510 16:04:37.593735 2464 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.693762ms
I0510 16:04:37.593778 2464 replica.cpp:342] Persisted promised to 1
I0510 16:04:37.594637 2469 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0510 16:04:37.596562 2473 replica.cpp:388] Replica received explicit promise request from (8663)@172.17.0.2:35810 for position 0 with proposal 2
I0510 16:04:37.635548 2473 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 38.892909ms
I0510 16:04:37.635632 2473 replica.cpp:712] Persisted action at 0
I0510 16:04:37.637006 2463 replica.cpp:537] Replica received write request for position 0 from (8664)@172.17.0.2:35810
I0510 16:04:37.637080 2463 leveldb.cpp:436] Reading position from leveldb took 37272ns
I0510 16:04:37.673544 2463 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 36.393025ms
I0510 16:04:37.673641 2463 replica.cpp:712] Persisted action at 0
I0510 16:04:37.674937 2463 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0510 16:04:37.715350 2463 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.335984ms
I0510 16:04:37.715438 2463 replica.cpp:712] Persisted action at 0
I0510 16:04:37.715476 2463 replica.cpp:697] Replica learned NOP action at position 0
I0510 16:04:37.716931 2473 log.cpp:540] Writer started with ending position 0
I0510 16:04:37.718569 2473 leveldb.cpp:436] Reading position from leveldb took 62320ns
I0510 16:04:37.720100 2459 registrar.cpp:364] Successfully fetched the registry (0B) in 0ns
I0510 16:04:37.720237 2459 registrar.cpp:463] Applied 1 operations in 33844ns; attempting to update the 'registry'
I0510 16:04:37.721513 2460 log.cpp:548] Attempting to append 170 bytes to the log
I0510 16:04:37.722020 2460 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0510 16:04:37.723147 2468 replica.cpp:537] Replica received write request for position 1 from (8665)@172.17.0.2:35810
I0510 16:04:37.757163 2468 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 33.948943ms
I0510 16:04:37.757253 2468 replica.cpp:712] Persisted action at 1
I0510 16:04:37.758702 2459 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0510 16:04:37.794975 2459 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 36.20591ms
I0510 16:04:37.795061 2459 replica.cpp:712] Persisted action at 1
I0510 16:04:37.795091 2459 replica.cpp:697] Replica learned APPEND action at position 1
I0510 16:04:37.796522 2467 registrar.cpp:508] Successfully updated the 'registry' in 0ns
I0510 16:04:37.796692 2467 registrar.cpp:394] Successfully recovered registrar
I0510 16:04:37.796993 2466 log.cpp:567] Attempting to truncate the log to 1
I0510 16:04:37.797127 2463 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0510 16:04:37.797293 2462 master.cpp:1747] Recovered 0 agents from the Registry (131B) ; allowing 10mins for agents to re-register
I0510 16:04:37.797349 2461 hierarchical.cpp:169] Skipping recovery of hierarchical allocator: nothing to recover
I0510 16:04:37.798007 2473 replica.cpp:537] Replica received write request for position 2 from (8666)@172.17.0.2:35810
I0510 16:04:37.826721 2473 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 28.643019ms
I0510 16:04:37.826807 2473 replica.cpp:712] Persisted action at 2
I0510 16:04:37.827592 2469 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0510 16:04:37.851847 2469 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.200994ms
I0510 16:04:37.852008 2469 leveldb.cpp:399] Deleting ~1 keys from leveldb took 78418ns
I0510 16:04:37.852035 2469 replica.cpp:712] Persisted action at 2
I0510 16:04:37.852069 2469 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0510 16:04:37.873960 2439 containerizer.cpp:178] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W0510 16:04:37.875366 2439 backend.cpp:66] Failed to create 'bind' backend: BindBackend requires root privileges
I0510 16:04:37.877398 2439 cluster.cpp:398] Creating default 'local' authorizer
I0510 16:04:37.879978 2461 slave.cpp:204] Agent started on 231)@172.17.0.2:35810
I0510 16:04:37.880028 2461 slave.cpp:205] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http="true" --authenticatee="crammd5" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.29.0/_build/src" --logbufsecs="0" --logging_level="INFO" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:1;mem:512;disk(role1):1024" --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o"
I0510 16:04:37.880579 2461 credentials.hpp:86] Loading credential for authentication from '/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/credential'
I0510 16:04:37.880858 2461 slave.cpp:342] Agent using credential for: test-principal
I0510 16:04:37.880919 2461 credentials.hpp:37] Loading credentials for authentication from '/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/http_credentials'
I0510 16:04:37.881232 2461 slave.cpp:394] Using default 'basic' HTTP authenticator
I0510 16:04:37.881922 2461 resources.cpp:572] Parsing resources as JSON failed: cpus:1;mem:512;disk(role1):1024
Trying semicolon-delimited string format instead
I0510 16:04:37.882457 2461 slave.cpp:593] Agent resources: cpus(*):1; mem(*):512; disk(role1):1024; ports(*):[31000-32000]
I0510 16:04:37.882534 2461 slave.cpp:601] Agent attributes: [ ]
I0510 16:04:37.882549 2461 slave.cpp:606] Agent hostname: e6116108716a
I0510 16:04:37.884428 2459 state.cpp:57] Recovering state from '/tmp/PersistentVolumeEndpointsTest_GoodCreateAndDestroyACL_ERXI7o/meta'
I0510 16:04:37.884992 2471 status_update_manager.cpp:200] Recovering status update manager
I0510 16:04:37.885273 2471 containerizer.cpp:444] Recovering containerizer
I0510 16:04:37.886862 2471 provisioner.cpp:245] Provisioner recovery complete
I0510 16:04:37.887295 2470 slave.cpp:4812] Finished recovery
I0510 16:04:37.887943 2470 slave.cpp:4984] Querying resource estimator for oversubscribable resources
I0510 16:04:37.888253 2471 status_update_manager.cpp:174] Pausing sending status updates
I0510 16:04:37.888301 2472 slave.cpp:951] New master detected at master@172.17.0.2:35810
I0510 16:04:37.888334 2472 slave.cpp:963] Delaying registration for 1.213535ms
I0510 16:04:37.888425 2472 slave.cpp:971] Detecting new master
I0510 16:04:37.888576 2472 slave.cpp:4998] Received oversubscribable resources from the resource estimator
Build timed out (after 180 minutes). Marking the build as failed.
Build was aborted
Jenkins build is back to normal : mesos-reviewbot #12989
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/12989/changes>