See <https://builds.apache.org/job/Mesos-Buildbot-ARM/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--disable-java%20--disable-python%20--disable-parallel-test-execution,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1%20%20MESOS_TEST_AWAIT_TIMEOUT=60secs%20JOBS=16%20GTEST_FILTER=-DiskQuotaTest.SlaveRecovery,label_exp=arm/1612/display/redirect?page=changes>
Changes: [bmahler] Logged failed TLS reverse DNS lookups as warnings for 'legacy' scheme. ------------------------------------------ [...truncated 38.21 MB...] 3: I1022 23:56:57.544930 18365 scheduler.cpp:847] Enqueuing event HEARTBEAT received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.545401 18376 hierarchical.cpp:1843] Performed allocation for 1 agents in 3.0714ms 3: I1022 23:56:57.547201 18348 master.cpp:10409] Sending offers [ 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-O0 ] to framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.552510 18314 scheduler.cpp:847] Enqueuing event OFFERS received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.560060 18386 hierarchical.cpp:1843] Performed allocation for 1 agents in 709038ns 3: I1022 23:56:57.562810 18355 scheduler.cpp:246] Adding authentication headers to ACCEPT call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.563911 18367 scheduler.cpp:600] Sending ACCEPT call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.566735 18373 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1022 23:56:57.570557 18359 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:56922 3: I1022 23:56:57.573580 18359 master.cpp:4719] Processing ACCEPT call for offers: [ 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-O0 ] on agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) for framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.573817 18359 master.cpp:4099] Authorizing principal 'test-principal' to create a MOUNT disk from 'disk(allocated: default-role)[RAW(,,profile)]:200' 3: I1022 23:56:57.577157 18359 master.cpp:12706] Removing offer 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-O0 3: I1022 23:56:57.577759 18359 master.cpp:6011] Processing CREATE_DISK operation with source disk(allocated: default-role)[RAW(,,profile)]:200 from framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) to agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) 3: I1022 23:56:57.580572 18359 master.cpp:12571] Sending operation 'operation' (uuid: 6260724b-9c9d-4839-ba99-6f8596ff556b) to agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) 3: I1022 23:56:57.581463 18351 hierarchical.cpp:1767] Allocation paused 3: I1022 23:56:57.582026 18363 slave.cpp:4352] Ignoring new checkpointed resources and operations identical to the current version 3: I1022 23:56:57.582386 18351 hierarchical.cpp:1566] Recovered ports(allocated: default-role):[31000-32000]; cpus(allocated: default-role):2; mem(allocated: default-role):1024; disk(allocated: default-role):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk[RAW(,,profile)]:200, offered or allocated: disk(allocated: default-role)[RAW(,,profile)]:200) on agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 from framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.584553 18351 hierarchical.cpp:1615] Framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 filtered agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 for 5secs 3: I1022 23:56:57.585283 18351 hierarchical.cpp:1777] Allocation resumed 3: I1022 23:56:57.596376 18316 master.cpp:1137] Master terminating 3: I1022 23:56:57.596844 18342 slave.cpp:1344] Lost leading master 3: I1022 23:56:57.596920 18342 slave.cpp:1416] Detecting new master 3: I1022 23:56:57.597033 18362 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I1022 23:56:57.596930 18336 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1022 23:56:57.597756 18383 scheduler.cpp:503] Lost leading master 3: I1022 23:56:57.598687 18383 scheduler.cpp:450] Ignoring disconnection attempt from stale connection 3: I1022 23:56:57.598944 18383 scheduler.cpp:450] Ignoring disconnection attempt from stale connection 3: I1022 23:56:57.599105 18383 scheduler.cpp:801] Ignoring event from old stale connection 3: I1022 23:56:57.599846 18394 hierarchical.cpp:1122] Removed all filters for agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 3: I1022 23:56:57.599897 18394 hierarchical.cpp:998] Removed agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 3: I1022 23:56:57.600857 18394 hierarchical.cpp:757] Removed framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.605041 18312 slave.cpp:6457] Got exited event for [email protected]:45405 3: W1022 23:56:57.605144 18312 slave.cpp:6462] Master disconnected! Waiting for a new master to be elected 3: I1022 23:56:57.626300 18303 cluster.cpp:177] Creating default 'local' authorizer 3: I1022 23:56:57.641500 18370 master.cpp:440] Master e0a7db3b-8d02-4fa3-8067-05bcc35320de (4e162b8e16e9) started on 172.17.0.2:45405 3: I1022 23:56:57.641633 18370 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/6Po1G8/credentials" --filter_gpu_resources="true" --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_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_operator_event_stream_subscribers="1000" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/6Po1G8/master" --zk_session_timeout="10secs" 3: I1022 23:56:57.642994 18370 master.cpp:492] Master only allowing authenticated frameworks to register 3: I1022 23:56:57.643051 18370 master.cpp:498] Master only allowing authenticated agents to register 3: I1022 23:56:57.643118 18370 master.cpp:504] Master only allowing authenticated HTTP frameworks to register 3: I1022 23:56:57.643173 18370 credentials.hpp:37] Loading credentials for authentication from '/tmp/6Po1G8/credentials' 3: I1022 23:56:57.643769 18370 master.cpp:548] Using default 'crammd5' authenticator 3: I1022 23:56:57.644304 18370 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1022 23:56:57.644903 18370 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1022 23:56:57.645319 18370 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1022 23:56:57.645746 18370 master.cpp:629] Authorization enabled 3: I1022 23:56:57.646574 18396 hierarchical.cpp:567] Initialized hierarchical allocator process 3: I1022 23:56:57.660491 18314 whitelist_watcher.cpp:77] No whitelist given 3: I1022 23:56:57.669648 18375 master.cpp:2169] Elected as the leading master! 3: I1022 23:56:57.669744 18375 master.cpp:1665] Recovering from registrar 3: I1022 23:56:57.670096 18355 registrar.cpp:339] Recovering registrar 3: I1022 23:56:57.671841 18355 registrar.cpp:383] Successfully fetched the registry (0B) in 0ns 3: I1022 23:56:57.672200 18355 registrar.cpp:487] Applied 1 operations in 132334ns; attempting to update the registry 3: I1022 23:56:57.673987 18355 registrar.cpp:544] Successfully updated the registry in 0ns 3: I1022 23:56:57.674286 18355 registrar.cpp:416] Successfully recovered registrar 3: I1022 23:56:57.675575 18317 master.cpp:1818] Recovered 0 agents from the registry (144B); allowing 10mins for agents to reregister 3: I1022 23:56:57.675874 18317 hierarchical.cpp:606] Skipping recovery of hierarchical allocator: nothing to recover 3: I1022 23:56:57.678959 18327 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1022 23:56:57.679013 18356 status_update_manager_process.hpp:379] Pausing operation status update manager 3: I1022 23:56:57.679054 18329 slave.cpp:1351] New master detected at [email protected]:45405 3: I1022 23:56:57.679196 18353 scheduler.cpp:525] New master detected at [email protected]:45405 3: I1022 23:56:57.679213 18329 slave.cpp:1416] Detecting new master 3: I1022 23:56:57.679271 18353 scheduler.cpp:534] Waiting for 0ns before initiating a re-(connection) attempt with the master 3: I1022 23:56:57.680236 18363 slave.cpp:1443] Authenticating with master [email protected]:45405 3: I1022 23:56:57.680415 18363 slave.cpp:1452] Using default CRAM-MD5 authenticatee 3: I1022 23:56:57.681056 18377 authenticatee.cpp:121] Creating new client SASL connection 3: I1022 23:56:57.681871 18319 master.cpp:10594] Authenticating slave(1019)@172.17.0.2:45405 3: I1022 23:56:57.682152 18382 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1759)@172.17.0.2:45405 3: I1022 23:56:57.682760 18378 authenticator.cpp:98] Creating new server SASL connection 3: I1022 23:56:57.683284 18339 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1022 23:56:57.683406 18339 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1022 23:56:57.683794 18379 authenticator.cpp:204] Received SASL authentication start 3: I1022 23:56:57.684015 18379 authenticator.cpp:326] Authentication requires more steps 3: I1022 23:56:57.684293 18398 authenticatee.cpp:259] Received SASL authentication step 3: I1022 23:56:57.684600 18398 authenticator.cpp:232] Received SASL authentication step 3: I1022 23:56:57.684720 18398 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4e162b8e16e9' server FQDN: '4e162b8e16e9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1022 23:56:57.684783 18398 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1022 23:56:57.684927 18398 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1022 23:56:57.685003 18398 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '4e162b8e16e9' server FQDN: '4e162b8e16e9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1022 23:56:57.685045 18398 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1022 23:56:57.685079 18398 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1022 23:56:57.685132 18398 authenticator.cpp:318] Authentication success 3: I1022 23:56:57.685510 18380 authenticatee.cpp:299] Authentication success 3: I1022 23:56:57.685761 18398 master.cpp:10626] Successfully authenticated principal 'test-principal' at slave(1019)@172.17.0.2:45405 3: I1022 23:56:57.685835 18371 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1759)@172.17.0.2:45405 3: I1022 23:56:57.686609 18395 slave.cpp:1543] Successfully authenticated with master [email protected]:45405 3: I1022 23:56:57.687584 18352 scheduler.cpp:416] Connected with the master at http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.688040 18395 slave.cpp:1993] Will retry registration in 1.436518ms if necessary 3: I1022 23:56:57.688552 18361 master.cpp:7434] Received reregister agent message from agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) 3: I1022 23:56:57.689651 18395 scheduler.cpp:246] Adding authentication headers to SUBSCRIBE call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.689728 18361 master.cpp:4189] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal' 3: I1022 23:56:57.690713 18309 scheduler.cpp:600] Sending SUBSCRIBE call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.691766 18340 master.cpp:7526] Authorized re-registration of agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) 3: I1022 23:56:57.691989 18340 master.cpp:7698] Consulting registry about agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405(4e162b8e16e9) 3: I1022 23:56:57.692695 18316 slave.cpp:1993] Will retry registration in 634461ns if necessary 3: I1022 23:56:57.693037 18304 master.cpp:7396] Ignoring reregister agent message from agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) as re-registration is already in progress 3: W1022 23:56:57.692996 18399 registry_operations.cpp:200] Allowing UNKNOWN agent to reregister: hostname: "4e162b8e16e9" 3: resources { 3: name: "cpus" 3: type: SCALAR 3: scalar { 3: value: 2 3: } 3: } 3: resources { 3: name: "mem" 3: type: SCALAR 3: scalar { 3: value: 1024 3: } 3: } 3: resources { 3: name: "disk" 3: type: SCALAR 3: scalar { 3: value: 1024 3: } 3: } 3: resources { 3: name: "ports" 3: type: RANGES 3: ranges { 3: range { 3: begin: 31000 3: end: 32000 3: } 3: } 3: } 3: id { 3: value: "83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0" 3: } 3: checkpoint: true 3: port: 45405 3: I1022 23:56:57.694185 18399 registrar.cpp:487] Applied 1 operations in 1.364245ms; attempting to update the registry 3: I1022 23:56:57.696116 18307 slave.cpp:1993] Will retry registration in 32.090318ms if necessary 3: I1022 23:56:57.696445 18360 master.cpp:7396] Ignoring reregister agent message from agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) as re-registration is already in progress 3: I1022 23:56:57.716776 18305 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1022 23:56:57.717195 18399 registrar.cpp:544] Successfully updated the registry in 22.830848ms 3: I1022 23:56:57.718621 18305 master.cpp:7754] Re-admitted agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) 3: I1022 23:56:57.721071 18305 master.cpp:7975] Re-registered agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 at slave(1019)@172.17.0.2:45405 (4e162b8e16e9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1022 23:56:57.721690 18331 hierarchical.cpp:955] Added agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 (4e162b8e16e9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (offered or allocated: {}) 3: I1022 23:56:57.721798 18346 slave.cpp:1700] Re-registered with master [email protected]:45405 3: I1022 23:56:57.722048 18369 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1022 23:56:57.722105 18306 status_update_manager_process.hpp:385] Resuming operation status update manager 3: I1022 23:56:57.722580 18331 hierarchical.cpp:1843] Performed allocation for 1 agents in 333599ns 3: I1022 23:56:57.725270 18370 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:56924 3: I1022 23:56:57.722585 18346 slave.cpp:1746] Forwarding agent update {"operations":{},"resource_providers":{"providers":[{"info":{"id":{"value":"d34841dc-9a3d-40bc-b54c-807899eae7c5"},"name":"test","type":"org.apache.mesos.rp.test"},"operations":{"operations":[{"framework_id":{"value":"83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000"},"info":{"create_disk":{"source":{"allocation_info":{"role":"default-role"},"disk":{"source":{"profile":"profile","type":"RAW"}},"name":"disk","provider_id":{"value":"d34841dc-9a3d-40bc-b54c-807899eae7c5"},"scalar":{"value":200.0},"type":"SCALAR"},"target_type":"MOUNT"},"id":{"value":"operation"},"type":"CREATE_DISK"},"latest_status":{"operation_id":{"value":"operation"},"resource_provider_id":{"value":"d34841dc-9a3d-40bc-b54c-807899eae7c5"},"slave_id":{"value":"83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0"},"state":"OPERATION_PENDING"},"slave_id":{"value":"83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0"},"uuid":{"value":"YmByS5ydSDm6mW+Flv9Vaw=="}}]},"resource_version_uuid":{"value":"lzAUo5qnS02uRTK/OziwbQ=="},"total_resources":[{"disk":{"source":{"profile":"profile","type":"RAW"}},"name":"disk","provider_id":{"value":"d34841dc-9a3d-40bc-b54c-807899eae7c5"},"scalar":{"value":200.0},"type":"SCALAR"}]}]},"resource_version_uuid":{"value":"pDHqrUqVREyA7yCs32aRUA=="},"slave_id":{"value":"83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0"},"update_oversubscribed_resources":false} 3: I1022 23:56:57.726115 18370 master.cpp:2669] Received subscription request for HTTP framework 'default' 3: I1022 23:56:57.726387 18370 master.cpp:2241] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }' 3: I1022 23:56:57.731571 18370 master.cpp:13672] Marking operation 6260724b-9c9d-4839-ba99-6f8596ff556b (ID: operation) (Agent: 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0) (Framework: 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000) in state OPERATION_PENDING as an orphan 3: I1022 23:56:57.732975 18370 master.cpp:2741] Subscribing framework 'default' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1022 23:56:57.733795 18367 hierarchical.cpp:1100] Grew agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 by disk[RAW(,,profile)]:200 (total), { } (used) 3: I1022 23:56:57.735383 18367 hierarchical.cpp:1057] Agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 (4e162b8e16e9) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1022 23:56:57.736335 18367 hierarchical.cpp:1843] Performed allocation for 1 agents in 425791ns 3: I1022 23:56:57.739167 18370 master.cpp:10926] Recovered orphan operation 6260724b-9c9d-4839-ba99-6f8596ff556b (ID: operation) on agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 belonging to framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 in state OPERATION_PENDING 3: I1022 23:56:57.739979 18370 master.cpp:10824] Adding framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) with roles { } suppressed 3: I1022 23:56:57.740528 18370 master.cpp:8295] Updating framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) with roles { } suppressed 3: I1022 23:56:57.740972 18334 hierarchical.cpp:1100] Grew agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 by disk[RAW(,,profile)]:200 (total), { 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000: disk(allocated: default-role)[RAW(,,profile)]:200 } (used) 3: I1022 23:56:57.743191 18370 slave.cpp:4222] Ignoring info update for framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 because it does not exist 3: I1022 23:56:57.744524 18334 hierarchical.cpp:700] Added framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.744520 18329 scheduler.cpp:847] Enqueuing event SUBSCRIBED received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.744644 18334 hierarchical.cpp:813] Deactivated framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.744906 18334 hierarchical.cpp:1671] Suppressed offers for roles { } of framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.744976 18334 hierarchical.cpp:1711] Unsuppressed offers and cleared filters for roles { } of framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.745199 18334 hierarchical.cpp:783] Activated framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.745713 18329 scheduler.cpp:847] Enqueuing event HEARTBEAT received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.747202 18374 scheduler.cpp:273] Sending RECONCILE_OPERATIONS call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.748211 18334 hierarchical.cpp:1843] Performed allocation for 1 agents in 2.629519ms 3: I1022 23:56:57.749372 18374 master.cpp:10409] Sending offers [ e0a7db3b-8d02-4fa3-8067-05bcc35320de-O0 ] to framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.750206 18374 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1022 23:56:57.752106 18383 scheduler.cpp:847] Enqueuing event OFFERS received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.753159 18345 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:56926 3: I1022 23:56:57.753659 18345 master.cpp:10029] Performing explicit operation state reconciliation for 1 operations of framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.753835 18309 scheduler.cpp:246] Adding authentication headers to DECLINE call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.754568 18316 scheduler.cpp:600] Sending DECLINE call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.755307 18307 scheduler.cpp:847] Enqueuing event UPDATE_OPERATION_STATUS received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.756166 18364 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1022 23:56:57.757738 18399 scheduler.cpp:273] Sending RECONCILE_OPERATIONS call to http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.802219 18331 process.cpp:3671] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1022 23:56:57.804708 18331 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:56926 3: I1022 23:56:57.805413 18331 master.cpp:6227] Processing DECLINE call for offers: [ e0a7db3b-8d02-4fa3-8067-05bcc35320de-O0 ] for framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) with 5 seconds filter 3: I1022 23:56:57.807204 18397 hierarchical.cpp:1566] Recovered ports(allocated: default-role):[31000-32000]; cpus(allocated: default-role):2; mem(allocated: default-role):1024; disk(allocated: default-role):1024; disk(allocated: default-role)[RAW(,,profile)]:200 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk[RAW(,,profile)]:200, offered or allocated: {}) on agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 from framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.807451 18331 master.cpp:12706] Removing offer e0a7db3b-8d02-4fa3-8067-05bcc35320de-O0 3: I1022 23:56:57.809291 18314 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:56926 3: I1022 23:56:57.809881 18314 master.cpp:10009] Performing implicit operation state reconciliation for framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.810343 18397 hierarchical.cpp:1615] Framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 filtered agent 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0 for 5secs 3: I1022 23:56:57.810449 18314 master.cpp:10029] Performing explicit operation state reconciliation for 0 operations of framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.812429 18388 scheduler.cpp:847] Enqueuing event UPDATE_OPERATION_STATUS received from http://172.17.0.2:45405/master/api/v1/scheduler 3: I1022 23:56:57.823302 18353 master.cpp:1411] Framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) disconnected 3: I1022 23:56:57.823451 18353 master.cpp:3356] Deactivating framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.823681 18353 master.cpp:3333] Disconnecting framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.823782 18353 master.cpp:1426] Giving framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 0ns to failover 3: I1022 23:56:57.824332 18359 hierarchical.cpp:813] Deactivated framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.825779 18372 master.cpp:10195] Framework failover timeout, removing framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.825860 18372 master.cpp:11197] Removing framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 (default) 3: I1022 23:56:57.826336 18363 slave.cpp:4062] Asked to shut down framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 by [email protected]:45405 3: I1022 23:56:57.826313 18372 master.cpp:13672] Marking operation 6260724b-9c9d-4839-ba99-6f8596ff556b (ID: operation) (Agent: 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-S0) (Framework: 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000) in state OPERATION_PENDING as an orphan 3: I1022 23:56:57.826431 18363 slave.cpp:4077] Cannot shut down unknown framework 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 3: I1022 23:56:57.828122 18329 hierarchical.cpp:1767] Allocation paused 3: F1022 23:56:57.828373 18329 hierarchical.cpp:745] Check failed: tryUntrackFrameworkUnderRole(framework, role) Framework: 83afc82c-bd90-4316-a4a9-8dcbd36de3b6-0000 role: default-role 3: *** Check failure stack trace: *** 3: @ 0xffff94a05d0c google::LogMessage::Fail() 3: @ 0xffff94a04ef0 google::LogMessage::SendToLog() 3: @ 0xffff94a0593c google::LogMessage::Flush() 3: @ 0xffff94a09548 google::LogMessageFatal::~LogMessageFatal() 3: @ 0xffff9ecc5048 mesos::internal::master::allocator::internal::HierarchicalAllocatorProcess::removeFramework() 3: @ 0x11cf930 _ZZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS1_11FrameworkIDES8_EEvRKNS_3PIDIT_EEMSA_FvT0_EOT1_ENKUlOS6_PNS_11ProcessBaseEE_clESJ_SL_ 3: @ 0x11cf60c _ZN5cpp176invokeIZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS3_11FrameworkIDESA_EEvRKNS1_3PIDIT_EEMSC_FvT0_EOT1_EUlOS8_PNS1_11ProcessBaseEE_JS8_SN_EEEDTclclsr3stdE7forwardISC_Efp_Espclsr3stdE7forwardIT0_Efp0_EEEOSC_DpOSP_ 3: @ 0x11cf59c _ZN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS4_11FrameworkIDESB_EEvRKNS2_3PIDIT_EEMSD_FvT0_EOT1_EUlOS9_PNS2_11ProcessBaseEE_JS9_St12_PlaceholderILi1EEEE13invoke_expandISP_St5tupleIJS9_SR_EESU_IJOSO_EEJLm0ELm1EEEEDTclsr5cpp17E6invokeclsr3stdE7forwardISD_Efp_Espcl6expandclsr3stdE3getIXT2_EEclsr3stdE7forwardISH_Efp0_EEclsr3stdE7forwardISK_Efp2_EEEEOSD_OSH_N5cpp1416integer_sequenceImJXspT2_EEEESL_ 3: @ 0x11cf4bc _ZNO6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS4_11FrameworkIDESB_EEvRKNS2_3PIDIT_EEMSD_FvT0_EOT1_EUlOS9_PNS2_11ProcessBaseEE_JS9_St12_PlaceholderILi1EEEEclIJSO_EEEDTcl13invoke_expandclL_ZSt4moveIRSP_EONSt16remove_referenceISD_E4typeEOSD_EdtdefpT1fEclL_ZSU_IRSt5tupleIJS9_SR_EEESZ_S10_EdtdefpT10bound_argsEcvN5cpp1416integer_sequenceImJLm0ELm1EEEE_Eclsr3stdE16forward_as_tuplespclsr3stdE7forwardIT_Efp_EEEEDpOS17_ 3: @ 0x11cf418 _ZN5cpp176invokeIN6lambda8internal7PartialIZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS6_11FrameworkIDESD_EEvRKNS4_3PIDIT_EEMSF_FvT0_EOT1_EUlOSB_PNS4_11ProcessBaseEE_JSB_St12_PlaceholderILi1EEEEEJSQ_EEEDTclclsr3stdE7forwardISF_Efp_Espclsr3stdE7forwardIT0_Efp0_EEEOSF_DpOSV_ 3: @ 0x11cf3cc _ZN6lambda8internal6InvokeIvEclINS0_7PartialIZN7process8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNS7_11FrameworkIDESE_EEvRKNS5_3PIDIT_EEMSG_FvT0_EOT1_EUlOSC_PNS5_11ProcessBaseEE_JSC_St12_PlaceholderILi1EEEEEJSR_EEEvOSG_DpOT0_ 3: @ 0x11cf280 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchIN5mesos8internal6master9allocator21MesosAllocatorProcessERKNSA_11FrameworkIDESH_EEvRKNS1_3PIDIT_EEMSJ_FvT0_EOT1_EUlOSF_S3_E_JSF_St12_PlaceholderILi1EEEEEEclEOS3_ 3: @ 0xffff95840968 _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEEclES3_ 3: @ 0xffff957fcd8c process::ProcessBase::consume() 3: @ 0xffff958ab944 _ZNO7process13DispatchEvent7consumeEPNS_13EventConsumerE 3: @ 0x11a6174 process::ProcessBase::serve() 3: @ 0xffff957f95fc process::ProcessManager::resume() 3: @ 0xffff95825448 process::ProcessManager::init_threads()::$_7::operator()() 3: @ 0xffff9582521c _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvE3$_7vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE 3: @ 0xffff958251e4 std::_Bind_simple<>::operator()() 3: @ 0xffff958250ac std::thread::_Impl<>::_M_run() 3: @ 0xffff91b11280 (unknown) 3: @ 0xffff9495bfc4 start_thread 3/3 Test #3: MesosTests .......................Child aborted***Exception: 1078.02 sec 67% tests passed, 1 tests failed out of 3 Total Test time (real) = 1164.53 sec The following tests FAILED: 3 - MesosTests (Child aborted) Errors while running CTest CMakeFiles/check.dir/build.make:60: recipe for target 'CMakeFiles/check' failed make[3]: *** [CMakeFiles/check] Error 8 make[3]: Leaving directory '/tmp/SRC/build' CMakeFiles/Makefile2:255: recipe for target 'CMakeFiles/check.dir/all' failed make[2]: *** [CMakeFiles/check.dir/all] Error 2 make[2]: Leaving directory '/tmp/SRC/build' CMakeFiles/Makefile2:262: recipe for target 'CMakeFiles/check.dir/rule' failed make[1]: *** [CMakeFiles/check.dir/rule] Error 2 make[1]: Leaving directory '/tmp/SRC/build' Makefile:232: recipe for target 'check' failed make: *** [check] Error 2 real 111m4.559s user 0m21.010s sys 0m15.844s Build step 'Execute shell' marked build as failure Recording test results
