Packaging tests fail on ownership check

[jpountz]

I haven't been able to dig much into this failure due to limited time (and the fact that my limited knowledge around Vagrant and bats tests also makes me much slower), but this seed reproduces a failure with the bats tests. Here is a relevant sample from https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+6.3+packaging-tests/154/consoleFull:

08:12:54 ok 187 [SYSTEMD] install elasticsearch
08:12:54 ok 188 [SYSTEMD] daemon reload after install
08:12:54 ok 189 [SYSTEMD] daemon isn't enabled on restart
08:12:54 ok 190 [SYSTEMD] enable
08:13:02 ok 191 [SYSTEMD] start
08:13:03 ok 192 [SYSTEMD] start (running)
08:13:03 ok 193 [SYSTEMD] is active (running)
08:13:03 ok 194 [SYSTEMD] status (running)
08:13:04 ok 195 [SYSTEMD] test elasticsearch
08:13:12 ok 196 [SYSTEMD] restart
08:13:12 ok 197 [SYSTEMD] stop (running)
08:13:12 ok 198 [SYSTEMD] status (stopping)
08:13:12 ok 199 [SYSTEMD] stop (stopped)
08:13:13 ok 200 [SYSTEMD] status (stopped)
08:13:21 ok 201 [SYSTEMD] delete PID_DIR and restart
08:13:29 ok 202 [SYSTEMD] start Elasticsearch with custom JVM options
08:13:32 ok 203 [SYSTEMD] masking systemd-sysctl
08:13:42 ok 204 [SYSTEMD] service file sets limits
08:13:53 ok 205 [SYSTEMD] test runtime directory
08:14:01 ok 206 [SYSTEMD] GC logs exist
08:14:01 ok 207 # skip (sysvinit is supported, but systemd too) [INIT.D] remove any leftover configuration to start elasticsearch on restart
08:14:01 ok 207 # skip (sysvinit is supported, but systemd too) [INIT.D] remove any leftover configuration to start elasticsearch on restart
08:14:01 ok 208 # skip (sysvinit is supported, but systemd too) [INIT.D] install elasticsearch
08:14:01 ok 208 # skip (sysvinit is supported, but systemd too) [INIT.D] install elasticsearch
08:14:01 ok 209 # skip (sysvinit is supported, but systemd too) [INIT.D] elasticsearch fails if startup script is not executable
08:14:01 ok 209 # skip (sysvinit is supported, but systemd too) [INIT.D] elasticsearch fails if startup script is not executable
08:14:01 ok 210 # skip (sysvinit is supported, but systemd too) [INIT.D] daemon isn't enabled on restart
08:14:01 ok 210 # skip (sysvinit is supported, but systemd too) [INIT.D] daemon isn't enabled on restart
08:14:01 ok 211 # skip (sysvinit is supported, but systemd too) [INIT.D] start
08:14:01 ok 211 # skip (sysvinit is supported, but systemd too) [INIT.D] start
08:14:02 ok 212 # skip (sysvinit is supported, but systemd too) [INIT.D] status (running)
08:14:02 ok 212 # skip (sysvinit is supported, but systemd too) [INIT.D] status (running)
08:14:02 ok 213 # skip (sysvinit is supported, but systemd too) [INIT.D] test elasticsearch
08:14:02 ok 213 # skip (sysvinit is supported, but systemd too) [INIT.D] test elasticsearch
08:14:02 ok 214 # skip (sysvinit is supported, but systemd too) [INIT.D] restart
08:14:02 ok 214 # skip (sysvinit is supported, but systemd too) [INIT.D] restart
08:14:02 ok 215 # skip (sysvinit is supported, but systemd too) [INIT.D] stop (running)
08:14:02 ok 215 # skip (sysvinit is supported, but systemd too) [INIT.D] stop (running)
08:14:02 ok 216 # skip (sysvinit is supported, but systemd too) [INIT.D] status (stopped)
08:14:02 ok 216 # skip (sysvinit is supported, but systemd too) [INIT.D] status (stopped)
08:14:02 ok 217 # skip (sysvinit is supported, but systemd too) [INIT.D] start Elasticsearch with custom JVM options
08:14:02 ok 217 # skip (sysvinit is supported, but systemd too) [INIT.D] start Elasticsearch with custom JVM options
08:14:02 ok 218 # skip (sysvinit is supported, but systemd too) [INIT.D] delete PID_DIR and restart
08:14:02 ok 218 # skip (sysvinit is supported, but systemd too) [INIT.D] delete PID_DIR and restart
08:14:02 ok 219 # skip (sysvinit is supported, but systemd too) [INIT.D] GC logs exist
08:14:02 ok 219 # skip (sysvinit is supported, but systemd too) [INIT.D] GC logs exist
08:14:02 ok 220 # skip (sysvinit is supported, but systemd too) [INIT.D] sysctl is run when the value set is too small
08:14:02 ok 220 # skip (sysvinit is supported, but systemd too) [INIT.D] sysctl is run when the value set is too small
08:14:02 ok 221 # skip (sysvinit is supported, but systemd too) [INIT.D] sysctl is not run when it already has a larger or equal value set
08:14:02 ok 221 # skip (sysvinit is supported, but systemd too) [INIT.D] sysctl is not run when it already has a larger or equal value set
08:14:02 ok 222 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] install old version
08:14:02 ok 222 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] install old version
08:14:02 ok 223 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] start old version
08:14:02 ok 223 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] start old version
08:14:02 ok 224 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] check elasticsearch version is old version
08:14:02 ok 224 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] check elasticsearch version is old version
08:14:02 ok 225 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] index some documents into a few indexes
08:14:02 ok 225 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] index some documents into a few indexes
08:14:02 ok 226 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] verify that the documents are there
08:14:02 ok 226 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] verify that the documents are there
08:14:02 ok 227 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] stop old version
08:14:02 ok 227 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] stop old version
08:14:02 ok 228 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] install version under test
08:14:02 ok 228 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] install version under test
08:14:02 ok 229 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] start version under test
08:14:02 ok 229 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] start version under test
08:14:02 ok 230 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] check elasticsearch version is version under test
08:14:02 ok 230 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] check elasticsearch version is version under test
08:14:03 ok 231 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] verify that the documents are there after restart
08:14:03 ok 231 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] verify that the documents are there after restart
08:14:03 ok 232 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] stop version under test
08:14:03 ok 232 # skip (upgrade cannot happen from pre 6.3.0 to elasticsearch-oss) [UPGRADE] stop version under test
08:14:05 ok 233 [REINSTALL] install
08:14:05 ok 234 [REINSTALL] purge elasticsearch
08:14:05 ok 235 [REINSTALL] chown directories
08:14:07 ok 236 [REINSTALL] reinstall elasticsearch
08:14:07 ok 237 [REINSTALL] check ownership
08:14:07 :qa:vagrant:vagrantOpensuse42#batsPackagingTest FAILED
08:14:07 REPRODUCE WITH: ./gradlew :qa:vagrant:vagrantOpensuse42#batsPackagingTest -Dtests.seed=724533D49F2B2E52 
08:14:07 :qa:vagrant:vagrantOpensuse42#batsPackagingTest (Thread[Task worker for ':' Thread 3,5,main]) completed. Took 13 mins 51.006 secs.
08:14:07 :qa:vagrant:vagrantOpensuse42#halt (Thread[Task worker for ':' Thread 3,5,main]) started.
08:14:07 :qa:vagrant:vagrantOpensuse42#halt
08:14:07 Task ':qa:vagrant:vagrantOpensuse42#halt' is not up-to-date because:
08:14:07   Task has not declared any outputs.
08:14:07 Starting process 'command 'vagrant''. Working directory: /var/lib/jenkins/workspace/elastic+elasticsearch+6.3+packaging-tests/qa/vagrant Command: vagrant halt opensuse-42
08:14:07 Successfully started process 'command 'vagrant''
08:14:08 ==> opensuse-42: Removing cache buckets symlinks...
08:14:10 ==> opensuse-42: Attempting graceful shutdown of VM...
08:14:20 :qa:vagrant:vagrantOpensuse42#halt (Thread[Task worker for ':' Thread 3,5,main]) completed. Took 12.102 secs.
08:14:20 
08:14:20 
08:14:20 FAILURE: Build failed with an exception.
08:14:20 Deprecated Gradle features were used in this build, making it incompatible with Gradle 5.0.
08:14:20 See https://docs.gradle.org/4.5/userguide/command_line_interface.html#sec:command_line_warnings
08:14:20 
08:14:20 393 actionable tasks: 392 executed, 1 up-to-date
08:14:20 * What went wrong:
08:14:20 Execution failed for task ':qa:vagrant:vagrantOpensuse42#batsPackagingTest'.
08:14:20 > Process 'command 'vagrant'' finished with non-zero exit value 1

[elasticmachine]

Pinging @elastic/es-core-infra

[andyb-elastic]

It looks like this is likely related to the other issues we've seen with these tests on the opensuse vm (#30295), I don't see anything in that CI log about ownership checks failing. FWIW it doesn't reproduce for me

# green
# {
#   "error" : {
#     "root_cause" : [
#       {
#         "type" : "index_not_found_exception",
#         "reason" : "no such index",
#         "resource.type" : "index_expression",
#         "resource.id" : "library",
#         "index_uuid" : "_na_",
#         "index" : "library"
#       }
#     ],
#     "type" : "index_not_found_exception",
#     "reason" : "no such index",
#     "resource.type" : "index_expression",
#     "resource.id" : "library",
#     "index_uuid" : "_na_",
#     "index" : "library"
#   },
#   "status" : 404
# }
# {
#   "error" : {
#     "root_cause" : [
#       {
#         "type" : "unavailable_shards_exception",
#         "reason" : "[library][2] primary shard is not active Timeout: [1m], request: [BulkShardRequest [[library][2]] containing [index {[library][book][2], source[{\n      \"title\": \"Book #2\",\n      \"pages\": 456\n    }]}] and a refresh]"
#       }
#     ],
#     "type" : "unavailable_shards_exception",
#     "reason" : "[library][2] primary shard is not active Timeout: [1m], request: [BulkShardRequest [[library][2]] containing [index {[library][book][2], source[{\n      \"title\": \"Book #2\",\n      \"pages\": 456\n    }]}] and a refresh]"
#   },
#   "status" : 503
# }

packaging-154.txt

[jpountz]

Thanks for looking. I got confused because the seed reproduces for me and I get an error about privileges locally: Expected privileges: 644, found 664 [/usr/share/elasticsearch/README.textile]. I assumed it was the same on CI since the last lines of the log are almost the same but it does seem like the issue is different indeed.

When you tried to reproduce, did you try on 6.3?

[jpountz]

OK, after looking further, I do have more issues when running packaging tests locally. Not sure what the root cause is yet, but this looks like a local problem, so I'll close this one.

[andyb-elastic]

What you saw locally is likely #30799

The fix for those files in the package distributions was #30823 which looks like it didn't make it into 6.3