So here is the log with trace enabled for the test itself an JGroups:
{noformat}
/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/bin/java -Djava.net.preferIPv4Stack=true -Djgroups.bind_addr=127.0.0.1 -Dhibernate.service.allow_crawling=false -Didea.launcher.port=7536 "-Didea.launcher.bin.path=/Applications/Development/IDE/IntelliJ IDEA 13.app/bin" -Dfile.encoding=UTF-8 -classpath "/Applications/Development/IDE/IntelliJ IDEA 13.app/lib/idea_rt.jar:/Applications/Development/IDE/IntelliJ IDEA 13.app/plugins/junit/lib/junit-rt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/javafx-doclet.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/lib/tools.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/htmlconverter.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/JObjC.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_45.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Users/hardy/work/hibernate/git/search/backends/jgroups/target/test-classes:/Users/hardy/work/hibernate/git/search/backends/jgroups/target/classes:/Users/hardy/work/hibernate/git/search/engine/target/classes:/Users/hardy/tmp/m2/org/hibernate/common/hibernate-commons-annotations/4.0.4.Final/hibernate-commons-annotations-4.0.4.Final.jar:/Users/hardy/tmp/m2/org/jboss/logging/jboss-logging/3.1.4.GA/jboss-logging-3.1.4.GA.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-core/4.6.1/lucene-core-4.6.1.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-facet/4.6.1/lucene-facet-4.6.1.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-analyzers-common/4.6.1/lucene-analyzers-common-4.6.1.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-queries/4.6.1/lucene-queries-4.6.1.jar:/Users/hardy/tmp/m2/org/jgroups/jgroups/3.5.0.Beta1/jgroups-3.5.0.Beta1.jar:/Users/hardy/work/hibernate/git/search/serialization/avro/target/classes:/Users/hardy/tmp/m2/org/apache/avro/avro/1.7.6/avro-1.7.6.jar:/Users/hardy/tmp/m2/org/codehaus/jackson/jackson-core-asl/1.9.13/jackson-core-asl-1.9.13.jar:/Users/hardy/tmp/m2/org/codehaus/jackson/jackson-mapper-asl/1.9.13/jackson-mapper-asl-1.9.13.jar:/Users/hardy/tmp/m2/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/Users/hardy/tmp/m2/org/apache/commons/commons-compress/1.5/commons-compress-1.5.jar:/Users/hardy/tmp/m2/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-queryparser/4.6.1/lucene-queryparser-4.6.1.jar:/Users/hardy/tmp/m2/org/apache/lucene/lucene-sandbox/4.6.1/lucene-sandbox-4.6.1.jar:/Users/hardy/tmp/m2/jakarta-regexp/jakarta-regexp/1.4/jakarta-regexp-1.4.jar:/Users/hardy/tmp/m2/junit/junit/4.8.2/junit-4.8.2.jar:/Users/hardy/tmp/m2/log4j/log4j/1.2.16/log4j-1.2.16.jar:/Users/hardy/tmp/m2/org/hibernate/hibernate-testing/4.3.4.Final/hibernate-testing-4.3.4.Final.jar:/Users/hardy/tmp/m2/org/jboss/logging/jboss-logging-annotations/1.2.0.Beta1/jboss-logging-annotations-1.2.0.Beta1.jar:/Users/hardy/tmp/m2/org/hibernate/hibernate-core/4.3.4.Final/hibernate-core-4.3.4.Final.jar:/Users/hardy/tmp/m2/org/jboss/spec/javax/transaction/jboss-transaction-api_1.2_spec/1.0.0.Final/jboss-transaction-api_1.2_spec-1.0.0.Final.jar:/Users/hardy/tmp/m2/dom4j/dom4j/1.6.1/dom4j-1.6.1.jar:/Users/hardy/tmp/m2/xml-apis/xml-apis/1.3.03/xml-apis-1.3.03.jar:/Users/hardy/tmp/m2/org/hibernate/javax/persistence/hibernate-jpa-2.1-api/1.0.0.Final/hibernate-jpa-2.1-api-1.0.0.Final.jar:/Users/hardy/tmp/m2/org/javassist/javassist/3.18.1-GA/javassist-3.18.1-GA.jar:/Users/hardy/tmp/m2/antlr/antlr/2.7.7/antlr-2.7.7.jar:/Users/hardy/tmp/m2/org/jboss/jandex/1.1.0.Final/jandex-1.1.0.Final.jar:/Users/hardy/tmp/m2/org/jboss/byteman/byteman/2.1.4/byteman-2.1.4.jar:/Users/hardy/tmp/m2/org/jboss/byteman/byteman-install/2.1.4/byteman-install-2.1.4.jar:/Users/hardy/tmp/m2/org/jboss/byteman/byteman-bmunit/2.1.4/byteman-bmunit-2.1.4.jar:/Users/hardy/tmp/m2/org/jboss/byteman/byteman-submit/2.1.4/byteman-submit-2.1.4.jar:/Users/hardy/work/hibernate/git/search/orm/target/classes:/Users/hardy/work/hibernate/git/search/orm/target/test-classes:/Users/hardy/work/hibernate/git/search/engine/target/test-classes:/Users/hardy/tmp/m2/com/h2database/h2/1.3.175/h2-1.3.175.jar" com.intellij.rt.execution.application.AppMain com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest,testSynchSerialisationWithTimeout
22:24:28,410 (main) INFO Version:43 - HSEARCH000034: Hibernate Search 5.0.0-SNAPSHOT
22:24:28,458 (main) DEBUG ConfigContext:263 - Setting Lucene compatibility to Version LUCENE_CURRENT
22:24:28,596 (main) DEBUG DispatchMessageSender:115 - HSEARCH200008: Starting JGroups ChannelProvider
22:24:28,599 (main) DEBUG DispatchMessageSender:199 - HSEARCH200014: Starting JGroups channel using configuration 'jgroups-testing-udp.xml'
22:24:29,201 (main) DEBUG Configurator:820 - set property UDP.mcast_group_addr to default value /228.8.8.8
22:24:29,202 (main) DEBUG Configurator:820 - set property UDP.diagnostics_addr to default value /224.0.75.75
22:24:29,640 (main) DEBUG GMS:398 - Sarmakand-2-19291: found state transfer protocol STATE_TRANSFER, setting install_view_locally_first to true
22:24:29,641 (main) TRACE STABLE:455 - Sarmakand-2-19291: stable task started
22:24:29,643 (main) DEBUG UDP:320 - sockets will use interface 127.0.0.1
22:24:29,647 (main) DEBUG UDP:387 - socket information:
mcast_addr=228.8.8.8:45588, bind_addr=/127.0.0.1, ttl=0
sock: bound to 127.0.0.1:56943, receive buffer size=20000, send buffer size=20000
mcast_sock: bound to 127.0.0.1:45588, send buffer size=20000, receive buffer size=20000
22:24:29,649 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on bridge100
22:24:29,649 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on en1
22:24:29,649 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on lo0
-------------------------------------------------------------------
GMS: address=Sarmakand-2-19291, cluster=Hibernate Search Cluster, physical address=127.0.0.1:56943
-------------------------------------------------------------------
22:24:29,660 (main) TRACE UDP:1420 - Sarmakand-2-19291: sending msg to null, src=Sarmakand-2-19291, headers are PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:29,661 (main) TRACE UDP:1450 - Sarmakand-2-19291: looping back message [dst: <null>, src: Sarmakand-2-19291 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL]
22:24:29,662 (INT-1,Hibernate Search Cluster,Sarmakand-2-19291) TRACE UDP:1507 - Sarmakand-2-19291: received [dst: <null>, src: Sarmakand-2-19291 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL], headers are PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:29,665 (TransferQueueBundler,Hibernate Search Cluster,Sarmakand-2-19291) TRACE UDP:2358 - Sarmakand-2-19291: sending 1 msgs (140 bytes (0.22 of max_bundle_size) to 1 dests(s): [Hibernate Search Cluster]
22:24:29,667 (INT-1,Hibernate Search Cluster,Sarmakand-2-19291) TRACE PING:671 - Sarmakand-2-19291: received GET_MBRS_REQ from Sarmakand-2-19291, sending response Sarmakand-2-19291, view_id=, is_server=false, is_coord=false, logical_name=Sarmakand-2-19291, physical_addrs=(1) 127.0.0.1:56943
22:24:29,667 (TransferQueueBundler,Hibernate Search Cluster,Sarmakand-2-19291) ERROR UDP:2405 - JGRP000029: Sarmakand-2-19291: failed sending message to cluster (140 bytes): java.io.IOException: Can't assign requested address, headers: PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:29,668 (INT-1,Hibernate Search Cluster,Sarmakand-2-19291) TRACE UDP:1420 - Sarmakand-2-19291: sending msg to Sarmakand-2-19291, src=Sarmakand-2-19291, headers are PING: [PING: type=GET_MBRS_RSP], UDP: [cluster_name=Hibernate Search Cluster]
22:24:29,669 (INT-1,Hibernate Search Cluster,Sarmakand-2-19291) TRACE UDP:1450 - Sarmakand-2-19291: looping back message [dst: Sarmakand-2-19291, src: Sarmakand-2-19291 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL]
22:24:29,671 (INT-2,Hibernate Search Cluster,Sarmakand-2-19291) TRACE UDP:1507 - Sarmakand-2-19291: received [dst: Sarmakand-2-19291, src: Sarmakand-2-19291 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL], headers are PING: [PING: type=GET_MBRS_RSP], UDP: [cluster_name=Hibernate Search Cluster]
22:24:29,672 (INT-2,Hibernate Search Cluster,Sarmakand-2-19291) TRACE PING:485 - Sarmakand-2-19291: received GET_MBRS_RSP from Sarmakand-2-19291: Sarmakand-2-19291, view_id=, is_server=false, is_coord=false, logical_name=Sarmakand-2-19291, physical_addrs=(1) 127.0.0.1:56943
22:24:29,865 (main) TRACE PING:554 - Sarmakand-2-19291: discovery took 209 ms: responses: 1 total (0 servers (0 coord), 1 clients)
22:24:29,866 (main) TRACE GMS:88 - Sarmakand-2-19291: no initial members discovered: creating cluster as first member
22:24:29,870 (main) DEBUG NAKACK2:1302 -
[Sarmakand-2-19291 setDigest()]
existing digest: []
new digest: Sarmakand-2-19291: [0 (0)]
resulting digest: Sarmakand-2-19291: [0 (0)]
22:24:29,871 (main) DEBUG GMS:690 - Sarmakand-2-19291: installing view [Sarmakand-2-19291|0] (1) [Sarmakand-2-19291]
22:24:29,872 (main) DEBUG STABLE:202 - resuming message garbage collection
22:24:29,873 (main) DEBUG FD_SOCK:338 - Sarmakand-2-19291: VIEW_CHANGE received: [Sarmakand-2-19291]
22:24:29,876 (main) TRACE STABLE:415 - Sarmakand-2-19291: reset digest to Sarmakand-2-19291: [-1]
22:24:29,877 (main) TRACE UFC:519 - new membership: [Sarmakand-2-19291]
22:24:29,878 (main) TRACE MFC:519 - new membership: [Sarmakand-2-19291]
22:24:29,879 (main) DEBUG FLUSH:640 - Sarmakand-2-19291: installing view [Sarmakand-2-19291|0] (1) [Sarmakand-2-19291]
22:24:29,880 (main) DEBUG FLUSH:656 - Sarmakand-2-19291: received STOP_FLUSH, unblocking FLUSH.down() and sending UNBLOCK up
22:24:29,884 (main) TRACE STABLE:415 - Sarmakand-2-19291: reset digest to Sarmakand-2-19291: [-1]
22:24:29,884 (main) DEBUG STABLE:202 - resuming message garbage collection
22:24:29,885 (main) DEBUG GMS:307 - created cluster (first member). My view is [Sarmakand-2-19291|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl
22:24:29,886 (main) INFO DispatchMessageSender:262 - HSEARCH200020: Connected to cluster [ Hibernate Search Cluster ]. The local Address is Sarmakand-2-19291
22:24:29,937 (main) DEBUG DispatchMessageSender:154 - HSEARCH200011: Using JGroups channel having configuration '<config>
<UDP bind_addr="127.0.0.1"
ignore_dont_bundle="true"
oob_thread_pool_keep_alive_time="5000"
timer_keep_alive_time="3000"
external_port="0"
oob_thread_pool_enabled="true"
max_bundle_size="64000"
diagnostics_ttl="8"
physical_addr_max_fetch_attempts="3"
internal_thread_pool_min_threads="2"
receive_on_all_interfaces="false"
mcast_port="45588"
thread_pool_min_threads="2"
thread_pool_keep_alive_time="5000"
internal_thread_pool_queue_enabled="true"
enable_diagnostics="true"
thread_pool_max_threads="8"
internal_thread_pool_queue_max_size="500"
ucast_send_buf_size="20000"
ip_ttl="0"
oob_thread_pool_queue_max_size="100"
enable_bundling="true"
internal_thread_pool_rejection_policy="discard"
thread_pool_queue_enabled="true"
suppress_time_different_cluster_warnings="60000"
diagnostics_port="7500"
timer_rejection_policy="abort"
oob_thread_pool_max_threads="8"
wheel_size="200"
disable_loopback="false"
logical_addr_cache_max_size="500"
ip_mcast="true"
internal_thread_pool_enabled="true"
tick_time="50"
logical_addr_cache_expiration="120000"
thread_pool_rejection_policy="discard"
internal_thread_pool_keep_alive_time="30000"
suppress_time_different_version_warnings="60000"
enable_batching="true"
oob_thread_pool_min_threads="1"
who_has_cache_timeout="2000"
port_range="50"
internal_thread_pool_max_threads="4"
stats="true"
mcast_send_buf_size="20000"
id="21"
diagnostics_addr="224.0.75.75"
mcast_recv_buf_size="20000"
bind_port="0" tos="8"
oob_thread_pool_rejection_policy="discard"
loopback="true"
oob_thread_pool_queue_enabled="false"
name="UDP"
enable_unicast_bundling="true"
time_service_interval="500"
log_discard_msgs_version="true"
thread_pool_enabled="true"
thread_naming_pattern="cl"
ucast_recv_buf_size="20000"
timer_max_threads="4"
timer_queue_max_size="500"
discard_incompatible_packets="true"
ergonomics="true"
bundler_capacity="20000"
loopback_separate_thread="true"
max_bundle_timeout="30"
mcast_group_addr="228.8.8.8"
bind_interface_str=""
loopback_copy="false"
timer_min_threads="2"
log_discard_msgs="true"
bundler_type="transfer-queue"
thread_pool_queue_max_size="10000"
timer_type="new3" />
<PING id="6"
always_send_physical_addr_with_discovery_request="false"
return_entire_cache="false"
num_initial_members="2"
break_on_coord_rsp="true"
use_disk_cache="false"
force_sending_discovery_rsps="true"
stagger_timeout="0"
stats="true"
name="PING"
ergonomics="true"
timeout="200"
num_initial_srv_members="0" />
<MERGE2 id="0" stats="true"
merge_fast="true"
name="MERGE2"
inconsistent_view_threshold="1"
min_interval="10000"
ergonomics="true"
merge_fast_delay="1000"
max_interval="30000" />
<FD_SOCK bind_addr="127.0.0.1"
external_port="0"
port_range="50"
stats="true"
suspect_msg_interval="5000"
client_bind_port="0"
ergonomics="true"
num_tries="3" id="3"
get_cache_timeout="1000"
sock_conn_timeout="1000"
bind_interface_str=""
name="FD_SOCK"
keep_alive="true"
start_port="0" />
<FD_ALL id="29" interval="8000"
stats="true"
name="FD_ALL"
use_time_service="true"
ergonomics="true"
msg_counts_as_heartbeat="false"
timeout="40000"
timeout_check_interval="2000" />
<VERIFY_SUSPECT id="13"
bind_addr="127.0.0.1"
bind_interface_str=""
stats="true"
name="VERIFY_SUSPECT"
num_msgs="1"
ergonomics="true"
use_mcast_rsps="false"
use_icmp="false"
timeout="1500" />
<BARRIER id="0"
max_close_time="60000"
stats="true"
name="BARRIER"
ergonomics="true"
flush_timeout="5000" />
<NAKACK2
use_mcast_xmit_req="false"
use_mcast_xmit="false"
suppress_time_non_member_warnings="60000"
max_msg_batch_size="500"
xmit_from_random_member="false"
stats="true"
xmit_table_max_compaction_time="30000"
log_not_found_msgs="true"
ergonomics="true"
discard_delivered_msgs="true"
print_stability_history_on_failed_xmit="false"
id="57"
become_server_queue_size="50"
max_rebroadcast_timeout="2000"
xmit_table_msgs_per_row="2000"
xmit_table_num_rows="100"
name="NAKACK2"
log_discard_msgs="true"
xmit_table_resize_factor="1.2"
xmit_interval="500" />
<UNICAST3
max_retransmit_time="60000"
max_msg_batch_size="500"
stats="true"
xmit_table_max_compaction_time="60000"
ack_batches_immediately="true"
log_not_found_msgs="true"
ergonomics="true"
conn_close_timeout="60000"
id="64"
conn_expiry_timeout="0"
xmit_table_msgs_per_row="2000"
xmit_table_num_rows="100"
name="UNICAST3"
ack_threshold="5"
xmit_table_resize_factor="1.2"
xmit_interval="500" />
<STABLE id="16"
desired_avg_gossip="50000"
max_bytes="4000000"
stats="true"
cap="0.1"
name="STABLE"
send_stable_msgs_to_coord_only="true"
ergonomics="true"
stability_delay="0" />
<GMS print_local_addr="true"
stats="true"
max_bundling_time="50"
log_collect_msgs="true"
resume_task_timeout="20000"
log_view_warnings="true"
num_prev_views="10"
ergonomics="true"
use_flush_if_present="true"
print_physical_addrs="true"
merge_timeout="5000"
id="14"
membership_change_policy="org.jgroups.protocols.pbcast.GMS$DefaultMembershipPolicy@4132b71e"
num_prev_mbrs="50"
leave_timeout="1000"
use_delta_views="true"
install_view_locally_first="true"
view_bundling="true"
name="GMS"
join_timeout="3000"
handle_concurrent_startup="true"
view_ack_collection_timeout="2000"
max_join_attempts="0" />
<UFC id="45"
max_block_time="5000"
max_credits="2000000"
stats="true"
ignore_synchronous_response="false"
min_credits="800000"
name="UFC"
min_threshold="0.4"
ergonomics="true" />
<MFC id="44"
max_block_time="5000"
max_credits="2000000"
stats="true"
ignore_synchronous_response="false"
min_credits="800000"
name="MFC"
min_threshold="0.4"
ergonomics="true" />
<FRAG2 id="5" frag_size="60000"
stats="true"
name="FRAG2"
ergonomics="true" />
<RSVP id="55" stats="true"
name="RSVP"
resend_interval="2000"
throw_exception_on_timeout="true"
ergonomics="true"
ack_on_delivery="true"
timeout="10000" />
<STATE_TRANSFER id="17"
stats="true"
name="STATE_TRANSFER"
ergonomics="true" />
<FLUSH id="31" stats="true"
start_flush_timeout="2000"
name="FLUSH"
enable_reconciliation="true"
bypass="false"
retry_timeout="2000"
end_flush_timeout="2000"
ergonomics="true"
timeout="8000" />
</config>'
22:24:29,975 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'drinks' using block_for_ack 'true'
22:24:29,986 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index drinks using an exclusive index strategy
22:24:30,284 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Drink.
22:24:30,285 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'stars' using block_for_ack 'true'
22:24:30,285 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index stars using an exclusive index strategy
22:24:30,287 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Star.
22:24:30,288 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'dvds' using block_for_ack 'true'
22:24:30,288 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index dvds using an exclusive index strategy
22:24:30,290 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Dvd.
22:24:30,290 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'books' using block_for_ack 'true'
22:24:30,291 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index books using an exclusive index strategy
22:24:30,292 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Book.
22:24:30,306 (main) DEBUG ConfigContext:263 - Setting Lucene compatibility to Version LUCENE_CURRENT
22:24:30,309 (main) DEBUG DispatchMessageSender:115 - HSEARCH200008: Starting JGroups ChannelProvider
22:24:30,309 (main) DEBUG DispatchMessageSender:199 - HSEARCH200014: Starting JGroups channel using configuration 'jgroups-testing-udp.xml'
22:24:30,408 (main) DEBUG Configurator:820 - set property UDP.mcast_group_addr to default value /228.8.8.8
22:24:30,409 (main) DEBUG Configurator:820 - set property UDP.diagnostics_addr to default value /224.0.75.75
22:24:30,449 (main) DEBUG GMS:398 - Sarmakand-2-55210: found state transfer protocol STATE_TRANSFER, setting install_view_locally_first to true
22:24:30,450 (main) TRACE STABLE:455 - Sarmakand-2-55210: stable task started
22:24:30,451 (main) DEBUG UDP:320 - sockets will use interface 127.0.0.1
22:24:30,452 (main) DEBUG UDP:387 - socket information:
mcast_addr=228.8.8.8:45588, bind_addr=/127.0.0.1, ttl=0
sock: bound to 127.0.0.1:60943, receive buffer size=20000, send buffer size=20000
mcast_sock: bound to 127.0.0.1:45588, send buffer size=20000, receive buffer size=20000
22:24:30,453 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on bridge100
22:24:30,453 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on en1
22:24:30,454 (main) TRACE UDP:215 - joined /224.0.75.75:7500 on lo0
-------------------------------------------------------------------
GMS: address=Sarmakand-2-55210, cluster=Hibernate Search Cluster, physical address=127.0.0.1:60943
-------------------------------------------------------------------
22:24:30,456 (main) TRACE UDP:1420 - Sarmakand-2-55210: sending msg to null, src=Sarmakand-2-55210, headers are PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:30,457 (main) TRACE UDP:1450 - Sarmakand-2-55210: looping back message [dst: <null>, src: Sarmakand-2-55210 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL]
22:24:30,458 (INT-1,Hibernate Search Cluster,Sarmakand-2-55210) TRACE UDP:1507 - Sarmakand-2-55210: received [dst: <null>, src: Sarmakand-2-55210 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL], headers are PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:30,458 (TransferQueueBundler,Hibernate Search Cluster,Sarmakand-2-55210) TRACE UDP:2358 - Sarmakand-2-55210: sending 1 msgs (140 bytes (0.22 of max_bundle_size) to 1 dests(s): [Hibernate Search Cluster]
22:24:30,459 (INT-1,Hibernate Search Cluster,Sarmakand-2-55210) TRACE PING:671 - Sarmakand-2-55210: received GET_MBRS_REQ from Sarmakand-2-55210, sending response Sarmakand-2-55210, view_id=, is_server=false, is_coord=false, logical_name=Sarmakand-2-55210, physical_addrs=(1) 127.0.0.1:60943
22:24:30,459 (TransferQueueBundler,Hibernate Search Cluster,Sarmakand-2-55210) ERROR UDP:2405 - JGRP000029: Sarmakand-2-55210: failed sending message to cluster (140 bytes): java.io.IOException: Can't assign requested address, headers: PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
22:24:30,459 (INT-1,Hibernate Search Cluster,Sarmakand-2-55210) TRACE UDP:1420 - Sarmakand-2-55210: sending msg to Sarmakand-2-55210, src=Sarmakand-2-55210, headers are PING: [PING: type=GET_MBRS_RSP], UDP: [cluster_name=Hibernate Search Cluster]
22:24:30,460 (INT-1,Hibernate Search Cluster,Sarmakand-2-55210) TRACE UDP:1450 - Sarmakand-2-55210: looping back message [dst: Sarmakand-2-55210, src: Sarmakand-2-55210 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL]
22:24:30,461 (INT-2,Hibernate Search Cluster,Sarmakand-2-55210) TRACE UDP:1507 - Sarmakand-2-55210: received [dst: Sarmakand-2-55210, src: Sarmakand-2-55210 (2 headers), size=51 bytes, flags=OOB|DONT_BUNDLE|INTERNAL], headers are PING: [PING: type=GET_MBRS_RSP], UDP: [cluster_name=Hibernate Search Cluster]
22:24:30,461 (INT-2,Hibernate Search Cluster,Sarmakand-2-55210) TRACE PING:485 - Sarmakand-2-55210: received GET_MBRS_RSP from Sarmakand-2-55210: Sarmakand-2-55210, view_id=, is_server=false, is_coord=false, logical_name=Sarmakand-2-55210, physical_addrs=(1) 127.0.0.1:60943
22:24:30,659 (main) TRACE PING:554 - Sarmakand-2-55210: discovery took 203 ms: responses: 1 total (0 servers (0 coord), 1 clients)
22:24:30,659 (main) TRACE GMS:88 - Sarmakand-2-55210: no initial members discovered: creating cluster as first member
22:24:30,660 (main) DEBUG NAKACK2:1302 -
[Sarmakand-2-55210 setDigest()]
existing digest: []
new digest: Sarmakand-2-55210: [0 (0)]
resulting digest: Sarmakand-2-55210: [0 (0)]
22:24:30,660 (main) DEBUG GMS:690 - Sarmakand-2-55210: installing view [Sarmakand-2-55210|0] (1) [Sarmakand-2-55210]
22:24:30,661 (main) DEBUG STABLE:202 - resuming message garbage collection
22:24:30,661 (main) DEBUG FD_SOCK:338 - Sarmakand-2-55210: VIEW_CHANGE received: [Sarmakand-2-55210]
22:24:30,662 (main) TRACE STABLE:415 - Sarmakand-2-55210: reset digest to Sarmakand-2-55210: [-1]
22:24:30,662 (main) TRACE UFC:519 - new membership: [Sarmakand-2-55210]
22:24:30,662 (main) TRACE MFC:519 - new membership: [Sarmakand-2-55210]
22:24:30,662 (main) DEBUG FLUSH:640 - Sarmakand-2-55210: installing view [Sarmakand-2-55210|0] (1) [Sarmakand-2-55210]
22:24:30,663 (main) DEBUG FLUSH:656 - Sarmakand-2-55210: received STOP_FLUSH, unblocking FLUSH.down() and sending UNBLOCK up
22:24:30,663 (main) TRACE STABLE:415 - Sarmakand-2-55210: reset digest to Sarmakand-2-55210: [-1]
22:24:30,663 (main) DEBUG STABLE:202 - resuming message garbage collection
22:24:30,664 (main) DEBUG GMS:307 - created cluster (first member). My view is [Sarmakand-2-55210|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl
22:24:30,664 (main) INFO DispatchMessageSender:262 - HSEARCH200020: Connected to cluster [ Hibernate Search Cluster ]. The local Address is Sarmakand-2-55210
22:24:30,704 (main) DEBUG DispatchMessageSender:154 - HSEARCH200011: Using JGroups channel having configuration '<config>
<UDP bind_addr="127.0.0.1"
ignore_dont_bundle="true"
oob_thread_pool_keep_alive_time="5000"
timer_keep_alive_time="3000"
external_port="0"
oob_thread_pool_enabled="true"
max_bundle_size="64000"
diagnostics_ttl="8"
physical_addr_max_fetch_attempts="3"
internal_thread_pool_min_threads="2"
receive_on_all_interfaces="false"
mcast_port="45588"
thread_pool_min_threads="2"
thread_pool_keep_alive_time="5000"
internal_thread_pool_queue_enabled="true"
enable_diagnostics="true"
thread_pool_max_threads="8"
internal_thread_pool_queue_max_size="500"
ucast_send_buf_size="20000"
ip_ttl="0"
oob_thread_pool_queue_max_size="100"
enable_bundling="true"
internal_thread_pool_rejection_policy="discard"
thread_pool_queue_enabled="true"
suppress_time_different_cluster_warnings="60000"
diagnostics_port="7500"
timer_rejection_policy="abort"
oob_thread_pool_max_threads="8"
wheel_size="200"
disable_loopback="false"
logical_addr_cache_max_size="500"
ip_mcast="true"
internal_thread_pool_enabled="true"
tick_time="50"
logical_addr_cache_expiration="120000"
thread_pool_rejection_policy="discard"
internal_thread_pool_keep_alive_time="30000"
suppress_time_different_version_warnings="60000"
enable_batching="true"
oob_thread_pool_min_threads="1"
who_has_cache_timeout="2000"
port_range="50"
internal_thread_pool_max_threads="4"
stats="true"
mcast_send_buf_size="20000"
id="21"
diagnostics_addr="224.0.75.75"
mcast_recv_buf_size="20000"
bind_port="0" tos="8"
oob_thread_pool_rejection_policy="discard"
loopback="true"
oob_thread_pool_queue_enabled="false"
name="UDP"
enable_unicast_bundling="true"
time_service_interval="500"
log_discard_msgs_version="true"
thread_pool_enabled="true"
thread_naming_pattern="cl"
ucast_recv_buf_size="20000"
timer_max_threads="4"
timer_queue_max_size="500"
discard_incompatible_packets="true"
ergonomics="true"
bundler_capacity="20000"
loopback_separate_thread="true"
max_bundle_timeout="30"
mcast_group_addr="228.8.8.8"
bind_interface_str=""
loopback_copy="false"
timer_min_threads="2"
log_discard_msgs="true"
bundler_type="transfer-queue"
thread_pool_queue_max_size="10000"
timer_type="new3" />
<PING id="6"
always_send_physical_addr_with_discovery_request="false"
return_entire_cache="false"
num_initial_members="2"
break_on_coord_rsp="true"
use_disk_cache="false"
force_sending_discovery_rsps="true"
stagger_timeout="0"
stats="true"
name="PING"
ergonomics="true"
timeout="200"
num_initial_srv_members="0" />
<MERGE2 id="0" stats="true"
merge_fast="true"
name="MERGE2"
inconsistent_view_threshold="1"
min_interval="10000"
ergonomics="true"
merge_fast_delay="1000"
max_interval="30000" />
<FD_SOCK bind_addr="127.0.0.1"
external_port="0"
port_range="50"
stats="true"
suspect_msg_interval="5000"
client_bind_port="0"
ergonomics="true"
num_tries="3" id="3"
get_cache_timeout="1000"
sock_conn_timeout="1000"
bind_interface_str=""
name="FD_SOCK"
keep_alive="true"
start_port="0" />
<FD_ALL id="29" interval="8000"
stats="true"
name="FD_ALL"
use_time_service="true"
ergonomics="true"
msg_counts_as_heartbeat="false"
timeout="40000"
timeout_check_interval="2000" />
<VERIFY_SUSPECT id="13"
bind_addr="127.0.0.1"
bind_interface_str=""
stats="true"
name="VERIFY_SUSPECT"
num_msgs="1"
ergonomics="true"
use_mcast_rsps="false"
use_icmp="false"
timeout="1500" />
<BARRIER id="0"
max_close_time="60000"
stats="true"
name="BARRIER"
ergonomics="true"
flush_timeout="5000" />
<NAKACK2
use_mcast_xmit_req="false"
use_mcast_xmit="false"
suppress_time_non_member_warnings="60000"
max_msg_batch_size="500"
xmit_from_random_member="false"
stats="true"
xmit_table_max_compaction_time="30000"
log_not_found_msgs="true"
ergonomics="true"
discard_delivered_msgs="true"
print_stability_history_on_failed_xmit="false"
id="57"
become_server_queue_size="50"
max_rebroadcast_timeout="2000"
xmit_table_msgs_per_row="2000"
xmit_table_num_rows="100"
name="NAKACK2"
log_discard_msgs="true"
xmit_table_resize_factor="1.2"
xmit_interval="500" />
<UNICAST3
max_retransmit_time="60000"
max_msg_batch_size="500"
stats="true"
xmit_table_max_compaction_time="60000"
ack_batches_immediately="true"
log_not_found_msgs="true"
ergonomics="true"
conn_close_timeout="60000"
id="64"
conn_expiry_timeout="0"
xmit_table_msgs_per_row="2000"
xmit_table_num_rows="100"
name="UNICAST3"
ack_threshold="5"
xmit_table_resize_factor="1.2"
xmit_interval="500" />
<STABLE id="16"
desired_avg_gossip="50000"
max_bytes="4000000"
stats="true"
cap="0.1"
name="STABLE"
send_stable_msgs_to_coord_only="true"
ergonomics="true"
stability_delay="0" />
<GMS print_local_addr="true"
stats="true"
max_bundling_time="50"
log_collect_msgs="true"
resume_task_timeout="20000"
log_view_warnings="true"
num_prev_views="10"
ergonomics="true"
use_flush_if_present="true"
print_physical_addrs="true"
merge_timeout="5000"
id="14"
membership_change_policy="org.jgroups.protocols.pbcast.GMS$DefaultMembershipPolicy@6debbf97"
num_prev_mbrs="50"
leave_timeout="1000"
use_delta_views="true"
install_view_locally_first="true"
view_bundling="true"
name="GMS"
join_timeout="3000"
handle_concurrent_startup="true"
view_ack_collection_timeout="2000"
max_join_attempts="0" />
<UFC id="45"
max_block_time="5000"
max_credits="2000000"
stats="true"
ignore_synchronous_response="false"
min_credits="800000"
name="UFC"
min_threshold="0.4"
ergonomics="true" />
<MFC id="44"
max_block_time="5000"
max_credits="2000000"
stats="true"
ignore_synchronous_response="false"
min_credits="800000"
name="MFC"
min_threshold="0.4"
ergonomics="true" />
<FRAG2 id="5" frag_size="60000"
stats="true"
name="FRAG2"
ergonomics="true" />
<RSVP id="55" stats="true"
name="RSVP"
resend_interval="2000"
throw_exception_on_timeout="true"
ergonomics="true"
ack_on_delivery="true"
timeout="10000" />
<STATE_TRANSFER id="17"
stats="true"
name="STATE_TRANSFER"
ergonomics="true" />
<FLUSH id="31" stats="true"
start_flush_timeout="2000"
name="FLUSH"
enable_reconciliation="true"
bypass="false"
retry_timeout="2000"
end_flush_timeout="2000"
ergonomics="true"
timeout="8000" />
</config>'
22:24:30,717 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'drinks' using block_for_ack 'true'
22:24:30,718 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index drinks using an exclusive index strategy
22:24:30,723 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Drink.
22:24:30,724 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'stars' using block_for_ack 'false'
22:24:30,725 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index stars using an exclusive index strategy
22:24:30,727 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Star.
22:24:30,729 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'dvds' using block_for_ack 'true'
22:24:30,731 (main) WARN BlackHoleBackendQueueProcessor:57 - HSEARCH000001: initialized "blackhole" backend. Index changes will be prepared but discarded!
22:24:30,734 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Dvd.
22:24:30,738 (main) DEBUG JGroupsBackendQueueProcessor:128 - HSEARCH200022: JGroups backend configured for index 'books' using block_for_ack 'false'
22:24:30,738 (main) DEBUG WorkspaceFactory:47 - Starting workspace for index books using an exclusive index strategy
22:24:30,740 (main) DEBUG DocumentBuilderIndexedEntity:184 - Field selection in projections is set to true for entity org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest$Book.
22:24:30,743 (main) TRACE SyncJGroupsBackendTest:116 - [PRESEND] Timestamp: 1395177870743037000
22:24:30,767 (main) TRACE JGroupsBackendQueueTask:69 - Preparing 1 Lucene works to be sent to master node.
22:24:30,768 (main) TRACE JGroupsBackendQueueTask:80 - Filtering: optimized Lucene works are not going to be sent to master node. There is 1 Lucene works after filtering.
22:24:30,774 (main) DEBUG AvroSerializationProvider:107 - HSEARCH000079: Serialization protocol version 1.0 initialized
22:24:31,088 (main) INFO DirectoryBasedIndexManager:163 - HSEARCH000168: Serialization service Avro SerializationProvider v1.0 being used for index 'dvds'
22:24:31,106 (main) TRACE MessageDispatcher:329 - real_dests=[]
22:24:31,107 (main) TRACE MessageDispatcher:333 - destination list is empty, won't send message
22:24:31,109 (main) TRACE JGroupsBackendQueueTask:98 - Lucene works have been sent from slave Sarmakand-2-55210 to master node.
22:24:31,109 (main) TRACE SyncJGroupsBackendTest:123 - [POSTSEND] Timestamp: 1395177871109375000 Diff: 366 ms.
22:24:31,110 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'drinks'
22:24:31,110 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'stars'
22:24:31,110 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'books'
22:24:31,111 (main) INFO DispatchMessageSender:253 - HSEARCH200017: Disconnecting and closing JGroups Channel to cluster 'Hibernate Search Cluster'
22:24:31,114 (main) DEBUG UDP:556 - multicast socket closed
22:24:31,114 (multicast receiver,Hibernate Search Cluster,Sarmakand-2-55210) DEBUG UDP:688 - receiver socket is closed, exception=java.net.SocketException: Socket closed
22:24:31,114 (multicast receiver,Hibernate Search Cluster,Sarmakand-2-55210) DEBUG UDP:698 - multicast receiver thread terminated
22:24:31,115 (unicast receiver,Hibernate Search Cluster,Sarmakand-2-55210) DEBUG UDP:688 - receiver socket is closed, exception=java.net.SocketException: Socket closed
22:24:31,115 (unicast receiver,Hibernate Search Cluster,Sarmakand-2-55210) DEBUG UDP:698 - unicast receiver thread terminated
22:24:31,115 (main) DEBUG UDP:250 - closing sockets and stopping threads
22:24:31,418 (main) INFO BlackHoleBackendQueueProcessor:63 - HSEARCH000002: closed "blackhole" backend.
22:24:31,419 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'drinks'
22:24:31,420 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'stars'
22:24:31,420 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'books'
22:24:31,421 (main) INFO DispatchMessageSender:253 - HSEARCH200017: Disconnecting and closing JGroups Channel to cluster 'Hibernate Search Cluster'
22:24:31,422 (main) DEBUG UDP:556 - multicast socket closed
22:24:31,423 (multicast receiver,Hibernate Search Cluster,Sarmakand-2-19291) DEBUG UDP:688 - receiver socket is closed, exception=java.net.SocketException: Socket closed
22:24:31,423 (multicast receiver,Hibernate Search Cluster,Sarmakand-2-19291) DEBUG UDP:698 - multicast receiver thread terminated
22:24:31,424 (unicast receiver,Hibernate Search Cluster,Sarmakand-2-19291) DEBUG UDP:688 - receiver socket is closed, exception=java.net.SocketException: Socket closed
22:24:31,424 (unicast receiver,Hibernate Search Cluster,Sarmakand-2-19291) DEBUG UDP:698 - unicast receiver thread terminated
22:24:31,424 (main) DEBUG UDP:250 - closing sockets and stopping threads
22:24:31,728 (main) DEBUG AbstractWorkspaceImpl:107 - HSEARCH000108: Shutting down backend for IndexManager 'dvds'
junit.framework.AssertionFailedError: The backend didn't receive any message: something wrong with the test setup of network configuration
at org.hibernate.search.backend.jgroups.impl.SyncJGroupsBackendTest.testSynchSerialisationWithTimeout(SyncJGroupsBackendTest.java:135)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:43)
at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:43)
at org.junit.runners.BlockJUnit4ClassRunner.runNotIgnored(BlockJUnit4ClassRunner.java:79)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:71)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:49)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:202)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:65)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)
{noformat}
Personally, I am having a hard time making sense of this. I set breakpoints into backend and there is really no message received/processed there. I tried to change the xml config file against the default one, makes no difference.
The one thing which I noticed with the JGroups log enabled is:
{noformat}
22:24:29,667 (TransferQueueBundler,Hibernate Search Cluster,Sarmakand-2-19291) ERROR UDP:2405 - JGRP000029: Sarmakand-2-19291: failed sending message to cluster (140 bytes): java.io.IOException: Can't assign requested address, headers: PING: [PING: type=GET_MBRS_REQ, cluster=Hibernate Search Cluster], UDP: [cluster_name=Hibernate Search Cluster]
{noformat}
Anyone has an idea what this could mean?
|
|
