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 2019/04/06 05:49:44 UTC
Build failed in Jenkins: Mesos-Reviewbot-Linux #650
See <https://builds.apache.org/job/Mesos-Reviewbot-Linux/650/display/redirect>
------------------------------------------
[...truncated 32.77 MB...]
E0406 03:57:45.801550 19722 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting CreateVolumeResponse. Retrying in 18.797739454secs
I0406 03:57:45.822590 19728 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631746081670150days
I0406 03:57:45.823629 19721 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.676347ms
I0406 03:57:45.825438 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/CreateVolume call
I0406 03:57:45.829172 19730 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O4 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:45.830425 19707 sched.cpp:914] Scheduler::resourceOffers took 159295ns
I0406 03:57:45.831161 19730 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O4 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:45.832208 19730 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O4
I0406 03:57:45.834177 19730 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:45.834988 19730 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:45.857239 19710 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting CreateVolumeResponse. Retrying in 1.21234495248333mins
I0406 03:57:45.882346 19726 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:45.883569 19716 master.cpp:1865] Skipping periodic registry garbage collection: no agents qualify for removal
I0406 03:57:45.883599 19711 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631746067104132days
I0406 03:57:45.884418 19726 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.747508ms
I0406 03:57:45.889185 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/CreateVolume call
E0406 03:57:45.929471 19728 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting CreateVolumeResponse. Retrying in 1.86324060515mins
I0406 03:57:45.935539 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/CreateVolume call
I0406 03:57:45.936271 19719 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.708448ms
I0406 03:57:45.936523 19721 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631746067104132days
I0406 03:57:45.937160 19710 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O5 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:45.939203 19710 sched.cpp:914] Scheduler::resourceOffers took 179101ns
I0406 03:57:45.940166 19710 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O5 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:45.941442 19710 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O5
I0406 03:57:45.943261 19710 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:45.943853 19710 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:45.956398 19727 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting CreateVolumeResponse. Retrying in 7.62039834986667mins
I0406 03:57:45.973579 19726 master.cpp:1865] Skipping periodic registry garbage collection: no agents qualify for removal
I0406 03:57:45.973743 19724 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631746052538113days
I0406 03:57:45.973814 19709 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:45.975760 19709 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.647404ms
I0406 03:57:45.977044 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/CreateVolume call
E0406 03:57:45.993293 19714 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting CreateVolumeResponse. Retrying in 1.59026596303333mins
I0406 03:57:46.003751 19708 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.707866ms
I0406 03:57:46.005070 19708 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O6 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.006243 19708 sched.cpp:914] Scheduler::resourceOffers took 155105ns
I0406 03:57:46.007058 19721 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O6 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.008240 19721 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O6
I0406 03:57:46.009917 19723 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.010996 19723 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
I0406 03:57:46.012641 19716 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631746052538113days
I0406 03:57:46.015527 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/CreateVolume call
I0406 03:57:46.135491 19728 provider.cpp:1511] Applying conversion from 'disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096' to 'disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096' for operation (uuid: 72160d05-c315-4284-a6f9-075352372304)
I0406 03:57:46.185236 19728 status_update_manager_process.hpp:152] Received operation status update OPERATION_FINISHED (Status UUID: c31c060d-5440-4798-bcf6-ef2fbe13f0cb) for operation UUID 72160d05-c315-4284-a6f9-075352372304 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:46.186170 19728 status_update_manager_process.hpp:414] Creating operation status update stream 72160d05-c315-4284-a6f9-075352372304 checkpoint=true
I0406 03:57:46.187654 19728 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status UUID: c31c060d-5440-4798-bcf6-ef2fbe13f0cb) for operation UUID 72160d05-c315-4284-a6f9-075352372304 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:46.251747 19728 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FINISHED (Status UUID: c31c060d-5440-4798-bcf6-ef2fbe13f0cb) for operation UUID 72160d05-c315-4284-a6f9-075352372304 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:46.254329 19709 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:45957/slave(722)/api/v1/resource_provider
I0406 03:57:46.257172 19730 process.cpp:3588] Handling HTTP event for process 'slave(722)' with path: '/slave(722)/api/v1/resource_provider'
I0406 03:57:46.294837 19723 http.cpp:1105] HTTP POST for /slave(722)/api/v1/resource_provider from 172.17.0.2:58062
I0406 03:57:46.296876 19711 slave.cpp:8177] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: 72160d05-c315-4284-a6f9-075352372304) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)'
I0406 03:57:46.298581 19711 slave.cpp:8630] Updating the state of operation with no ID (uuid: 72160d05-c315-4284-a6f9-075352372304) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0406 03:57:46.299844 19711 slave.cpp:8384] Forwarding status update of operation with no ID (operation_uuid: 72160d05-c315-4284-a6f9-075352372304) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.301584 19726 master.cpp:11826] Updating the state of operation '' (uuid: 72160d05-c315-4284-a6f9-075352372304) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0406 03:57:46.305891 19707 hierarchical.cpp:997] Updated allocation of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[RAW(org.apache.mesos.csi.test.local,,test)]:4096 to disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096
I0406 03:57:46.306797 19726 slave.cpp:4201] Ignoring new checkpointed resources and operations identical to the current version
I0406 03:57:46.307790 19714 provider.cpp:455] Received ACKNOWLEDGE_OPERATION_STATUS event
I0406 03:57:46.308746 19730 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: c31c060d-5440-4798-bcf6-ef2fbe13f0cb) for stream 72160d05-c315-4284-a6f9-075352372304
I0406 03:57:46.308079 19707 hierarchical.cpp:1266] Recovered disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: {}) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.309254 19730 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID: c31c060d-5440-4798-bcf6-ef2fbe13f0cb) for operation UUID 72160d05-c315-4284-a6f9-075352372304 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:46.313511 19719 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.815003ms
I0406 03:57:46.314980 19721 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O7 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.317065 19717 sched.cpp:914] Scheduler::resourceOffers took 118008ns
I0406 03:57:46.385188 19730 status_update_manager_process.hpp:490] Cleaning up operation status update stream 72160d05-c315-4284-a6f9-075352372304
I0406 03:57:46.447888 19710 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O7
I0406 03:57:46.448535 19710 master.cpp:4590] Processing ACCEPT call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O7 ] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.448664 19710 master.cpp:4034] Authorizing principal 'test-principal' to destroy disk 'disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096'
I0406 03:57:46.450363 19727 master.cpp:5932] Processing DESTROY_DISK operation for volume disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 to agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c)
I0406 03:57:46.451624 19727 master.cpp:12170] Sending operation '' (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91) to agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c)
I0406 03:57:46.453323 19712 slave.cpp:4201] Ignoring new checkpointed resources and operations identical to the current version
I0406 03:57:46.453986 19715 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.456991 19715 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
I0406 03:57:46.459208 19720 provider.cpp:455] Received APPLY_OPERATION event
I0406 03:57:46.459818 19720 provider.cpp:1209] Received DESTROY_DISK operation '' (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91)
I0406 03:57:46.511787 19707 v0_volume_manager.cpp:418] Deleting volume '43a6ba73-0479-402b-970b-f79d1b40b4fd' in CREATED state
I0406 03:57:46.513136 19717 v0_volume_manager.cpp:763] Calling '/csi.v0.Controller/DeleteVolume' for volume '43a6ba73-0479-402b-970b-f79d1b40b4fd'
I0406 03:57:46.517856 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.530685 19710 v0_volume_manager.cpp:575] Received 'DEADLINE_EXCEEDED' while expecting DeleteVolumeResponse. Retrying in 7.868973118secs
I0406 03:57:46.541234 19716 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.543186 19716 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.658718ms
I0406 03:57:46.545126 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.557554 19715 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 10.481564146secs
I0406 03:57:46.568773 19726 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.005136ms
II0406 03:57:46.569850 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
0406 03:57:46.569710 19719 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O8 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.571091 19719 sched.cpp:914] Scheduler::resourceOffers took 170409ns
I0406 03:57:46.571671 19708 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O8 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.573027 19708 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O8
I0406 03:57:46.574925 19708 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.575264 19708 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:46.587800 19723 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 22.867404903secs
I0406 03:57:46.598989 19711 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.600309 19711 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.958183ms
I0406 03:57:46.599915 19716 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745972425000days
I0406 03:57:46.603632 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.616688 19718 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 31.964434921secs
I0406 03:57:46.627254 19726 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745972425000days
I0406 03:57:46.627458 19714 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.648703ms
I0406 03:57:46.628643 19722 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O9 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.630137 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
I0406 03:57:46.630365 19714 sched.cpp:914] Scheduler::resourceOffers took 145063ns
I0406 03:57:46.631078 19714 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O9 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.631958 19714 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O9
I0406 03:57:46.633337 19714 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.633663 19714 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:46.650324 19729 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 57.912491363secs
I0406 03:57:46.665937 19711 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.666220 19711 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.103666ms
I0406 03:57:46.670853 19716 master.cpp:1865] Skipping periodic registry garbage collection: no agents qualify for removal
I0406 03:57:46.671559 19728 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745957858982days
I0406 03:57:46.671924 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.697415 19708 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 4.98161343716667mins
I0406 03:57:46.712219 19730 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.874063ms
I0406 03:57:46.714228 19717 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O10 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.716420 19713 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745957858982days
I0406 03:57:46.719658 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
I0406 03:57:46.721120 19727 sched.cpp:914] Scheduler::resourceOffers took 181235ns
I0406 03:57:46.722124 19727 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O10 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.723632 19727 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O10
I0406 03:57:46.725916 19718 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.726835 19718 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:46.746178 19721 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 7.10353710553333mins
I0406 03:57:46.754016 19719 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745950575972days
I0406 03:57:46.757082 19707 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.758415 19707 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.018346ms
I0406 03:57:46.759521 19723 master.cpp:1865] Skipping periodic registry garbage collection: no agents qualify for removal
I0406 03:57:46.759325 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.783622 19720 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 42.933523768secs
I0406 03:57:46.791848 19713 hierarchical.cpp:1595] Performed allocation for 1 agents in 1.698452ms
I0406 03:57:46.794441 19729 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O11 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.797144 19729 sched.cpp:914] Scheduler::resourceOffers took 159809ns
I0406 03:57:46.798074 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
I0406 03:57:46.798210 19729 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O11 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.799170 19729 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O11
I0406 03:57:46.795367 19725 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745950575972days
I0406 03:57:46.801476 19725 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.802088 19725 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:46.825810 19722 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 6.72913960028333mins
I0406 03:57:46.838946 19707 hierarchical.cpp:2365] Filtered offer with cpus:2; mem:1024; disk:1024; ports:[31000-32000] on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for role storage of framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.840461 19723 master.cpp:1865] Skipping periodic registry garbage collection: no agents qualify for removal
I0406 03:57:46.840587 19707 hierarchical.cpp:1595] Performed allocation for 1 agents in 2.316982ms
I0406 03:57:46.840188 19716 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745936009942days
I0406 03:57:46.844519 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
E0406 03:57:46.865269 19721 v0_volume_manager.cpp:575] Received 'UNAVAILABLE' while expecting DeleteVolumeResponse. Retrying in 2.62589572118333mins
II0406 03:57:46.881346 28804 test_csi_plugin.cpp:1078] Forwarding /csi.v0.Controller/DeleteVolume call
0406 03:57:46.881283 19718 slave.cpp:7126] Current disk usage 9.55%. Max allowed age: 5.631745936009942days
I0406 03:57:46.884743 19710 master.cpp:10007] Sending offers [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O12 ] to framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:46.886395 19710 sched.cpp:914] Scheduler::resourceOffers took 173273ns
I0406 03:57:46.887832 19710 master.cpp:6040] Processing DECLINE call for offers: [ e38f1104-337c-4a83-9313-5ca3c4f3737b-O12 ] for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 with 5 seconds filter
I0406 03:57:46.889762 19710 master.cpp:12279] Removing offer e38f1104-337c-4a83-9313-5ca3c4f3737b-O12
I0406 03:57:46.890792 19709 hierarchical.cpp:1595] Performed allocation for 1 agents in 8.811228ms
I0406 03:57:46.893800 19709 hierarchical.cpp:1266] Recovered cpus(allocated: storage):2; mem(allocated: storage):1024; disk(allocated: storage):1024; ports(allocated: storage):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:46.894649 19709 hierarchical.cpp:1312] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 filtered agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 for 5secs
E0406 03:57:46.978778 19707 provider.cpp:1266] Failed to apply operation (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91): UNIMPLEMENTED
I0406 03:57:46.979203 19723 status_update_manager_process.hpp:152] Received operation status update OPERATION_FAILED (Status UUID: 3f7b8e47-34d8-486f-8332-1fe3bf932225) for operation UUID b8f6826b-5ed6-4a79-8bae-1b5375557c91 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:46.980945 19723 status_update_manager_process.hpp:414] Creating operation status update stream b8f6826b-5ed6-4a79-8bae-1b5375557c91 checkpoint=true
I0406 03:57:46.982447 19723 status_update_manager_process.hpp:929] Checkpointing UPDATE for operation status update OPERATION_FAILED (Status UUID: 3f7b8e47-34d8-486f-8332-1fe3bf932225) for operation UUID b8f6826b-5ed6-4a79-8bae-1b5375557c91 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:47.062089 19723 status_update_manager_process.hpp:528] Forwarding operation status update OPERATION_FAILED (Status UUID: 3f7b8e47-34d8-486f-8332-1fe3bf932225) for operation UUID b8f6826b-5ed6-4a79-8bae-1b5375557c91 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:47.064533 19713 http_connection.hpp:131] Sending 2 call to http://172.17.0.2:45957/slave(722)/api/v1/resource_provider
I0406 03:57:47.067062 19711 process.cpp:3588] Handling HTTP event for process 'slave(722)' with path: '/slave(722)/api/v1/resource_provider'
I0406 03:57:47.107362 19724 http.cpp:1105] HTTP POST for /slave(722)/api/v1/resource_provider from 172.17.0.2:58062
I0406 03:57:47.109710 19730 slave.cpp:8177] Handling resource provider message 'UPDATE_OPERATION_STATUS: (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_FAILED, status update state: OPERATION_FAILED)'
I0406 03:57:47.111793 19730 slave.cpp:8630] Updating the state of operation with no ID (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_FAILED, status update state: OPERATION_FAILED)
I0406 03:57:47.112669 19730 slave.cpp:8384] Forwarding status update of operation with no ID (operation_uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:47.114004 19722 master.cpp:11826] Updating the state of operation '' (uuid: b8f6826b-5ed6-4a79-8bae-1b5375557c91) for framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FAILED)
I0406 03:57:47.116047 19726 hierarchical.cpp:1266] Recovered disk(allocated: storage)(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations: [(DYNAMIC,storage)])[MOUNT(org.apache.mesos.csi.test.local,43a6ba73-0479-402b-970b-f79d1b40b4fd,test)]:4096, allocated: {}) on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 from framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:47.116262 19722 slave.cpp:4201] Ignoring new checkpointed resources and operations identical to the current version
I0406 03:57:47.119058 19727 provider.cpp:455] Received ACKNOWLEDGE_OPERATION_STATUS event
I0406 03:57:47.120275 19727 status_update_manager_process.hpp:252] Received operation status update acknowledgement (UUID: 3f7b8e47-34d8-486f-8332-1fe3bf932225) for stream b8f6826b-5ed6-4a79-8bae-1b5375557c91
I0406 03:57:47.121167 19727 status_update_manager_process.hpp:929] Checkpointing ACK for operation status update OPERATION_FAILED (Status UUID: 3f7b8e47-34d8-486f-8332-1fe3bf932225) for operation UUID b8f6826b-5ed6-4a79-8bae-1b5375557c91 of framework 'e38f1104-337c-4a83-9313-5ca3c4f3737b-0000' on agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
I0406 03:57:47.121685 19719 process.cpp:3588] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
I0406 03:57:47.124140 19717 authorization.cpp:135] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
I0406 03:57:47.196463 19727 status_update_manager_process.hpp:490] Cleaning up operation status update stream b8f6826b-5ed6-4a79-8bae-1b5375557c91
I0406 03:57:47.254029 19726 process.cpp:3588] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
I0406 03:57:47.258350 19722 authorization.cpp:135] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
I0406 03:57:47.323451 19710 process.cpp:3588] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
I0406 03:57:47.326617 19728 authorization.cpp:135] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
I0406 03:57:47.382853 19727 process.cpp:3588] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
I0406 03:57:47.386615 19727 authorization.cpp:135] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
I0406 03:57:47.446585 19708 master.cpp:1410] Framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 disconnected
I0406 03:57:47.447705 19706 slave.cpp:912] Agent terminating
I0406 03:57:47.448158 19708 master.cpp:3296] Deactivating framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:47.448997 19706 manager.cpp:163] Terminating resource provider 2e361302-a76b-45d7-a8d0-03ccd69f7e10
I0406 03:57:47.450157 19719 hierarchical.cpp:453] Deactivated framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:47.451850 19708 master.cpp:3273] Disconnecting framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:47.452548 19708 master.cpp:1425] Giving framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957 0ns to failover
I0406 03:57:47.453588 19708 master.cpp:1295] Agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c) disconnected
I0406 03:57:47.454003 19708 master.cpp:3333] Disconnecting agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c)
I0406 03:57:47.454438 19708 master.cpp:3352] Deactivating agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 at slave(722)@172.17.0.2:45957 (63d3a395c66c)
I0406 03:57:47.455148 19708 master.cpp:9799] Framework failover timeout, removing framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
I0406 03:57:47.455662 19708 master.cpp:10793] Removing framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000 (default) at scheduler-445b66d1-28a8-4220-ad55-040fe241a025@172.17.0.2:45957
E0406 03:57:47.452853 19711 http_connection.hpp:452] End-Of-File received
I0406 03:57:47.455425 19717 hierarchical.cpp:829] Agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0 deactivated
I0406 03:57:47.457118 19717 hierarchical.cpp:1519] Allocation paused
I0406 03:57:47.457720 19711 http_connection.hpp:217] Re-detecting endpoint
I0406 03:57:47.457787 19717 hierarchical.cpp:392] Removed framework e38f1104-337c-4a83-9313-5ca3c4f3737b-0000
I0406 03:57:47.459993 19727 provider.cpp:445] Disconnected from resource provider manager
I0406 03:57:47.460274 19717 hierarchical.cpp:1529] Allocation resumed
I0406 03:57:47.460628 19721 status_update_manager_process.hpp:379] Pausing operation status update manager
I0406 03:57:47.460520 19711 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0406 03:57:47.464576 19711 http_connection.hpp:338] Ignoring disconnection attempt from stale connection
I0406 03:57:47.464888 19711 http_connection.hpp:227] New endpoint detected at http://172.17.0.2:45957/slave(722)/api/v1/resource_provider
I0406 03:57:47.467451 19723 containerizer.cpp:2576] Destroying container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2 in RUNNING state
I0406 03:57:47.467702 19723 containerizer.cpp:3278] Transitioning the state of container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2 from RUNNING to DESTROYING
I0406 03:57:47.468394 19723 launcher.cpp:161] Asked to destroy container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2
I0406 03:57:47.470135 19726 hierarchical.cpp:1595] Performed allocation for 1 agents in 227439ns
I0406 03:57:47.471355 19722 http_connection.hpp:283] Connected with the remote endpoint at http://172.17.0.2:45957/slave(722)/api/v1/resource_provider
I0406 03:57:47.485882 19727 provider.cpp:433] Connected to resource provider manager
I0406 03:57:47.488533 19727 http_connection.hpp:131] Sending 1 call to http://172.17.0.2:45957/slave(722)/api/v1/resource_provider
I0406 03:57:47.491636 19731 process.cpp:2754] Returning '404 Not Found' for '/slave(722)/api/v1/resource_provider'
E0406 03:57:47.498948 19716 provider.cpp:666] Failed to subscribe resource provider with type 'org.apache.mesos.rp.local.storage' and name 'test': Received '404 Not Found' ()
I0406 03:57:47.541036 19711 hierarchical.cpp:1595] Performed allocation for 1 agents in 250513ns
I0406 03:57:47.587788 19709 containerizer.cpp:3117] Container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2 has exited
I0406 03:57:47.591828 19707 provisioner.cpp:597] Ignoring destroy request for unknown container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2
I0406 03:57:47.593438 19707 hierarchical.cpp:1595] Performed allocation for 1 agents in 256999ns
I0406 03:57:47.601320 19728 container_daemon.cpp:189] Invoking post-stop hook for container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2'
I0406 03:57:47.602285 19713 service_manager.cpp:632] Disconnected from endpoint 'unix:///tmp/mesos-csi-KKLSB6/endpoint.sock' of CSI plugin container org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2
I0406 03:57:47.603229 19728 container_daemon.cpp:121] Launching container 'org-apache-mesos-rp-local-storage-test--org-apache-mesos-csi-test-local--1-2'
I0406 03:57:47.641813 19731 process.cpp:2754] Returning '404 Not Found' for '/slave(722)/api/v1'
I0406 03:57:47.758808 19706 master.cpp:1135] Master terminating
I0406 03:57:47.760171 19715 hierarchical.cpp:680] Removed agent e38f1104-337c-4a83-9313-5ca3c4f3737b-S0
[ OK ] StorageLocalResourceProviderTest.RetryRpcWithExponentialBackoff (3567 ms)
[ RUN ] StorageLocalResourceProviderTest.FrameworkTeardownBeforeTerminalOperationStatusUpdate
I0406 03:57:47.797935 19706 cluster.cpp:176] Creating default 'local' authorizer
I0406 03:57:47.804759 19729 master.cpp:440] Master d964305f-74fe-4fc7-93d1-b9108892f51f (63d3a395c66c) started on 172.17.0.2:45957
I0406 03:57:47.805328 19729 master.cpp:443] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --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/WRVJui/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="/mesos/mesos-1.9.0/_inst/share/mesos/webui" --work_dir="/tmp/WRVJui/master" --zk_session_timeout="10secs"
I0406 03:57:47.806350 19729 master.cpp:492] Master only allowing authenticated frameworks to register
I0406 03:57:47.806721 19729 master.cpp:498] Master only allowing authenticated agents to register
I0406 03:57:47.807086 19729 master.cpp:504] Master only allowing authenticated HTTP frameworks to register
I0406 03:57:47.807457 19729 credentials.hpp:37] Loading credentials for authentication from '/tmp/WRVJui/credentials'
I0406 03:57:47.808205 19729 master.cpp:548] Using default 'crammd5' authenticator
I0406 03:57:47.808794 19729 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0406 03:57:47.809396 19729 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0406 03:57:47.810195 19729 http.cpp:965] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0406 03:57:47.811053 19729 master.cpp:629] Authorization enabled
*** Aborted at 1554523067 (unix time) try "date -d @1554523067" if you are using GNU date ***
PC: @ 0x2b03b9aa07ec (unknown)
I0406 03:57:47.816407 19726 hierarchical.cpp:210] Initialized hierarchical allocator process
I0406 03:57:47.820773 19723 master.cpp:2141] Elected as the leading master!
I0406 03:57:47.821238 19723 master.cpp:1664] Recovering from registrar
I0406 03:57:47.822055 19723 registrar.cpp:339] Recovering registrar
I0406 03:57:47.823899 19723 registrar.cpp:383] Successfully fetched the registry (0B) in 1.401344ms
I0406 03:57:47.824663 19723 registrar.cpp:487] Applied 1 operations in 53128ns; attempting to update the registry
I0406 03:57:47.826216 19723 registrar.cpp:544] Successfully updated the registry in 1.117952ms
I0406 03:57:47.832321 19723 registrar.cpp:416] Successfully recovered registrar
I0406 03:57:47.833822 19719 hierarchical.cpp:250] Skipping recovery of hierarchical allocator: nothing to recover
I0406 03:57:47.834339 19723 master.cpp:1790] Recovered 0 agents from the registry (135B); allowing 10mins for agents to reregister
Build timed out (after 240 minutes). Marking the build as failed.
Build was aborted
Jenkins build is back to normal : Mesos-Reviewbot-Linux #651
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot-Linux/651/display/redirect>