[
https://issues.apache.org/jira/browse/MESOS-1061?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Vinod Kone resolved MESOS-1061.
-------------------------------
Resolution: Duplicate
> GarbageCollectorIntegrationTest.DiskUsage is flaky
> --------------------------------------------------
>
> Key: MESOS-1061
> URL: https://issues.apache.org/jira/browse/MESOS-1061
> Project: Mesos
> Issue Type: Bug
> Components: test
> Reporter: Vinod Kone
>
> [ RUN ] GarbageCollectorIntegrationTest.DiskUsage
> I0305 16:32:59.974095 27236 master.cpp:252] Master ID:
> 2014-03-05-16:32:59-2256185536-33036-27236 Hostname: fedora-19
> I0305 16:32:59.974203 27260 master.cpp:262] Master started on
> 192.168.122.134:33036
> I0305 16:32:59.974215 27260 master.cpp:265] Master only allowing
> authenticated frameworks to register!
> I0305 16:32:59.974628 27260 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> master@192.168.122.134:33036
> I0305 16:32:59.974663 27260 master.cpp:96] No whitelist given. Advertising
> offers for all slaves
> I0305 16:32:59.974808 27260 master.cpp:771] The newly elected leader is
> master@192.168.122.134:33036 with id
> 2014-03-05-16:32:59-2256185536-33036-27236
> I0305 16:32:59.974820 27260 master.cpp:781] Elected as the leading master!
> I0305 16:32:59.977638 27259 slave.cpp:119] Slave started on
> 53)@192.168.122.134:33036
> I0305 16:32:59.977720 27259 slave.cpp:129] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0305 16:32:59.978029 27259 slave.cpp:157] Slave hostname: fedora-19
> I0305 16:32:59.978042 27259 slave.cpp:158] Slave checkpoint: false
> I0305 16:32:59.978410 27259 state.cpp:33] Recovering state from
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_vsBzsr/meta'
> I0305 16:32:59.978499 27259 status_update_manager.cpp:193] Recovering status
> update manager
> I0305 16:32:59.978569 27259 slave.cpp:2710] Finished recovery
> I0305 16:32:59.978806 27259 slave.cpp:404] New master detected at
> master@192.168.122.134:33036
> I0305 16:32:59.978853 27259 slave.cpp:429] Detecting new master
> I0305 16:32:59.978884 27259 status_update_manager.cpp:167] New master
> detected at master@192.168.122.134:33036
> I0305 16:32:59.978936 27259 master.cpp:1858] Attempting to register slave on
> fedora-19 at slave(53)@192.168.122.134:33036
> I0305 16:32:59.978947 27259 master.cpp:2842] Adding slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 at fedora-19 with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0305 16:32:59.979054 27259 slave.cpp:447] Registered with master
> master@192.168.122.134:33036; given slave ID
> 2014-03-05-16:32:59-2256185536-33036-27236-0
> I0305 16:32:59.979115 27259 hierarchical_allocator_process.hpp:445] Added
> slave 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19) with
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0305 16:32:59.979151 27259 hierarchical_allocator_process.hpp:708] Performed
> allocation for slave 2014-03-05-16:32:59-2256185536-33036-27236-0 in 7240ns
> I0305 16:32:59.982027 27236 sched.cpp:121] Version: 0.19.0
> I0305 16:32:59.983299 27261 sched.cpp:217] New master detected at
> master@192.168.122.134:33036
> I0305 16:32:59.983324 27261 sched.cpp:267] Authenticating with master
> master@192.168.122.134:33036
> I0305 16:32:59.983407 27261 authenticatee.hpp:128] Creating new client SASL
> connection
> I0305 16:32:59.983818 27261 master.cpp:2355] Authenticating framework at
> scheduler(70)@192.168.122.134:33036
> I0305 16:32:59.983898 27261 authenticator.hpp:148] Creating new server SASL
> connection
> I0305 16:32:59.984202 27261 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0305 16:32:59.984222 27261 authenticatee.hpp:245] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0305 16:32:59.984396 27261 authenticator.hpp:254] Received SASL
> authentication start
> I0305 16:32:59.984438 27261 authenticator.hpp:342] Authentication requires
> more steps
> I0305 16:32:59.984472 27261 authenticatee.hpp:265] Received SASL
> authentication step
> I0305 16:32:59.984508 27261 authenticator.hpp:282] Received SASL
> authentication step
> I0305 16:32:59.984524 27261 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0305 16:32:59.984531 27261 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0305 16:32:59.984544 27261 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0305 16:32:59.984552 27261 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0305 16:32:59.984558 27261 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0305 16:32:59.984563 27261 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0305 16:32:59.984575 27261 authenticator.hpp:334] Authentication success
> I0305 16:32:59.984598 27261 authenticatee.hpp:305] Authentication success
> I0305 16:32:59.984618 27261 master.cpp:2395] Successfully authenticated
> framework at scheduler(70)@192.168.122.134:33036
> I0305 16:32:59.984678 27261 sched.cpp:341] Successfully authenticated with
> master master@192.168.122.134:33036
> I0305 16:32:59.984691 27261 sched.cpp:460] Sending registration request to
> master@192.168.122.134:33036
> I0305 16:32:59.984731 27261 master.cpp:829] Received registration request
> from scheduler(70)@192.168.122.134:33036
> I0305 16:32:59.984753 27261 master.cpp:847] Registering framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 at
> scheduler(70)@192.168.122.134:33036
> I0305 16:32:59.984802 27261 sched.cpp:391] Framework registered with
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.984823 27261 sched.cpp:405] Scheduler::registered took 9942ns
> I0305 16:32:59.984850 27261 hierarchical_allocator_process.hpp:332] Added
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.984885 27261 hierarchical_allocator_process.hpp:752] Offering
> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 to framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.984977 27261 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 114500ns
> I0305 16:32:59.985024 27261 master.hpp:456] Adding offer
> 2014-03-05-16:32:59-2256185536-33036-27236-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19)
> I0305 16:32:59.985061 27261 master.cpp:2310] Sending 1 offers to framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.986477 27261 sched.cpp:528] Scheduler::resourceOffers took
> 1.343035ms
> I0305 16:32:59.987185 27260 master.hpp:466] Removing offer
> 2014-03-05-16:32:59-2256185536-33036-27236-0 with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19)
> I0305 16:32:59.987264 27260 master.cpp:1585] Processing reply for offers: [
> 2014-03-05-16:32:59-2256185536-33036-27236-0 ] on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19) for framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.987331 27260 master.hpp:428] Adding task 0 with resources
> cpus(*):2; mem(*):1024 on slave 2014-03-05-16:32:59-2256185536-33036-27236-0
> (fedora-19)
> I0305 16:32:59.987438 27260 master.cpp:2479] Launching task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 with resources cpus(*):2;
> mem(*):1024 on slave 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19)
> I0305 16:32:59.987557 27260 slave.cpp:665] Got assigned task 0 for framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.987720 27260 slave.cpp:774] Launching task 0 for framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.988298 27262 hierarchical_allocator_process.hpp:547] Framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 left disk(*):1024;
> ports(*):[31000-32000] unused on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0
> I0305 16:32:59.988351 27262 hierarchical_allocator_process.hpp:590] Framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 filtered slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 for 5secs
> I0305 16:32:59.990694 27260 exec.cpp:131] Version: 0.19.0
> I0305 16:32:59.991338 27257 exec.cpp:181] Executor started at:
> executor(24)@192.168.122.134:33036 with pid 27236
> I0305 16:32:59.991952 27260 slave.cpp:884] Queuing task '0' for executor
> default of framework '2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.991998 27260 slave.cpp:365] Successfully attached file
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_vsBzsr/slaves/2014-03-05-16:32:59-2256185536-33036-27236-0/frameworks/2014-03-05-16:32:59-2256185536-33036-27236-0000/executors/default/runs/310ad836-472b-4aa2-a8e4-df68e2a9c66b'
> I0305 16:32:59.992024 27260 slave.cpp:1356] Got registration for executor
> 'default' of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.992682 27259 exec.cpp:205] Executor registered on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0
> I0305 16:32:59.993489 27259 exec.cpp:217] Executor::registered took 15912ns
> I0305 16:32:59.994130 27260 slave.cpp:1474] Flushing queued task 0 for
> executor 'default' of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.994763 27255 exec.cpp:292] Executor asked to run task '0'
> I0305 16:32:59.994803 27255 exec.cpp:301] Executor::launchTask took 22823ns
> I0305 16:32:59.995609 27255 exec.cpp:524] Executor sending status update
> TASK_RUNNING (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0 of
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.996297 27260 slave.cpp:2029] Monitoring executor 'default' of
> framework '2014-03-05-16:32:59-2256185536-33036-27236-0000' in container
> '310ad836-472b-4aa2-a8e4-df68e2a9c66b'
> I0305 16:32:59.996945 27260 slave.cpp:1683] Handling status update
> TASK_RUNNING (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0 of
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000 from
> executor(24)@192.168.122.134:33036
> I0305 16:32:59.997689 27261 status_update_manager.cpp:320] Received status
> update TASK_RUNNING (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0
> of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.997710 27261 status_update_manager.cpp:499] Creating
> StatusUpdate stream for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.997761 27261 status_update_manager.cpp:373] Forwarding status
> update TASK_RUNNING (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0
> of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000 to
> master@192.168.122.134:33036
> I0305 16:32:59.997871 27257 master.cpp:2042] Status update TASK_RUNNING
> (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 from
> slave(53)@192.168.122.134:33036
> I0305 16:32:59.997931 27257 sched.cpp:619] Scheduler::statusUpdate took
> 14057ns
> I0305 16:32:59.998798 27259 status_update_manager.cpp:398] Received status
> update acknowledgement (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task
> 0 of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.999398 27260 slave.cpp:1803] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:32:59.999418 27260 slave.cpp:1809] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 3aec2071-bd99-4dcb-87f1-2918782b46cb) for
> task 0 of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000 to
> executor(24)@192.168.122.134:33036
> I0305 16:33:00.013356 27260 slave.cpp:1296] Status update manager
> successfully handled status update acknowledgement (UUID:
> 3aec2071-bd99-4dcb-87f1-2918782b46cb) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.014122 27256 slave.cpp:2087] Executor 'default' of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 has exited with status 0
> I0305 16:33:00.018606 27256 slave.cpp:1683] Handling status update TASK_LOST
> (UUID: bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 from @0.0.0.0:0
> I0305 16:33:00.018647 27256 slave.cpp:3182] Terminating task 0
> I0305 16:33:00.018777 27256 status_update_manager.cpp:320] Received status
> update TASK_LOST (UUID: bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.018807 27256 status_update_manager.cpp:373] Forwarding status
> update TASK_LOST (UUID: bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000 to
> master@192.168.122.134:33036
> I0305 16:33:00.018910 27256 master.cpp:2115] Executor default of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 (fedora-19) has exited with
> status 0
> I0305 16:33:00.019011 27256 master.cpp:2042] Status update TASK_LOST (UUID:
> bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000 from
> slave(53)@192.168.122.134:33036
> I0305 16:33:00.019053 27256 master.hpp:446] Removing task 0 with resources
> cpus(*):2; mem(*):1024 on slave 2014-03-05-16:32:59-2256185536-33036-27236-0
> (fedora-19)
> I0305 16:33:00.019121 27256 slave.cpp:1803] Status update manager
> successfully handled status update TASK_LOST (UUID:
> bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.019186 27256 hierarchical_allocator_process.hpp:637] Recovered
> cpus(*):2; mem(*):1024 (total allocatable: disk(*):1024;
> ports(*):[31000-32000]; cpus(*):2; mem(*):1024) on slave
> 2014-03-05-16:32:59-2256185536-33036-27236-0 from framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.020098 27256 sched.cpp:619] Scheduler::statusUpdate took
> 13958ns
> I0305 16:33:00.020797 27262 status_update_manager.cpp:398] Received status
> update acknowledgement (UUID: bd0266ab-150a-4c96-838a-c893cf82c25b) for task
> 0 of framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.020828 27262 status_update_manager.cpp:530] Cleaning up status
> update stream for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.020901 27262 slave.cpp:1296] Status update manager
> successfully handled status update acknowledgement (UUID:
> bd0266ab-150a-4c96-838a-c893cf82c25b) for task 0 of framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.020917 27262 slave.cpp:3205] Completing task 0
> I0305 16:33:00.020926 27262 slave.cpp:2226] Cleaning up executor 'default' of
> framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.021029 27262 slave.cpp:2301] Cleaning up framework
> 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.021087 27262 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_vsBzsr/slaves/2014-03-05-16:32:59-2256185536-33036-27236-0/frameworks/2014-03-05-16:32:59-2256185536-33036-27236-0000/executors/default/runs/310ad836-472b-4aa2-a8e4-df68e2a9c66b'
> for gc 1.00000000228825weeks in the future
> I0305 16:33:00.021131 27262 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_vsBzsr/slaves/2014-03-05-16:32:59-2256185536-33036-27236-0/frameworks/2014-03-05-16:32:59-2256185536-33036-27236-0000/executors/default'
> for gc 1.00000000228825weeks in the future
> I0305 16:33:00.021159 27262 gc.cpp:56] Scheduling
> '/tmp/GarbageCollectorIntegrationTest_DiskUsage_vsBzsr/slaves/2014-03-05-16:32:59-2256185536-33036-27236-0/frameworks/2014-03-05-16:32:59-2256185536-33036-27236-0000'
> for gc 1.00000000228825weeks in the future
> I0305 16:33:00.021185 27262 status_update_manager.cpp:282] Closing status
> update streams for framework 2014-03-05-16:32:59-2256185536-33036-27236-0000
> I0305 16:33:00.040454 27255 slave.cpp:2551] Current usage 90.00%. Max allowed
> age: 0ns
> tests/gc_tests.cpp:657: Failure
> Value of: os::exists(executorDir)
> Actual: true
> Expected: false
> Build timed out (after 180 minutes). Marking the build as failed.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
