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 2017/05/25 16:38:35 UTC

Build failed in Jenkins: Mesos-Reviewbot #18178

See <https://builds.apache.org/job/Mesos-Reviewbot/18178/display/redirect>

------------------------------------------
[...truncated 15.14 MB...]
I0525 16:38:04.272213 31004 authenticator.cpp:232] Received SASL authentication step
I0525 16:38:04.272253 31004 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b143979dc84a' server FQDN: 'b143979dc84a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0525 16:38:04.272269 31004 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0525 16:38:04.272294 31004 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0525 16:38:04.272315 31004 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b143979dc84a' server FQDN: 'b143979dc84a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0525 16:38:04.272326 31004 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0525 16:38:04.272336 31004 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0525 16:38:04.272351 31004 authenticator.cpp:318] Authentication success
I0525 16:38:04.272442 31005 authenticatee.cpp:299] Authentication success
I0525 16:38:04.272464 31008 master.cpp:7517] Successfully authenticated principal 'test-principal' at slave(330)@172.17.0.2:55697
I0525 16:38:04.272598 31006 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(716)@172.17.0.2:55697
I0525 16:38:04.272771 31003 slave.cpp:1079] Successfully authenticated with master master@172.17.0.2:55697
I0525 16:38:04.272955 31003 slave.cpp:1507] Will retry registration in 13.128538ms if necessary
I0525 16:38:04.273102 30999 master.cpp:5429] Received register agent message from slave(330)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.273227 30999 master.cpp:3659] Authorizing agent with principal 'test-principal'
I0525 16:38:04.273568 30997 master.cpp:5489] Authorized registration of agent at slave(330)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.273684 30997 master.cpp:5568] Registering agent at slave(330)@172.17.0.2:55697 (b143979dc84a) with id edda13fd-e775-4a60-b4fc-2a0756755624-S0
I0525 16:38:04.274098 30998 registrar.cpp:493] Applied 1 operations in 57479ns; attempting to update the registry
I0525 16:38:04.274713 30998 registrar.cpp:550] Successfully updated the registry in 561920ns
I0525 16:38:04.274893 30999 master.cpp:5615] Admitted agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 at slave(330)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.275388 31010 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.275555 30999 master.cpp:5646] Registered agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 at slave(330)@172.17.0.2:55697 (b143979dc84a) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0525 16:38:04.275636 31002 slave.cpp:1125] Registered with master master@172.17.0.2:55697; given agent ID edda13fd-e775-4a60-b4fc-2a0756755624-S0
I0525 16:38:04.275657 31002 fetcher.cpp:94] Clearing fetcher cache
I0525 16:38:04.275789 31006 status_update_manager.cpp:184] Resuming sending status updates
I0525 16:38:04.276003 31002 slave.cpp:1153] Checkpointing SlaveInfo to '/tmp/PartitionTest_FailHealthChecksTwice_7M8jL0/meta/slaves/edda13fd-e775-4a60-b4fc-2a0756755624-S0/slave.info'
I0525 16:38:04.275995 31010 hierarchical.cpp:525] Added agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 (b143979dc84a) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0525 16:38:04.276337 31002 slave.cpp:1191] Forwarding total oversubscribed resources {}
I0525 16:38:04.276501 31007 master.cpp:6336] Received update of agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 at slave(330)@172.17.0.2:55697 (b143979dc84a) with total oversubscribed resources {}
I0525 16:38:04.277243 31010 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.277292 31010 hierarchical.cpp:1438] Performed allocation for 1 agents in 1.112562ms
I0525 16:38:04.277721 31002 master.cpp:7317] Sending 1 offers to framework edda13fd-e775-4a60-b4fc-2a0756755624-0000 (default) at scheduler-6fef25a9-4ff0-401e-b8bb-b58887f03ab1@172.17.0.2:55697
I0525 16:38:04.278128 30996 sched.cpp:933] Scheduler::resourceOffers took 48410ns
I0525 16:38:04.280517 31006 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.280586 31006 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.280701 31006 hierarchical.cpp:1438] Performed allocation for 1 agents in 315691ns
I0525 16:38:04.280751 31004 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.281005 31004 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.281183 31004 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.282768 30999 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.282979 31002 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.283030 31002 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.283076 30999 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.283082 31002 hierarchical.cpp:1438] Performed allocation for 1 agents in 243646ns
I0525 16:38:04.283291 30999 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.284886 30998 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.285074 30998 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.285104 31003 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.285187 31003 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.285223 30998 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.285316 31003 hierarchical.cpp:1438] Performed allocation for 1 agents in 353121ns
I0525 16:38:04.287039 31001 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.287163 30995 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.287204 31001 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.287226 30995 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.287358 30995 hierarchical.cpp:1438] Performed allocation for 1 agents in 313837ns
I0525 16:38:04.287433 31001 slave.cpp:5672] Current disk usage 9.73%. Max allowed age: 5.619124975580267days
I0525 16:38:04.287603 31001 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.289356 31004 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.289474 31008 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.289526 31008 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.289527 31004 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.289590 30996 master.cpp:6708] Marking agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 at slave(330)@172.17.0.2:55697 (b143979dc84a) unreachable: health check timed out
I0525 16:38:04.289620 31008 hierarchical.cpp:1438] Performed allocation for 1 agents in 250033ns
I0525 16:38:04.289820 31010 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.291664 31008 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.291718 31008 hierarchical.cpp:1944] No inverse offers to send out!
I0525 16:38:04.291767 31008 hierarchical.cpp:1438] Performed allocation for 1 agents in 195857ns
I0525 16:38:04.292049 31010 slave.cpp:6158] Querying resource estimator for oversubscribable resources
W0525 16:38:04.292225 31000 master.cpp:6696] Not marking agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 unreachable because another unreachable transition is already in progress
I0525 16:38:04.292348 31010 slave.cpp:4751] Received ping from slave-observer(337)@172.17.0.2:55697
I0525 16:38:04.292517 31010 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.293017 30998 registrar.cpp:493] Applied 1 operations in 86833ns; attempting to update the registry
I0525 16:38:04.293859 30998 registrar.cpp:550] Successfully updated the registry in 0ns
I0525 16:38:04.294070 31000 master.cpp:6756] Marked agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 at slave(330)@172.17.0.2:55697 (b143979dc84a) unreachable: health check timed out
I0525 16:38:04.294972 31003 hierarchical.cpp:558] Removed agent edda13fd-e775-4a60-b4fc-2a0756755624-S0
I0525 16:38:04.295120 30999 sched.cpp:959] Rescinded offer edda13fd-e775-4a60-b4fc-2a0756755624-O0
I0525 16:38:04.295191 30999 sched.cpp:970] Scheduler::offerRescinded took 22675ns
I0525 16:38:04.295542 31000 master.cpp:2078] Notifying framework edda13fd-e775-4a60-b4fc-2a0756755624-0000 (default) at scheduler-6fef25a9-4ff0-401e-b8bb-b58887f03ab1@172.17.0.2:55697 of lost agent edda13fd-e775-4a60-b4fc-2a0756755624-S0 (b143979dc84a)
I0525 16:38:04.295790 31002 sched.cpp:1103] Lost agent edda13fd-e775-4a60-b4fc-2a0756755624-S0
I0525 16:38:04.295898 31002 sched.cpp:1114] Scheduler::slaveLost took 67191ns
I0525 16:38:04.299268 31000 process.cpp:3730] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
I0525 16:38:04.300467 30995 http.cpp:798] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
I0525 16:38:04.329246 30976 sched.cpp:2021] Asked to stop the driver
I0525 16:38:04.329393 31003 sched.cpp:1203] Stopping framework edda13fd-e775-4a60-b4fc-2a0756755624-0000
I0525 16:38:04.329741 31006 master.cpp:8000] Processing TEARDOWN call for framework edda13fd-e775-4a60-b4fc-2a0756755624-0000 (default) at scheduler-6fef25a9-4ff0-401e-b8bb-b58887f03ab1@172.17.0.2:55697
I0525 16:38:04.329789 31006 master.cpp:8012] Removing framework edda13fd-e775-4a60-b4fc-2a0756755624-0000 (default) at scheduler-6fef25a9-4ff0-401e-b8bb-b58887f03ab1@172.17.0.2:55697
I0525 16:38:04.329826 31006 master.cpp:3160] Deactivating framework edda13fd-e775-4a60-b4fc-2a0756755624-0000 (default) at scheduler-6fef25a9-4ff0-401e-b8bb-b58887f03ab1@172.17.0.2:55697
I0525 16:38:04.330248 30996 hierarchical.cpp:374] Deactivated framework edda13fd-e775-4a60-b4fc-2a0756755624-0000
I0525 16:38:04.330529 30996 hierarchical.cpp:325] Removed framework edda13fd-e775-4a60-b4fc-2a0756755624-0000
I0525 16:38:04.331815 31000 slave.cpp:794] Agent terminating
I0525 16:38:04.337754 30976 master.cpp:1155] Master terminating
[       OK ] PartitionTest.FailHealthChecksTwice (106 ms)
[----------] 16 tests from PartitionTest (5536 ms total)

[----------] 2 tests from OneWayPartitionTest
[ RUN      ] OneWayPartitionTest.MasterToSlave
I0525 16:38:04.345937 30976 cluster.cpp:162] Creating default 'local' authorizer
I0525 16:38:04.348944 30999 master.cpp:436] Master 9de148fb-71f0-4762-a1f8-19ee54c51e4d (b143979dc84a) started on 172.17.0.2:55697
I0525 16:38:04.348979 30999 master.cpp:438] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/jh9Iud/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --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" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.4.0/_inst/share/mesos/webui" --work_dir="/tmp/jh9Iud/master" --zk_session_timeout="10secs"
I0525 16:38:04.349392 30999 master.cpp:488] Master only allowing authenticated frameworks to register
I0525 16:38:04.349409 30999 master.cpp:502] Master only allowing authenticated agents to register
I0525 16:38:04.349421 30999 master.cpp:515] Master only allowing authenticated HTTP frameworks to register
I0525 16:38:04.349436 30999 credentials.hpp:37] Loading credentials for authentication from '/tmp/jh9Iud/credentials'
I0525 16:38:04.349802 30999 master.cpp:560] Using default 'crammd5' authenticator
I0525 16:38:04.349995 30999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0525 16:38:04.350258 30999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0525 16:38:04.350507 30999 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0525 16:38:04.350749 30999 master.cpp:640] Authorization enabled
I0525 16:38:04.351071 31002 hierarchical.cpp:158] Initialized hierarchical allocator process
I0525 16:38:04.351104 30998 whitelist_watcher.cpp:77] No whitelist given
I0525 16:38:04.353881 31007 master.cpp:2161] Elected as the leading master!
I0525 16:38:04.353922 31007 master.cpp:1700] Recovering from registrar
I0525 16:38:04.354081 31000 registrar.cpp:345] Recovering registrar
I0525 16:38:04.354786 31000 registrar.cpp:389] Successfully fetched the registry (0B) in 656128ns
I0525 16:38:04.354897 31000 registrar.cpp:493] Applied 1 operations in 21564ns; attempting to update the registry
I0525 16:38:04.355664 31000 registrar.cpp:550] Successfully updated the registry in 706048ns
I0525 16:38:04.355784 31000 registrar.cpp:422] Successfully recovered registrar
I0525 16:38:04.356597 30995 hierarchical.cpp:185] Skipping recovery of hierarchical allocator: nothing to recover
I0525 16:38:04.356650 31008 master.cpp:1799] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0525 16:38:04.362735 30976 containerizer.cpp:230] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni,environment_secret
W0525 16:38:04.363369 30976 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
W0525 16:38:04.363492 30976 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0525 16:38:04.363545 30976 provisioner.cpp:255] Using default backend 'copy'
I0525 16:38:04.365710 30976 cluster.cpp:448] Creating default 'local' authorizer
I0525 16:38:04.367251 30996 slave.cpp:225] Mesos agent started on (331)@172.17.0.2:55697
I0525 16:38:04.367282 30996 slave.cpp:226] 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/OneWayPartitionTest_MasterToSlave_PlSCfP/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_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/OneWayPartitionTest_MasterToSlave_PlSCfP/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/OneWayPartitionTest_MasterToSlave_PlSCfP/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.4.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --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/OneWayPartitionTest_MasterToSlave_PlSCfP" --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/OneWayPartitionTest_MasterToSlave_zLsan1"
I0525 16:38:04.367624 30996 credentials.hpp:86] Loading credential for authentication from '/tmp/OneWayPartitionTest_MasterToSlave_PlSCfP/credential'
I0525 16:38:04.367853 30996 slave.cpp:258] Agent using credential for: test-principal
I0525 16:38:04.367888 30996 credentials.hpp:37] Loading credentials for authentication from '/tmp/OneWayPartitionTest_MasterToSlave_PlSCfP/http_credentials'
I0525 16:38:04.368222 30996 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0525 16:38:04.368384 30996 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
I0525 16:38:04.369848 30996 slave.cpp:529] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0525 16:38:04.369922 30996 slave.cpp:537] Agent attributes: [  ]
I0525 16:38:04.369941 30996 slave.cpp:542] Agent hostname: b143979dc84a
I0525 16:38:04.370146 31001 status_update_manager.cpp:177] Pausing sending status updates
I0525 16:38:04.371651 31007 state.cpp:62] Recovering state from '/tmp/OneWayPartitionTest_MasterToSlave_zLsan1/meta'
I0525 16:38:04.372264 30995 status_update_manager.cpp:203] Recovering status update manager
I0525 16:38:04.372542 31010 containerizer.cpp:629] Recovering containerizer
I0525 16:38:04.374358 31002 provisioner.cpp:416] Provisioner recovery complete
I0525 16:38:04.374791 31009 slave.cpp:5976] Finished recovery
I0525 16:38:04.375356 31009 slave.cpp:6158] Querying resource estimator for oversubscribable resources
I0525 16:38:04.375936 30999 status_update_manager.cpp:177] Pausing sending status updates
I0525 16:38:04.375937 30995 slave.cpp:922] New master detected at master@172.17.0.2:55697
I0525 16:38:04.376013 30995 slave.cpp:957] Detecting new master
I0525 16:38:04.376135 30995 slave.cpp:6172] Received oversubscribable resources {} from the resource estimator
I0525 16:38:04.384647 31010 slave.cpp:984] Authenticating with master master@172.17.0.2:55697
I0525 16:38:04.384737 31010 slave.cpp:995] Using default CRAM-MD5 authenticatee
I0525 16:38:04.384969 31001 authenticatee.cpp:121] Creating new client SASL connection
I0525 16:38:04.385306 31005 master.cpp:7487] Authenticating slave(331)@172.17.0.2:55697
I0525 16:38:04.385586 31009 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(717)@172.17.0.2:55697
I0525 16:38:04.385915 30997 authenticator.cpp:98] Creating new server SASL connection
I0525 16:38:04.386203 31001 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0525 16:38:04.386245 31001 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0525 16:38:04.386394 31003 authenticator.cpp:204] Received SASL authentication start
I0525 16:38:04.386466 31003 authenticator.cpp:326] Authentication requires more steps
I0525 16:38:04.386596 30999 authenticatee.cpp:259] Received SASL authentication step
I0525 16:38:04.386754 31005 authenticator.cpp:232] Received SASL authentication step
I0525 16:38:04.386801 31005 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b143979dc84a' server FQDN: 'b143979dc84a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0525 16:38:04.386827 31005 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0525 16:38:04.386873 31005 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0525 16:38:04.386904 31005 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'b143979dc84a' server FQDN: 'b143979dc84a' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0525 16:38:04.386920 31005 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0525 16:38:04.386934 31005 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0525 16:38:04.386953 31005 authenticator.cpp:318] Authentication success
I0525 16:38:04.387059 30997 authenticatee.cpp:299] Authentication success
I0525 16:38:04.387131 31003 master.cpp:7517] Successfully authenticated principal 'test-principal' at slave(331)@172.17.0.2:55697
I0525 16:38:04.387202 31002 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(717)@172.17.0.2:55697
I0525 16:38:04.387553 31008 slave.cpp:1079] Successfully authenticated with master master@172.17.0.2:55697
I0525 16:38:04.387790 31008 slave.cpp:1507] Will retry registration in 1.805022ms if necessary
I0525 16:38:04.388020 30998 master.cpp:5429] Received register agent message from slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.388187 30998 master.cpp:3659] Authorizing agent with principal 'test-principal'
I0525 16:38:04.388716 30999 master.cpp:5489] Authorized registration of agent at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.388839 30999 master.cpp:5568] Registering agent at slave(331)@172.17.0.2:55697 (b143979dc84a) with id 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0
I0525 16:38:04.389379 30996 registrar.cpp:493] Applied 1 operations in 70774ns; attempting to update the registry
I0525 16:38:04.390276 30996 registrar.cpp:550] Successfully updated the registry in 827136ns
I0525 16:38:04.390662 30999 slave.cpp:1507] Will retry registration in 25.959247ms if necessary
I0525 16:38:04.390681 31008 master.cpp:5615] Admitted agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.391592 31005 slave.cpp:4751] Received ping from slave-observer(338)@172.17.0.2:55697
I0525 16:38:04.391609 31008 master.cpp:5646] Registered agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0525 16:38:04.391988 31005 slave.cpp:1125] Registered with master master@172.17.0.2:55697; given agent ID 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0
I0525 16:38:04.392016 31005 fetcher.cpp:94] Clearing fetcher cache
I0525 16:38:04.392145 31008 master.cpp:5429] Received register agent message from slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.392165 31009 hierarchical.cpp:525] Added agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 (b143979dc84a) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0525 16:38:04.392318 31008 master.cpp:3659] Authorizing agent with principal 'test-principal'
I0525 16:38:04.392400 31006 status_update_manager.cpp:184] Resuming sending status updates
I0525 16:38:04.392534 31009 hierarchical.cpp:1854] No allocations performed
I0525 16:38:04.392618 31009 hierarchical.cpp:1438] Performed allocation for 1 agents in 247852ns
I0525 16:38:04.392635 31005 slave.cpp:1153] Checkpointing SlaveInfo to '/tmp/OneWayPartitionTest_MasterToSlave_zLsan1/meta/slaves/9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0/slave.info'
I0525 16:38:04.392979 31009 master.cpp:1313] Agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a) disconnected
I0525 16:38:04.393010 31009 master.cpp:3197] Disconnecting agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.393072 31005 slave.cpp:1191] Forwarding total oversubscribed resources {}
I0525 16:38:04.393139 31009 master.cpp:3216] Deactivating agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.393347 31002 hierarchical.cpp:653] Agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 deactivated
I0525 16:38:04.393383 31009 master.cpp:5489] Authorized registration of agent at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.393506 31009 master.cpp:5537] Removing old disconnected agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a) because a registration attempt occurred
I0525 16:38:04.393563 31009 master.cpp:8365] Removing agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a): a new agent registered at the same address
I0525 16:38:04.393820 31009 master.cpp:5568] Registering agent at slave(331)@172.17.0.2:55697 (b143979dc84a) with id 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S1
I0525 16:38:04.393965 31004 registrar.cpp:493] Applied 1 operations in 64291ns; attempting to update the registry
I0525 16:38:04.394290 31009 master.cpp:6336] Received update of agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a) with total oversubscribed resources {}
I0525 16:38:04.394961 31004 registrar.cpp:550] Successfully updated the registry in 0ns
I0525 16:38:04.395146 30998 master.cpp:8407] Removed agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0 at slave(331)@172.17.0.2:55697 (b143979dc84a): a new agent registered at the same address
I0525 16:38:04.395231 31004 registrar.cpp:493] Applied 1 operations in 66939ns; attempting to update the registry
I0525 16:38:04.395980 31003 hierarchical.cpp:558] Removed agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0
I0525 16:38:04.396111 31004 registrar.cpp:550] Successfully updated the registry in 0ns
I0525 16:38:04.396358 31008 master.cpp:5615] Admitted agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S1 at slave(331)@172.17.0.2:55697 (b143979dc84a)
I0525 16:38:04.396916 31009 slave.cpp:4751] Received ping from slave-observer(339)@172.17.0.2:55697
E0525 16:38:04.397229 30997 slave.cpp:1173] EXIT with status 1: Registered but got wrong id: 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S1 (expected: 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S0). Committing suicide
I0525 16:38:04.397145 31008 master.cpp:5646] Registered agent 9de148fb-71f0-4762-a1f8-19ee54c51e4d-S1 at slave(331)@172.17.0.2:55697 (b143979dc84a) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]

../../src/tests/mock_registrar.cpp:54: ERROR: this mock object (used in test OneWayPartitionTest.MasterToSlave) should be deleted but never is. Its address is @0x2aef6697b470.
../../3rdparty/libprocess/include/process/gmock.hpp:209: ERROR: this mock object (used in test OneWayPartitionTest.MasterToSlave) should be deleted but never is. Its address is @0x2aef66e121b8.
ERROR: 2 leaked mock objects found at program exit.
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.4.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.4.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1495727604-15986
Untagged: mesos-1495727604-15986:latest
Deleted: sha256:9002001954cce9591c9e3705ab3f1ed47756b385b71ebe8c85000b1d81508aec
Deleted: sha256:dcd15f3e566813a0daba7a158e5054e680b724eab6a3012ce20aa9424004e37f
Deleted: sha256:28514cd619a92883f2cd8f0dd9edd5ee5138dd9695a6dfdb770e56eed8097434
Deleted: sha256:d50db57e2e1e271ca8cc276c99b0beb787bb116570889b02c2fb0ba12e7c16d1
Deleted: sha256:a1365336a4185ca47671adf4bb93059900d5ea5a7da62091896df861a8f46f35
Deleted: sha256:aed009ba1ebf9e1ce97dc5148039ea7cd4880cd4ac409b19c591b92869ce7496
Deleted: sha256:5b8b1b8ab1efdf95a8c3e8e48bae1de97b6c2d879bb4d3aca20d25f910bd76f7
Deleted: sha256:14e04a77fa9c324f48aebd3a65e55f52280c02e306e02b60d920e0d13b6727f4
Deleted: sha256:e37e23d6be586604b11f338971b8d25e42ed7a431f98a503a83c5bbed3163a0d
Deleted: sha256:06df2c6e1fa1c4a6ad923bac0ffe4e9188ed5b531b9165ca763da5a06074b1c0
Deleted: sha256:06ed7a56955f199e751d7cefeacf64e66e7998f3ede891bb6c3124c0fa0462de
Deleted: sha256:29b5ae7e3328484578b199c0d5da26539e0cae3ec764aa273cba4d3c837ef8ae
Deleted: sha256:c523ad432426100dd3dbb549896ffe330eedf8bb56915c6f4055002cc7afdcaf
Deleted: sha256:f14c303d83c3396c0711480e591bbaec714468f3c2957b0f3ed2abdcb14f4db8
Deleted: sha256:6ee5355998d4e9b162d0ad927034028a61510e7115cf83a8a2cb7b5ee75d5433
Deleted: sha256:520dcafd97f2dae8d3ad91899194f8bdc494da2c78fa8a232e4f58963a09ad42
Deleted: sha256:e416470eef6ab0913a0b3ef48bef043166b2eb17e899084b26b9225487e42db5
Deleted: sha256:f94897b574450bda2b53153d8eb1d440d34301735a5dcfa457eec4eb43bd5f5a
Deleted: sha256:6bc17d766b1117222a2a0adb24534e6c3021caa0475abefa9802ebbdfb5f87be
Deleted: sha256:07338f644950655056b8d5887ac569a5611b1fe319890ece1ff4a86b421ddcdd
Deleted: sha256:87c26526000be18fce5f88c0bd359a0e308cdbd76e84c63d33ef254ac45b3ec7
Deleted: sha256:a8f3c36178cb2e6ff92a148664d4f9381b4400e2ff59824edee8f28302c8700e
Deleted: sha256:261f558f1efd9b1515fa5803dcb1384b8a61c73661755b948b60eba2444780eb
Deleted: sha256:8d20d847a580ca32736b486d97003ccdfdfb736bf3999e57073ecb48b7b725df
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos-Reviewbot #18179

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Reviewbot/18179/display/redirect?page=changes>