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/09/22 16:55:52 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4257

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4257/display/redirect>

------------------------------------------
[...truncated 17.45 MB...]
3: I0922 16:55:45.166766 17170 registrar.cpp:495] Applied 1 operations in 64824ns; attempting to update the registry
3: I0922 16:55:45.167438 17170 registrar.cpp:552] Successfully updated the registry in 605184ns
3: I0922 16:55:45.167613 17168 master.cpp:5969] Admitted agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.168244 17167 slave.cpp:4978] Received ping from slave-observer(430)@172.17.0.3:54946
3: I0922 16:55:45.168386 17167 slave.cpp:1205] Registered with master master@172.17.0.3:54946; given agent ID fd65044d-8282-466f-9977-577e2a87d463-S0
3: I0922 16:55:45.168267 17168 master.cpp:6000] Registered agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I0922 16:55:45.168684 17168 status_update_manager.cpp:184] Resuming sending status updates
3: I0922 16:55:45.168663 17159 hierarchical.cpp:593] Added agent fd65044d-8282-466f-9977-577e2a87d463-S0 (d68894cf14fb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I0922 16:55:45.168802 17167 slave.cpp:1225] Checkpointing SlaveInfo to '/tmp/TaskGroupValidationTest_ExecutorEnvironmentInvalid_n5auYt/meta/slaves/fd65044d-8282-466f-9977-577e2a87d463-S0/slave.info'
3: I0922 16:55:45.169265 17167 slave.cpp:1274] Forwarding total oversubscribed resources {}
3: I0922 16:55:45.169472 17166 master.cpp:6746] Received update of agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb) with total oversubscribed resources {}
3: I0922 16:55:45.169816 17159 hierarchical.cpp:2033] No inverse offers to send out!
3: I0922 16:55:45.169857 17159 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.046169ms
3: I0922 16:55:45.170017 17159 hierarchical.cpp:660] Agent fd65044d-8282-466f-9977-577e2a87d463-S0 (d68894cf14fb) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I0922 16:55:45.170461 17159 master.cpp:7725] Sending 1 offers to framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.171010 17164 sched.cpp:933] Scheduler::resourceOffers took 114581ns
3: I0922 16:55:45.172988 17168 master.cpp:9225] Removing offer fd65044d-8282-466f-9977-577e2a87d463-O0
3: I0922 16:55:45.173195 17168 master.cpp:4164] Processing ACCEPT call for offers: [ fd65044d-8282-466f-9977-577e2a87d463-O0 ] on agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb) for framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.173355 17168 master.cpp:3533] Authorizing framework principal 'test-principal' to launch task 1
3: I0922 16:55:45.173665 17168 master.cpp:3533] Authorizing framework principal 'test-principal' to launch task 2
3: I0922 16:55:45.176681 17168 master.cpp:6961] Sending status update TASK_ERROR for task 1 of framework Test_Framework 'Executor's `CommandInfo` is invalid: Environment variable 'ENV_VAR_KEY' of type 'VALUE' must have a value set'
3: I0922 16:55:45.176887 17168 master.cpp:6961] Sending status update TASK_ERROR for task 2 of framework Test_Framework 'Executor's `CommandInfo` is invalid: Environment variable 'ENV_VAR_KEY' of type 'VALUE' must have a value set'
3: I0922 16:55:45.177420 17168 sched.cpp:1041] Scheduler::statusUpdate took 57605ns
3: I0922 16:55:45.177628 17168 sched.cpp:1041] Scheduler::statusUpdate took 41852ns
3: I0922 16:55:45.178490 17170 master.cpp:7338] Performing implicit task state reconciliation for framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.178505 17166 hierarchical.cpp:1161] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent fd65044d-8282-466f-9977-577e2a87d463-S0 from framework Test_Framework
3: I0922 16:55:45.178580 17166 hierarchical.cpp:1207] Framework Test_Framework filtered agent fd65044d-8282-466f-9977-577e2a87d463-S0 for 5secs
3: I0922 16:55:45.178797 17158 sched.cpp:2021] Asked to stop the driver
3: I0922 16:55:45.178900 17160 sched.cpp:1203] Stopping framework Test_Framework
3: I0922 16:55:45.179245 17168 master.cpp:8406] Processing TEARDOWN call for framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.179343 17168 master.cpp:8418] Removing framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.179437 17168 master.cpp:3267] Deactivating framework Test_Framework (default) at scheduler-fb349663-be8e-46e4-a364-8fc160de9b63@172.17.0.3:54946
3: I0922 16:55:45.179700 17172 hierarchical.cpp:412] Deactivated framework Test_Framework
3: I0922 16:55:45.179776 17172 slave.cpp:3223] Asked to shut down framework Test_Framework by master@172.17.0.3:54946
3: I0922 16:55:45.179800 17172 slave.cpp:3238] Cannot shut down unknown framework Test_Framework
3: I0922 16:55:45.180626 17170 hierarchical.cpp:355] Removed framework Test_Framework
3: I0922 16:55:45.181358 17172 slave.cpp:869] Agent terminating
3: I0922 16:55:45.181572 17159 master.cpp:1321] Agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb) disconnected
3: I0922 16:55:45.181637 17159 master.cpp:3304] Disconnecting agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.181727 17159 master.cpp:3323] Deactivating agent fd65044d-8282-466f-9977-577e2a87d463-S0 at slave(431)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.181910 17168 hierarchical.cpp:690] Agent fd65044d-8282-466f-9977-577e2a87d463-S0 deactivated
3: I0922 16:55:45.194687 17158 master.cpp:1163] Master terminating
3: I0922 16:55:45.195518 17169 hierarchical.cpp:626] Removed agent fd65044d-8282-466f-9977-577e2a87d463-S0
3: [       OK ] TaskGroupValidationTest.ExecutorEnvironmentInvalid (69 ms)
3: [ RUN      ] TaskGroupValidationTest.TaskEnvironmentInvalid
3: I0922 16:55:45.200868 17158 cluster.cpp:162] Creating default 'local' authorizer
3: I0922 16:55:45.204075 17166 master.cpp:445] Master 924ea564-e6e4-4dc4-b8d1-42cec2079fd2 (d68894cf14fb) started on 172.17.0.3:54946
3: I0922 16:55:45.204098 17166 master.cpp:447] 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/0PdxGy/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_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="/usr/local/share/mesos/webui" --work_dir="/tmp/0PdxGy/master" --zk_session_timeout="10secs"
3: I0922 16:55:45.204442 17166 master.cpp:497] Master only allowing authenticated frameworks to register
3: I0922 16:55:45.204452 17166 master.cpp:511] Master only allowing authenticated agents to register
3: I0922 16:55:45.204457 17166 master.cpp:524] Master only allowing authenticated HTTP frameworks to register
3: I0922 16:55:45.204463 17166 credentials.hpp:37] Loading credentials for authentication from '/tmp/0PdxGy/credentials'
3: I0922 16:55:45.204782 17166 master.cpp:569] Using default 'crammd5' authenticator
3: I0922 16:55:45.204926 17166 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I0922 16:55:45.205087 17166 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I0922 16:55:45.205376 17166 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I0922 16:55:45.205541 17166 master.cpp:649] Authorization enabled
3: I0922 16:55:45.205691 17171 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I0922 16:55:45.205708 17159 whitelist_watcher.cpp:77] No whitelist given
3: I0922 16:55:45.208425 17172 master.cpp:2166] Elected as the leading master!
3: I0922 16:55:45.208448 17172 master.cpp:1705] Recovering from registrar
3: I0922 16:55:45.208573 17168 registrar.cpp:347] Recovering registrar
3: I0922 16:55:45.209167 17168 registrar.cpp:391] Successfully fetched the registry (0B) in 529920ns
3: I0922 16:55:45.209275 17168 registrar.cpp:495] Applied 1 operations in 27836ns; attempting to update the registry
3: I0922 16:55:45.209821 17168 registrar.cpp:552] Successfully updated the registry in 489984ns
3: I0922 16:55:45.209935 17168 registrar.cpp:424] Successfully recovered registrar
3: I0922 16:55:45.210307 17165 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I0922 16:55:45.210297 17164 master.cpp:1804] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: W0922 16:55:45.216377 17158 process.cpp:3194] Attempted to spawn already running process files@172.17.0.3:54946
3: I0922 16:55:45.217502 17158 containerizer.cpp:292] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W0922 16:55:45.218102 17158 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W0922 16:55:45.218225 17158 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I0922 16:55:45.218261 17158 provisioner.cpp:255] Using default backend 'copy'
3: I0922 16:55:45.220479 17158 cluster.cpp:448] Creating default 'local' authorizer
3: I0922 16:55:45.222884 17159 slave.cpp:254] Mesos agent started on (432)@172.17.0.3:54946
3: I0922 16:55:45.222903 17159 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/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/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/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/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/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/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/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/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6" --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/TaskGroupValidationTest_TaskEnvironmentInvalid_KJL6tP" --zk_session_timeout="10secs"
3: I0922 16:55:45.223361 17159 credentials.hpp:86] Loading credential for authentication from '/tmp/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/credential'
3: W0922 16:55:45.223482 17158 process.cpp:3194] Attempted to spawn already running process version@172.17.0.3:54946
3: I0922 16:55:45.223521 17159 slave.cpp:287] Agent using credential for: test-principal
3: I0922 16:55:45.223556 17159 credentials.hpp:37] Loading credentials for authentication from '/tmp/TaskGroupValidationTest_TaskEnvironmentInvalid_N1WHh6/http_credentials'
3: I0922 16:55:45.223803 17159 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I0922 16:55:45.223997 17159 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I0922 16:55:45.224550 17158 sched.cpp:232] Version: 1.5.0
3: I0922 16:55:45.225172 17173 sched.cpp:336] New master detected at master@172.17.0.3:54946
3: I0922 16:55:45.225272 17173 sched.cpp:407] Authenticating with master master@172.17.0.3:54946
3: I0922 16:55:45.225288 17173 sched.cpp:414] Using default CRAM-MD5 authenticatee
3: I0922 16:55:45.225244 17159 slave.cpp:585] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I0922 16:55:45.225549 17159 slave.cpp:593] Agent attributes: [  ]
3: I0922 16:55:45.225565 17159 slave.cpp:602] Agent hostname: d68894cf14fb
3: I0922 16:55:45.225572 17171 authenticatee.cpp:121] Creating new client SASL connection
3: I0922 16:55:45.225734 17168 status_update_manager.cpp:177] Pausing sending status updates
3: I0922 16:55:45.225864 17171 master.cpp:7895] Authenticating scheduler-6948c471-c2bd-4e12-b210-6acbe30f7d60@172.17.0.3:54946
3: I0922 16:55:45.225976 17166 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(897)@172.17.0.3:54946
3: I0922 16:55:45.226431 17166 authenticator.cpp:98] Creating new server SASL connection
3: I0922 16:55:45.226691 17160 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I0922 16:55:45.226718 17160 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I0922 16:55:45.226999 17170 authenticator.cpp:204] Received SASL authentication start
3: I0922 16:55:45.227128 17170 authenticator.cpp:326] Authentication requires more steps
3: I0922 16:55:45.227133 17169 state.cpp:64] Recovering state from '/tmp/TaskGroupValidationTest_TaskEnvironmentInvalid_KJL6tP/meta'
3: I0922 16:55:45.227450 17160 authenticatee.cpp:259] Received SASL authentication step
3: I0922 16:55:45.227475 17169 status_update_manager.cpp:203] Recovering status update manager
3: I0922 16:55:45.227653 17168 authenticator.cpp:232] Received SASL authentication step
3: I0922 16:55:45.227699 17168 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd68894cf14fb' server FQDN: 'd68894cf14fb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I0922 16:55:45.227715 17168 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I0922 16:55:45.227777 17168 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I0922 16:55:45.227785 17162 containerizer.cpp:648] Recovering containerizer
3: I0922 16:55:45.227870 17168 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd68894cf14fb' server FQDN: 'd68894cf14fb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I0922 16:55:45.227918 17168 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0922 16:55:45.227931 17168 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0922 16:55:45.227967 17168 authenticator.cpp:318] Authentication success
3: I0922 16:55:45.228216 17165 master.cpp:7925] Successfully authenticated principal 'test-principal' at scheduler-6948c471-c2bd-4e12-b210-6acbe30f7d60@172.17.0.3:54946
3: I0922 16:55:45.228678 17168 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(897)@172.17.0.3:54946
3: I0922 16:55:45.228955 17160 authenticatee.cpp:299] Authentication success
3: I0922 16:55:45.229182 17170 sched.cpp:513] Successfully authenticated with master master@172.17.0.3:54946
3: I0922 16:55:45.229205 17170 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.3:54946
3: *** Aborted at 1506099345 (unix time) try "date -d @1506099345" if you are using GNU date ***
3: I0922 16:55:45.229390 17170 sched.cpp:869] Will retry registration in 1.633200942secs if necessary
3: I0922 16:55:45.229796 17159 master.cpp:2897] Received SUBSCRIBE call for framework 'default' at scheduler-6948c471-c2bd-4e12-b210-6acbe30f7d60@172.17.0.3:54946
3: I0922 16:55:45.229876 17159 master.cpp:2231] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I0922 16:55:45.230172 17167 provisioner.cpp:416] Provisioner recovery complete
3: I0922 16:55:45.230448 17168 slave.cpp:6322] Finished recovery
3: I0922 16:55:45.230875 17168 slave.cpp:6504] Querying resource estimator for oversubscribable resources
3: I0922 16:55:45.231138 17159 master.cpp:2977] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I0922 16:55:45.231199 17170 status_update_manager.cpp:177] Pausing sending status updates
3: I0922 16:55:45.231261 17162 slave.cpp:1002] New master detected at master@172.17.0.3:54946
3: I0922 16:55:45.231484 17159 master.cpp:6681] Updating info for framework Test_Framework
3: I0922 16:55:45.231487 17162 slave.cpp:1037] Detecting new master
3: I0922 16:55:45.231791 17162 slave.cpp:6518] Received oversubscribable resources {} from the resource estimator
3: I0922 16:55:45.232017 17171 sched.cpp:759] Framework registered with Test_Framework
3: I0922 16:55:45.232059 17171 sched.cpp:773] Scheduler::registered took 21879ns
3: I0922 16:55:45.232156 17174 hierarchical.cpp:303] Added framework Test_Framework
3: I0922 16:55:45.232185 17174 hierarchical.cpp:412] Deactivated framework Test_Framework
3: I0922 16:55:45.232285 17174 hierarchical.cpp:380] Activated framework Test_Framework
3: I0922 16:55:45.232429 17174 hierarchical.cpp:1943] No allocations performed
3: I0922 16:55:45.232460 17174 hierarchical.cpp:2033] No inverse offers to send out!
3: I0922 16:55:45.232497 17174 hierarchical.cpp:1486] Performed allocation for 0 agents in 107057ns
3: I0922 16:55:45.233758 17166 slave.cpp:1064] Authenticating with master master@172.17.0.3:54946
3: I0922 16:55:45.233810 17166 slave.cpp:1075] Using default CRAM-MD5 authenticatee
3: I0922 16:55:45.234092 17169 authenticatee.cpp:121] Creating new client SASL connection
3: I0922 16:55:45.234346 17167 master.cpp:7895] Authenticating slave(432)@172.17.0.3:54946
3: I0922 16:55:45.234549 17168 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(898)@172.17.0.3:54946
3: I0922 16:55:45.234784 17170 authenticator.cpp:98] Creating new server SASL connection
3: I0922 16:55:45.234952 17161 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I0922 16:55:45.235008 17161 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I0922 16:55:45.235148 17161 authenticator.cpp:204] Received SASL authentication start
3: I0922 16:55:45.235275 17161 authenticator.cpp:326] Authentication requires more steps
3: I0922 16:55:45.235360 17172 authenticatee.cpp:259] Received SASL authentication step
3: I0922 16:55:45.235471 17161 authenticator.cpp:232] Received SASL authentication step
3: I0922 16:55:45.235492 17161 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd68894cf14fb' server FQDN: 'd68894cf14fb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I0922 16:55:45.235499 17161 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I0922 16:55:45.235532 17161 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I0922 16:55:45.235559 17161 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd68894cf14fb' server FQDN: 'd68894cf14fb' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I0922 16:55:45.235575 17161 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0922 16:55:45.235584 17161 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0922 16:55:45.235599 17161 authenticator.cpp:318] Authentication success
3: I0922 16:55:45.235746 17159 authenticatee.cpp:299] Authentication success
3: I0922 16:55:45.235782 17161 master.cpp:7925] Successfully authenticated principal 'test-principal' at slave(432)@172.17.0.3:54946
3: I0922 16:55:45.235839 17171 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(898)@172.17.0.3:54946
3: I0922 16:55:45.236163 17159 slave.cpp:1159] Successfully authenticated with master master@172.17.0.3:54946
3: I0922 16:55:45.236361 17159 slave.cpp:1638] Will retry registration in 2.771193ms if necessary
3: I0922 16:55:45.236616 17167 master.cpp:5769] Received register agent message from slave(432)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.236747 17167 master.cpp:3806] Authorizing agent with principal 'test-principal'
3: I0922 16:55:45.237109 17168 master.cpp:5829] Authorized registration of agent at slave(432)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.237212 17168 master.cpp:5922] Registering agent at slave(432)@172.17.0.3:54946 (d68894cf14fb) with id 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0
3: I0922 16:55:45.237597 17170 registrar.cpp:495] Applied 1 operations in 51213ns; attempting to update the registry
3: I0922 16:55:45.238138 17170 registrar.cpp:552] Successfully updated the registry in 491776ns
3: I0922 16:55:45.238356 17163 master.cpp:5969] Admitted agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 at slave(432)@172.17.0.3:54946 (d68894cf14fb)
3: I0922 16:55:45.238878 17174 slave.cpp:4978] Received ping from slave-observer(431)@172.17.0.3:54946
3: I0922 16:55:45.239094 17174 slave.cpp:1205] Registered with master master@172.17.0.3:54946; given agent ID 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0
3: I0922 16:55:45.238914 17163 master.cpp:6000] Registered agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 at slave(432)@172.17.0.3:54946 (d68894cf14fb) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I0922 16:55:45.239267 17171 status_update_manager.cpp:184] Resuming sending status updates
3: I0922 16:55:45.239437 17169 hierarchical.cpp:593] Added agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 (d68894cf14fb) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I0922 16:55:45.239717 17174 slave.cpp:1225] Checkpointing SlaveInfo to '/tmp/TaskGroupValidationTest_TaskEnvironmentInvalid_KJL6tP/meta/slaves/924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0/slave.info'
3: I0922 16:55:45.240247 17174 slave.cpp:1274] Forwarding total oversubscribed resources {}
3: I0922 16:55:45.240437 17174 master.cpp:6746] Received update of agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 at slave(432)@172.17.0.3:54946 (d68894cf14fb) with total oversubscribed resources {}
3: I0922 16:55:45.240842 17169 hierarchical.cpp:2033] No inverse offers to send out!
3: I0922 16:55:45.240882 17169 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.278828ms
3: I0922 16:55:45.241034 17169 hierarchical.cpp:660] Agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 (d68894cf14fb) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I0922 16:55:45.241407 17167 master.cpp:7725] Sending 1 offers to framework Test_Framework (default) at scheduler-6948c471-c2bd-4e12-b210-6acbe30f7d60@172.17.0.3:54946
3: I0922 16:55:45.241849 17165 sched.cpp:933] Scheduler::resourceOffers took 89128ns
3: I0922 16:55:45.243566 17173 master.cpp:9225] Removing offer 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-O0
3: I0922 16:55:45.243768 17173 master.cpp:4164] Processing ACCEPT call for offers: [ 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-O0 ] on agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 at slave(432)@172.17.0.3:54946 (d68894cf14fb) for framework Test_Framework (default) at scheduler-6948c471-c2bd-4e12-b210-6acbe30f7d60@172.17.0.3:54946
3: I0922 16:55:45.243917 17173 master.cpp:3533] Authorizing framework principal 'test-principal' to launch task 1
3: I0922 16:55:45.244215 17173 master.cpp:3533] Authorizing framework principal 'test-principal' to launch task 2
3: I0922 16:55:45.245923 17173 master.cpp:6961] Sending status update TASK_ERROR for task 1 of framework Test_Framework 'Task '1' is invalid: Task's `CommandInfo` is invalid: Environment variable 'ENV_VAR_KEY' of type 'VALUE' must have a value set'
3: I0922 16:55:45.246084 17173 master.cpp:6961] Sending status update TASK_ERROR for task 2 of framework Test_Framework 'Task '1' is invalid: Task's `CommandInfo` is invalid: Environment variable 'ENV_VAR_KEY' of type 'VALUE' must have a value set'
3: I0922 16:55:45.246356 17169 sched.cpp:1041] Scheduler::statusUpdate took 63691ns
3: I0922 16:55:45.246646 17169 sched.cpp:1041] Scheduler::statusUpdate took 50611ns
3: I0922 16:55:45.247131 17167 hierarchical.cpp:1161] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 from framework Test_Framework
3: I0922 16:55:45.247191 17167 hierarchical.cpp:1207] Framework Test_Framework filtered agent 924ea564-e6e4-4dc4-b8d1-42cec2079fd2-S0 for 5secs
3: PC: @     0x2ae57701e27c process::EventQueue::Consumer::empty()
3: *** SIGSEGV (@0x8) received by PID 17158 (TID 0x2ae5827ff700) from PID 8; stack trace: ***
3:     @     0x2ae577789330 (unknown)
3:     @     0x2ae57701e27c process::EventQueue::Consumer::empty()
3:     @     0x2ae57700410a process::ProcessManager::resume()
3:     @     0x2ae577000824 _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
3:     @     0x2ae577012072 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
3:     @     0x2ae577011fc9 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
3:     @     0x2ae577011f62 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
3:     @     0x2ae579922a60 (unknown)
3:     @     0x2ae577781184 start_thread
3:     @     0x2ae57a18effd (unknown)
3/3 Test #3: MesosTests .......................***Exception: SegFault211.01 sec

67% tests passed, 1 tests failed out of 3

Total Test time (real) = 239.49 sec

The following tests FAILED:
	  3 - MesosTests (SEGFAULT)
Errors while running CTest
make[3]: *** [CMakeFiles/check] Error 8
make[3]: Leaving directory `/mesos/build'
make[2]: *** [CMakeFiles/check.dir/all] Error 2
make[2]: Leaving directory `/mesos/build'
make[1]: *** [CMakeFiles/check.dir/rule] Error 2
make[1]: Leaving directory `/mesos/build'
make: *** [check] Error 2
+ docker rmi mesos-1506096643-9775
Untagged: mesos-1506096643-9775:latest
Deleted: sha256:2ba1fea52ae6f3e7bfc8f96e6c858a86fd90f4b61af2e027f5423c79bc4e977c
Deleted: sha256:f58017cf4225a4072a625b3d2f0eab10a54841af4046f5ddba5b69b0f10115c7
Deleted: sha256:da12310c1f8d6c412a415201a76a3f3772e72169b24b1a91f5b7b5d207761739
Deleted: sha256:098a128a3b8e38953b8e9bf35c8248920d93b2c5971b6ad8218d46044f81edc6
Deleted: sha256:b1dbc9f3a085f2e3e26f80e216c7e7433f9a855c67c2a67d6b70d7ef41883773
Deleted: sha256:d3d997cde2c643d8bdf47ad92367d702453bc1a8f8f5085b2b615c8dd5a424f7
Deleted: sha256:de25d4da732f53ffc8259bd1294091f2acbcfd57eae08e34e37c8d5131fe62c8
Deleted: sha256:c3ede3f5ac69d2ce2ce4ddb5e668aa97128df84f54947f31807c355ca75887b1
Deleted: sha256:c4fd15fbba6b092526fca22f16194812e0f50754eb0630bd045e1799b6936db0
Deleted: sha256:227a536c7d3e95a3fcc3dd9becc8cb620b9b6c70edbefaec1369d5696e7739ef
Deleted: sha256:55e4d5207e59b37c0fe22cc5d6fe2e55b426d01fe5bc982c94eff25ff22ae849
Deleted: sha256:86edd08f773fb61e5c1251d89571dae584c82930d0c1eafab3cc0e1b81d7b364
Deleted: sha256:570fe521cce078ee2e024993700fcbff009eaa004ae2a2e0eae0a36da02b1811
Deleted: sha256:2e97742c13a4af097ab1e010a1e49d7cb2b0aad0c48a372380b038e5a61bd0c7
Deleted: sha256:29dff4baa539652f6d783b68c60a5c9868d9dcf2e7a7bef85cf2e857953f1123
Deleted: sha256:828795232620cc4167f1fba09c2b9b3e29db45ea89d77fec3cf8bea7b3f5ba8a
Deleted: sha256:e407917489df35dc50a841bf7cc9cfab142ef0daacd67d9289313e9fc7dbeb95
Deleted: sha256:6d5e6fcfd9bc84def86ed1808f2ea0a3a027b5fd0a52f561256c6a454e18a9a0
Deleted: sha256:c991311b3a9a73b1e8b92b6030be379a1fdcb6ff82423aabb3109794402aa520
Deleted: sha256:173dfa5e36d271bb25ee4264766080465d8070de6a8d5b2d8c879d500fea91cf
Deleted: sha256:82f9cead4378a8dd246f64a5f080eb2e91a2e1ad0a799fd990266544375d8e82
Deleted: sha256:9c565aec072537551bda705cbdc7033069cb57dac6935c2d5b4226aab0d090fe
Deleted: sha256:11fbe5205a324ad99403cb0de1a933f8f43245e0f70dc880b7a4aba11048c56f
Deleted: sha256:fc88b942e9ee19c4506f249113c19e7040875fe9747c0c1c4718dc47a9fc5eda
Deleted: sha256:99c29e9dbad98ba03c850962bffbb39aa4b967ea417779cf535e26c15a30cbc6
Deleted: sha256:f600d87e2a5e3669e36ca17df52fcbd49d4abddfc25cbe6a1fb2b1deb3d83e39
Deleted: sha256:bba3040386271949b7a2610eec68ba187d703fddd67458a971dec7f8a3292d3d
Deleted: sha256:ce47c11227fd38add80efdd876dd5cca06df003a0fdf136c9a6ba6543da87869
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4258

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4258/display/redirect?page=changes>