[jitsi-dev] ice4j / SocketTimeoutException before RTP starts


#1

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

I've been trying various socket implementations, as well as the default,
and getting the same behavior - audio never starts immediately

This is for host-host communication on 192.168.1.0/24 (no STUN or relay
or NAT mappings)

There may well be issues in the rest of the RTP stack I'm using, but it
does work fine without using the sockets from ice4j (just using a
vanilla DatagramSocket, for example)

ICE COMPLETED

.... 30 seconds or more ....

W/Connector( 877): A net access point has gone useless:
W/Connector( 877): java.net.SocketTimeoutException: Connection timed out
W/Connector( 877): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:263)
W/Connector( 877): at
java.net.DatagramSocket.receive(DatagramSocket.java:414)
  ( W/Connector( 877): at
     daniel.SomeSocketImpl.receive..... if delegating to my own socket
abstraction )
W/Connector( 877): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:557)
W/Connector( 877): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 877): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 877): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 877): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 877): at java.lang.Thread.run(Thread.java:1096)


#2

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

I've been trying various socket implementations, as well as the default,
and getting the same behavior - audio never starts immediately

Attaching (below) a second stack, this time without my DatagramSocket
abstraction - notice the stacks are common up to:

org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java
(lines 555 or 557)

This is for host-host communication on 192.168.1.0/24 (no STUN or relay
or NAT mappings)

There may well be issues in the rest of the RTP stack I'm using, but it
does work fine without using the sockets from ice4j (just using a
vanilla DatagramSocket, for example)

ICE COMPLETED

.... 30 seconds or more ....

W/Connector( 877): A net access point has gone useless:
W/Connector( 877): java.net.SocketTimeoutException: Connection timed out
W/Connector( 877): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:263)
W/Connector( 877): at
java.net.DatagramSocket.receive(DatagramSocket.java:414)
  ( W/Connector( 877): at
     daniel.SomeSocketImpl.receive..... if delegating to my own socket
abstraction )
W/Connector( 877): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:557)
W/Connector( 877): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 877): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 877): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 877): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 877): at java.lang.Thread.run(Thread.java:1096)

W/Connector( 4612): A net access point has gone useless:
W/Connector( 4612): java.net.SocketTimeoutException: Try again
W/Connector( 4612): at
org.apache.harmony.luni.platform.OSNetworkSystem.recv(Native Method)
W/Connector( 4612): at
dalvik.system.BlockGuard$WrappedNetworkSystem.recv(BlockGuard.java:321)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.doRecv(PlainDatagramSocketImpl.java:172)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:181)
W/Connector( 4612): at
java.net.DatagramSocket.receive(DatagramSocket.java:402)
W/Connector( 4612): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:555)
W/Connector( 4612): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 4612): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 4612): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 4612): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 4612): at java.lang.Thread.run(Thread.java:1027)

···

On 12/01/12 18:55, Daniel Pocock wrote:


#3

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

Just some further observations:

- the RTP implementation has some overlap between send and receive
logic, I've isolated that now so I can see where the problem exists

- I've identified that it can happily send out packets as soon as it
gets the sockets for selected candidates, so there is no sending issue,
and there are definitely packets reaching the peer

- the DatagramSocket instance returned by ICE is MultiplexingDatagramSocket

- the RTP receive thread sets a 1000ms timeout with setSoTimeout()

- However, the RTP receive thread is blocking for quite some time (maybe
30 seconds) on DatagramSocket.receive() - and then, it receives a whole
bunch of packets in a rush and from there everything is somewhat normal

- another observation: when I start the app, the first time I run the
agent, tcpdump can see it sending out packets, sometimes it discovers
the STUN/TURN candidates, sometimes it doesn't, and the ICE protocol
always fails on the first run. On a subsequent run (same instance of
the app), it seems more likely to discover STUN/TURN candidates, and ICE
almost always completes successfully.

All of the above leads me to think something is not quite right in the
receive logic.

···

On 12/01/12 19:25, Daniel Pocock wrote:

On 12/01/12 18:55, Daniel Pocock wrote:

I've been trying various socket implementations, as well as the default,
and getting the same behavior - audio never starts immediately

Attaching (below) a second stack, this time without my DatagramSocket
abstraction - notice the stacks are common up to:

org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java
(lines 555 or 557)

This is for host-host communication on 192.168.1.0/24 (no STUN or relay
or NAT mappings)

There may well be issues in the rest of the RTP stack I'm using, but it
does work fine without using the sockets from ice4j (just using a
vanilla DatagramSocket, for example)

ICE COMPLETED

.... 30 seconds or more ....

W/Connector( 877): A net access point has gone useless:
W/Connector( 877): java.net.SocketTimeoutException: Connection timed out
W/Connector( 877): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:263)
W/Connector( 877): at
java.net.DatagramSocket.receive(DatagramSocket.java:414)
  ( W/Connector( 877): at
     daniel.SomeSocketImpl.receive..... if delegating to my own socket
abstraction )
W/Connector( 877): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:557)
W/Connector( 877): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 877): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 877): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 877): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 877): at java.lang.Thread.run(Thread.java:1096)

W/Connector( 4612): A net access point has gone useless:
W/Connector( 4612): java.net.SocketTimeoutException: Try again
W/Connector( 4612): at
org.apache.harmony.luni.platform.OSNetworkSystem.recv(Native Method)
W/Connector( 4612): at
dalvik.system.BlockGuard$WrappedNetworkSystem.recv(BlockGuard.java:321)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.doRecv(PlainDatagramSocketImpl.java:172)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:181)
W/Connector( 4612): at
java.net.DatagramSocket.receive(DatagramSocket.java:402)
W/Connector( 4612): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:555)
W/Connector( 4612): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 4612): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 4612): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 4612): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 4612): at java.lang.Thread.run(Thread.java:1027)


#4

Hi Daniel,

Le 12/01/12 23:46, Daniel Pocock a �crit :

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

Just some further observations:

- the RTP implementation has some overlap between send and receive
logic, I've isolated that now so I can see where the problem exists

- I've identified that it can happily send out packets as soon as it
gets the sockets for selected candidates, so there is no sending issue,
and there are definitely packets reaching the peer

- the DatagramSocket instance returned by ICE is MultiplexingDatagramSocket

- the RTP receive thread sets a 1000ms timeout with setSoTimeout()

Just to be sure, is it your application/lib that sets the timeout on the socket ? Is it necessary ?

- However, the RTP receive thread is blocking for quite some time (maybe
30 seconds) on DatagramSocket.receive() - and then, it receives a whole
bunch of packets in a rush and from there everything is somewhat normal

Maybe it has to do with receive buffer size of the socket. Try to set a lower value with socket.setReceiveBufferSize(size).

- another observation: when I start the app, the first time I run the
agent, tcpdump can see it sending out packets, sometimes it discovers
the STUN/TURN candidates, sometimes it doesn't, and the ICE protocol
always fails on the first run. On a subsequent run (same instance of
the app), it seems more likely to discover STUN/TURN candidates, and ICE
almost always completes successfully.

Do you use a public STUN server or your own ? Maybe you should increase STUN retransmission timeout delay.

···

On 12/01/12 19:25, Daniel Pocock wrote:

On 12/01/12 18:55, Daniel Pocock wrote:

All of the above leads me to think something is not quite right in the
receive logic.

I've been trying various socket implementations, as well as the default,
and getting the same behavior - audio never starts immediately

Attaching (below) a second stack, this time without my DatagramSocket
abstraction - notice the stacks are common up to:

org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java
(lines 555 or 557)

This is for host-host communication on 192.168.1.0/24 (no STUN or relay
or NAT mappings)

There may well be issues in the rest of the RTP stack I'm using, but it
does work fine without using the sockets from ice4j (just using a
vanilla DatagramSocket, for example)

ICE COMPLETED

.... 30 seconds or more ....

W/Connector( 877): A net access point has gone useless:
W/Connector( 877): java.net.SocketTimeoutException: Connection timed out
W/Connector( 877): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:263)
W/Connector( 877): at
java.net.DatagramSocket.receive(DatagramSocket.java:414)
   ( W/Connector( 877): at
      daniel.SomeSocketImpl.receive..... if delegating to my own socket
abstraction )
W/Connector( 877): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:557)
W/Connector( 877): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 877): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 877): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 877): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 877): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 877): at java.lang.Thread.run(Thread.java:1096)

W/Connector( 4612): A net access point has gone useless:
W/Connector( 4612): java.net.SocketTimeoutException: Try again
W/Connector( 4612): at
org.apache.harmony.luni.platform.OSNetworkSystem.recv(Native Method)
W/Connector( 4612): at
dalvik.system.BlockGuard$WrappedNetworkSystem.recv(BlockGuard.java:321)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.doRecv(PlainDatagramSocketImpl.java:172)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:181)
W/Connector( 4612): at
java.net.DatagramSocket.receive(DatagramSocket.java:402)
W/Connector( 4612): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:555)
W/Connector( 4612): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 4612): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 4612): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 4612): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 4612): at java.lang.Thread.run(Thread.java:1027)


#5

Hi Daniel,

Le 12/01/12 23:46, Daniel Pocock a �crit :

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

Just some further observations:

- the RTP implementation has some overlap between send and receive
logic, I've isolated that now so I can see where the problem exists

- I've identified that it can happily send out packets as soon as it
gets the sockets for selected candidates, so there is no sending issue,
and there are definitely packets reaching the peer

- the DatagramSocket instance returned by ICE is
MultiplexingDatagramSocket

- the RTP receive thread sets a 1000ms timeout with setSoTimeout()

Just to be sure, is it your application/lib that sets the timeout on
the socket ? Is it necessary ?

I am adapting existing code to use ice4j - so I am trying to use it with
the minimum modifications

If I substitute a normal DatagramSocket, there is no problem with the
timeout logic in the RTP receiver

The timeout logic is part of this RTP implementation - it is intended to
ensure the thread doesn't block indefinitely if packets stop coming from
the peer.

- However, the RTP receive thread is blocking for quite some time (maybe
30 seconds) on DatagramSocket.receive() - and then, it receives a whole
bunch of packets in a rush and from there everything is somewhat normal

Maybe it has to do with receive buffer size of the socket. Try to set a
lower value with socket.setReceiveBufferSize(size).

I'm trying that now

Existing value was 110592 on one device, 112640 on another

When I call setReceiveBufferSize(1024) just before starting the RTP
thread, I notice there is a very long pause - I think something from
ice4j is still trying to receive on the socket

- another observation: when I start the app, the first time I run the
agent, tcpdump can see it sending out packets, sometimes it discovers
the STUN/TURN candidates, sometimes it doesn't, and the ICE protocol
always fails on the first run. On a subsequent run (same instance of
the app), it seems more likely to discover STUN/TURN candidates, and ICE
almost always completes successfully.

Do you use a public STUN server or your own ? Maybe you should increase
STUN retransmission timeout delay.

I have my own - I'm trying both open turnserver and reTurn from resiprocate

···

On 13/01/12 08:54, Sebastien Vincent wrote:

On 12/01/12 19:25, Daniel Pocock wrote:

On 12/01/12 18:55, Daniel Pocock wrote:


#6

Le 13/01/12 12:21, Daniel Pocock a �crit :

Hi Daniel,

Le 12/01/12 23:46, Daniel Pocock a �crit :

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

Just some further observations:

- the RTP implementation has some overlap between send and receive
logic, I've isolated that now so I can see where the problem exists

- I've identified that it can happily send out packets as soon as it
gets the sockets for selected candidates, so there is no sending issue,
and there are definitely packets reaching the peer

- the DatagramSocket instance returned by ICE is
MultiplexingDatagramSocket

- the RTP receive thread sets a 1000ms timeout with setSoTimeout()

Just to be sure, is it your application/lib that sets the timeout on
the socket ? Is it necessary ?

I am adapting existing code to use ice4j - so I am trying to use it with
the minimum modifications

If I substitute a normal DatagramSocket, there is no problem with the
timeout logic in the RTP receiver

The timeout logic is part of this RTP implementation - it is intended to
ensure the thread doesn't block indefinitely if packets stop coming from
the peer.

- However, the RTP receive thread is blocking for quite some time (maybe
30 seconds) on DatagramSocket.receive() - and then, it receives a whole
bunch of packets in a rush and from there everything is somewhat normal

Maybe it has to do with receive buffer size of the socket. Try to set a
lower value with socket.setReceiveBufferSize(size).

I'm trying that now

Existing value was 110592 on one device, 112640 on another

When I call setReceiveBufferSize(1024) just before starting the RTP
thread, I notice there is a very long pause - I think something from
ice4j is still trying to receive on the socket

I suggest you debug in org.ice4j.socket.MultiplexingDatagramSocket's receive(List<DatagramPacket> received, DatagramPacket p) methods and if it is the socket receive() that blocks or something else (MultiplexedDatagramSocket sockets, ...). You can also see in org.ice4j.stack.Connector's run() method where we also use receive() method.

- another observation: when I start the app, the first time I run the
agent, tcpdump can see it sending out packets, sometimes it discovers
the STUN/TURN candidates, sometimes it doesn't, and the ICE protocol
always fails on the first run. On a subsequent run (same instance of
the app), it seems more likely to discover STUN/TURN candidates, and ICE
almost always completes successfully.

Do you use a public STUN server or your own ? Maybe you should increase
STUN retransmission timeout delay.

I have my own - I'm trying both open turnserver and reTurn from resiprocate

OK

Regards,

···

On 13/01/12 08:54, Sebastien Vincent wrote:

On 12/01/12 19:25, Daniel Pocock wrote:

On 12/01/12 18:55, Daniel Pocock wrote:

--
Seb


#7

I can definitely see that there is a blocking receive from Connector.run
- even after ICE is in the terminated state. That is how I get the
stack traces (see below) in the log, even after the call is set up.

Should that simultaneous call to receive() be safe with no impact on the
thread that wants to receive RTP?

Or should that other receive() not be active at all after ICE terminates?

In the org.ice4j.socket.MultiplexingDatagramSocket.receive() method, I
tried changing notifyAll() to just notify() - the RTP seems to work more
quickly, but it is still not perfect.

Do you have any test cases that exercise RTP together with the datagram
sockets from an active Agent?

W/Connector( 4612): A net access point has gone useless:
W/Connector( 4612): java.net.SocketTimeoutException: Try again
W/Connector( 4612): at
org.apache.harmony.luni.platform.OSNetworkSystem.recv(Native Method)
W/Connector( 4612): at
dalvik.system.BlockGuard$WrappedNetworkSystem.recv(BlockGuard.java:321)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.doRecv(PlainDatagramSocketImpl.java:172)
W/Connector( 4612): at
org.apache.harmony.luni.net.PlainDatagramSocketImpl.receive(PlainDatagramSocketImpl.java:181)
W/Connector( 4612): at
java.net.DatagramSocket.receive(DatagramSocket.java:402)
W/Connector( 4612): at
org.ice4j.socket.DelegatingDatagramSocket.receive(DelegatingDatagramSocket.java:555)
W/Connector( 4612): at
org.ice4j.socket.SafeCloseDatagramSocket.receive(SafeCloseDatagramSocket.java:184)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:411)
W/Connector( 4612): at
org.ice4j.socket.MultiplexingDatagramSocket.receive(MultiplexingDatagramSocket.java:466)
W/Connector( 4612): at
org.ice4j.socket.MultiplexedDatagramSocket.receive(MultiplexedDatagramSocket.java:141)
W/Connector( 4612): at
org.ice4j.socket.IceUdpSocketWrapper.receive(IceUdpSocketWrapper.java:50)
W/Connector( 4612): at org.ice4j.stack.Connector.run(Connector.java:175)
W/Connector( 4612): at java.lang.Thread.run(Thread.java:1027)

···

On 13/01/12 13:52, Sebastien Vincent wrote:

Le 13/01/12 12:21, Daniel Pocock a �crit :

On 13/01/12 08:54, Sebastien Vincent wrote:

Hi Daniel,

Le 12/01/12 23:46, Daniel Pocock a �crit :

On 12/01/12 19:25, Daniel Pocock wrote:

On 12/01/12 18:55, Daniel Pocock wrote:

Yesterday, I got my application to the point where ICE completes
successfully

However, I was not getting audio

I've noticed that audio does eventually start after some delay (never
less than 30 seconds)

Just before it starts, I notice a stack appears in the logs on one
endpoint (see below)

Just some further observations:

- the RTP implementation has some overlap between send and receive
logic, I've isolated that now so I can see where the problem exists

- I've identified that it can happily send out packets as soon as it
gets the sockets for selected candidates, so there is no sending issue,
and there are definitely packets reaching the peer

- the DatagramSocket instance returned by ICE is
MultiplexingDatagramSocket

- the RTP receive thread sets a 1000ms timeout with setSoTimeout()

Just to be sure, is it your application/lib that sets the timeout on
the socket ? Is it necessary ?

I am adapting existing code to use ice4j - so I am trying to use it with
the minimum modifications

If I substitute a normal DatagramSocket, there is no problem with the
timeout logic in the RTP receiver

The timeout logic is part of this RTP implementation - it is intended to
ensure the thread doesn't block indefinitely if packets stop coming from
the peer.

- However, the RTP receive thread is blocking for quite some time
(maybe
30 seconds) on DatagramSocket.receive() - and then, it receives a whole
bunch of packets in a rush and from there everything is somewhat normal

Maybe it has to do with receive buffer size of the socket. Try to set a
lower value with socket.setReceiveBufferSize(size).

I'm trying that now

Existing value was 110592 on one device, 112640 on another

When I call setReceiveBufferSize(1024) just before starting the RTP
thread, I notice there is a very long pause - I think something from
ice4j is still trying to receive on the socket

I suggest you debug in org.ice4j.socket.MultiplexingDatagramSocket's
receive(List<DatagramPacket> received, DatagramPacket p) methods and if
it is the socket receive() that blocks or something else
(MultiplexedDatagramSocket sockets, ...). You can also see in
org.ice4j.stack.Connector's run() method where we also use receive()
method.