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/09/24 04:30:21 UTC
Build failed in Jenkins: mesos-reviewbot #15377
See <https://builds.apache.org/job/mesos-reviewbot/15377/>
------------------------------------------
[...truncated 317614 lines...]
I0924 04:30:12.135668 28980 replica.cpp:708] Persisted action APPEND at position 5
I0924 04:30:12.137816 28982 registrar.cpp:506] Successfully updated the registry in 227.500288ms
I0924 04:30:12.138070 28982 registrar.cpp:392] Successfully recovered registrar
I0924 04:30:12.138137 28972 log.cpp:596] Attempting to truncate the log to 5
I0924 04:30:12.138363 28977 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6
I0924 04:30:12.139346 28971 master.cpp:1676] Recovered 1 agents from the registry (298B); allowing 10mins for agents to re-register
I0924 04:30:12.139401 28969 hierarchical.cpp:176] Skipping recovery of hierarchical allocator: nothing to recover
I0924 04:30:12.139773 28971 replica.cpp:537] Replica received write request for position 6 from __req_res__(3198)@172.17.0.2:41296
I0924 04:30:12.222888 28971 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 83.034029ms
I0924 04:30:12.222967 28971 replica.cpp:708] Persisted action TRUNCATE at position 6
I0924 04:30:12.224591 28971 replica.cpp:691] Replica received learned notice for position 6 from @0.0.0.0:0
I0924 04:30:12.357331 28971 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 132.687797ms
I0924 04:30:12.357471 28971 leveldb.cpp:399] Deleting ~2 keys from leveldb took 61962ns
I0924 04:30:12.357502 28971 replica.cpp:708] Persisted action TRUNCATE at position 6
I0924 04:30:12.363736 28948 cluster.cpp:435] Creating default 'local' authorizer
I0924 04:30:12.365705 28968 slave.cpp:208] Mesos agent started on (208)@172.17.0.2:41296
I0924 04:30:12.365731 28968 slave.cpp:209] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --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/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf/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" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="true" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.1.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:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf" --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/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8"
I0924 04:30:12.366271 28968 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf/credential'
I0924 04:30:12.366446 28968 slave.cpp:346] Agent using credential for: test-principal
I0924 04:30:12.366464 28968 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_xZUEXf/http_credentials'
I0924 04:30:12.366704 28968 http.cpp:883] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0924 04:30:12.366843 28968 http.cpp:883] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0924 04:30:12.366924 28948 sched.cpp:226] Version: 1.1.0
I0924 04:30:12.367547 28977 sched.cpp:330] New master detected at master@172.17.0.2:41296
I0924 04:30:12.367677 28977 sched.cpp:396] Authenticating with master master@172.17.0.2:41296
I0924 04:30:12.367696 28977 sched.cpp:403] Using default CRAM-MD5 authenticatee
I0924 04:30:12.367800 28968 slave.cpp:533] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0924 04:30:12.367872 28968 slave.cpp:541] Agent attributes: [ ]
I0924 04:30:12.367885 28968 slave.cpp:546] Agent hostname: 9c540ef72bce
I0924 04:30:12.367908 28981 authenticatee.cpp:121] Creating new client SASL connection
I0924 04:30:12.368280 28975 master.cpp:6583] Authenticating scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.368391 28967 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(470)@172.17.0.2:41296
I0924 04:30:12.368609 28970 authenticator.cpp:98] Creating new server SASL connection
I0924 04:30:12.368835 28978 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0924 04:30:12.368875 28978 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0924 04:30:12.368973 28978 authenticator.cpp:204] Received SASL authentication start
I0924 04:30:12.369031 28978 authenticator.cpp:326] Authentication requires more steps
I0924 04:30:12.369135 28976 authenticatee.cpp:259] Received SASL authentication step
I0924 04:30:12.369242 28980 authenticator.cpp:232] Received SASL authentication step
I0924 04:30:12.369274 28980 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c540ef72bce' server FQDN: '9c540ef72bce' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0924 04:30:12.369289 28980 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0924 04:30:12.369325 28980 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0924 04:30:12.369351 28980 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c540ef72bce' server FQDN: '9c540ef72bce' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0924 04:30:12.369362 28980 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0924 04:30:12.369371 28980 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0924 04:30:12.369385 28980 authenticator.cpp:318] Authentication success
I0924 04:30:12.369433 28967 state.cpp:57] Recovering state from '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/meta'
I0924 04:30:12.369453 28974 authenticatee.cpp:299] Authentication success
I0924 04:30:12.369523 28977 master.cpp:6613] Successfully authenticated principal 'test-principal' at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.369570 28981 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(470)@172.17.0.2:41296
I0924 04:30:12.369956 28971 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:41296
I0924 04:30:12.369977 28971 sched.cpp:820] Sending SUBSCRIBE call to master@172.17.0.2:41296
I0924 04:30:12.370012 28977 status_update_manager.cpp:203] Recovering status update manager
I0924 04:30:12.370095 28971 sched.cpp:853] Will retry registration in 1.268238451secs if necessary
I0924 04:30:12.370231 28970 master.cpp:2587] Received SUBSCRIBE call for framework 'default' at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.370337 28970 master.cpp:2049] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0924 04:30:12.370381 28969 slave.cpp:5233] Finished recovery
I0924 04:30:12.370863 28978 master.cpp:2663] Subscribing framework default with checkpointing disabled and capabilities [ ]
I0924 04:30:12.371430 28973 sched.cpp:743] Framework registered with 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.371492 28967 hierarchical.cpp:272] Added framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.371529 28973 sched.cpp:757] Scheduler::registered took 67060ns
I0924 04:30:12.371579 28967 hierarchical.cpp:1691] No allocations performed
I0924 04:30:12.371623 28967 hierarchical.cpp:1786] No inverse offers to send out!
I0924 04:30:12.371693 28967 hierarchical.cpp:1283] Performed allocation for 0 agents in 175826ns
I0924 04:30:12.386590 28969 slave.cpp:5405] Querying resource estimator for oversubscribable resources
I0924 04:30:12.386976 28974 status_update_manager.cpp:177] Pausing sending status updates
I0924 04:30:12.386988 28967 slave.cpp:915] New master detected at master@172.17.0.2:41296
I0924 04:30:12.387039 28967 slave.cpp:974] Authenticating with master master@172.17.0.2:41296
I0924 04:30:12.387110 28967 slave.cpp:985] Using default CRAM-MD5 authenticatee
I0924 04:30:12.387264 28967 slave.cpp:947] Detecting new master
I0924 04:30:12.387308 28972 authenticatee.cpp:121] Creating new client SASL connection
I0924 04:30:12.387400 28967 slave.cpp:5419] Received oversubscribable resources {} from the resource estimator
I0924 04:30:12.387580 28978 master.cpp:6583] Authenticating slave(208)@172.17.0.2:41296
I0924 04:30:12.387691 28970 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(471)@172.17.0.2:41296
I0924 04:30:12.387909 28980 authenticator.cpp:98] Creating new server SASL connection
I0924 04:30:12.388125 28976 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0924 04:30:12.388157 28976 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0924 04:30:12.388283 28979 authenticator.cpp:204] Received SASL authentication start
I0924 04:30:12.388345 28979 authenticator.cpp:326] Authentication requires more steps
I0924 04:30:12.388527 28972 authenticatee.cpp:259] Received SASL authentication step
I0924 04:30:12.388623 28972 authenticator.cpp:232] Received SASL authentication step
I0924 04:30:12.388656 28972 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c540ef72bce' server FQDN: '9c540ef72bce' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0924 04:30:12.388698 28972 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0924 04:30:12.388756 28972 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0924 04:30:12.388790 28972 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c540ef72bce' server FQDN: '9c540ef72bce' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0924 04:30:12.388808 28972 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0924 04:30:12.388823 28972 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0924 04:30:12.388845 28972 authenticator.cpp:318] Authentication success
I0924 04:30:12.388932 28979 authenticatee.cpp:299] Authentication success
I0924 04:30:12.388996 28981 master.cpp:6613] Successfully authenticated principal 'test-principal' at slave(208)@172.17.0.2:41296
I0924 04:30:12.389024 28973 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(471)@172.17.0.2:41296
I0924 04:30:12.389286 28977 slave.cpp:1069] Successfully authenticated with master master@172.17.0.2:41296
I0924 04:30:12.389449 28977 slave.cpp:1475] Will retry registration in 13.420253ms if necessary
I0924 04:30:12.389642 28971 master.cpp:5040] Registering agent at slave(208)@172.17.0.2:41296 (9c540ef72bce) with id 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.390120 28967 registrar.cpp:461] Applied 1 operations in 75702ns; attempting to update the registry
I0924 04:30:12.391041 28971 log.cpp:577] Attempting to append 503 bytes to the log
I0924 04:30:12.391221 28979 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7
I0924 04:30:12.392195 28977 replica.cpp:537] Replica received write request for position 7 from __req_res__(3199)@172.17.0.2:41296
I0924 04:30:12.404167 28970 slave.cpp:1475] Will retry registration in 32.837721ms if necessary
I0924 04:30:12.404263 28974 master.cpp:5028] Ignoring register agent message from slave(208)@172.17.0.2:41296 (9c540ef72bce) as admission is already in progress
I0924 04:30:12.437940 28972 slave.cpp:1475] Will retry registration in 21.075228ms if necessary
I0924 04:30:12.438172 28982 master.cpp:5028] Ignoring register agent message from slave(208)@172.17.0.2:41296 (9c540ef72bce) as admission is already in progress
I0924 04:30:12.459544 28968 slave.cpp:1475] Will retry registration in 51.845329ms if necessary
I0924 04:30:12.459697 28979 master.cpp:5028] Ignoring register agent message from slave(208)@172.17.0.2:41296 (9c540ef72bce) as admission is already in progress
I0924 04:30:12.512075 28971 slave.cpp:1475] Will retry registration in 124.90881ms if necessary
I0924 04:30:12.512265 28972 master.cpp:5028] Ignoring register agent message from slave(208)@172.17.0.2:41296 (9c540ef72bce) as admission is already in progress
I0924 04:30:12.528097 28977 leveldb.cpp:341] Persisting action (522 bytes) to leveldb took 135.848122ms
I0924 04:30:12.528168 28977 replica.cpp:708] Persisted action APPEND at position 7
I0924 04:30:12.529044 28977 replica.cpp:691] Replica received learned notice for position 7 from @0.0.0.0:0
I0924 04:30:12.637956 28978 slave.cpp:1475] Will retry registration in 493.110446ms if necessary
I0924 04:30:12.638232 28971 master.cpp:5028] Ignoring register agent message from slave(208)@172.17.0.2:41296 (9c540ef72bce) as admission is already in progress
I0924 04:30:12.650234 28977 leveldb.cpp:341] Persisting action (524 bytes) to leveldb took 121.15533ms
I0924 04:30:12.650290 28977 replica.cpp:708] Persisted action APPEND at position 7
I0924 04:30:12.652447 28982 registrar.cpp:506] Successfully updated the registry in 262.24512ms
I0924 04:30:12.652645 28975 log.cpp:596] Attempting to truncate the log to 7
I0924 04:30:12.653327 28976 slave.cpp:4089] Received ping from slave-observer(207)@172.17.0.2:41296
I0924 04:30:12.653511 28976 slave.cpp:1115] Registered with master master@172.17.0.2:41296; given agent ID 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.653425 28977 master.cpp:5111] Registered agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0924 04:30:12.653563 28976 fetcher.cpp:86] Clearing fetcher cache
I0924 04:30:12.653530 28967 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8
I0924 04:30:12.653715 28979 hierarchical.cpp:482] Added agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 (9c540ef72bce) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0924 04:30:12.653751 28980 status_update_manager.cpp:184] Resuming sending status updates
I0924 04:30:12.654289 28968 replica.cpp:537] Replica received write request for position 8 from __req_res__(3200)@172.17.0.2:41296
I0924 04:30:12.654938 28979 hierarchical.cpp:1786] No inverse offers to send out!
I0924 04:30:12.655017 28979 hierarchical.cpp:1306] Performed allocation for agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 in 1.159329ms
I0924 04:30:12.655329 28980 master.cpp:6412] Sending 1 offers to framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.655840 28981 sched.cpp:917] Scheduler::resourceOffers took 168687ns
I0924 04:30:12.657436 28969 master.cpp:3521] Processing ACCEPT call for offers: [ 93b936b9-12eb-4126-9d02-c3cf0884848d-O0 ] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce) for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.657536 28969 master.cpp:3143] Authorizing framework principal 'test-principal' to launch task 0
W0924 04:30:12.659235 28979 validation.cpp:916] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0924 04:30:12.659271 28979 validation.cpp:928] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0924 04:30:12.659692 28979 master.cpp:8159] Adding task 0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 (9c540ef72bce)
I0924 04:30:12.659932 28979 master.cpp:4121] Launching task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.666890 28976 slave.cpp:1138] Checkpointing SlaveInfo to '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/meta/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/slave.info'
I0924 04:30:12.667280 28976 slave.cpp:1175] Forwarding total oversubscribed resources {}
I0924 04:30:12.667492 28967 master.cpp:5508] Received update of agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce) with total oversubscribed resources {}
I0924 04:30:12.667564 28976 slave.cpp:1539] Got assigned task '0' for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.667773 28973 hierarchical.cpp:552] Agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 (9c540ef72bce) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I0924 04:30:12.667917 28973 hierarchical.cpp:1691] No allocations performed
I0924 04:30:12.667953 28973 hierarchical.cpp:1786] No inverse offers to send out!
I0924 04:30:12.668006 28973 hierarchical.cpp:1306] Performed allocation for agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 in 181620ns
I0924 04:30:12.668162 28976 slave.cpp:1696] Launching task '0' for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.668716 28976 paths.cpp:536] Trying to chown '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000/executors/default/runs/adfc868c-3adf-4c74-934c-4a329b3e5d20' to user 'mesos'
I0924 04:30:12.674599 28976 slave.cpp:6122] Launching executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 with resources {} in work directory '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000/executors/default/runs/adfc868c-3adf-4c74-934c-4a329b3e5d20'
I0924 04:30:12.677568 28976 exec.cpp:162] Version: 1.1.0
I0924 04:30:12.677891 28979 exec.cpp:212] Executor started at: executor(90)@172.17.0.2:41296 with pid 28948
I0924 04:30:12.678237 28976 slave.cpp:1982] Queued task '0' for executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.678300 28976 slave.cpp:868] Successfully attached file '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000/executors/default/runs/adfc868c-3adf-4c74-934c-4a329b3e5d20'
I0924 04:30:12.678372 28976 slave.cpp:3203] Got registration for executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 from executor(90)@172.17.0.2:41296
I0924 04:30:12.678755 28969 exec.cpp:237] Executor registered on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.678812 28969 exec.cpp:249] Executor::registered took 32138ns
I0924 04:30:12.679275 28976 slave.cpp:2186] Sending queued task '0' to executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 at executor(90)@172.17.0.2:41296
I0924 04:30:12.679622 28981 exec.cpp:324] Executor asked to run task '0'
I0924 04:30:12.679713 28981 exec.cpp:333] Executor::launchTask took 65856ns
I0924 04:30:12.679801 28981 exec.cpp:550] Executor sending status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.680066 28976 slave.cpp:3606] Handling status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 from executor(90)@172.17.0.2:41296
I0924 04:30:12.680923 28981 status_update_manager.cpp:323] Received status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.680968 28981 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.681502 28981 status_update_manager.cpp:377] Forwarding update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to the agent
I0924 04:30:12.681787 28980 slave.cpp:4007] Forwarding the update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to master@172.17.0.2:41296
I0924 04:30:12.682001 28980 slave.cpp:3901] Status update manager successfully handled status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.682052 28980 slave.cpp:3917] Sending acknowledgement for status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to executor(90)@172.17.0.2:41296
I0924 04:30:12.682140 28974 master.cpp:5638] Status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 from agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.682289 28975 exec.cpp:373] Executor received status update acknowledgement 1107cca5-8f34-4718-a741-a69cae9df675 for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.682277 28974 master.cpp:5700] Forwarding status update TASK_FINISHED (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.682487 28974 master.cpp:7537] Updating the state of task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
I0924 04:30:12.682682 28980 sched.cpp:1025] Scheduler::statusUpdate took 117023ns
I0924 04:30:12.683229 28974 master.cpp:4756] Processing ACKNOWLEDGE call 1107cca5-8f34-4718-a741-a69cae9df675 for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.683303 28974 master.cpp:7633] Removing task 0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.683588 28973 hierarchical.cpp:1015] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 from framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.683820 28969 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.684053 28969 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.684331 28974 slave.cpp:2953] Status update manager successfully handled status update acknowledgement (UUID: 1107cca5-8f34-4718-a741-a69cae9df675) for task 0 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.684378 28974 slave.cpp:6486] Completing task 0
I0924 04:30:12.787564 28968 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 133.204334ms
I0924 04:30:12.787653 28968 replica.cpp:708] Persisted action TRUNCATE at position 8
I0924 04:30:12.788542 28980 replica.cpp:691] Replica received learned notice for position 8 from @0.0.0.0:0
I0924 04:30:12.855600 28971 hierarchical.cpp:1786] No inverse offers to send out!
I0924 04:30:12.855720 28971 hierarchical.cpp:1283] Performed allocation for 1 agents in 1.405618ms
I0924 04:30:12.856119 28976 master.cpp:6412] Sending 1 offers to framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.856727 28973 sched.cpp:917] Scheduler::resourceOffers took 200683ns
I0924 04:30:12.858922 28968 master.cpp:3521] Processing ACCEPT call for offers: [ 93b936b9-12eb-4126-9d02-c3cf0884848d-O1 ] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce) for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.859035 28968 master.cpp:3143] Authorizing framework principal 'test-principal' to launch task 1
W0924 04:30:12.861536 28976 validation.cpp:916] Executor 'default' for task '1' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0924 04:30:12.861584 28976 validation.cpp:928] Executor 'default' for task '1' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0924 04:30:12.862120 28976 master.cpp:8159] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 (9c540ef72bce)
I0924 04:30:12.862495 28976 master.cpp:4121] Launching task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.863066 28969 slave.cpp:1539] Got assigned task '1' for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.863672 28969 slave.cpp:1696] Launching task '1' for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.863878 28969 slave.cpp:2004] Queued task '1' for executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 at executor(90)@172.17.0.2:41296
I0924 04:30:12.864593 28969 slave.cpp:2186] Sending queued task '1' to executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 at executor(90)@172.17.0.2:41296
I0924 04:30:12.864987 28974 exec.cpp:324] Executor asked to run task '1'
I0924 04:30:12.865097 28974 exec.cpp:333] Executor::launchTask took 76187ns
I0924 04:30:12.865231 28974 exec.cpp:550] Executor sending status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.865586 28974 slave.cpp:3606] Handling status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 from executor(90)@172.17.0.2:41296
I0924 04:30:12.866793 28976 status_update_manager.cpp:323] Received status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.866861 28976 status_update_manager.cpp:500] Creating StatusUpdate stream for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.867385 28976 status_update_manager.cpp:377] Forwarding update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to the agent
I0924 04:30:12.867722 28974 slave.cpp:4007] Forwarding the update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to master@172.17.0.2:41296
I0924 04:30:12.867993 28974 slave.cpp:3901] Status update manager successfully handled status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.868067 28974 slave.cpp:3917] Sending acknowledgement for status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 to executor(90)@172.17.0.2:41296
I0924 04:30:12.868137 28975 master.cpp:5638] Status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 from agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.868198 28975 master.cpp:5700] Forwarding status update TASK_FINISHED (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.868224 28973 exec.cpp:373] Executor received status update acknowledgement 93745834-4ca0-4bdc-8662-fb3a371ef026 for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.868371 28975 master.cpp:7537] Updating the state of task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
I0924 04:30:12.868590 28979 sched.cpp:1025] Scheduler::statusUpdate took 114666ns
I0924 04:30:12.868953 28975 master.cpp:4756] Processing ACKNOWLEDGE call 93745834-4ca0-4bdc-8662-fb3a371ef026 for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.869037 28948 sched.cpp:1995] Asked to stop the driver
I0924 04:30:12.869015 28975 master.cpp:7633] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.869150 28977 sched.cpp:1187] Stopping framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869271 28981 hierarchical.cpp:1015] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 from framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869474 28975 master.cpp:6988] Processing TEARDOWN call for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.869508 28975 master.cpp:7000] Removing framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 (default) at scheduler-1a52372c-528f-447f-b7ae-79d72fde23c7@172.17.0.2:41296
I0924 04:30:12.869499 28971 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869711 28975 master.cpp:7662] Removing executor 'default' with resources {} of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.869716 28971 status_update_manager.cpp:531] Cleaning up status update stream for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869745 28976 hierarchical.cpp:383] Deactivated framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869714 28968 slave.cpp:2506] Asked to shut down framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 by master@172.17.0.2:41296
I0924 04:30:12.869798 28968 slave.cpp:2531] Shutting down framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.869858 28968 slave.cpp:4816] Shutting down executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 at executor(90)@172.17.0.2:41296
I0924 04:30:12.869994 28973 exec.cpp:414] Executor asked to shutdown
I0924 04:30:12.870038 28973 exec.cpp:429] Executor::shutdown took 21084ns
I0924 04:30:12.870188 28971 slave.cpp:2953] Status update manager successfully handled status update acknowledgement (UUID: 93745834-4ca0-4bdc-8662-fb3a371ef026) for task 1 of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.870263 28971 slave.cpp:6486] Completing task 1
I0924 04:30:12.870370 28971 slave.cpp:4135] Got exited event for executor(90)@172.17.0.2:41296
I0924 04:30:12.870455 28968 hierarchical.cpp:334] Removed framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.871237 28970 process.cpp:3377] Handling HTTP event for process 'master' with path: '/master/state'
I0924 04:30:12.872150 28982 http.cpp:382] HTTP GET for /master/state from 172.17.0.2:53366
I0924 04:30:12.878962 28982 slave.cpp:4498] Executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 exited with status 0
I0924 04:30:12.879161 28982 slave.cpp:4602] Cleaning up executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 at executor(90)@172.17.0.2:41296
W0924 04:30:12.879256 28979 master.cpp:5756] Ignoring unknown exited executor 'default' of framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000 on agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.879426 28973 gc.cpp:55] Scheduling '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000/executors/default/runs/adfc868c-3adf-4c74-934c-4a329b3e5d20' for gc 6.99998982249778days in the future
I0924 04:30:12.879556 28982 slave.cpp:4690] Cleaning up framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.879575 28973 gc.cpp:55] Scheduling '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000/executors/default' for gc 6.99998982049778days in the future
I0924 04:30:12.879686 28967 status_update_manager.cpp:285] Closing status update streams for framework 93b936b9-12eb-4126-9d02-c3cf0884848d-0000
I0924 04:30:12.879712 28973 gc.cpp:55] Scheduling '/tmp/MasterTest_MaxCompletedTasksPerFrameworkFlag_N68Xj8/slaves/93b936b9-12eb-4126-9d02-c3cf0884848d-S0/frameworks/93b936b9-12eb-4126-9d02-c3cf0884848d-0000' for gc 6.99998981875259days in the future
I0924 04:30:12.879724 28982 slave.cpp:787] Agent terminating
I0924 04:30:12.879911 28970 master.cpp:1258] Agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce) disconnected
I0924 04:30:12.879940 28970 master.cpp:2947] Disconnecting agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.879983 28970 master.cpp:2966] Deactivating agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 at slave(208)@172.17.0.2:41296 (9c540ef72bce)
I0924 04:30:12.880080 28968 hierarchical.cpp:581] Agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0 deactivated
I0924 04:30:12.882382 28977 master.cpp:1097] Master terminating
I0924 04:30:12.883071 28979 hierarchical.cpp:514] Removed agent 93b936b9-12eb-4126-9d02-c3cf0884848d-S0
I0924 04:30:12.963937 28980 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 175.319901ms
I0924 04:30:12.964098 28980 leveldb.cpp:399] Deleting ~2 keys from leveldb took 88582ns
I0924 04:30:12.964176 28980 replica.cpp:708] Persisted action TRUNCATE at position 8
I0924 04:30:13.004467 28948 cluster.cpp:158] Creating default 'local' authorizer
Build timed out (after 180 minutes). Marking the build as failed.
Build was aborted
Jenkins build is back to normal : mesos-reviewbot #15378
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/15378/changes>