We're updating the issue view to help you get more done. 

Fix ORM performance tests on Wildfly (they fail silently)

Description

To be precise, the failures are logged but only to the test output, which does not appear in the console, and no top-level exception is thrown. So we didn't notice the failures.

Example:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 11:35:40,226 INFO [org.hibernate.search.batchindexing.impl.SimpleIndexingProgressMonitor] (default task-2) HSEARCH000028: Reindexed 999 entities 11:35:40,226 INFO [stdout] (default task-2) [2017-09-27 11:35:40.226] starting measuring 11:35:40,271 INFO [stdout] (default task-2) ================================================================== 11:35:40,272 INFO [stdout] (default task-2) HIBERNATE SEARCH PERFORMANCE TEST REPORT 11:35:40,272 INFO [stdout] (default task-2) 11:35:40,273 INFO [stdout] (default task-2) SUMMARY 11:35:40,273 INFO [stdout] (default task-2) Name : SmokeTestScenario 11:35:40,274 INFO [stdout] (default task-2) Date : 2017-09-27 11:35 11:35:40,275 INFO [stdout] (default task-2) 11:35:40,276 INFO [stdout] (default task-2) Measured time (HH:mm:ss.SSS) 11:35:40,278 INFO [stdout] (default task-2) MEASURED TASKS : 00:00:00.039 11:35:40,280 INFO [stdout] (default task-2) init database : 00:00:00.330 11:35:40,281 INFO [stdout] (default task-2) init index : 00:00:00.849 11:35:40,282 INFO [stdout] (default task-2) warmup phase : 00:00:00.089 11:35:40,282 INFO [stdout] (default task-2) 11:35:40,282 INFO [stdout] (default task-2) TASKS 11:35:40,284 INFO [stdout] (default task-2) 10x InsertBookTask | sum n/a | avg n/a 11:35:40,286 INFO [stdout] (default task-2) 10x UpdateBookRatingTask | sum n/a | avg n/a 11:35:40,288 INFO [stdout] (default task-2) 10x UpdateBookTotalSoldTask | sum n/a | avg n/a 11:35:40,289 INFO [stdout] (default task-2) 10x QueryBooksByAuthorTask | sum n/a | avg n/a 11:35:40,291 INFO [stdout] (default task-2) 10x QueryBooksByAverageRatingTask | sum n/a | avg n/a 11:35:40,292 INFO [stdout] (default task-2) 10x QueryBooksByBestRatingTask | sum n/a | avg n/a 11:35:40,294 INFO [stdout] (default task-2) 10x QueryBooksByNewestPublishedTask | sum n/a | avg n/a 11:35:40,295 INFO [stdout] (default task-2) 10x QueryBooksBySummaryTask | sum n/a | avg n/a 11:35:40,297 INFO [stdout] (default task-2) 10x QueryBooksByTitleTask | sum n/a | avg n/a 11:35:40,298 INFO [stdout] (default task-2) 10x QueryBooksByTotalSoldTask | sum n/a | avg n/a 11:35:40,298 INFO [stdout] (default task-2) 11:35:40,299 INFO [stdout] (default task-2) TEST CONFIGURATION 11:35:40,299 INFO [stdout] (default task-2) measure performance : false 11:35:40,300 INFO [stdout] (default task-2) threads : 2 11:35:40,301 INFO [stdout] (default task-2) measured cycles : 10 11:35:40,301 INFO [stdout] (default task-2) warmup cycles : 10 11:35:40,302 INFO [stdout] (default task-2) initial book count : 10 11:35:40,303 INFO [stdout] (default task-2) initial autor count : 10 11:35:40,303 INFO [stdout] (default task-2) verbose : false 11:35:40,304 INFO [stdout] (default task-2) measure memory : false 11:35:40,305 INFO [stdout] (default task-2) measure task time : false 11:35:40,306 INFO [stdout] (default task-2) check query results : true 11:35:40,307 INFO [stdout] (default task-2) check index state : true 11:35:40,307 INFO [stdout] (default task-2) 11:35:40,307 INFO [stdout] (default task-2) HIBERNATE SEARCH PROPERTIES 11:35:40,309 INFO [stdout] (default task-2) hibernate.search.default.directory_provider = local-heap 11:35:40,310 INFO [stdout] (default task-2) hibernate.search.default.lucene_version = LUCENE_CURRENT 11:35:40,310 INFO [stdout] (default task-2) 11:35:40,310 INFO [stdout] (default task-2) VERSIONS 11:35:40,311 INFO [stdout] (default task-2) org.hibernate.search : 5.9.0-SNAPSHOT 11:35:40,312 INFO [stdout] (default task-2) org.hibernate : 5.2.11.Final 11:35:40,312 INFO [stdout] (default task-2) 11:35:40,314 INFO [stdout] (default task-2) ================================================================== 11:35:40,315 INFO [stdout] (default task-2) INDEX CHECK... 11:35:40,315 INFO [stdout] (default task-2) 11:35:40,319 INFO [stdout] (default task-2) directory : RAMDirectory@59e1e563 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c656afe 11:35:40,319 INFO [stdout] (default task-2) 11:35:40,327 INFO [stdout] (default task-2) Segments file=segments_2 numSegments=1 version=5.5.4 id=cyje3agk07bn9ocfyrn6yc2xr format= 11:35:40,329 INFO [stdout] (default task-2) 1 of 1: name=_6 maxDoc=999 11:35:40,330 INFO [stdout] (default task-2) version=5.5.4 11:35:40,332 INFO [stdout] (default task-2) id=cyje3agk07bn9ocfyrn6yc2xq 11:35:40,333 INFO [stdout] (default task-2) codec=Lucene54 11:35:40,334 INFO [stdout] (default task-2) compound=false 11:35:40,335 INFO [stdout] (default task-2) numFiles=12 11:35:40,339 INFO [stdout] (default task-2) size (MB)=0.286 11:35:40,346 INFO [stdout] (default task-2) diagnostics = {os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_121, java.vm.version=25.121-b13, lucene.version=5.5.4, mergeMaxNumSegments=1, os.arch=amd64, java.runtime.version=1.8.0_121-b13, source=merge, mergeFactor=6, os.version=4.12.9-300.fc26.x86_64, timestamp=1506504940097} 11:35:40,347 INFO [stdout] (default task-2) no deletions 11:35:40,350 INFO [stdout] (default task-2) test: open reader.........OK [took 0.001 sec] 11:35:40,352 INFO [stdout] (default task-2) test: check integrity.....OK [took 0.001 sec] 11:35:40,353 INFO [stdout] (default task-2) test: check live docs.....OK [took 0.001 sec] 11:35:40,356 INFO [stdout] (default task-2) test: field infos.........OK [8 fields] [took 0.002 sec] 11:35:40,358 INFO [stdout] (default task-2) test: field norms.........OK [3 fields] [took 0.001 sec] 11:35:40,427 INFO [stdout] (default task-2) test: terms, freq, prox...OK [3237 terms; 110078 terms/docs pairs; 146396 tokens] [took 0.066 sec] 11:35:40,440 INFO [stdout] (default task-2) test: stored fields.......OK [5994 total field count; avg 6.0 fields per doc] [took 0.011 sec] 11:35:40,443 INFO [stdout] (default task-2) test: term vectors........OK [0 total term vector count; avg 0.0 term/freq vector fields per doc] [took 0.001 sec] 11:35:40,448 INFO [stdout] (default task-2) test: docvalues...........OK [3 docvalues fields; 0 BINARY; 3 NUMERIC; 0 SORTED; 0 SORTED_NUMERIC; 0 SORTED_SET] [took 0.001 sec] 11:35:40,448 INFO [stdout] (default task-2) 11:35:40,450 INFO [stdout] (default task-2) No problems were detected with this index. 11:35:40,450 INFO [stdout] (default task-2) 11:35:40,451 INFO [stdout] (default task-2) Took 0.126 sec total. 11:35:40,453 INFO [stdout] (default task-2) ================================================================== 11:35:40,461 INFO [stdout] (default task-2) =========================================================================== 11:35:40,462 INFO [stdout] (default task-2) EXCEPTIONS 11:35:40,462 INFO [stdout] (default task-2) 11:35:40,464 INFO [stdout] (default task-2) java.lang.IllegalStateException: A JTA EntityManager cannot use getTransaction() 11:35:40,467 INFO [stdout] (default task-2) at org.hibernate.internal.AbstractSharedSessionContract.getTransaction(AbstractSharedSessionContract.java:382) 11:35:40,469 INFO [stdout] (default task-2) at org.hibernate.internal.AbstractSharedSessionContract.beginTransaction(AbstractSharedSessionContract.java:408) 11:35:40,472 INFO [stdout] (default task-2) at org.hibernate.engine.spi.SessionDelegatorBaseImpl.beginTransaction(SessionDelegatorBaseImpl.java:468) 11:35:40,474 INFO [stdout] (default task-2) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:50) 11:35:40,476 INFO [stdout] (default task-2) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 11:35:40,478 INFO [stdout] (default task-2) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 11:35:40,480 INFO [stdout] (default task-2) at java.lang.Thread.run(Thread.java:745) 11:35:40,481 INFO [stdout] (default task-2) --------------------------------------------------------------- 11:35:40,483 INFO [stdout] (default task-2) java.lang.IllegalStateException: A JTA EntityManager cannot use getTransaction() 11:35:40,486 INFO [stdout] (default task-2) at org.hibernate.internal.AbstractSharedSessionContract.getTransaction(AbstractSharedSessionContract.java:382) 11:35:40,489 INFO [stdout] (default task-2) at org.hibernate.internal.AbstractSharedSessionContract.beginTransaction(AbstractSharedSessionContract.java:408) 11:35:40,491 INFO [stdout] (default task-2) at org.hibernate.engine.spi.SessionDelegatorBaseImpl.beginTransaction(SessionDelegatorBaseImpl.java:468) 11:35:40,493 INFO [stdout] (default task-2) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:50) 11:35:40,495 INFO [stdout] (default task-2) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) (etc.)

Environment

None

Status

Assignee

Yoann Rodière

Reporter

Yoann Rodière

Labels

None

Suitable for new contributors

None

Feedback Requested

None

Components

Fix versions

Priority

Major